How does partial caching actually work? (I'm not getting the results I expected)

support
1

I’m working on optimizing an eCommerce site built with Hugo. I’m caching some of our most used partials based on the feedback from running hugo --templateMetrics --templateMetricsHints but the results I’m getting are not always as expected.

Example: We have partial that imports a JSON file, does some logic on it, and returns a Hugo dictionary. We use that dictionary in a number of different places in our site, so the partial is always cached (I have triple-checked that it is always called with partialCached and it is never given any caching args).

However, despite this, I see via templateMetrics that the partial is run 11 times. This isn’t even something that runs on every page, (although it is used a lot):

      cache     cumulative       average       maximum
  potential       duration      duration      duration  count  template
      -----     ----------      --------      --------  -----  --------
          0    4.8749971s  443.181554ms    612.9998ms     11  partials/products/get-all-products.html

In contrast, our footer partial, which runs on almost every single page of the site, is only run 3 times after caching it. This is closer to what I’d expect (since we have 2 different languages) although I’m still not sure what’s going on with it running the third time.

      cache     cumulative       average       maximum
  potential       duration      duration      duration  count  template
      -----     ----------      --------      --------  -----  --------
        100     4.0015ms    1.333833ms      3.0009ms      3   partials/footer.html

Note that the footer partial was running 353 times before we started caching it.

The only differences that I can think of between these two partials are that the first one involves a JSON get, a YML get, and has its value passed to js.Build as a “param” on a few different occasions, but I can’t think of why any of those things should matter unless this is some sort of race condition with how the build runs under the hood.

TL;DR:
So my question is: what is it that I don’t understand about partial caching? What other things cause a cached partial to be re-run besides language and caching arguments? Or is this a bug?

For further details, the basic outline of the file in question is like this:

{{/* Import some JSON data and then import data from a YML file */}}
{{- $products := getJSON $.Site.Params.shopifyProducts -}}
{{- $coreProducts := $.Site.Data.en.coreproducts.products -}}

{{/* Do a bunch work with all that raw data and spit out a single Hugo dictionary */}}
{{/* ... */}}

{{/* Return dictionary */}}
{{ return $allProductMetadata }}

If you want to see the entire file in question, see below:


<!-- prettier-ignore -->
{{/**************** 
  * This partial returns a Hugo dictionary containing product 
    metadata for all Products.

  * The variants property of each item has been preserved for compatibility, but 
    at this time, it should not ever be needed as all relevant data from .variants[0]
    is already added to the top level properties of each product.
  
  * If you do not use the "with" pattern to
    call this, that data will simply be dumped onto the DOM. Do not do that.

  * If you only need info about one or two products, you probably want to use one of the following partials instead:
    These two partials both wrap 'get-all-products' with a 'where range' statement in order to pull out only the product object you want 
    - '/partials/products/get-product-by-key'  
    - '/partials/products/get-product-by-id'
****************/}}

{{- $products := getJSON $.Site.Params.shopifyProducts -}}
{{- $coreProducts := $.Site.Data.en.coreproducts.products -}}

{{/* Dev-store config */}}
{{- $isDevStore := false -}}
{{- if eq hugo.Environment "devstore" -}}
  {{- $isDevStore = true -}}
{{- end -}}

{{ warnf (print "Generating all-products array with IsDevstore = " $isDevStore ) }}

{{ $allProductMetadata := slice }}

{{- range $idx, $shopifyProduct := $products.products -}}
  {{ $coreProduct:= "" }}

  {{/* Find corresponding coreproducts.yml entry if it exists */}}
  {{- range $idy, $cProduct := $coreProducts -}}
    {{ if (eq (string $shopifyProduct.id) (cond $isDevStore (string $cProduct.dev_id) (string $cProduct.id) ) ) }}
      {{ $coreProduct = $cProduct }}
      {{ if (not (reflect.IsMap $coreProduct) ) }}
        {{ errorf (print "CoreProduct item was somehow not a map:") }}
        {{ errorf (print $coreProduct ) }}
      {{ end }}
    {{ end }}
  {{ end }}

  {{ $modifiedProduct := $shopifyProduct }}

  {{/* Rename or delete properties as needed from existing properties. */}}
  {{/**********************************************************************************************************************
  Note: 'variant' can only be nil if there are multiple items in 'variants' or
  add to cart actions will fail If we want to be able to choose from multiple
  variants though, 'variant' MUST be nil or add to cart will always just add the
  first variant See 'window.selectVariant()' in 'product.js' and
  'partials/products/variant-select.html' for details.
  **********************************************************************************************************************/}}
  {{ $modifiedProduct = merge $modifiedProduct (dict "admin_graphql_api_id" nil ) }}
  {{ $modifiedProduct = merge $modifiedProduct (dict "barcode"              (index ($modifiedProduct.variants) 0).barcode ) }}
  {{ $modifiedProduct = merge $modifiedProduct (dict "category"             $modifiedProduct.product_type ) }}
  {{ $modifiedProduct = merge $modifiedProduct (dict "gtin12"               (index ($modifiedProduct.variants) 0).barcode ) }}
  {{ $modifiedProduct = merge $modifiedProduct (dict "body_html"            nil ) }}
  {{ $modifiedProduct = merge $modifiedProduct (dict "compare_at_price"     (index ($modifiedProduct.variants) 0).compare_at_price ) }}
  {{ $modifiedProduct = merge $modifiedProduct (dict "grams"                (index ($modifiedProduct.variants) 0).grams ) }}
  {{ $modifiedProduct = merge $modifiedProduct (dict "images"               nil ) }}
  {{ $modifiedProduct = merge $modifiedProduct (dict "inventory_management" (index ($modifiedProduct.variants) 0).inventory_management ) }}
  {{ $modifiedProduct = merge $modifiedProduct (dict "inventory_policy"     (index ($modifiedProduct.variants) 0).inventory_policy ) }}
  {{ $modifiedProduct = merge $modifiedProduct (dict "inventory_quantity"   (index ($modifiedProduct.variants) 0).inventory_quantity ) }}
  {{ $modifiedProduct = merge $modifiedProduct (dict "key"                  $modifiedProduct.handle ) }}
  {{ $modifiedProduct = merge $modifiedProduct (dict "link"                 (print "/products/" $modifiedProduct.handle "/" ) ) }}
  {{ $modifiedProduct = merge $modifiedProduct (dict "name"                 $modifiedProduct.title ) }}
  {{ $modifiedProduct = merge $modifiedProduct (dict "price"                (index ($modifiedProduct.variants) 0).price ) }}
  {{ $modifiedProduct = merge $modifiedProduct (dict "sku"                  (index ($modifiedProduct.variants) 0).sku ) }}
  {{ $modifiedProduct = merge $modifiedProduct (dict "variant"              (cond (lt (len $modifiedProduct.variants) 2) (index ($modifiedProduct.variants) 0).id nil ) ) }}
  {{ $modifiedProduct = merge $modifiedProduct (dict "variantTitle"         (index ($modifiedProduct.variants) 0).title ) }}

  {{/* Substitute and/or add in values from core products (if available) */}}
  {{ with $coreProduct }}
    {{ $modifiedProduct = merge $modifiedProduct (dict "active"             .suggestion.active ) }}
    {{ $modifiedProduct = merge $modifiedProduct (dict "affirm"             .affirm ) }}
    {{ $modifiedProduct = merge $modifiedProduct (dict "hide_guarantee"      .hide_guarantee) }}
    {{ $modifiedProduct = merge $modifiedProduct (dict "href"               .pdp) }}
    {{ $modifiedProduct = merge $modifiedProduct (dict "id"                 (cond $isDevStore .dev_id .id)) }}
    {{ $modifiedProduct = merge $modifiedProduct (dict "isCoreProduct"      true ) }}
    {{ $modifiedProduct = merge $modifiedProduct (dict "image"              .cart_thumbnail ) }}
    {{ $modifiedProduct = merge $modifiedProduct (dict "key"                .key ) }}
    {{ $modifiedProduct = merge $modifiedProduct (dict "link"               .pdp) }}
    {{ $modifiedProduct = merge $modifiedProduct (dict "long_title"         .long_title ) }}
    {{ $modifiedProduct = merge $modifiedProduct (dict "name"               .name ) }}
    {{ $modifiedProduct = merge $modifiedProduct (dict "oos_form"           .oos_form ) }}
    {{ $modifiedProduct = merge $modifiedProduct (dict "relevant"           .suggestion.relevant ) }}
    {{ $modifiedProduct = merge $modifiedProduct (dict "servings"           .servings ) }}
    {{ $modifiedProduct = merge $modifiedProduct (dict "thumbnail"          .cart_thumbnail ) }}
    {{ $modifiedProduct = merge $modifiedProduct (dict "variant"            (cond (lt (len $modifiedProduct.variants) 2) (cond $isDevStore .dev_variant .variant) nil ) ) }}
    {{ $modifiedProduct = merge $modifiedProduct (dict "defaultVariantName" .manual_variant_name ) }}
    {{ $modifiedProduct = merge $modifiedProduct (dict "weight"             .suggestion.weight ) }}
    {{ with .special_shipping_exclusions }}
      {{ $modifiedProduct = merge $modifiedProduct (dict "specialShippingExclusions" . ) }}
    {{ end }}

    {{ with .subscription }}
      {{ $subscriptionData := "" }}
      {{ if (reflect.IsSlice .) }}
        {{ $subscriptionData = slice }}
        {{ range $idz, $subData := . }}
          {{ $subscriptionDataItem := dict }}
          {{ $subscriptionDataItem  =                              dict "groupid"     (cond $isDevStore .dev_group_id .group_id) }}
          {{ $subscriptionDataItem  = merge $subscriptionDataItem (dict "discount"    .discount ) }}
          {{ $subscriptionDataItem  = merge $subscriptionDataItem (dict "options"     (dict "1" .option_1 "2" .option_2 )) }}
          {{ $subscriptionDataItem  = merge $subscriptionDataItem (dict "text"        .text ) }}
          {{ $subscriptionDataItem  = merge $subscriptionDataItem (dict "bundle_text" .bundle_text ) }}
          {{ $subscriptionDataItem  = merge $subscriptionDataItem (dict "disabled"    .disabled ) }}
          {{ $subscriptionData = $subscriptionData | append (merge (index $modifiedProduct.variants $idz) (dict "subscription" $subscriptionDataItem)) }}
        {{ end }}
        {{ else if (reflect.IsMap .) }}
        {{ $subscriptionData  =                          dict "groupid"     (cond $isDevStore .dev_group_id .group_id) }}
        {{ $subscriptionData  = merge $subscriptionData (dict "discount"    .discount ) }}
        {{ $subscriptionData  = merge $subscriptionData (dict "options"     (dict "1" .option_1 "2" .option_2 )) }}
        {{ $subscriptionData  = merge $subscriptionData (dict "text"        .text ) }}
        {{ $subscriptionData  = merge $subscriptionData (dict "bundle_text" .bundle_text ) }}
        {{ $subscriptionData  = merge $subscriptionData (dict "disabled"    .disabled ) }}
        {{ else }}
        {{ errorf (print "Core product subscription data was neither map nor array for: " $coreProduct.name ) }}
      {{ end }}

      {{/*  If there is more than one subscription data object, assign each object to the corresponding variant and set top level subscription to 'seeVariants'   */}}
      {{ if (reflect.IsSlice $subscriptionData ) }}
        {{ $modifiedProduct = merge $modifiedProduct (dict "variants" $subscriptionData ) }}
        {{ $modifiedProduct = merge $modifiedProduct (dict "subscription" "seeVariants" ) }}
        {{ else }}
        {{ $modifiedProduct = merge $modifiedProduct (dict "subscription" $subscriptionData ) }}
      {{ end }}
    {{ end }}

    {{ with .bundles }}
      {{ $bundleData :=                     dict "id"             (cond $isDevStore .dev_bundled_id .bundled_id) }}
      {{ $bundleData  = merge $bundleData ( dict "variant"        (cond $isDevStore .dev_bundled_variant .bundled_variant) ) }}
      {{ $bundleData  = merge $bundleData ( dict "bundleTitle"    .bundled_title ) }}

      {{ $modifiedProduct = merge $modifiedProduct (dict "bundle" $bundleData ) }}
    {{ end }}
  {{ end }}

  <!-- prettier-ignore -->
  {{/*********************************** 
    Set 'inStock' property: 
    // Where the returned value is what will be assigned to inStock
    - Logic summary (simplified and in JS style): 
      if (isNotCoreProduct) return true;                                                                   // Only core products can ever be out of stock
      else if (coreproduct.currently_out_of_stock === true) return false;                                 // Always overrides everything else
      else if (coreproduct.never_out_of_stock === true) return true;                                      // Overrides shopify
      else if (shopify.inventory_quantity < 10 && shopify.inventory_policy === "deny" ) return false;      // If there is no stock (at build time) then it is out of stock unless explicitly set to 'allow'
      else return true;                                                                                    // If no conditionals were triggered, then it is available

    - Note: To work with the Hugo logic, the actual code below is almost exactly backwards of the way it is written above
  ***********************************/}}

  {{ $modifiedVariantArray := slice }}
  {{ $totalVariantsInStock := 0 }}
  {{ $totalVariantsOutOfStock := 0 }}
  {{ range $index, $variant := $modifiedProduct.variants }}
    {{ $inStock := true }}
    {{ with $coreProduct }}
      {{ with $variant.inventory_policy }}
        {{ with $variant.inventory_quantity }}
          {{ if and ( le (int $variant.inventory_quantity) 10 ) (eq $variant.inventory_policy "deny") }}
            {{ $inStock = false }}
          {{ end }}
        {{ end }}
      {{ end }}
      {{ with $coreProduct.currently_out_of_stock }}
        {{ if (or (eq $coreProduct.currently_out_of_stock true ) (eq $coreProduct.currently_out_of_stock "true" )) }}
          {{ $inStock = false }}
        {{ end }}
        {{ else }}
        {{ with $coreProduct.never_out_of_stock }}
          {{ if (or (eq . true) (eq . "true")) }}
            {{ $inStock = true }}
          {{ end }}
        {{ end }}
      {{ end }}
    {{ end }}

    {{/* Track total true and false values across variants so we can easily see if they are all the same (for this product) at the end */}}
    {{ if (eq $inStock true) }}
      {{ $totalVariantsInStock = add $totalVariantsInStock 1 }}
      {{ else }}
      {{ $totalVariantsOutOfStock = add $totalVariantsOutOfStock 1 }}
    {{ end }}

    {{ $modifiedVariant := merge $variant (dict "inStock" $inStock ) }}
    {{ $modifiedVariantArray = $modifiedVariantArray | append $modifiedVariant }}
  {{ end }}

  {{ $modifiedProduct = merge $modifiedProduct (dict "variants" $modifiedVariantArray ) }}
  {{/* If all variants have the same value for inStock, then set inStock for the product to that value */}}
  {{ if (or (eq $totalVariantsInStock 0) (eq $totalVariantsOutOfStock 0) ) }}
    {{ $modifiedProduct = merge $modifiedProduct (dict "inStock" (index $modifiedVariantArray 0).inStock ) }}
  {{ end }}

  {{ $allProductMetadata = $allProductMetadata | append $modifiedProduct }}
{{ end }}

{{ return $allProductMetadata }}

This is from a private repo, so I’m unable to share our entire website’s code with you, but I’m happy to provide any additional details.

$ hugo version
Hugo Static Site Generator v0.80.0/extended windows/amd64 BuildDate: unknown

PS: I also just noticed that the footer partial still shows a “cache potential” of 100, while the other one has a “cache potential” of 0. What do those numbers actually mean, and how does a fully cached file still have a “cache potential” of 100?

1 Like
2

Please post (or look into) how these partials are cached.

{{ partial "filename" .TheData "more" "cache" "identifiers" }}

Everything after .TheData is used to identify a cached partial. If you have 11 products and one of these (1 or more) identifiers has the product ID then the partial is run 11 times. If you have NO such identifiers added, then the partial is run one single time and cached. Those identifiers can of course be variables and probably are already vars.

{{ partial "filename" .TheData $productID }}
1 Like
3

Here are the two different ways in which we call this partial:

{{- $products := (partialCached "products/get-all-products" $ ) -}}

and

{{ range where ( partialCached "products/get-all-products" $ ) "id" .productId }}

We call it more than twice, but it is only ever called in one of the above or a very similar manner. As I stated in the original post, I have double and triple check that we are never, ever passing caching arguments to the partial.

As you can see, we never include caching args.

Based on my own understanding, as well as what you just said in your post, this partial SHOULD only run once (per language). Yet, templateMetrics seems to be showing it running 11 times. Thus, my confusion.

1 Like
4

As far as I remember, I haven’t quite seen anyone passing the global context to a partial the way you do.

It does seem slightly odd and I don’t quite understand why you use the dollar sign instead of the dot and yet within the products partial you are again accessing the global context:
e.g. $coreProducts := $.Site.Data.en.coreproducts.products

ref: Use $. to Access the Global Context

Perhaps some of the more knowledgeable people, that I am tagging below, might have the time to look into your issue.

cc: @moorereason @bep @regis @digitalcraftsman

1 Like
5

As far as I remember, I haven’t quite seen anyone passing the global context to a partial the way you do.

I actually used to call this partial with the dot, but I changed to using $ in order to ensure that I never ran into any trouble with scoping, since my partial only ever wants to access global context. Changing from . to $ was actually one of the first things I tried to see if it would make a difference. It did not, but I just left it like that as it didn’t seem like it could cause any harm.

Thanks!

6

Also the above construct may be problematic.

You may not use the documented syntax to pass arguments to the cached partial, yet you are ranging over it and then passing arguments.

Again I don’t quite remember seeing this setup before. In any case perhaps the others will have a look.

7

Good point about the range. I’ll try separating it out to an import and then a range and report back.

In the mean time, perhaps I can provide an even better, more cut and dried example:
We have a partial that imports a JS file, builds it, and then drops in a script tag with the src filled in. Here is literally the entire file:

{{- $lazySizes := resources.Get "/js/plugins/lazysizes-import.js" | js.Build (dict "minify" true) | fingerprint -}}

{{- with $lazySizes -}}
    <script src="{{ .RelPermalink }}" async></script>
{{- else -}}
    {{- errorf "Critical Error: Partial 'site/lazysizes-js' failed to return anything. Build will be aborted." -}}
{{- end -}}

We then call this partial only in one single place and it’s cached, but template metrics shows it being run 9 times seemingly.

      cache     cumulative       average       maximum
  potential       duration      duration      duration  count  template
      -----     ----------      --------      --------  -----  --------
          0    167.9984ms   18.666488ms     20.9998ms      9  partials/site/lazysizes-js.html

The partial is called a single time inside of another partial, just like this:

{{- partialCached "site/lazysizes-js" . -}}

It’s not inside a loop or anything. Just by itself on its own line being cached. And yet, seemingly runs 9 times during every build.

EDIT/UPDATE: Swapped out all the instances where the get-all-products partial was called within range to returning the partial to a variable and then ranging over the variable. No change what so ever to template metrics data.

8

What you’re seeing (JSON partial runs 11 times while footer runs 3 times) is the result of parallelism. Until the first cacheable result is rendered, other executions of the same partial may have already started (we don’t block them from executing). The reason the JSON one is executing more times is because it takes longer for the first cacheable result to complete (443ms avg duration vs the 1.3ms for the footer partial).

5 Likes
9

Probably related to this recent fix:

1 Like
10

@moorereason

Ah, that totally makes sense! Thank you for the explanation!

I wonder if you have any advice about how best to optimize for speed with parallelization in mind? I’ve been finding that speeding up individual partials often doesn’t speed up the overall build time of our site and that totally makes sense with this in mind. Is there a way of figuring out what partials are actually slowing down the overall build with their execution time vs partials that have a negligible impact due to being non-blocking (no idea if that’s the correct terminology, but hopefully that makes sense).

And/or is it worth trying to force a costly partial to run once up front to ensure that a cached version exists for later? Not that I really know how I’d accomplish that anyway.

Thanks again!

11

I’ve been in your shoes, but I don’t have any secrets.

I usually start by looking for the outliers in each column of the template metrics. The cache hints will tell you how similar the output is for each template. If similarity is high but less than 100, you may can split it off into a few variants and reduce the number of executions.

Just because a template has a zero cache hint doesn’t mean you should ignore it. Pieces of a template could be split off and cached. The goal is to not to the same work twice.

Potential improvements in hugo (while I’m thinking about it):

  • I hadn’t considered blocking partialCached executions until now. If you have a really expensive partial (as you do), hugo could try to render them all before the first one even finishes, so the caching is irrelevant. Not sure how hard this would be to implement. cc: @bep
  • It would be interesting to know how much time each page took to render (i.e. /about/index.html) – a “page metrics” report.
2 Likes
12

Yeah that makes sense. Love those improvement ideas as well.

Also, the only hint values I’ve ever seen on our website are 0 and 100. Not sure if that’s an “us” issue or a Hugo issue though. Either way, thanks for the advice!!

13

It’s just you :slight_smile:

The Hugo docs site returns values such as 54, 60, 99, 70, 38, …

1 Like
14

So, I’m not sure how non-blocking partials would work, but remember that the rendering step in Hugo is already plenty parallel, so you’re CPUs should already be plenty busy.

That said, I have a proposal in the “back log” about a new defer keyword, which is plenty cool:

15

I was talking about blocking partials to ensure that a partialCached only executes once.

2 Likes
16

This topic was automatically closed 2 days after the last reply. New replies are no longer allowed.