Major slow down in kubernetes.io build time over the past 1-2 years.

[jimangel]

What version of Hugo are you using (hugo version)?

hugo v0.87.0-B0C541E4+extended linux/amd64 BuildDate=2021-08-03T10:57:28Z VendorInfo=gohugoio

                   |  EN  | ZH  | KO  | JA  | FR  | IT  | DE  | ES  | PT-BR | ID  | RU  | VI  | PL  | UK
-------------------+------+-----+-----+-----+-----+-----+-----+-----+-------+-----+-----+-----+-----+------
  Pages            | 1382 | 921 | 511 | 403 | 335 |  71 | 158 | 270 |   148 | 335 | 150 |  77 |  69 |  92
  Paginator pages  |   39 |   7 |   0 |   0 |   0 |   0 |   0 |   0 |     0 |   0 |   0 |   0 |   0 |   0
  Non-page files   |  484 | 353 | 178 | 260 |  73 |  20 |  17 |  33 |    27 | 105 |  24 |   8 |   6 |  20
  Static files     |  794 | 794 | 794 | 794 | 794 | 794 | 794 | 794 |   794 | 794 | 794 | 794 | 794 | 794
  Processed images |    1 |   1 |   0 |   0 |   0 |   0 |   0 |   0 |     0 |   0 |   0 |   0 |   0 |   0
  Aliases          |    9 |   1 |   2 |   0 |   0 |   1 |   0 |   0 |     1 |   1 |   1 |   0 |   0 |   0
  Sitemaps         |    2 |   1 |   1 |   1 |   1 |   1 |   1 |   1 |     1 |   1 |   1 |   1 |   1 |   1
  Cleaned          |    0 |   0 |   0 |   0 |   0 |   0 |   0 |   0 |     0 |   0 |   0 |   0 |   0 |   0

$ time hugo
Start building sites …
hugo v0.87.0-B0C541E4+extended linux/amd64 BuildDate=2021-08-03T10:57:28Z VendorInfo=gohugoio
WARNING: calling IsSet with unsupported type "invalid" () will always return false.
Error: Error building site: POSTCSS: failed to transform "scss/main.css" (text/css). Check your PostCSS installation; install with "npm install postcss-cli". See https://gohugo.io/hugo-pipes/postcss/
Total in 82120 ms

real    1m22.217s
user    5m9.767s
sys     0m7.096s

Sorry, this issue is a bit subjective but I'll do my best to build a case. I joined SIG Docs in 2018 and hugo built fast (that would probably be around release 1.11 / hugo version 0.40.3). Today it takes ~1:23m

Since then, we've added many more localizations, increased content, changed themes, and began relying more on data to generate pages such as k8s.io/releases/. The slowness in hugo wasn't overnight, it gradually became slower and slower. I'm trying now to decipher how we can correct the build times or improve them but grasping for straws. It doesn't seem like we're building a site that huge (~11,000 static files and ~4,500 pages).

It's also worth noting that the build consumes a TON of resources, mainly CPU (occasionally crashing my 4x4 VM due to OOM).

Any suggestions? I cross opened an issue on k/website too: kubernetes/website#29429

[ghost]

IMO one of the best ways to pinpoint what may be causing the issue(s) is running with --templateMetrics and --templateMetricsHints.

[jimangel]

Thanks for the tip @braderhart! Everything w/ cumulative duration over 1s:

$ hugo --templateMetrics --templateMetricsHints

[...]

Template Metrics:

      cache     cumulative       average       maximum
  potential       duration      duration      duration  count  template
      -----     ----------      --------      --------  -----  --------
         13 4m49.980649054s  105.678079ms  280.847687ms   2744  partials/sidebar.html
          0 4m34.459678205s  135.201811ms  364.112636ms   2030  docs/single.html
         21 4m23.351904615s   95.973726ms   276.08674ms   2744  partials/sidebar-tree.html
          0 1m22.249188771s  120.954689ms  314.871636ms    680  docs/list.html
          0  45.64788803s   65.775054ms  2.570300238s    694  docs/list.print.html
          0 33.649583697s   47.865695ms   2.49773768s    703  partials/print/render.html
          4 23.696646127s    5.600719ms  261.513449ms   4231  partials/head.html
          0 17.419702778s   36.596014ms  299.091542ms    476  blog/single.html
         54   5.47626444s    1.294319ms  112.931094ms   4231  partials/navbar.html
         81  5.265351696s    9.915916ms   38.228533ms    531  partials/blog-sidebar.html
         91  2.994508473s     750.127µs   70.607823ms   3992  partials/scripts.html
          0  2.908855516s  323.206168ms  2.586272948s      9  blog/section.print.html
          0  2.379470116s     695.141µs   73.038778ms   3423  shortcodes/glossary_tooltip.html
          0  2.179129987s  155.652141ms  326.681935ms     14  docs/glossary.html
         24  2.066409769s     753.064µs   50.626091ms   2744  partials/toc.html
          8  2.000907736s    2.942511ms   24.168887ms    680  partials/section-index.html
          0  1.790354554s  127.882468ms  283.237765ms     14  docs/docsportal_home.html
          0  1.668993183s     186.981µs  150.549187ms   8926  partials/print/content.html
          0  1.534285369s   27.896097ms  136.058437ms     55  blog/list.html
         60   1.24718803s     300.817µs   11.571222ms   4146  partials/footer.html
          0   1.19264261s    2.505551ms   43.225275ms    476  blog/content.html

I'll try to dig a bit more into making sense out of this. Let me know if anything jumps out.

[jimangel]

Looks like we might be able to leverage partialcached function on a few things:

        100  993.666411ms   58.450965ms  248.501758ms     17  partials/head-css.html
        100  915.300728ms     267.475µs   39.800689ms   3422  partials/announcement.html
        100  545.811093ms     158.804µs   22.582664ms   3437  partials/docs/glossary-terms.html
        100   64.821751ms      18.718µs    1.862062ms   3463  partials/deprecation-warning.html
        100   38.666362ms       9.138µs    1.908608ms   4231  partials/hooks/head-end.html
        100   15.400555ms      16.177µs     580.571µs    952  partials/taxonomy_terms_article.html
        100    7.490925ms      15.737µs     289.614µs    476  partials/featured-image.html
        100    3.684897ms     263.206µs     555.523µs     14  partials/frontpage-announcement.html
        100     378.615µs      27.043µs      79.452µs     14  partials/favicons.html
        100     324.794µs      23.199µs      313.67µs     14  partials/handle-version-switch-404.html
        99   24.390482ms      45.933µs     277.331µs    531  partials/blog-meta-links.html
        97   195.15966ms      46.126µs    2.076883ms   4231  partials/css.html
        91  2.994508473s     750.127µs   70.607823ms   3992  partials/scripts.html
        90    57.31494ms      14.357µs     974.138µs   3992  partials/hooks/body-end.html

Edit: Spoke too soon, looks like we might already be leveraging it.

$ grep -rnw '/website' -e 'head-css'

/website/themes/docsy/layouts/partials/head.html:24:{{ partialCached "head-css.html" . "asdf" }}
/website/api-ref-generator/themes/docsy/layouts/partials/head.html:25:{{ partialCached "head-css.html" . "asdf" }}
/website/.git/modules/themes/docsy/index matches
/website/.git/modules/api-ref-generator/modules/themes/docsy/index matches
/website/layouts/partials/head.html:39:{{ partialCached "head-css.html" . "asdf" }}

[jmooring]

This discussion is better suited for the forum (https://discourse.gohugo.io/). Having said that...

https://www.docsy.dev/docs/adding-content/navigation/

On large sites (default: > 2000 pages) the section menu is not generated for each page, but cached for the whole section. The HTML classes for marking the active menu item (and menu path) are then set using JS. You can adjust the limit for activating the cached section menu with the optional parameter .ui.sidebar_cache_limit.

After setting params.ui.sidebar_cache_limit to 1, my build time decreased from 130s to 30s.

[jimangel]

Good call out, you're right, I'll move to discuss. Thanks for the tip.

Closing the issue now but will test / record / link any solution back for posteriority.

[ghost]

Last note, this is the area you'll want to focus for now. The cumulative duration appears to include the time it takes to generate the previous templates, so you'll want to focus on these for now:

• partials/head.html
• partials/print/render.html
• docs/list.print.html
• docs/list.html

Last, it appears this is what is taking up the most time, but it could be docs/list.html:

• partials/sidebar-tree.html

[jimangel]

After setting params.ui.sidebar_cache_limit to 1, my build time decreased from 130s to 30s.

I need to validate the functionality of the site but WOW did that improve things. Thanks @jmooring

$ time hugo
Start building sites …
hugo v0.87.0-B0C541E4+extended linux/amd64 BuildDate=2021-08-03T10:57:28Z VendorInfo=gohugoio
WARNING: calling IsSet with unsupported type "invalid" (<nil>) will always return false.

                   |  EN  | ZH  | KO  | JA  | FR  | IT  | DE  | ES  | PT-BR | ID  | RU  | VI  | PL  | UK
-------------------+------+-----+-----+-----+-----+-----+-----+-----+-------+-----+-----+-----+-----+------
  Pages            | 1383 | 920 | 511 | 403 | 335 |  71 | 158 | 270 |   155 | 335 | 150 |  77 |  69 |  92
  Paginator pages  |   39 |   7 |   0 |   0 |   0 |   0 |   0 |   0 |     0 |   0 |   0 |   0 |   0 |   0
  Non-page files   |  485 | 353 | 178 | 260 |  73 |  20 |  17 |  33 |    28 | 105 |  24 |   8 |   6 |  20
  Static files     |  794 | 794 | 794 | 794 | 794 | 794 | 794 | 794 |   794 | 794 | 794 | 794 | 794 | 794
  Processed images |    1 |   1 |   0 |   0 |   0 |   0 |   0 |   0 |     0 |   0 |   0 |   0 |   0 |   0
  Aliases          |    9 |   1 |   2 |   0 |   0 |   1 |   0 |   0 |     1 |   1 |   1 |   0 |   0 |   0
  Sitemaps         |    2 |   1 |   1 |   1 |   1 |   1 |   1 |   1 |     1 |   1 |   1 |   1 |   1 |   1
  Cleaned          |    0 |   0 |   0 |   0 |   0 |   0 |   0 |   0 |     0 |   0 |   0 |   0 |   0 |   0

Total in 15082 ms

real    0m15.158s
user    0m44.314s
sys     0m4.341s

[github-actions]

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.