Problem/Motivation
Hooks services that are automatically registered for classes in the Hooks namespace aren't marked as autoconfigured. This means we can't utilise things like autoconfigured logger services without adding an entry to services.yml
This was possible when using the Hux module - https://git.drupalcode.org/project/hux/-/work_items/3447110
Steps to reproduce
Use the method in https://www.drupal.org/node/3395436 to autoconfigure a $logger on a Hooks class
Notice it does not work
You must put the following in my_module.services.yml to fix it:
Drupal\my_module\Hook\MyModuleHooks:
autoconfigure: true
Proposed resolution
Add ->setAutoconfigured(TRUE) to services automatically registered for Hooks classes.
Remaining tasks
Agree, do it
User interface changes
N/A
Introduced terminology
N/A
API changes
N/A
Data model changes
N/A
Release notes snippet
N/A
| Comment | File | Size | Author |
|---|---|---|---|
| #20 | generate_hook_perf_modules.sh_.txt | 7.25 KB | acbramley |
Issue fork drupal-3605797
Show commands
Start within a Git clone of the project using the version control instructions.
Or, if you do not have SSH keys set up on git.drupalcode.org:
Comments
Comment #3
acbramley commentedMR is up to see if anything breaks, I'm not sure if there is any downside to adding this. Confirming that adding this one line allows me to autoconfigure a logger without a services.yml entry.
Comment #4
nicxvan commentedWe will definitely want to add it to ThemeHookCollectorPass too.
Maybe the Kernel Hooks too?
Comment #5
mstrelan commentedAre there any performance considerations here? Does it take longer to compile the container, perhaps?
Comment #6
acbramley commentedThat's what I'm wondering, other than that I can't see a downside. I wonder what the best approach to profiling the compiler pass would be, I think we'd need to profile the full pass to also include the other passes that are autoconfiguring things.
Comment #7
nicxvan commentedWhere I would start:
Write scripts to generate 1000 hook classes.
Four separate modules each with 1000 classes.
One set with a trivial empty constructor.
One set with a couple commonly injected services.
Then both with the autoconfiguration.
Use longwave's ddev spx addon. Then on a cold cache to measure the load of the first two on head then the second two on this branch. Track the max memory and wall times.
You have to be very meticulous in ensuring you are clearing cache switch branches and enabling/ disabling the right modules.
Share the script here and I'll verify locally too.
Comment #8
mstrelan commentedRegardless of performance, I think we should have a test to prove we can autoconfigure something in tests, e.g. in
\Drupal\KernelTests\Core\Hook\HookCollectorPassTest.Comment #9
acbramley commentedThinking about it more - is performance really going to be an issue? How many sites are going to have thousands of Hooks classes? And even then, we're just adding N loops to any compiler pass that acts on autoconfiguration (there's only 5 things that we call
registerForAutoconfigurationon in CoreServiceProvider). Surely symfony can happily handle this.Comment #10
acbramley commentedModule and Theme hooks added + test coverage. Hooks in Kernel tests look like their own special thing, I don't quite understand how they work but it looks like the methods themselves are on the test class and therefore we don't register them as services and wouldn't be autoconfigured, etc. If I've got it wrong then no worries, but I think it can be added in a separate issue.
Comment #11
nicxvan commentedWe need to verify, symfony many times isn't set up to handle Drupal's scale that's why we had to do this: #3506930: Separate hooks from events
And why this exists: #3538212: Reintroduce the container aware dispatcher for a 10% speedup
People may not have 1000s of classes, but to get enough to easily test we need to script generating them anyway so why not 1000 to make it easier to see.
Comment #12
acbramley commentedI didn't quite follow what you meant in #7 but tried to do something similar that I think will still give us good metrics.
Drupal was installed on the HEAD of
mainusing standard profile:I had Claude generate me 4 modules, each with 1000 hooks classes:
1. hooks_perf_test_simple - no DI, no constructors
2. hooks_perf_test_di - Construtor DI with 1-4 common services (EntityTypeManagerInterface, ConfigFactoryInterface, etc)
3. hooks_perf_test_logger_aware - 300 of the classes had manually autoconfigured services with LoggerAwareInterface pattern
4. hooks_perf_test_mixed - a mix of simple, DI, heavy DI, etc
Performance tests:
I ran
SPX_REPORT=full SPX_ENABLED=1 drush crwhich does a container rebuild/compile.I ran the command a few times in each test to ensure consistent numbers
Baseline
This was just on standard profile install with no modules enabled:
Wall time: 3.36s
Memory: 64.35MB
Func calls: 1.97M
With hooks_perf_test_simple only enabled
Wall time: 3.50s
Memory: 70.65MB
Func calls: 3.2M
With hooks_perf_test_di only enabled
Wall time: 3.69s
Memory: 71.56MB
Func calls: 3.36M
With hooks_perf_test_logger_aware only enabled
Wall time: 3.53s
Memory: 74.54MB
Func calls: 2.68M
With hooks_perf_test_mixed only enabled
Wall time: 3.70s
Memory: 77.19MB
Func calls: 3.07M
I think just by looking at these numbers it's clear that the largest impact on performance is the number of services injected and NOT how many services are autoconfigured
To round out some testing I swapped to this issue's branch and updated hooks_perf_test_logger_aware to use autoconfiguration without services.yml entries... and then I hit an order of operations bug that wasn't present in my testing on 11.3....
It seems like some combination of the HookCompilerPass, LoggerAwarePass, and the
$container->registerForAutoconfiguration(LoggerAwareInterface::class)->addTag('logger_aware');call are out of order such that a hooks class implementing LoggerAwareInterface doesn't get tagged withlogger_awareby the time the LoggerAwarePass runs and therefore the logger doesn't get set properly.I tried to manually resolve this and didn't get far, so asked Claude for help.
This was the summary of the issue:
It found Bug 2 when trying to fix Bug 1.
The fix for Bug 1:
That then fixed the tagging issue, but Bug 2 surfaced via the error
The fix for Bug 2:
With those 2 fixes everything wired up correctly and I was able to complete my performance tests...
With hooks_perf_test_logger_aware only enabled on 3605797-mark-hooks-services
Wall time: 3.67s
Memory: 70.80MB
Func calls: 3.29M
Comment #13
acbramley commentedAdded testHookServiceLoggerAwareAutoconfiguration which fails without the 2 bug fixes, then the 2 bug fixes as separate follow up commits.
Comment #14
nicxvan commentedIn order for a performance comparison like this to have value we'd need to control the variables a lot more which is why I suggested a script to generate the hook classes, then we would know each module only adds one variation.
Using an LLM to generate these would introduce too much uncertainty, we don't know why those numbers are changing because we didn't control the variables properly.
Comment #15
nicxvan commentedAlso if the priority matters why did your test in 3 work?
Also themes don't support services.yml so they can't provide a default logger so I think this change in theme collector pass actually isn't need.
Comment #16
acbramley commentedCan you please then provide much more detailed steps as to what you'd like to see? It's a bit hard to parse what you're after.
You're suggesting I didn't check and control what it generated? I did.
I'm assuming it's because of some difference between main and 11.3 (see "...and then I hit an order of operations bug that wasn't present in my testing on 11.3..."
LoggerAwarePass is just one example of autoconfigure, there are probably more that themes could benefit from but I'm fine with dropping it (although it would be kinda weird to have them out of sync IMO)
Comment #17
nicxvan commentedSure!
So when I was testing the effect the number of methods had on reflection I put together this script:
(Fun fact, I tried 10 million too and my laptop crashed lol)
We could adapt this to do the same just with 1000 classes each meeting our requirements.
1 module with empty constructor on each.
1 module with two services injected (one of which is the logger)
1 module with two services (one of which is the auto configured logger)
Note I realized we didn't need 4 modules thinking this through further.
We need to test how long HCP takes on HEAD for module 1 and 2, and how long HCP takes on this branch for module 1 and 3.
Module 1 tells us the effect of autoconfigure alone.
Module 2 vs 3 tells us the effect autoconfiguring a service is.
I did assume you spot checked, I didn't think you checked all 4000 classes generated and confirmed exact consistency between each module.
My specific concern about the test is a variation in the number or type of dependencies causing variation in the test rather than just the autoconfiguration we are trying to test.
The nice thing about using a script like above it's repeatable and more easily shareable. We also know exactly what each class contains deterministically and can very easily vary it and test additional edge cases.
It's also not dependent on outside services for other users to verify the test results which is something I do for many performance issues.
Interesting, I really wonder what that could be, it might be worth tracking that down at some point
Yes, let's drop it for now,
Themes and module hooks are already out of sync in important ways.
Comment #18
acbramley commentedIs there a command that would be easy to execute to profile this properly rather than a full
drush cr?Comment #19
nicxvan commentedI'm not sure how we would pare this down since we're testing multiple compiler passes, I think a cache clear with SPX is the way to do it, if you share the script I'll run it too on multiple pages to see the effect.
IIRC the container is rebuilt if the deployment identifier changes so I sometimes put this in settings.php:
$settings['deployment_identifier'] = rand();Comment #20
acbramley commentedOk, here's a bash script that generates 3 modules as per #17 into an output directory. Running it with
--manualwill autoconfigure the loggers via manual services.yml definitions, without--manualwill leave the autoconfiguration to the HookCompilerPass.Performance tests:
I ran SPX_REPORT=full SPX_ENABLED=1 drush cr which does a container rebuild/compile.
I ran the command a few times in each test to ensure consistent numbers and averaged them out.
Baseline
This was just on standard profile install with no modules enabled:
Wall time: 3.36s
Memory: 64.35MB
Func calls: 1.97M
With hook_perf_empty_constructor only enabled
Wall time: 3.49s
Memory: 69.34MB
Func calls: 2.75M
With hook_perf_di_autowire_logger only enabled
Wall time: 3.63s
Memory: 79.44MB
Func calls: 3.18M
With hook_perf_di_autoconfigure_logger only enabled, with manual autoconfigure
Wall time: 3.84s
Memory: 72.48MB
Func calls: 4.25M
With hook_perf_di_autoconfigure_logger only enabled, with automated autoconfigure
Wall time: 3.78s
Memory: 72.44MB
Func calls: 4.23M
So we can see we're actually either improving or barely changing performance by automating the autoconfigure :)
Comment #21
nicxvan commentedThank you, I'll try to replicate this as soon as I can.