Updated: Comment #19
Problem/Motivation
It is possible for implementations of hook_form_alter() to disappear from the module_implements() cache, such that they are not called anymore.
This can apparently happen with the GenPass module installed, for example.
Proposed resolution
Per #10, this could be due to a module calling module_implements() before all modules are loaded.
To prevent that from corrupting the cache, core could add a line to the module implements cache to prevent a cache write for that request. The theme registry has a similar problem which has already been fixed similarly in #592008: Don't save theme registry before modules are included.
Alternatively (or in addition), this could be fixed within the modules that call this function too early.
Remaining tasks
Determine exactly how to reproduce the bug and where it should be fixed.
User interface changes
None.
API changes
None yet.
Related Issues
None yet.
Original report by Growiel
We're using the GenPass Module which implements hook_form_alter().
After a variable time, the module seems to diseaper from the module_implements cache.
The module is still activated in the database, we can var_dump stuff from the module file, but the hook_form_alter is not called anymore.
We looked in the cache table (after changing it from BLOB to TEXT) and saw that genpass was absent from the module_implements cache.
Is there any reason why the cache would suddendly remove the module from the module_implements list ?
Comment | File | Size | Author |
---|---|---|---|
#48 | core-bootstrap-phase-fix-1934192-51-7.x-dev.patch | 1.73 KB | angrytoast |
#47 | core-bootstrap-completion-1934192-47-7.x-dev.patch | 2.06 KB | angrytoast |
Comments
Comment #1
pfrenssenThanks for the report. Did this occur on a site with only Drupal core installed or do you have any contributed modules enabled apart from GenPass? If you have more modules installed you will need to narrow down the problem by trying to disable some modules and then replicating the problem.
The module_implements() function is one of the most important functions in Drupal and is extremely well tested. Chances are that the problem is not in Drupal core but in a contributed module, but you'll need to figure out which one.
Can you try to set up a system where you can replicate the problem? You can reset the module_implements cache by calling:
Then you can rebuild it and look if your module exists in the list by calling:
A good idea would also be to grep your sites/all/modules folder and look for any modules that happen to mess with the module_implements() cache.
If you find that the problem only occurs when a certain module is enabled, then you can move this issue to the queue of module. If you can reliably repeat the problem with only Drupal core, then it would be great if you could provide some more information on the circumstances.
Happy debugging!
Comment #2
netbear CreditAttribution: netbear commentedI've got the same problem in drupal-7.21 and commerce_kickstart profile enabled. But I have it with my very simple module with only one hook:
When I clear all caches, my validation function does work, but after some time it stops working. I clear the cache again and my function again works as I expect for some time(changes the output of views module).
Also I put drupal_set_message('hello'); into the hook and it sends message only after clearing cache for some time (may be only before first cron run) and stops after that.
Here is the related question: http://drupal.stackexchange.com/questions/50950/hook-form-alter-only-fir...
Comment #3
netbear CreditAttribution: netbear commentedComment #4
netbear CreditAttribution: netbear commentedComment #5
soxofaan CreditAttribution: soxofaan commentedprobably related in the CAPTCHA module issue queue: #1874038: drupal captcha always disappear, return when clear performance cache
Comment #6
netbear CreditAttribution: netbear commentedmy new code in module is even simpler:
and again i get the message for some time after cache clear and after that it disappeares.
I even tried to add simple hook_form_alter into 2 modules and they both work for some time after cache clear action and later are both switched off.
And it happens for every form on my site.
Comment #7
Growiel CreditAttribution: Growiel commentedHappy to see i'm not the only one with that problem, maybe someone from Drupal will actually get a look at it.
@pfrenssen, I did all that debugging before opening the ticket, that's how I pinpointed the problem in the module_implements cache.
Comment #8
Growiel CreditAttribution: Growiel commentedThis is actually affecting multiple modules.
This is the contain of the "module_implements" line of the "cache_bootstrap" in the database, just AFTER clearing the cache (I isolated only the "form_alter" part) :
and about 45minutes later :
That's SEVEN modules that get removed from the cache !
Comment #9
matt2000 CreditAttribution: matt2000 commentedSome random questions that might shed light on avenues for exploration:
- Are you using memcached or anything other than Drupal's built-in cache backend?
- Do you use drush to clear caches sometimes?
- Do you run cron in a way that it might be run as a user other than the web server user?
- Do the modules that go missing have different filesystem permissions than the ones that don't?
Comment #10
catchThis sounds like a module calling module_implements() before all modules are loaded.
To prevent that from corrupting the cache, could add a line to the module implements cache to prevent a cache write for that request. The theme registry has a similar problem which has already been fixed similarly #592008: Don't save theme registry before modules are included.
Comment #11
Growiel CreditAttribution: Growiel commented@matt2000:
1) We use APC.
2) Never.
3) The Drupal cron is always used by the same user as Apache's. We have other cron running on other user accounts, but nothing to do with Drupal. This is how we do it :
0 * * * * /usr/bin/wget -O - -q -t 1 cron.php?cron_key=IaeTD5DN3RhyMiSqv0GF8GLBQcbI2Z8OHY0EUIIpBEE
4) They're all the same: owned by the webserver user with 755 permissions.
@catch:
I can search for "module_implements" in my entire "module" directory, but how will I know if it's called "too soon" ?
Comment #12
netbear CreditAttribution: netbear commented1) Use only drupal built-in cache backend
2) Don't use drush to clear cache. Sometimes use admin-menu to clear cache when do some changes.
3) run cron as server user
4) I created module with only one hook form_alter and use commerce_kickstart install profile, all permissions are standart, no special files.
Comment #13
criznach CreditAttribution: criznach commentedWho's your host and what are your PHP and MySQL versions? That might help to reproduce the problem and get a closer look.
Comment #14
Growiel CreditAttribution: Growiel commentedWe're hosted on decicated servers by OVH (French hosting company) with PHP 5.3.15 and MySQL 5.1.49 on Apache 2.2.16 (Debian)
Comment #15
jaredsmith CreditAttribution: jaredsmith commentedThis issue could use an updated issue summary based on the templates at http://drupal.org/issue-summaries.
Comment #16
kkubali CreditAttribution: kkubali commentedI'm about to work on this in the Portland 2013 sprint.
Comment #17
netbear CreditAttribution: netbear commentedMy site have changed hosting and the problem remained but is happening less frequently (now it is happening one time for day and before it was every hour or less).
Comment #18
criznach CreditAttribution: criznach commentedNetbear did your cron schedule change?
Comment #19
netbear CreditAttribution: netbear commented@ criznach : No, the shedule is the same, because call to cron is still going from old server, no cron tasks on new server yet, but strangely this again is happening with the same frequency as before.
I have no genpass module installed on my site, though I looked into the code of this module and found call to module_implements() function, but I've not understood how it could be called before all modules been loaded. The module_implements() function not called in hook_init or something like this. I've found only that in genpass module it is called in the process of altering genpass admin form and when validating user register form.
So my problem with disappearing form_alter_hook still persist, may be because of some of installed modules. Can anyone explain what to look for in these modules, which can cause the problem?
I also checked what is returned by module_implements('form_alter') after cache clear and before and only my module is absent in the list before cache clear and presents for some time after. All other modules aren't touched.
Comment #19.0
netbear CreditAttribution: netbear commentedAdded Issue Summary
Comment #19.1
David_Rothstein CreditAttribution: David_Rothstein commentedUpdate issue summary to flesh it out and restore the original report
Comment #20
David_Rothstein CreditAttribution: David_Rothstein commentedThe issue summary looked incorrect (it mentioned GenPass as the module to "blame" but based on the comments that doesn't sound true, or at least not the only one) so I fixed it up a bit and also restored the original report which contained a lot of the initial information about what the bug is.
Is this really a critical core bug? Do we need to figure out which module is calling module_implements() too early still?
Comment #21
David_Rothstein CreditAttribution: David_Rothstein commentedI have tried to reproduce this with Commerce Kickstart (as recommended above) but after waiting a while and also running cron several times, my hook implementation still never goes away.
I think this still needs steps to reproduce and information about which modules are causing it. (I'd recommend looking at modules that have hook_boot() implementations as a possible culprit.)
Or... we could just not worry about it and do what @catch suggested in #10, since that seems like an improvement anyway. Downgrading to major, though, and also moving to Drupal 8 since as far as I know there's no fix for that in Drupal 8 yet.
Comment #22
Growiel CreditAttribution: Growiel commentedNice to see some activity on this.
I've looked once again in the Genpass module code and I can't figure out if they call module_implements() "too soon". They call it once in a custom function and not in hook_boot() or hook_init() which leads me to believe that this is not the problem.
This issue is only appearing in our production environment, I can't reproduce it in my local environment.
To fix it we're using a really uggly but function fix where we check directly in the DB if genpass is present inside the module_implements cache. If not, we force Drupal to rebuild said cache.
I think this still needs to be fixed directly for D7 as most people (us included) won't be switching to Drupal 8 any time soon.
Comment #23
netbear CreditAttribution: netbear commentedMy temporary workaround of this situation is to transfear code of hook_form_alter from my module to template.php of the theme. Not good, but works for me untill problem will be solved.
Comment #24
netbear CreditAttribution: netbear commentedMay be it will be helpful to locate the bug, print here the output of command to find all "boot" words in my site directory.
find . -name '*.module' -type f -print0 | xargs -0 grep "boot"
==============
=================
So, hook_boot implementations are only in variable, variable_store, variable_realm, i18n modules and only two of them are enabled on my site - variable and i18n. In variable and i18n modules functions variable_boot and i18n_boot are empty and are there just to ensure modules are loaded on early faze of bootstrapping for other modules (like variable_realm) to be able to use the API. I have only i18n_field module enabled in addition to i18n itself and no variable submodules enabled at all.
Comment #25
Growiel CreditAttribution: Growiel commentedSo for me hook_boot is in i18n, bonita_loopfuse_module (custom module, no signs of module_implements in it), variable_realm, variable, variable_store and performance.
Comment #26
dlumberg CreditAttribution: dlumberg commentedI'm experiencing this with https://api.drupal.org/api/drupal/modules!system!system.api.php/function... not getting rebuilt for the http://drupal.org/project/eck module. I added a new module to try and use module_implements_alter to re-add eck as a quick bandaid fix but the new module won't run any hooks.
Like Growiel #22 it's only happening on our production site and I'm unable to reproduce it on our staging or testing environments.
I know that one of our developers was getting errors trying to import some entity objects and at one point truncated the field_config table before re-importing it. I'm thinking that cron may have run before he re-imported it and it may have altered some sort of system or registry entry. Right now I've got debugging code all over the place and if I figure out what's actually happening then I'll report back.
EDIT:
OK so after some more playing around I moved cache_bootstrap into my APC cache out of memcache and it started working. Then I was deluged with emails from the server about CLI caches not being able to be cleared (Our cron is running through drush & elysia). So it would appear that there is a module that is clearing the cache on every cron run which is not running a full bootstrap.
In my case it's the feeds module. I think the problem was getting and setting several variables during it's cron run. I didn't dig into the classes that the functions in feeds_cron was calling to see if there were any cache_flush calls.
Comment #27
Growiel CreditAttribution: Growiel commentedWe don't use memcache, but we do use APC. We also don't use the Feeds module.
How were you able to pinpoint the problem to the Feeds module ? Maybe I can do the same to locate witch one of my modules is creating the issue.
Comment #28
dlumberg CreditAttribution: dlumberg commentedI had added this line to my settings.php
and we have our server set up to email us if there's an error running jobs in crontab (using a ".forward" file containing just an email in /root). Since APC isn't setup to run on the command line and we run cron through drush it was returning the error about not being able to clear the variable cache. I was able to determine the frequency that it was happening, in my case at every 1 and 6 (9:01, 9:06, 9:11.....). I then checked Elysia cron for anything that was set to run at a 5 minute interval and narrowed it down to feeds by changing the intervals one by one down to 1 minute.
Comment #29
dlumberg CreditAttribution: dlumberg commentedI think this may be caused by elysia_cron and the bootstrap level in drush. To get elysia-cron to run a full bootstrap you can change the elysia_cron.drush.inc file:
Cross posted to issue in elysia_cron https://drupal.org/node/2023586
Comment #30
catchThat sounds very likely to be your problem, of course other modules can trigger the bug via the same mechanism.
This has already been fixed in Drupal 8:
moving back to Drupal 7.
Comment #31
netbear CreditAttribution: netbear commentedThe bug is really annoying. Today I installed Captcha module on my site and it worked for some time as expected but after some time captcha disappeared.
I compeared the output of
before cache clearing and after and found that not only 'form_alter' hook suffered but other hooks too, for example 'element_info' hook.
'element_info' section after cache clear contains
-----------
array (
'addressfield' => false,
'captcha' => false,
'contextual' => false,
'date' => false,
'date_api' => false,
'date_popup' => false,
'field_ui' => false,
'file' => false,
'filter' => false,
'imce' => false,
'link' => false,
'system' => false,
'user' => false,
'variable' => false,
'rules' => false,
),
--------------
'element_info' before cache clearing contains
--------------
array (
'addressfield' => false,
'contextual' => false,
'date' => false,
'date_api' => false,
'date_popup' => false,
'field_ui' => false,
'file' => false,
'filter' => false,
'imce' => false,
'link' => false,
'system' => false,
'user' => false,
'variable' => false,
'rules' => false,
),
-----------
As you see captcha hook element_info disappeared.
So, when I tried my workaround with form_alter invoke through my theme template.php
it didnot work because though $form['captcha'] was added to form, drupal was not able to render captcha element:
------
array ( '#type' => 'captcha', '#captcha_type' => 'image_captcha/Image', '#description' => 'Ниже не психологический тест, просто мы устали бороться с автоматическим спамом и проверяем, что пишет живой человек.', '#weight' => 98.9, '#tree' => false, '#parents' => array ( 0 => 'captcha', ), '#array_parents' => array ( 0 => 'captcha', ), '#processed' => false, '#required' => false, '#attributes' => array ( ), '#title_display' => 'before', '#id' => 'edit-captcha', '#sorted' => true, )
---------
There are 2 questions for me:
1) What should we do to make impossible to modules to damage cache_bootstrap, is there quick temporary patch to current stable version of drupal 7?
2) What to look for to find the module that corrupts cache_bootstrap?
Comment #32
netbear CreditAttribution: netbear commentedWhen I look into file cron.php I see there drupal_bootstrap(DRUPAL_BOOTSTRAP_FULL); before the function drupal_cron_run(); is called, so it seems that there is no possibility to execute module_implements function before all modules are loaded.
Also I tried to give weight=-1 to captcha module in system table of database to load this module earlier, but it didn't solve the disappearing of captcha after some time after cache clearing.
Comment #33
David_Rothstein CreditAttribution: David_Rothstein commentedhook_boot() runs during the bootstrap, so module_implements() could still be executed during an implementation of that hook, before all modules are loaded.
Comment #33.0
David_Rothstein CreditAttribution: David_Rothstein commentedFix comment links.
Comment #34
Solidmark CreditAttribution: Solidmark commentedI thought I would share this in case it helps someone. In our case, it turned out to be a case of simple stupidity, but since the symptoms (cache poisoning) were almost identical to this and equally as hard to track down I thought it worth posting.
In our case we were experiencing module_implements randomly losing items but were unable to find any issues with any modules we had installed. The only solution was to continuously clear the cache which obviously wasn't a viable option in the long term.
As it turns out:
1) We had a staging server running openly accessible with the same code,
2) Sharing the same database (not intentionally),
3) But whose codebase was not up to date with the live site. Therefore missing the very modules that would randomly and mysteriously drop from the live module_implements cache.
Naturally, each time the staging site was pinged - bam. Cache poisoned. And incredibly difficult to track down.
Comment #35
joachim CreditAttribution: joachim commentedThere are quite a few reports over at Flag of hook data disappearing from the cache: #1925922: Unsupported operand types in factory_by_row() in flag_flag.inc.
Comment #36
chx CreditAttribution: chx commentedIs #496170: module_implements() cache can be polluted by module_invoke_all() being called (in)directly prior to full bootstrap completion related / duplicate?
Comment #37
joachim CreditAttribution: joachim commentedIt looks like it might be a duplicate.
Comment #38
catchYes, marking this one duplicate since the other is older and has an RTBC patch. #496170: module_implements() cache can be polluted by module_invoke_all() being called (in)directly prior to full bootstrap completion.
Comment #39
Molfar CreditAttribution: Molfar commentedThis is not a duplicate. This topic is about randomly disappearing hooks. Not about bootstrap mode overwriting.
Comment #40
joachim CreditAttribution: joachim commentedThis to me looks like an effect of the bootstrap overwriting. Could you explain more why you think this is a different bug?
Comment #41
Fabianx CreditAttribution: Fabianx as a volunteer commentedClosing again as duplicate, because I saw randomly disappearing hooks (fences not finding its own hooks ...) as well and the other patch fixed those.
Comment #42
codeelegance CreditAttribution: codeelegance as a volunteer commentedI hate to open this again at this late date.
Running core 7.53 and the most recent version of panels, ctools, etc.
Recently our site has been experiencing a loss of content on panels pages. A simple cc fixes it, but that only lasts about 45 minutes. After a lot of digging, I narrowed it down to the module_impliments record of cache_bootstrap. The only difference I could tell between the record BEFORE the content went missing and AFTER was some missing hooks - for instance ones for panels.
The patch for the "duplicate" issue: https://www.drupal.org/node/496170 is in my version of core, so I don't think that's it.
If someone can convince me I shouldn't have awakened this issue, I'm more than willing to listen...
Comment #43
amit0212 CreditAttribution: amit0212 as a volunteer and at Iksula commentedIf you look at the module_implements() function, it uses the following code to reset the hook cache:
cache_set('module_implements', array(), 'cache_bootstrap');
drupal_static_reset('module_hook_info');
drupal_static_reset('drupal_alter');
cache_clear_all('hook_info', 'cache_bootstrap');
Comment #44
joachim CreditAttribution: joachim as a volunteer commentedAn issue should only be set to 'needs review' if there's a patch.
Comment #45
amit0212 CreditAttribution: amit0212 as a volunteer and at Iksula commentedComment #46
Fabianx CreditAttribution: Fabianx as a volunteer commentedOkay, I found the problem:
- module_hook_info() is protected via:
but that's not enough.
Because the phase is set in drupal_bootstrap() _before_ it is completed anything that goes wrong during module_load_all() (e.g. DB unavailable) can trigger the module_hook_info() to be incomplete
Proposed fix:
New core function to get the completed phase:
Comment #47
angrytoast CreditAttribution: angrytoast as a volunteer commentedAdding a patch per the comment in https://www.drupal.org/project/drupal/issues/1934192#comment-12937496
This adds:
- A net new
drupal_bootstrap_completed_phase()
function- It relies on an internal static variable to track the completed state
- It is called in
drupal_bootstrap()
after the bootstrap phase function to ensure that the completed phase is only updated after the function runs.I did come across a point of clarification for
drupal_get_bootstrap_phase()
during the process. This function states that it is retrieving the completed phase. Per the previous comment this is actually the initiated phase, which doesn't guarantee that it is fully completed?Comment #48
angrytoast CreditAttribution: angrytoast as a volunteer commentedLooking over the
drupal_get_bootstrap_phase()
function, it callsdrupal_bootstrap(NULL, FALSE)
, and it is already used in other parts of core to check against the current phase. The function doc states:Based on that, here's an alternate patch that:
- Rearranges the phase variable assignment in
drupal_bootstrap()
to after the bootstrap phase function has executed.- Updates
module_hook_info()
to calldrupal_get_bootstrap_phase()
rather thandrupal_bootstrap(NULL, FALSE)
Comment #49
gambryFrom whoever lands in this issue, I'm experiencing this as well on Drupal 8.
It's really difficult to nail this is the true origin because the errors actually happen in completely unrelated places: missing tokens, entity info alter not taking places, hook_module_implements_alter() hook priorities not respected, etc. But when you go down into the rabbit's hole you ended up with wrong cached module_implements.
Not sure if it's related to code as this issue - D7 and D8 are different, but still the code of the latter is inspired by the former - or to my setup - BLT 9.2.0, Lightning 3.301, Memcache, Acquia.
If anyone has a clue, or simply experiencing the same in D8 raise a hand, or share a drink. :(
Comment #50
jtwalters CreditAttribution: jtwalters commented@gambry can you describe your hosting setup? Is it a multi app container host like Pantheon by chance? I am curious if there's other complicating factors to this bug.
edit: nevermind, saw you are on Acquia.
Comment #51
gambryRE #49 I may have found to culprit for Drupal 8. Due the randomness of the error - in both the symptoms and the frequencies it happened - I can't be 100% sure, but after we applied the fixes explain below we haven't been experiencing the same issue since 3 weeks now.
hook_form_FORM_ID_alter
and so we had themodule_implements
cache item growing for no reasons. Form IDs don't need to be dynamic. Although this is unlikely to fix the issue, for sure was a natural trigger due all the writes against themodule_implements
cache.Comment #52
roi CreditAttribution: roi commentedHappens on D8 - my hook is MODULE_views_query_substitutions()
It is called correctly after cache-clear, but then after a few hours it stops, and my view query becomes wrong.
Servers are stable
2 servers behind AWS load balancer with EFS as file system.
Comment #53
gambry@roi have you checked module_implements values before and after not working as expected?
That's the first step to understand what's going on. And then - if they ARE different - you may want to check if you have belong to any of the two cases on #51.
Comment #54
roi CreditAttribution: roi commented@gambry
Indeed I checked \Drupal::moduleHandler()->getImplementations("views_query_substitutions")
and saw that my module implementation was missing after some time.
Unfortunately, none of the options in #51 apply.
Comment #55
gambry@roi I don't know if there is a smart way to debug this. The only thing coming up on my mind is swapping the module_handler service with a custom handler modifying
getImplementationInfo()
and dumping all stack information and globals in a watchdog message when hook isviews_query_substitutions
and your module is missing.If you are lucky you may get enough info to replicate this locally.
Comment #56
stephencamilo CreditAttribution: stephencamilo as a volunteer commentedComment #57
hestenetReset issue status.