This might sound a bit edge case, but we've run into exactly this problem on DrupalGardens.
Suppose you have an installation profile that enables a bunch of modules, adds sample content, runs cron (as per the end of install_finished()), causing search module to index the display of the sample content. Now, suppose you run the installation task non-interactively, so it happens in a single PHP request.
If theme_get_registry() gets called before all modules are enabled, then when theme() is called in the search indexing phase, it doesn't have access to theme hooks defined by modules that got enabled later, causing both an exception to get triggered, and content to not get indexed correctly.
Probably the most robust solution to this problem would be for theme_get_registry() and theme() to use resettable statics, but that would incur some performance cost, given how large the registry is and how often theme() is called. Perhaps the D8 context core initiative will implement some kind of pluggable renderer that solves this problem cleanly.
But meanwhile, here's a patch that addresses the most common reason I've found for why theme_get_registry() ends up getting called at all during module install and update hooks. For background on this configuration variable, see #318636: Make l() themable.
Comments
Comment #1
sunIf it only pertains to non-interactive installs, can't we move this hack into install.core.inc, wrapped in a drupal_is_cli()?
Comment #2
moshe weitzman CreditAttribution: moshe weitzman commentedLooks like a fine fix. Could live here or in install.core.inc as sun proposes.
I'll just throw in my standard answer that we have way too many caches, and noone really knows when they all get cleared, so we have to play wack-a-mole with resets. Not an easily solved problem though.
Comment #3
David_Rothstein CreditAttribution: David_Rothstein commentedI'd be curious to see how big of a performance hit it actually is. We already use drupal_static() on some pretty heavily-called functions in core, don't we? drupal_alter() comes to mind, especially since that gets called every time url() is called...
If the numbers in #619666-11: Make performance-critical usage of drupal_static() grokkable are correct (they might not be since they were not run against the final committed patch in that issue), then the $drupal_static_fast pattern adds about 0.6 milliseconds to each page request for every 1,000 times it is called, compared to a regular static.
Also, I didn't know that the size of the static variable has a noticeable impact on how expensive it is to call drupal_static(), but if it does, note that the registry itself doesn't have to be stored there (it could simply be a boolean indicating whether or not the registry needs to be regenerated).
Finally, if I understand this bug correctly, it's not limited to the installer at all. Any code that results in this sequence getting called on the same page request would do it, right?
If so, that could be the basis of writing a test for this issue.
Comment #4
effulgentsia CreditAttribution: effulgentsia commentedWhy not. Let's try it David's way :)
Comment #5
effulgentsia CreditAttribution: effulgentsia commentedComment #6
sunhummm.... isn't there a high chance that this will shortcut drupal_theme_initialize()?
Not visible in the diff context are the following lines:
17 days to next Drupal core point release.
Comment #7
effulgentsia CreditAttribution: effulgentsia commentedI'm not seeing how.
&drupal_static('theme_get_registry');
would return NULL before the first time theme_get_registry() is called. And nothing in the patch makes theme_get_registry() called any sooner.Comment #8
David_Rothstein CreditAttribution: David_Rothstein commentedThe patch looks very good to me. I haven't tested out the scenario @sun mentioned, but I think @effulgentsia is right that as long as drupal_static() returns NULL for variables that don't exist yet (which it does) it should be fine.
Will this patch also cut down on Drupal's memory usage? It seems like it should, if both theme() and theme_get_registry() now access the same static to get the registry, rather than caching it separately in two different variables.
Note: I also ran the tests and confirmed that they fail without the rest of the patch applied.
Comment #9
sunThat would be a major improvement. Even though the shared usage of a static is "not exactly clean and an approved way"... @Dries (heavily) warned about possible "mis-designs" like that when drupal_static() got introduced. I'd personally be fine with it in this case.
I think we should be able to test the edge-case I've mentioned. Use the testing profile to load the bare minimum, use a hook_init() or earlier hook to call theme_get_registry() and right afterwards theme('whateversimple') and check whether it blows up or not.
Comment #10
David_Rothstein CreditAttribution: David_Rothstein commentedPatch no longer applied, so here is a reroll for D7 and D8. (This is just a regular reroll - the new test suggested in #9 is not yet added.)
Comment #12
David_Rothstein CreditAttribution: David_Rothstein commentedThat's strange. The test passes fine when I run it locally through the UI. However, when I run it via the command line, I get several failures (not just the one the testbot reports)... Not really sure what's going on.
Let's try to run the tests against the D7 patch also, to see where we're at.
Comment #13
David_Rothstein CreditAttribution: David_Rothstein commentedOK, now the testbot just seems to have gotten stuck.... Let's try one more time.
I'm also attaching a second version of the patch which applies cleanly against Drupal 7.10 (I need this for Drush Make purposes). Sorry for the noise and feel free to ignore that one :)
Comment #15
David_Rothstein CreditAttribution: David_Rothstein commentedHm, no idea at the moment. I can generally reproduce those failures locally, but only when running tests via the command line. But the failures in SimpleTestFunctionalTest I can reproduce through the UI also.
I think this might turn out to be one of those "interesting" Simpletest-related bugs...
Comment #16
sunIt looks like this issue is going to help me with some other tough Testing system issues.
The test failure can be cleanly reproduced when running tests with run-tests.sh:
Attached patch makes it work.
Comment #17
David_Rothstein CreditAttribution: David_Rothstein commentedAh, very nice... So basically, during simpletests there must be a code path somewhere that involves theme_get_registry() being called before theme(), so that's why the drupal_theme_initialize() call has to happen inside there. (And in theory this could happen outside simpletests also, but I guess it doesn't.)
My only comment:
So ideally we want to avoid this, because theme() is called very often and it's an extra function call every time. Basically, it's the same performance hit as using drupal_static() as opposed to the "drupal_static_fast" pattern.
I think it should be possible to use 'drupal_static_fast' here too (and directly share the static), more like my previous patch. If we want to. Maybe it's not worth the micro-performance-optimization, because doing it like in your patch definitely keeps the code a lot cleaner, and the only 'drupal_static_fast' pattern that is used winds up being the more standard one.
Comment #18
sunI forgot to mention that I actually played around with a couple of drupal_static[_fast]() variations (based on your previous patch), but none of them worked - the theme was never properly re-initialized after a reset.
Not to mention that this entire static caching in theme.inc is a horrible mess... I'd say, unless someone can prove that the function call (which simply returns the static cache from theme_get_registry()) has a serious performance impact, #16 looks a lot cleaner to me. Additionally, as you already mentioned, this change makes us statically cache the theme registry only in once instead of twice - so if anyone is going to do performance benchmarks, then we need to measure both the processing time and memory consumption.
Comment #19
David_Rothstein CreditAttribution: David_Rothstein commentedMakes sense to me.
Since the previous patch had a whole different set of test failures in D7 compared to D8, let's try a new D7 version and make sure the tests now pass there too. I'll move this back to D8 as soon as the testbot runs.
Comment #20
David_Rothstein CreditAttribution: David_Rothstein commentedBack to Drupal 8.
I noticed that testRegistryRebuild() was running the same assertion twice in a row, so I removed one of them in the attached. This fix is already in the Drupal 7 patch.
Comment #21
sunAh, sorry for that little oversight. But yeah, this gives me the chance to rant about the current insanity of handling $message assertion parameters -- I've become the anti-fan of custom assertion messages, since they completely hide the actual asserted values in the verbose test output. IMO, we badly need to do something about that. But yeah, separate issue ;)
This patch looks ready to fly for me.
Comment #22
sunQuote @moshe from #2:
This patch removes a particularly wack one, a static that duplicates another static, whereas none of the two is or can be reset while the entire subsystem can be reset/re-initialized. Architecturally, that makes no sense.
On top of that, it fixes a relatively major bug in terms of module/theme subsystem dependencies. The theme system is not properly updated for the current implementations within a request when it ought to be.
The two statics are replaced with a single resettable drupal_static(), and the second function previously having a static calls into the first/central instead. This means more function calls, but less memory usage.
Based on that, I think this is ready to be committed.
Comment #23
effulgentsia CreditAttribution: effulgentsia commentedIt's hard for me to imagine catch accepting this without benchmarks, but leaving as RTBC, so that he can make that call.
Comment #24
David_Rothstein CreditAttribution: David_Rothstein commentedSo it turned out there was a wee little performance problem with this patch... see the attached interdiff :)
Here is a new one that fixes that.
Comment #26
sunoh my. Looks like someone with a full PHP environment debugger needs to actually plant the test lines into index.php and check where the heck this is statically cached deeper down the rabbit hole.
Thanks for fixing my blatant mistake, @David_Rothstein! No wonder that my patch passed ;)
I already spent a few hours with this patch, and was really confident the theme/theme_get_registry changes would resolve it.
If you'd ask me: This amount of excessive static caching in the theme system is not maintainable anymore. Whatever we can drop without major performance impact, I'd personally suggest to drop.
Comment #27
David_Rothstein CreditAttribution: David_Rothstein commentedI have a version of this patch running in a production environment, so I'm hoping/planning to dig deeper into this later today and figure it out :)
Comment #28
David_Rothstein CreditAttribution: David_Rothstein commentedLooked into this a bit more, and this turns out to be a really odd one.
Basically, it seems that calling
drupal_static_reset('theme_get_registry')
can result in the database cache getting populated. Yup. The reason is due to the fact that there's a DrupalCacheArray object stored in the static cache, and that object's __destruct() method has some code which basically says "save any new stuff to the database cache when this object is destroyed". That's the case for 'theme_test_foo' in the theme registry (when the module that provides it is disabled during the test), so clearing the static cache winds up putting the stale data right back into the database cache, and the test fails.The attached patch fixes it by simply rearranging the cache-clearing order in drupal_theme_rebuild(), but that certainly seems like a workaround more than a fix. However, let's at least see if the testbot likes it that way.
Meanwhile, it turns out that the Drupal 7 test failures are due to something else entirely... don't know what at the moment.
Comment #29
oriol_e9g#28: drupal8.theme-registry-reset.28.patch queued for re-testing.
Comment #30
David_Rothstein CreditAttribution: David_Rothstein commentedOK, I think I figured out the test failures in Drupal 7. Let's move this there temporarily to see if the testbot agrees.
Basically the problem is that the setUp() method for DrupalWebTestCase resets static variables too late in the pseudo-installation process, so that there's a chance to talk to a simpletest database that doesn't exist yet. In Drupal 8, this setUp() bug was already fixed as part of #81461: Clean up the cache API (stop overloading function arguments, remove procedural wrappers) (though there doesn't seem to be a comment in that issue explaining the motivation). If we move the drupal_static_reset() call earlier in Drupal 7 too, that should hopefully fix the broken tests, so let's try that.
Comment #31
David_Rothstein CreditAttribution: David_Rothstein commentedAlso, this issue really belongs in the theme system queue at this point.
Comment #32
sunInteresting. That change kinda "conflicts" with my patch in #1376122: Stream wrappers of parent site are leaking into all tests, in which I'm moving the config/static reset (back) to the bottom. The reasoning for doing so, over there, is that every single of the function calls to prepare the testing environment primes various statics and subsystems (directly or indirectly) again with environment parameters of the parent site. Therefore, we want to perform the resets right before
drupal_install_system()
, so it is guaranteed that nothing is primed.Comment #33
David_Rothstein CreditAttribution: David_Rothstein commentedHm... Maybe that issue should add a second drupal_static_reset() call, rather than moving the existing one? If we're lucky that would solve both problems.
The Drupal 7 tests passed here, so I'm reuploading the Drupal 8 patch.
Comment #34
tamasd CreditAttribution: tamasd commentedReroll of David's patch in #30 for Drupal 7.12.
Comment #35
sunI'm happy with #33 (and it doesn't seem to introduce a second reset in setUp())
Comment #36
David_Rothstein CreditAttribution: David_Rothstein commented#34 is broken since it redeclares theme_test_theme() twice. Here's a rerolled version to chase the latest Drupal 7.x code.
Comment #37
sunAnyone up for doing benchmarks / basic profiling here?
I don't expect any difference in performance, but this needs to be confirmed.
Comment #38
xjmThis is blocking #1454686: When a new module is installed, the admin role doesn't get all new permissions, which is major, so escalating to major.
Comment #39
sun#33: drupal8.theme-registry-reset.28.patch queued for re-testing.
Comment #41
sunmeh. No more D7 patches in here, please.
Comment #42
sun#33: drupal8.theme-registry-reset.28.patch queued for re-testing.
Comment #43
sunRe-rolled against HEAD.
Comment #44
Anonymous (not verified) CreditAttribution: Anonymous commentedi think this is good to go if the bot comes back green.
it's a simple patch, and the trade-off of an extra function call to get a) less duplicate arrays of doom and b) functional reset capabilities is worth it IMO.
Comment #45
no_commit_credit CreditAttribution: no_commit_credit commentedStripping
t()
from the assertion messages and uploading the tests by themselves to expose the expected failures. The docblock for that theme function is also probably not to standard but I don't know how to correct it, either, so. ;)Comment #46
Anonymous (not verified) CreditAttribution: Anonymous commentedgreens.
Comment #47
catchThanks. Committed/pushed to 8.x, moving to 7.x for backport. I don't think this needs profiling, we know how expensive drupal_static() and function calls are already, and this fixes a functional bug.
Comment #48
tim.plunkettRerolled.
Comment #50
xjmLooks like #48 has already been requeued on testbot (which also makes the previous results hard to find). I can't see any reason for it to fail.
Comment #51
tim.plunkettOkay, had missed a hunk in module_enable. Also removed the data type hinting in @param.
Comment #52
tim.plunkettfor the bot
Comment #54
tim.plunkettLast attempt for the night. Sorry for the noise.
Comment #55
tim.plunkettComment #56
xjmUm actually, the "combined" patch is failing and the "tests" patch is weirdly empty/not viewable. :)
Also, for the record, I did check the branch tests and they are OK:
http://qa.drupal.org/8.x-status
Comment #57
sunI'm not able to reproduce the test failures after cherry-picking the commit from 8.x and manually resolving the conflicts.
Comment #59
tim.plunkettSee, the cherry-pick just blew up for me, which is why I tried to do it with patch -p2. Grr.
Thanks sun.
Comment #60
tim.plunkettCross post, also, those are the same failures I had in #51.
Comment #61
David_Rothstein CreditAttribution: David_Rothstein commentedEr... folks? I already debugged this for Drupal 7 a while ago. See #30 :)
Here's a reroll of #36, which was the latest D7 patch. I left the t() messages in the assertions (based on the theory that we might still be leaving them there for D7, though I can't remember).
Comment #62
xjmWe don't. :)
This hunk should also go. :)
Fixed here.
Comment #63
sunok, sorry for not catching the advanced debugging that happened earlier. I'm happy with the DrupalWebTestCase change for now, and I'll figure out what to do about #32 later, in a separate issue.
For later reference: Since this is about the theme system/registry, this likely means that some of the functions being called to prepare the testing environment have a dependency on the theme system, but since the database gets nuked/replaced, there's no more theme registry, even though the current theme registry still exists in a static. (In turn, this might be caused by the ThemeRegistry/CacheArray, which tries to write a cache on destruction [when statics are reset], but the new database does not contain a cache table yet.)
Comment #64
webchickWow. EPIC sleuthing here, folks. I was concerned about benchmarks, but catch seems to think this is ok.
Committed and pushed to 7.x. Thanks!
Comment #66
grendzy CreditAttribution: grendzy commentedThis patch had the strange side-effect of making simpletest always run with clean urls off, so some contrib tests have stopped working. Was that intentional? In the past I believe simpletest would inherit the clean_url setting from the host site.
Comment #67
Dave ReidUm, holy crap. Moving $conf = array() up to before the variable_get() calls completely screws up setUp(). We cannot make a change like that.
Comment #68
swentel CreditAttribution: swentel commentedIt looks like this may have broken clean urls in simpletest. Confirmed by me and grendzy. Davereid also thinks that moving the $conf variable is the cause of this. I'm not sure whether this is good or bad though. But previously, I could assert on say /node/1 in my simpletests, which is of course not the right way, I should've used url(). Still, some contribs are starting to produce failures because they are doing it wrong as well.
Comment #69
swentel CreditAttribution: swentel commented- edit - didn't mean to change the status, crossposts all over the place :)
Comment #70
catchBumping to critical if this has broken 7.x tests in contrib modules unintentionally, also we should do any fixes in 8.x first then backport again.
Comment #71
David_Rothstein CreditAttribution: David_Rothstein commentedHm, in that case, Drupal 8 has been broken this way for a long time (the change was introduced in another issue, not this one)... So let's not discuss this here. I'll open a fresh issue.
But now I finally understand the reason for this (previous) discrepancy between D7 and D8: #1346772-22: StatisticsLoggingTestCase->testLogging() fails with clean URLs in some environments. After the commit here, they are now consistent again, but in the wrong way :)
Also, we should fix this, but I'm not sure I see why it's critical. If a test failed because of this, then it was already an unreliable test that would have failed in certain environments anyway, right?
And this:
seems like it might actually be environment-dependent for two reasons; not only does it assume clean URLs, but it also assumes Drupal is installed at the top of the domain, rather than in a subdirectory. (Well, I guess so. Maybe it depends on exactly what the assertion was; checking for
<a href="/node/1">
would definitely be making that assumption though, and so for many people those tests would have been failing all along.)Comment #72
David_Rothstein CreditAttribution: David_Rothstein commentedCreated #1587990: Regression: Simpletest always runs with clean URLs off and went with major priority for now.
Comment #73
sunI'm sorry for this, but the reality is that it's a pure coincidence of many different factors which made Simpletest's original setUp() code ever "work."
Some background in #1587990: Regression: Simpletest always runs with clean URLs off
For the impatient: The proper fix is to perform a full backport of #1541958: Split setUp() into specific sub-methods
Comment #74
chriscohen CreditAttribution: chriscohen commented@David_Rothstein in our case, we use a non-standard public file path. This change has broken the 'verbose' link in simpletest, as it now links to the wrong location, and makes it virtually impossible to see verbose simpletest messages. So, I'd say this was down to more than just fixing unreliable tests.
#1587990: Regression: Simpletest always runs with clean URLs off therefore doesn't cover ALL the things that were broken by this change... I'd suggest either reopening this or creating a new issue for this new "non-standard public file path is borked" issue.
Comment #75
sun#1541958: Split setUp() into specific sub-methods fixes most regressions that have been stated here.
I've no idea what "we're using a custom public files path for tests" means, but that belongs into a separate issue, indeed. Please create a new issue to explain and link to it here.
Comment #76
chriscohen CreditAttribution: chriscohen commentedIn Drupal lingo...
;)
I have now filed #1597064: Verbose links in simpletest results fail when public files path is not default as you suggested.