Performance problem with the on-the-fly minification and xdebug

Created on 6 October 2023, about 1 year ago
Updated 15 March 2024, 8 months ago

Problem/Motivation

Using drupal 10.1.5, each back-office page takes up to 10 seconds to load.
After a few research, I found that the problem comes from the on-the-fly minification implemented in πŸ“Œ On-the-fly JavaScript minification Fixed .

You may think that this occurs only once and then the javascript is loaded from the disk.
But in reality, as each back-office page uses differents library, the loading time occurs again and again when you go through the back-office.

Consequently, at the moment the back-office is mostly unusable until the core javascript aggregation is disabled.

I attached a screenshot taken from xhprof so you can see how many time takes the on-the-fly minification for 75 javascripts files (from core and contrib only, no custom modules).

Steps to reproduce

  1. Install Drupal 10.1.5
  2. Ensure the core javascript aggregation is enabled
  3. Display a back-office page
  4. See that the loading time is really slow (might be slower on a project with multiple modules enabled)

Proposed resolution

I looked at the issue #3308122: Pre-minify core JavaScript β†’ which should solve the problem in the end, but I'm not sure this can wait until then.

You may want to rollback πŸ“Œ On-the-fly JavaScript minification Fixed and deliver the whole feature πŸ“Œ On-the-fly JavaScript minification Fixed + #3308122: Pre-minify core JavaScript β†’ at once.

πŸ› Bug report
Status

Active

Version

11.0 πŸ”₯

Component
Asset libraryΒ  β†’

Last updated about 5 hours ago

No maintainer
Created by

πŸ‡«πŸ‡·France Nixou Toulon

Live updates comments and jobs are added and updated live.
Sign in to follow issues

Comments & Activities

Not all content is available!

It's likely this issue predates Contrib.social: some issue and comment data are missing.

  • Issue created by @Nixou
  • πŸ‡«πŸ‡·France Nixou Toulon
  • πŸ‡«πŸ‡·France Nixou Toulon
  • πŸ‡¬πŸ‡§United Kingdom catch

    We did quite a lot of performance testing on the original issue and while Peast was not fast, it was not seven seconds slow.

    Can you ensure that you have xdebug disabled, and check loading times both of the HTML page and the aggregate URLs in devtools or similar without xhprof too? Both for CSS and JS so we can compare?

    There was also a version of the original patch to cache the minified versions of the files. This might help to compare and would be easy to make a proof of concept for that.

  • Status changed to Postponed: needs info about 1 year ago
  • πŸ‡¬πŸ‡§United Kingdom catch

    I double checked this in case a recent Peast update might have introduced a performance regression, but was unable to.

    Installed umami (and drush).

    drush cr.

    Browse directly to en/admin/structure/views/view/content to get a js-heavy page.

    As you can see the second (larger) JavaScript aggregate takes 547ms to serve (the smaller one was about 140ms). This is consistent with the performance testing we did on the original issue.

    Also showing the response headers from that same request:

    Now 500ms is not great performance but we decided it was an OK trade-off, especially since before aggregation was moved out to a separate controller, it could add 500-700ms to the main HTML request (just to generate 4-5 different aggregates without js minification).

    We would not have made that same trade-off for 5 second aggregate generation times, but I really would like steps to reproduce that without xdebug or other debugging tools running.

    There are a couple of thing I think we need here:

    1. Can you confirm that you're testing raw times without xdebug or xhprof enabled?

    2. Can you test locally with umami using the steps I used above, to get a rough baseline of aggregation generation time without contrib modules installed?

    3. For the 75 js files you mention, can you check the ones from contributed modules to ensure they don't include any pre-minified files. See for example issues like #3029950: Add { minified: true } to already minified libraries β†’ . Drupal relies on {minified: true } in the library definition to know whether to attempt to minify a library or not. If a contrib module is shipping a large, pre-minified, js file without specifying this, Peast will attempt to re-minify it and that might explain things.

  • Status changed to Active about 1 year ago
  • πŸ‡«πŸ‡·France Nixou Toulon

    Thanks for your feedback.

    I tried again today on the Umami Demo and on my project and below are my observations (I ran all my tests on the /admin/content page) :

    On the Umami Demo, without XDEBUG and XHPROF, the second JS file loads in ~0.6 second.

    On my project, I was not able to reproduce the 8 seconds loading time today, the maximum I got was 4 seconds.

    Below are the loading time of the second JS file :

    1. With XDEBUG (trigger mode) and XHPROF : 4 seconds
    2. With XDEBUG (trigger mode) only : 4 seconds
    3. Without XDEBUG and XHPROF : 1 second (which seems ok with all contributed theme and modules I have)

    So it is about XDEBUG (even in trigger mode, which intends to avoid to slow the environment when xdebug is not used).

    I had not this problem before on the previous version of Drupal, before the on-the-fly minification implementation.

    I tried with XDEBUG enabled and the core JS aggregation disabled, all javascript files are loaded in 146ms and the whole page loads in 1.15 seconds.
    As soon as the core JS aggregation is enabled again, the complete page loading time is back to 4 seconds.

    So finally I think the only problem is that the new on-the-fly minification has an important impact for developers using xdebug making the back-office mostly unusable while developing.
    It will be complicated now to work locally without disabling the JS aggregation or removing totally xDebug when not used.

    Do you think something can be improved there ?

    Let me know if you need more information.

    Thanks again.

  • πŸ‡¬πŸ‡§United Kingdom catch

    Couple of things:

    I might put up a patch here to cache the minification per-file so we can compare with that. There was a fair bit of discussion against doing that on the original issue but interested what the impact would be on multiple admin pages given you seem to be seeing the same files minified multiple times. If it helps and we can find a way to do it without drawbacks, why not.

    We could add a separate setting to enable/disable minification, distinct from aggregation.

    Bumping down to normal given this only appears with xdebug, thanks for retesting!

  • πŸ‡¬πŸ‡§United Kingdom Lincoln-Batsirayi

    Hey guys, just commenting here because this sounds exactly like an issue we've been experiencing since upgrading to Drupal 10 except that it's only happening on front end pages for both logged in and anon users.

    Initially when the bug was showing up, pages would take around 8 seconds on the initial load (not locally but on acquia hosted envs), and then load quickly after that. I found that this was coming from the aggregated js file. (note we were using the advagg module at this point). But then i noticed if i turned off js aggregation then pages would always load fast.

    Since i and other members of our team weren't able to narrow down the issue we decided to deploy to prod without js aggregation turned on. This was okay at the start but now we've noticed that periodically when some pages load none of the js on the page works until the page is refreshed again. But reenabling js aggregation solves this BUT obviously this reintroduces the slow loading +8 seconds issue.

    After some tinkering today I've noticed that both issues go away if i disable the advagg module AND the core js aggregation setting, I've not tested this on prod yet but I'm hoping that the results will be the same there.

    Obviously this isn't ideal at all since js aggregation is supposed to improve performance but any tips on a better path/approach would be much appreciated!

  • πŸ‡¬πŸ‡§United Kingdom catch

    @Lincoln-Batsirayi can you confirm whether you've tried core aggregation without advagg. Advagg isn't really compatible with 10.1 any more per πŸ“Œ Document which parts of the module are still relevant after aggregation changes in 10.1.0 Needs review .

    If you get 8 second load times with core aggregation and no advagg, the following would be useful:

    1. Can you look in the dev tools network tab and identify which aggregates are taking long to process (or if it's all of them).

    2. Can you check your js and css folders to check how many aggregates are being created - i..e is it one or two dozen or many dozens of aggregates?

    3. If a particular aggregate is taking longer to produce, can you check the contents to see if any large source files in there?

    4. Can you confirm xdebug isn't enabled on the environment?

  • πŸ‡¬πŸ‡§United Kingdom Lincoln-Batsirayi

    Hey @catch yes I've tried core aggregation without advagg and I'm still getting the issue. I tried the following steps you provided and here were the results:

    1. It's just javascript aggregates which are taking a long time to load, it's always one of the js file too
    2. It's always 2 js & css aggregates which are created in the folders per page load
    3. Looking at the contents of the file, there actually isn't much in there, from what i can tell it's some minified jquery, drupal once and drupal core js, obviously the durpal core one is the largest by far. When i cropped it out into a new file it came to about 479kb (I don't know if this typical or not). An additional note, when i compare the aggregate file from the D9 version of the page and the D10 version it's only a 20kb difference in sizes between the two files
    4. Yes xdebug is disabled on the environment

    If you need me to share any screenshots from the network tab or the files themselves please let me know as I'm not a 100% sure what it is I'm looking for...

  • πŸ‡¬πŸ‡§United Kingdom catch

    @Lincoln-Batsirayi could you attach the contents of the slow aggregate file (and maybe the other js aggregate just for comparison) as .txt files to this issue?

  • πŸ‡¬πŸ‡§United Kingdom Lincoln-Batsirayi

    Hey @catch here are the files, I've also included a couple of network related screenshots of the file incase they have some information.

  • πŸ‡¬πŸ‡§United Kingdom catch

    Thanks that helps, so about 1/3rd of the way down that file, I get to content like this, which suggests there's a lot of contrib/custom JavaScript in the aggregate alongside core's. Much more than 1/3rd of the file is not jQuery JavaScript and it looks like not core's either. This makes me think there is a specific file causing trouble for peast.

    eart.png":24,"./raster/icons/illustration-memorial-horseshoe.png":25,"./raster/icons/illustration-memorial-lead.png":26,"./raster/icons/illustration-memorial-paw.png":27,"./raster/icons/illustration-memorial-rainbow.png":28,"./raster/loader-on-blue-dark.gif":29,"./raster/map-food-bank-small.png":30,"./raster/map-food-bank.png":31,"./raster/map-rehome-food-bank-small.png":32,"./raster/map-rehome-food-bank.png":33,"./raster/map-rehome-small.png":34,"./raster/map-rehome-vetinary-small.png":35,"./raster/map-rehome-vetinary.png":36,"./raster/map-rehome.png":37,"./raster/map-shop-food-bank-small.png":38,"./raster/map-shop-food-bank.png":39,"./raster/map-shop-small.png":40,"./raster/map-shop.png":41,"./raster/map-vetinary-food-bank-small.png":42,"./raster/map-vetinary-food-bank.png":43,"./raster/map-vetinary-small.png":44,"./raster/map-vetinary.png":45,"./raster/memorial-donate.jpg":46,"./raster/memorial-illustrations-ball.png":47,"./raster/memorial-illustrations-heart.png":48,"./raster/memorial-illustrations-horseshoe.png":49,"./raster/memorial-illustrations-lead.png":50,"./raster/memorial-illustrations-paw.png":51,"./raster/memorial-illustrations-rainbow.png":52,"./raster/placeholder.jpg":53,"./raster/sponsor-dodson-horrell.png":54,"./raster/stars_left_desktop_1x.png":55,"./raster/stars_left_desktop_2x.png":56,"./raster/stars_left_mobile_1x.png":57,"./raster/stars_left_mobile_2x.png":58,"./raster/stars_right_desktop_1x.png":59,"./raster/stars_right_desktop_2x.png":60,"./raster/stars_right_mobile_1x.png":61,"./raster/stars_right_mobile_2x.png":62,"./svg/comment-alt-exclamation-light.svg":63,"./svg/decoration-cross-blue.svg":64,"./svg/decoration-cross.svg":65,"./svg/decoration-heart-blue.svg":66,"./svg/decoration-heart.svg":67,"./svg/divider-pattern.svg":68,"./svg/hero-curve-bottom.svg":69,"./svg/hero-curve-top.svg":70,"./svg/lightbulb-on-light.svg":71,"./svg/loader-cross.svg":72,"./svg/logo-fundraising-standards-board.svg":73,"./svg/pattern-bg.svg":74,"./svg/sprite-badge-reserved.svg":75,"./svg/sprite-icon-confetti-cross.svg":76,"./svg/sprite-icon-confetti-heart.svg":77,"./svg/sprite-icon-cross.svg":78,"./svg/sprite-icon-decoration-cross.svg":79,"./svg/sprite-icon-downloadable.svg":80,"./svg/sprite-icon-dropdown-dark.svg":81,"./svg/sprite-icon-dropdown-light.svg":82,"./svg/sprite-icon-dropdown.svg":83,"./svg/sprite-icon-email.svg":84,"./svg/sprite-icon-facebook.svg":85,"./svg/sprite-icon-hamburger.svg":86,"./svg/sprite-icon-height.svg":87,"./svg/sprite-icon-info.svg":88,"./svg/sprite-icon-location-pin.svg":89,"./svg/sprite-icon-map-pointer.svg":90,"./svg/sprite-icon-pause.svg":91,"./svg/sprite-icon-paw.svg":92,"./svg/sprite-icon-pinterest.svg":93,"./svg/sprite-icon-play.svg":94,"./svg/sprite-icon-pound.svg":95,"./svg/sprite-icon-reference.svg":96,"./svg/sprite-icon-scroll.svg":97,"./svg/sprite-icon-search-white.svg":98,"./svg/sprite-icon-search.svg":99,"./svg/sprite-icon-service-education.svg":100,"./svg/sprite-icon-service-pet-behaviour.svg":101,"./svg/sprite-icon-service-pet-bereavement-support.svg":102,"./svg/sprite-icon-service-rehoming.svg":103,"./svg/sprite-icon-service-veterinary.svg":104,"./svg/sprite-icon-sex.svg":105,"./svg/sprite-icon-slider-nav-left.svg":106,"./svg/sprite-icon-slider-nav-right.svg":107,"./svg/sprite-icon-social-facebook.svg":108,"./svg/sprite-icon-social-instagram.svg":109,"./svg/sprite-icon-social-twitter.svg":110,"./svg/sprite-icon-social-youtube.svg":111,"./svg/sprite-icon-solid-arrow-right-white.svg":112,"./svg/sprite-icon-solid-arrow-right.svg":113,"./svg/sprite-icon-tick.svg":11
    

    I'm also seeing content like:

    (this.next=r),s;},finish:function(e){for(var r=this.tryEntries.length-1;r>=0;--r){var t=this.tryEntries[r];if(t.finallyLoc===e)return this.complete(t.completion,t.afterLoc),E(t),s;}},catch:function(e){for(var r=this.tryEntries.length-1;r>=0;--r){var t=this.tryEntries[r];if(t.tryLoc===e){var m=t.completion;if("throw"===m.type){var n=m.arg;E(t);}return n;}}throw new Error("illegal catch attempt");},delegateYield:function(e,r,t){return this.delegate={iterator:w(e),resultName:r,nextLoc:t},"next"===this.method&&(this.arg=void 0),s;}},e;}(e.exports);try{regeneratorRuntime=m;}catch(e){"object"==typeof globalThis?globalThis.regeneratorRuntime=m:Function("r","regeneratorRuntime = r")(m);}},15:function(e){e.exports=JSON.parse('{"tailwind":{"theme":{"screens":{"sm":"640px","md":"768px","lg":"1024px","xl":"1260px","2xl":"1440px"},"colors":{"black":"#000233","white":"#fff","transparent":"transparent","current":"currentColor","blue":{"100":"#E1F4FB","200":"#33BBEE","300":"#0066BB","400":"#003388","500":"#000233","DEFAULT":"#0066BB"},"grey":{"100":"#FBFBFB","200":"#666666","300":"#414140","400":"#1D1E1B","DEFAULT":"#666666"},"green":{"100":"#9CCE12","200":"#8CB910","300":"#447744","DEFAULT":"#9CCE12"},"red":"#CF1348","orange":"#F08C00","yellow":"#FBB800"},"spacing":{"0":"0px","1":"0.25rem","2":"0.5rem","3":"0.75rem","4":"1rem","5":"1.25rem","6":"1.5rem","7":"1.75rem","8":"2rem","9":"2.25rem","10":"2.5rem","11":"2.75rem","12":"3rem","14":"3.5rem","15":"3.75rem","16":"4rem","20":"5rem","24":"6rem","28":"7rem","32":"8rem","36":"9rem","40":"10rem","44":"11rem","48":"12rem","52":"13rem","56":"14rem","60":"16rem","64":"17rem","72":"18rem","80":"20rem","96":"24rem","px":"1px","0.5":"0.125rem","1.5":"0.375rem","2.5":"0.625rem","3.5":"0.875rem","video":"56.25%","16by9":"56.25%","full":"100%"},"animation":{"none":"none","spin":"spin 1s linear infinite","ping":"ping 1s cubic-bezier(0, 0, 0.2, 1) infinite","pulse":"pulse 2s cubic-bezier(0.4, 0, 0.6, 1) infinite","bounce":"bounce 1s infinite"},"backdropBlur":{"0":"0","none":"0","sm":"4px","DEFAULT":"8px","md":"12px","lg":"16px","xl":"24px","2xl":"40px","3xl":"64px"},"backdropBrightness":{"0":"0","50":".5","75":".75","90":".9","95":".95","100":"1","105":"1.05","110":"1.1","125":"1.25","150":"1.5","200":"2"},"backdropContrast":{"0":"0","50":".5","75":".75","100":"1","125":"1.25","150":"1.5","200":"2"},"backdropGrayscale":{"0":"0","DEFAULT":"100%"},"backdropHueRotate":{"0":"0deg","15":"15deg","30":"30deg","60":"60deg","90":"90deg","180":"180deg","-180":"-180deg","-90":"-90deg","-60":"-60deg","-30":"-30deg","-15":"-15deg"},"backdropInvert":{"0":"0","DEFAULT":"100%"},"backdropOpacity":{"0":"0","5":"0.05","10":"0.1","20":"0.2","25":"0.25","30":"0.3","40":"0.4","50":"0.5","60":"0.6","70":"0.7","75":"0.75","80":"0.8","90":"0.9","95":"0.95","100":"1"},"backdropSaturate":{"0":"0","50":".5","100":"1","150":"1.5","200":"2"},"backdropSepia":{"0":"0","DEFAULT":"100%"},"backgroundColor":{"black":"#000233","white":"#fff","transparent":"transparent","current":"currentColor","blue":{"100":"#E1F4FB","200":"#33BBEE","300":"#0066BB","400":"#003388","500":"#000233","DEFAULT":"#0066BB"},"grey":{"100":"#FBFBFB","200":"#666666","300":"#414140","400":"#1D1E1B","DEFAULT":"#666666"},"green":{"100":"#9CCE12","200":"#8CB910","300":"#447744","DEFAULT":"#9CCE12"},"red":"#CF1348","orange":"#F08C00","yellow":"#FBB800"},"backgroundImage":{"none":"none","gradient-to-t":"linear-gradient(to top, var(--tw-gradient-sto
    

    As well as lots of webform JavaScript.

    I think the next step would be if you could add some debug to JsCollectionOptimizerLazy, something like this:

    diff --git a/core/lib/Drupal/Core/Asset/JsCollectionOptimizerLazy.php b/core/lib/Drupal/Core/Asset/JsCollectionOptimizerLazy.php
    index 6dff3650f2..85378a5cf4 100644
    --- a/core/lib/Drupal/Core/Asset/JsCollectionOptimizerLazy.php
    +++ b/core/lib/Drupal/Core/Asset/JsCollectionOptimizerLazy.php
    @@ -175,6 +175,7 @@ public function optimizeGroup(array $group): string {
             $data .= file_get_contents($js_asset['data']);
           }
           else {
    +        file_put_contents('/tmp/js_asset.txt', print_r($js_asset, TRUE), FILE_APPEND);
             $data .= $this->optimizer->optimize($js_asset);
           }
           // Append a ';' and a newline after each JS file to prevent them from
    

    Then the goal would be to look through there for a JavaScript file that is pre-minified, but where the library definition has not set {minified: true} - if that exists, then Peast would essentially be trying to re-minify a file that's already minified, and that could potentially cause performance issues.

  • πŸ‡ΊπŸ‡ΈUnited States oivanov

    Hi guys, this looks exactly like an issue that brought down our dev server after upgrading to Drupal 10.1.5 core. While the band-aid solution is easy - removing XDebug - we do need it (xdebug) on our dev server for...well...developing. @catch - would you be so kind as to bump it up to something "more urgent than normal" please??? Let me know if I can help by providing more data. Thanks!

  • πŸ‡ΈπŸ‡ͺSweden johnzzon Gothenburg πŸ‡ΈπŸ‡ͺ

    We experienced this on a project. There was a react app included on some pages. This JS was minified but did not have the minified: true option in its libraries.yml. Setting that fixed the issue for us.

  • πŸ‡¬πŸ‡§United Kingdom Lincoln-Batsirayi

    Commenting to update and confirm that the issue was indeed minified js files which didn't have the `minified: true` option set on them. After adding this to the files the issue was resolved.

Production build 0.71.5 2024