Support for Drupal 7 is ending on 5 January 2025—it’s time to migrate to Drupal 10! Learn about the many benefits of Drupal 10 and find migration tools in our resource center.
Problem/Motivation
The Simpletest UI form takes quite a while to render.
It does not currently take advantage of Drupal's sophisticate page rendering caches.
We currently want to simplify TestDiscovery, the class which the UI form uses to gather the list of tests it displays: #1667822: Remove caching of test classes in TestDiscovery
As a consequence, the minor performance improvement that the TestDiscovery cache gave us will probably be removed, and so the form itself needs some attention.
Proposed resolution
Use dynamic caching to improve the performance of the form.
Remaining tasks
User interface changes
API changes
Data model changes
Comment | File | Size | Author |
---|---|---|---|
#50 | 2893117-50.patch | 9.11 KB | yogeshmpawar |
#44 | 2893117_44.patch | 8.99 KB | Mile23 |
#44 | interdiff.txt | 1.82 KB | Mile23 |
#38 | interdiff.txt | 1.82 KB | Mile23 |
#38 | 2893117_38.patch | 10.81 KB | Mile23 |
Comments
Comment #3
Mile23Here's a go.
The value of this patch is tightly coupled to #1667822: Remove caching of test classes in TestDiscovery :-)
The good news: Loading the form on an empty cache is ~23 seconds. Subsequent loads are <10 seconds. This is accomplished by making a hash of the discovered tests in a cache context implementation.
The bad news: The goal of having the cached form reflect changes to tests on the filesystem isn't fixed. That's because the form makes a call to
TestDiscovery::getTestClasses()
, which loadsTestDiscovery
's cache. This happens before the cache is removed by the cache context implementation in order to calculate the hash for the actual filesystem. This is a chicken/egg scenario, and the way to break the cycle is to do both the solution here and removing the cache fromTestDiscovery
in #1667822: Remove caching of test classes in TestDiscoveryThis change is a performance improvement, and without it we still have the problem of cache invalidation within
TestDiscovery
, so we don't lose anything.Comment #5
Mile23Fixed the test.
Also we just invalidate caches all day long so
TestDiscovery
is up-to-date. This means cached requests are 11 seconds instead of 9, but still better than 23. Also this will likely change and be even more efficient after we removeTestDiscovery
's cache, or at least refactor it.And just a reminder: We're messing with this form so that we can decouple
TestDiscovery
away from having a cache, so that we can moveTestDiscovery
out of the simpletest module, so that we can deprecate simpletest. Right? :-) #2866082: [Plan] Roadmap for Simpletest #1667822: Remove caching of test classes in TestDiscoveryComment #6
LendudeJust some nitpicks, the rest looks good to me:
params are missing in the docblock
new param is missing in the docblock
missing docblock
Did some benchmarking:
AB test for 10 requests without patch applied:
Document Path: /admin/config/development/testing/
Document Length: 5156895 bytes
Concurrency Level: 1
Time taken for tests: 129.257 seconds
Complete requests: 10
Failed requests: 0
Write errors: 0
Total transferred: 51581900 bytes
HTML transferred: 51568950 bytes
Requests per second: 0.08 [#/sec] (mean)
Time per request: 12925.723 [ms] (mean)
Time per request: 12925.723 [ms] (mean, across all concurrent requests)
Transfer rate: 389.71 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 27 1121 2299.6 31 5687
Processing: 7151 11805 2278.1 12946 13189
Waiting: 7126 11778 2277.0 12918 13162
Total: 12213 12926 310.8 13015 13224
AB test for 10 requests with patch applied:
Document Path: /admin/config/development/testing/
Document Length: 5158552 bytes
Concurrency Level: 1
Time taken for tests: 71.464 seconds
Complete requests: 10
Failed requests: 1
(Connect: 0, Receive: 0, Length: 1, Exceptions: 0)
Write errors: 0
Total transferred: 51598619 bytes
HTML transferred: 51585519 bytes
Requests per second: 0.14 [#/sec] (mean)
Time per request: 7146.401 [ms] (mean)
Time per request: 7146.401 [ms] (mean, across all concurrent requests)
Transfer rate: 705.10 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 30 2272 2890.6 45 5749
Processing: 71 4874 5744.4 5726 19161
Waiting: 42 4838 5724.8 5696 19062
Total: 5686 7146 4238.3 5821 19207
conclussion
Running this multiple times gives fairly consistent results. So this indicates that the initial request that builds the dynamic cache is considerably longer, but after that things speed up nicely.
Comment #7
dawehnerIs there a better name? test_discovery doesn't indicate for me that this caches the simpletest admin UI. What about using something like 'simpletest_ui_table' or so?
Comment #8
Mile23Updated docblocks, changed the key name.
Honestly I'm not sure what the key is for, because it's basically undocumented. But apparently it needs to be there in order to make the caching context work. It seems like it's just another hash to go in the cache id column.
Comment #9
LendudeAll feedback has been addressed, looks good to me
Comment #10
Wim LeersWhy call this
simpletest
and not justtest
in general? It's about discovered tests, not justsimpletest
tests?Woah, fancy!
Even though it's fancy to have this cache context, this means we're potentially caching many, many variations of the SimpleTest UI. Why can't we just rely on a cache tag?
Comment #11
BerdirI also don't really understand what this is doing exactly.
It defines a new cache bin "simpletest", but TestDiscovery uses cache.discovery, so how is invalidating/deleting in the new bin affecting anything?
Maybe this shouldn't be split from removing caching but just be done at the same time?
Also seems like this needs more than ApacheBench testing but actual profiling with blackfire or so?
Comment #12
BerdirAh I missed that this changes the bin, forget that part.
But even more then, doesn't seem very useful to introduce a new cache bin as a temporary measure to remove it again then?
Comment #13
LendudeHow/when would you invalidate that tag? I don't see it, but maybe I'm missing something?
Really? For the simpletest UI page? The only thing I care about there is the load time, efficiency be damned. ¯\_(ツ)_/¯
Comment #14
Mile23I will give you USD$50 if this patch introduces a performance hit by any metric. :-)
I added a bin because the module is the only thing using the bin. It is a bit out of scope here, so we'll remove it. That means our cache context service is dependent on cache.discovery but no biggie. It also means that the cache of discovered tests will persist even if you remove the simpletest module, but again: Better scope for #1667822: Remove caching of test classes in TestDiscovery
So that takes care of #11 and #12, but leaves #10.3:
The only thing that can invalidate the form cache is a change to the file system. If the tests change at all, then we want to update the form cache.
If that's a tag, then we have to invalidate the tag somewhere. The only place to do that is in the form itself, because this form is literally the only thing in Drupal that cares. :-)
A cache context does this for us automatically, but as you say fills the DB up with cached form stuff. This is mitigated by:
Comment #16
Mile23Unrelated fail.
Comment #17
BerdirI'm sorry, my comment wasn't very useful, was a bit in a hurry.
I didn't mean to say that I'm worried about regressions. What I'm saying is that now the whole thing is a blackbox, we do now how long it takes and we know that is an improvement. But we have no idea which part takes how long. One look at a blackfire.io report might show us a way for some additional improvements.
I gave it a try and what I'm seeing is what I already suspected from the code. Having the render cache removes a huge amount of theme processing, but you're calling the TestDiscovery twice and you are now invalidating it on every request as well. As far as I see, you're basically adding more code to work around the cache as there is actual caching code, so I just don't see how splitting this into two steps is useful.
TestDiscovery::getTestClasses() now makes up 60% of the execution time, which means that by adding a property to store it, we can save another 30% of the execution time.
The total execution time for me per request is 1.6s, which a fast CPU and reasonably fast SDD.
So why exactly is that cache delete/invalidate necessary? My suggestion would be to replace the persistent cache with a static cache/property on TestDiscovery, through out all the cache and cache invalidation code and the result should be about 30% faster than it is now :)
I can maybe work a bit on it on the weekend.
Comment #18
BerdirForgot the blackfire.io screenshot:
Comment #19
Mile23Agreed. And in fact I should have said that this was the ideal solution, and then explained why I did it this way instead. And here's that explanation:
That's why there are a lot of @todos.
In order to remove the
TestDiscovery
cache, we'd have to change a service API. Literally the only thing in core using this API is the form under discussion here, but that's what we'd be doing. We'd also have to make an update function to remove the cached discovered stuff, which should be tested.That's out of scope here, but it will all happen. :-)
Comment #20
Mile23Comment #21
Berdir> That's why there are a lot of @todos.
Yeah, there are literally more @todo's in the patch than there is actual caching code. @todo's that completely remove the caching by writing and deleting it on every request.
> In order to remove the TestDiscovery cache, we'd have to change a service API. Literally the only thing in core using this API is the form under discussion here, but that's what we'd be doing.
We change the implementation, not the API. The only change is in the constructor and protected property which is excluded from BC. And even if we'd keep that, we could simply stop using it. This change is perfectly OK for a minor update and exactly what you want to do in that follow-up .
> We'd also have to make an update function to remove the cached discovered stuff, which should be tested.
I don't see why that's necessary. It's a cache, it will be cleared on the next cache clear. And everyone updating from 8.4 to 8.5 will during the update do at least 2 if not more cache clears. We did update functions to clear caches before but because it was required for Drupal to work correctly after the update, this is just a bit of stale data.
Also, even if we would leave the cache in place, we' need a static property because this change results in two calls to getTestClasses() as shown in my screenshot above, so...
> I will give you USD$50 if this patch introduces a performance hit by any metric. :-)
I think that counts as "any metric" (whole page is faster, but there are additional, unecessary calls that didn't exist before), so cool, thanks! I accept amazon vouchers ;)
Here is a counter-proposal, replacing the optional cache with a statically cached property which is similar to what you already did in the cache context, I think that's worth keeping as calcuting the cache of that huge array is probably not trivial. Although not having it would simplify the kernel test you added. I also added a !empty($types) to the cache logic because it would have still returned all through the cache when calling it with some types only. I also noticed that simpletest_clean_environment() has bogus cache clear calls, it didn't clear the actually relevant cache but two bogus non-existing cache entries. And I removed the max-age line, max-age defaults to unlimited, only needs to be specified if something is not cacheable or only for a specific time.
Execution time here is now down to 1.16s and blackfire shows that the second call is now basically free:
This patch that removes the caching is even a bit smaller than yours and we also fix the other issue.
Comment #23
Mile23Yup, that's the two things in one.
It also allows us to decouple
TestDiscovery
from simpletest #2863055: Move TestDiscovery out of simpletest module, minimize dependencies and eventually decouple simpletest from Drupal #2866082: [Plan] Roadmap for SimpletestSetting to RTBC even though it's partially my work so that we can get maintainer eyes on this and figure out if it should be two issues or one, or whatever. The fail in #22 seems to be unrelated.
Also: Must collect in person. :-)
Comment #25
Mile23Patch still applies, running tests for #21 in 8.6.x.
Comment #27
catchCommitted/pushed to 8.6.x and cherry-picked to 8.5.x. Thanks!
Comment #29
xjmI think this may have broken 8.5.x:
https://www.drupal.org/pift-ci-job/870735
Comment #30
BerdirI saw such errors in an issue too, but I can't really imagine how they would be connected.
This is only about the simpletest UI. run-tests.sh was never using caches (at least not anymore since a long time) and those are phpunit tests actually.
Comment #31
Berdir@xjm: If you haven't seen yet: #2817833: Delay sql map table creation
Comment #32
xjmYep, thanks.
Comment #33
Mile23Woot. Thanks everybody. I still owe @Berdir $50.
Next up in Mission: Destroy Simpletest: #2460521: Deprecate hook_simpletest_alter()
Comment #34
xjmAlright, so while this did not break HEAD, it did break the Simpletest UI. On my local development environment (installed in a subdirectory FWIW), if I enable SimpleTest and navigate to the UI, it briefly flashes an exception message (attached) and then redirects to the installer with the "Drupal already installed" message.
I confirmed that if I revert this commit, it resolves the issue.
The form is slow as heck, but slow is better than broken, so reverting. :) Also moving it to 8.6.x as (given the above) the issue may be disruptive.
Comment #37
Mile23I can't repro.
SHOW VARIABLES LIKE 'max_allowed_packet';
says 67108864.Docs: https://www.drupal.org/node/259580
Are we saying the form takes up too big a cache entry?
Comment #38
Mile23This is #21, with an added test that exercises all of simpletest's routes.
Comment #39
xjmmax-allowed-packet 16777216
So yeah looks like my Homebrew default has 16 MB rather than 64 MB. Unfortunately I can't test increasing it right at the moment.
https://www.drupal.org/docs/8/system-requirements/database-server doesn't specify a requirement for this one way or the other.
Comment #40
BerdirMaybe it should at least mention it though. At least there is a documentation page on the mysql has gone away error. Because it is a pretty common problem, https://drupal.stackexchange.com/search?q=max_allowed_packet has quite a few questions about it.
#1281408: Add a compressing serializer decorator would also help ;)
Comment #41
Mile23This form is pretty much the edge case for everything. :-)
Updated the database docs: https://www.drupal.org/docs/8/system-requirements/database-server#commen...
Comment #42
Mile23Seting to RTBC to see if there's anything else we need to do for this issue.
Comment #43
alexpottFor me this test is duplicating parts of other more extensive tests - for example \Drupal\simpletest\Tests\SimpleTestBrowserTest::testTestingThroughUI() and \Drupal\simpletest\Tests\SimpleTestTest() which do a far more extensive test of running tests via the UI. If we want to test the other routes - fine but then we should have explicit tests that test what each route actually does. The other new thing that is being tested here is the
admin/config/development/testing/settings
route but we're not actually testing the impact of the changes to simpletest_clean_environment() made here.Also I have max_allowed_packet set to 16mb and the form works fine before and after the applying the patch - at least on PHP 7.1.
Comment #44
Mile23We really can't test changes to
simpletest_clean_environment()
but we could if: #2800267: Turn simpletest_clean*() functions into a helper classThe tests you mention get some PHPUnit cleanup in #2932909: Convert web tests to browser tests for Simpletest module
Here's the same patch without the test from #38. It's basically @Berdir's patch from #21.
I'm at a loss as to why we'd see MySQL 2006, other than a misconfigured DB or some other similar concern.
Comment #45
dawehnerMaybe a more radical approach than doing HTML based caching. An alternative would be do pure frontend rendering, and pass along the discovered tests to some JS using
drupalSettings
.Comment #46
Mile23I thought we were trying to get rid of this form.
The reason we're doing this exercise is so that we can decouple TestDiscovery from simpletest so that we can deprecate all or part of simpletest.
It might be that we want to keep the form to display test results, and that it would help us to, for instance, display incoming results as a stream if it were in JS. If that's the case, RTBC here, file a follow-up, and get to work.
Comment #47
jibranBack to RTBC as #43 is addressed.
Comment #49
yogeshmpawarComment #50
yogeshmpawarStraight Re-roll because #44 patch failed to apply on 8.6.x branch.
Comment #51
Anonymous (not verified) CreditAttribution: Anonymous commentedThanks for good reroll. Back to RTBC!
Comment #52
catchThe last time there was a lot of discussion about this form, we got to "Stop using the UI test runner, but keep the form as a test command generator", so it's worth making improvements to the form, even if we change what submitting it does eventually.
Committed 259bf40 and pushed to 8.6.x. Thanks!
Comment #54
Mile23Thanks!
Actually what we got to was: Leave the Simpletest UI form as-is for the D8 cycle, figure out if we hate it in D9.
#2866082: [Plan] Roadmap for Simpletest
That's based on #2750461: Remove Simpletest UI because we don't want to maintain a graphical test runner and #2312191: Change Simpletest UI from a test runner to a CLI snippet generator.