Problem/Motivation
#3259188: Extend post update system to provide themes a way to install newly-required dependencies subscribed Drupal\Core\Update\UpdateRegistryto ConfigEvents::SAVE.
As a result Drupal\Core\Extension\ExtensionDiscovery::scan runs 7 times more often than before. The function is very costly, mainly because Drupal\Core\Extension\Extension::getName using basename to retrieve the extension name form the extension path.
Steps to reproduce
Run a functional test extending BrowserTestBase with config that enables a large number of contrib and core modules (150+).
Proposed resolution
Revert those changes in Drupal 9.x and fix it in Drupal 10.x. In addition, optimize Drupal\Core\Extension\Extension::getName to call basename less often.
Remaining tasks
- Optimize changes introduced in #3259188: Extend post update system to provide themes a way to install newly-required dependencies to trigger
Drupal\Core\Update\UpdateRegistry::getUpdateFunctionsas less as possible - Refactor
Drupal\Core\Extension\Extension::getNameto only usebasenameonce and then store the extension name in the object for subsequent requests.
User interface changes
API changes
Revert API changes from #3259188: Extend post update system to provide themes a way to install newly-required dependencies
Release notes snippet
| Comment | File | Size | Author |
|---|---|---|---|
| #19 | 3294299-9.patch | 2.28 KB | alexpott |
| #10 | 3294299-9.patch | 2.28 KB | alexpott |
| #8 | interdiff_6-8.txt | 603 bytes | pooja saraah |
| #8 | 3294299-8.patch | 4.7 KB | pooja saraah |
| #7 | xhprof_snapshot2.png | 279.42 KB | phma |
Comments
Comment #2
phma commentedMaybe suggesting to revert the change is a little too drastically and we can fix the basename issue to mitigate the problem instead?
Comment #3
cilefen commentedComment #4
phma commentedThe extension name is only retrieved once, so this can't be the solution either.
Comment #5
phma commentedWhile I still haven't found a better solution yet, I can confirm that reverting changes from #3279850: Theme post updates are not recognised when the theme is used in the installer and #3259188: Extend post update system to provide themes a way to install newly-required dependencies cause execution time to go back to what they roughly are with Drupal 9.3.x.
As an example: Our install test took over 6min on my machine with a sqlite database in memory on Drupal 9.4.x. Reverting the above changes brought them back down to about 2.5min again.
Comment #6
phma commentedI managed to significantly reduce test running times on my local machine by slightly refactoring
UpdateRegistryandExtensionDiscovery.I also added an option setting variable to enable file cache, which gives additional performance. But even without file cache, tests seem to run almost twice as fast. Would be nice to get some independent testing results though. I'm also wondering if there are any caveats when file cache is enabled.
Changes in the patch:
basename()to generate it once if it's missing.UpdateRegistry::scanExtensionsAndLoadUpdateFiles()could now run multiple times, it's better do storeExtensionDiscoveryin a property than constructing it from scratch every time.Still, I can't get nowhere near the performance unless I complete revert the changes introduced, so there's probably room for more.
Comment #7
phma commentedI ran my test again with profiling enabled. There might be some additional potential for optimization in
Drupal\Core\Extension\ExtensionDiscovery::sortandDrupal\Core\Extension\ExtensionDiscovery::process. See screenshot attached.Comment #8
pooja saraah commentedFixed Failed commands on #6
Attached patch
Comment #10
alexpott@phma really nice find.
I think we should consider setting file cache to TRUE I think we should be using it here. I'm on the fence about adding an extension discovery as a class property. I think if we do this we should do this in the constructor.
We need to use extension discovery here because this is happening very very early... i.e. before the module handler is updated with the new module info.
I think we can make this much better by limiting the extensions returned by scanExtensionsAndLoadUpdateFiles() in specific circumstances... see patch attached. How does this compare for you?
Comment #11
phma commented@alexpott I sensed that there was something else going on there. Thanks a lot.
With patch #9 I now get
Time: 02:51.385, Memory: 18.00 MB.With patch #6 it was
Time: 03:53.055, Memory: 18.00 MBfor the same test. Before it would take 6-8min.When passing the name to Extension object like in #6, I could even get it down to
Time: 02:37.555, Memory: 18.00 MB. Maybe we should open another issue for that?Comment #12
alexpott@phma I think it is worth doing these separately. It's really interesting that basename() is so expensive. It would also be great to know what was the test run time with #3259188: Extend post update system to provide themes a way to install newly-required dependencies reverted.
Comment #13
phma commentedI reverted all changes related to #3259188: Extend post update system to provide themes a way to install newly-required dependencies and ran my test twice:
I noticed that the time it takes to run the tests varies by about 10-20s. There are still a little faster, but it's not as bad as without the patch.
It's hard to say if skipping basename helps much. Profiling might make it look more costly than it actually is. It think the main issue is that it gets called over a billion times. So there should be some potential of saving time. I've attached a new patch which can apply together with #9 as a reference which could be posted as a separate issue.
Comment #14
catchShould this always be optional or should it be the penultimate argument and deprecate passing NULL?
Comment #16
alexpottBringing back #10 as I think this is the patch to commit on this one. And yeah I'm suspicious about the cost of profiling and benefit of the changing the basename. #10 just does not do as much.
We could file a separate issue for #13 but in order to prove that that is necessary I think we'd need to profile it without any profiling tools and just look at raw execution times.
Comment #17
xjmComment #18
phma commentedI found time to pick this up again after tests seems to have slowed down further on my machine.
I tried to reduce the number of times, the UpdateRegistry scans for extensions by adding an extra flag that skips the scan when called within a loop. We don't have to re-scan it for every single extension we are checking, right? It's unlikely something changes in between those calls.
Running times went from
Time:03:01.750, Memory: 18.00 MBtoTime: 02:33.451, Memory: 16.00 MB. There have been some changes to the code base and the environment in the meantime, so it's difficult to compare to my previous results. I will also have to do some more profiling with my new patch and compare with my earlier results.EDIT: Looks like we missed to to describe extension in one of the comments.
Comment #19
alexpott@phma can we do the smaller change that brings us back in line with the before times that's in #16 and make further improvements in separate issues?
I don't think the scan extensions flag is necessary and it add complexity and new ways to fail. Upping #9 again.
Comment #20
mikelutzAlright, first off, this seems fine. I've gone over it a bit, I see no problems here, just an obvious efficiency improvement code-wise. I wonder if it could be improved slightly more with
Just to avoid looping over all the enabled extensions in loadUpdateFiles() when we know there's only one we are interested in, but we are really talking minimal cycles saved there, and the current patch code is cleaner anyway.
Sadly, I was unable to really get a feel for what this saves in the typical case. I don't have a functional test that enables 150 modules, but I wanted to see what it would do for the typical core test suite and the improvement was not as exciting as I hoped. I ran the migrate MultilingualReviewPage test half a dozen times locally, which enables 10ish modules, and got averages of 39.47s without and 39.23s with this patch, which are well within the range of times this test took locally. Looking at the 3 times Alex posted the same patch, we have Functional test runtimes of 23:18m, 31:42m, 31:02m (avarege of 28:40m) against 9.4, and between the latest branch test and the one from yesterday, we have times of 30.47m and 31.43m for an average of 31:15, but if I take the 23:18 out as an outlier, then with this patch the average is 31:22, again with all the variance of machines we get spot instances of on amazon, its all well within margin of error.
So, I say it's still a good improvement, if not as useful in saving the DA on the AWS bill as I had hoped it would be. It will definitely help for some specialized tests.
Comment #21
borisson_Thanks for getting those numbers @mikelutz, I think that proves that this is a small but real improvement for core +1
Comment #22
alexpottThere's no indication that #21 meant to un-rtbc this :)
Comment #24
catchCommitted/pushed to 10.1.x, cherry-picked to 10.0.x, 9.5.x, and 9.4.x, thanks!
Comment #25
phma commented@alexpott Going with the smaller change was definitely the best way forward!
@catch Thanks for getting this in!
I've opened #3303751: Reduce the number of times Drupal scans for extensions and reposted my patch there as a place for further discussions. I'm not a big fan of the extensions flag either but I still believe there's potential to improve this and gain more speed without compromising on reliability.