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.

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 ?

Support from Acquia helps fund testing for Drupal Acquia logo

Comments

pfrenssen’s picture

Status: Active » Postponed (maintainer needs more info)

Thanks 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:

module_implements(NULL, FALSE, TRUE);

Then you can rebuild it and look if your module exists in the list by calling:

var_dump(module_implements('form_alter'));

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!

netbear’s picture

Version: 7.21 » 7.20
Status: Active » Postponed (maintainer needs more info)

I'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:


function MYMODULE_form_views_exposed_form_alter(&$form, &$form_state) {
  drupal_set_message('hello');//just to check that hook is called by drupal
  if($form['#id'] == 'views-exposed-form-display-products-page')
  {
    $form['#validate'][] = 'MYMODULE_exposed_form_validate';
  }
}

function MYMODULE_exposed_form_validate(&$form, &$form_state) {
  if(isset($form_state['values']['search_api_views_fulltext'])) {
    //lets preserve tokens like ddd.dd.ddd to not been exploded by '.' symbol
    $form_state['values']['search_api_views_fulltext'] = preg_replace('/\b(\d+)\.(\d+)\.(\d+)\b/', "$1#$2#$3", $form_state['values']['search_api_views_fulltext']);
    $form_state['values']['search_api_views_fulltext'] = preg_replace('/(\d+)\./', " $1 . ", $form_state['values']['search_api_views_fulltext']);
    $form_state['values']['search_api_views_fulltext'] = preg_replace('/\b(\d+)#(\d+)#(\d+)\b/', "$1.$2.$3", $form_state['values']['search_api_views_fulltext']);
  }
}

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...

netbear’s picture

Version: 7.20 » 7.21
netbear’s picture

Status: Postponed (maintainer needs more info) » Active
soxofaan’s picture

Version: 7.20 » 7.21
Status: Postponed (maintainer needs more info) » Active

probably related in the CAPTCHA module issue queue: #1874038: drupal captcha always disappear, return when clear performance cache

netbear’s picture

my new code in module is even simpler:

function MYMODULE_form_alter(&$form, &$form_state, $form_id) {
   drupal_set_message($form_id);  // print form ID to messages
}

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.

Growiel’s picture

Happy 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.

Growiel’s picture

Priority: Major » Critical

This 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) :

'form_alter' => 
 array (
   'webform' => false,
   'block_class' => false,
   'bonita_views' => false,
   'captcha' => false,
   'genpass' => false,
   'l10n_update' => false,
   'locale' => false,
   'metatag' => false,
   'rules_admin' => false,
   'scheduler' => false,
   'sfweb2lead_webform' => false,
   'simplesamlphp_auth' => false,
   'token' => false,
   'wysiwyg' => false,
   'i18n_taxonomy' => false,
   'rules_forms' => false,
   'variable' => false,
 ),

and about 45minutes later :

'form_alter' => 
 array (
   'webform' => false,
   'captcha' => false,
   'l10n_update' => false,
   'locale' => false,
   'metatag' => false,
   'scheduler' => false,
   'simplesamlphp_auth' => false,
   'token' => false,
   'wysiwyg' => false,
   'i18n_taxonomy' => false,
 ),

That's SEVEN modules that get removed from the cache !

matt2000’s picture

Some 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?

catch’s picture

This 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.

Growiel’s picture

@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" ?

netbear’s picture

- 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?

1) 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.

criznach’s picture

Who's your host and what are your PHP and MySQL versions? That might help to reproduce the problem and get a closer look.

Growiel’s picture

We'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)

jaredsmith’s picture

This issue could use an updated issue summary based on the templates at http://drupal.org/issue-summaries.

kkubali’s picture

I'm about to work on this in the Portland 2013 sprint.

netbear’s picture

My 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).

criznach’s picture

Netbear did your cron schedule change?

netbear’s picture

@ 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.

netbear’s picture

Issue summary: View changes

Added Issue Summary

David_Rothstein’s picture

Issue summary: View changes

Update issue summary to flesh it out and restore the original report

David_Rothstein’s picture

The 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?

David_Rothstein’s picture

Version: 7.21 » 8.x-dev
Priority: Critical » Major
Issue tags: +Needs backport to D7

I 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.

Growiel’s picture

Nice 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.

netbear’s picture

My 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.

netbear’s picture

May 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"
==============

./profiles/commerce_kickstart/modules/contrib/i18n/tests/i18n_test.module:  // We just implement this hook so this one is loaded always on bootstap
./profiles/commerce_kickstart/modules/contrib/i18n/i18n.module: * Implements hook_boot().
./profiles/commerce_kickstart/modules/contrib/i18n/i18n.module:function i18n_boot() {
./profiles/commerce_kickstart/modules/contrib/i18n/i18n.module:  // Just make sure the module is loaded for boot and the API is available.
./profiles/commerce_kickstart/modules/contrib/i18n/i18n.module:    drupal_bootstrap(DRUPAL_BOOTSTRAP_LANGUAGE);
./profiles/commerce_kickstart/modules/contrib/i18n/i18n.module:    drupal_bootstrap(DRUPAL_BOOTSTRAP_LANGUAGE);
./profiles/commerce_kickstart/modules/contrib/migrate/migrate.module:  // Ensure that the Migration class exists, as different bootstrap phases may
./profiles/commerce_kickstart/modules/contrib/variable/variable.module: * Implementation of hook_boot()
./profiles/commerce_kickstart/modules/contrib/variable/variable.module: * Though we don't do anything here, we ensure the module is loaded at boot stage
./profiles/commerce_kickstart/modules/contrib/variable/variable.module:function variable_boot() {
./profiles/commerce_kickstart/modules/contrib/variable/variable.module:    drupal_bootstrap(DRUPAL_BOOTSTRAP_LANGUAGE);
./profiles/commerce_kickstart/modules/contrib/variable/variable_store/variable_store.module: * Implementation of hook_boot()
./profiles/commerce_kickstart/modules/contrib/variable/variable_store/variable_store.module:function variable_store_boot() {
./profiles/commerce_kickstart/modules/contrib/variable/variable_store/variable_store.module:  // Do nothing, we just want this module to be available for boot.
./profiles/commerce_kickstart/modules/contrib/variable/variable_store/variable_store.module:  cache_clear_all('variable:' . $realm . ':' . $key, 'cache_bootstrap');
./profiles/commerce_kickstart/modules/contrib/variable/variable_store/variable_store.module:  if ($cached = cache_get($cacheid, 'cache_bootstrap')) {
./profiles/commerce_kickstart/modules/contrib/variable/variable_store/variable_store.module:    cache_set($cacheid, $variables, 'cache_bootstrap');
./profiles/commerce_kickstart/modules/contrib/variable/variable_store/variable_store.module:  cache_clear_all('variable:', 'cache_bootstrap', TRUE);
./profiles/commerce_kickstart/modules/contrib/variable/variable_store/variable_store.module:  cache_clear_all('variable:' . $realm . ':' . $key, 'cache_bootstrap');
./profiles/commerce_kickstart/modules/contrib/variable/variable_realm/variable_realm.module: * Implements hook_boot()
./profiles/commerce_kickstart/modules/contrib/variable/variable_realm/variable_realm.module:function variable_realm_boot() {
./profiles/commerce_kickstart/modules/contrib/variable/variable_realm/variable_realm.module:      // modules and the menu access callbacks early in the bootstrap,
./profiles/commerce_kickstart/modules/contrib/variable/variable_realm/variable_realm.module: * This may be invoked really early in the bootstrap so it needs to be safe enough
./profiles/commerce_kickstart/modules/contrib/variable/variable_realm/variable_realm.module: * Variable realm usually starts from bootstrap, on hook_boot() and from here it is not
./profiles/commerce_kickstart/modules/contrib/variable/variable_realm/variable_realm.module: * bootstrap_invoke_all() but returning the values (with deep merge).
./profiles/commerce_kickstart/modules/contrib/features/features.module:        'bootstrap' => 0,
./sites/all/modules/redirect/redirect.module:    // Ensure the database is loaded. This is only the next bootstrap step
./sites/all/modules/redirect/redirect.module:    drupal_bootstrap(DRUPAL_BOOTSTRAP_DATABASE);
./sites/all/modules/redirect/redirect.module:  if (drupal_get_bootstrap_phase() == DRUPAL_BOOTSTRAP_FULL) {
./sites/all/modules/admin_menu/admin_menu.module:  // @see _drupal_bootstrap_page_cache()
./sites/all/modules/globalredirect/globalredirect.module:   * in its folder doing a bootstrap which invoked hook_init() and caused some
./modules/statistics/statistics.module:  // in which case we need to bootstrap to the session phase anyway.
./modules/statistics/statistics.module:  drupal_bootstrap(DRUPAL_BOOTSTRAP_VARIABLES);
./modules/statistics/statistics.module:    drupal_bootstrap(DRUPAL_BOOTSTRAP_SESSION);
./modules/locale/tests/locale_test.module: * Implements hook_boot().
./modules/locale/tests/locale_test.module:function locale_test_boot() {
./modules/simpletest/tests/system_test.module:    'page arguments' => array('simpletest_bootstrap_variable_test', NULL),
./modules/simpletest/tests/system_test.module: * Implements hook_boot().
./modules/simpletest/tests/system_test.module:function system_test_boot() {
./modules/simpletest/tests/system_test.module:  watchdog('system_test', 'hook_boot');
./modules/simpletest/tests/menu_test.module:  // active trail during Drupal's bootstrap (before the user is redirected to a
./modules/simpletest/tests/session_test.module: * Implements hook_boot().
./modules/simpletest/tests/session_test.module:function session_test_boot() {
./modules/image/image.module:  // actual file path, this avoids bootstrapping PHP once the files are built.
./modules/system/system.module: * bootstrap level so that it is not reliant on the entire site being
./modules/system/system.module: * bootstrap level, without all modules being invoked, so it needs to be careful
./modules/system/system.module:  // them via the class autoloader, even without a full bootstrap.
./modules/system/system.module:    'bootstrap' => 0,
./modules/system/system.module: * Refresh bootstrap column in the system table.
./modules/system/system.module: * implement hooks used during bootstrap, such as hook_boot(). These modules
./modules/system/system.module:function _system_update_bootstrap_status() {
./modules/system/system.module:  $bootstrap_modules = array();
./modules/system/system.module:  foreach (bootstrap_hooks() as $hook) {
./modules/system/system.module:      $bootstrap_modules[] = $module;
./modules/system/system.module:  $query = db_update('system')->fields(array('bootstrap' => 0));
./modules/system/system.module:  if ($bootstrap_modules) {
./modules/system/system.module:      ->fields(array('bootstrap' => 1))
./modules/system/system.module:      ->condition('name', $bootstrap_modules, 'IN')
./modules/system/system.module:    $query->condition('name', $bootstrap_modules, 'NOT IN');
./modules/system/system.module:  // Reset the cached list of bootstrap modules.
./modules/update/update.module:    && file_exists("$directory/$project/includes/bootstrap.inc")
./modules/overlay/overlay.module:    // The authorize.php script bootstraps Drupal to a very low level, where

=================

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.

Growiel’s picture

./i18n/i18n.module: * Implements hook_boot().                                                                                                                                                                                                      
./i18n/i18n.module:function i18n_boot() {                                                                                                                                                                                                          
./i18n/i18n.module:    drupal_bootstrap(DRUPAL_BOOTSTRAP_LANGUAGE);                                                                                                                                                                                
./i18n/i18n.module:    drupal_bootstrap(DRUPAL_BOOTSTRAP_LANGUAGE);                                                                                                                                                                                
./redirect/redirect.module:    drupal_bootstrap(DRUPAL_BOOTSTRAP_DATABASE);                                                                                                                                                                        
./redirect/redirect.module:  if (drupal_get_bootstrap_phase() == DRUPAL_BOOTSTRAP_FULL) {                                                                                                                                                          
./bonita_loopfuse/bonita_loopfuse.module:function bonita_loopfuse_boot(){                                                                                                                                                                          
./variable/variable_realm/variable_realm.module: * Implements hook_boot()
./variable/variable_realm/variable_realm.module:function variable_realm_boot() {
./variable/variable_realm/variable_realm.module: * Variable realm usually starts from bootstrap, on hook_boot() and from here it is not
./variable/variable.module: * Implementation of hook_boot()
./variable/variable.module:function variable_boot() {
./variable/variable.module:    drupal_bootstrap(DRUPAL_BOOTSTRAP_LANGUAGE);
./variable/variable_store/variable_store.module: * Implementation of hook_boot()
./variable/variable_store/variable_store.module:function variable_store_boot() {
./variable/variable_store/variable_store.module:  cache_clear_all('variable:' . $realm . ':' . $key, 'cache_bootstrap');
./variable/variable_store/variable_store.module:  if ($cached = cache_get($cacheid, 'cache_bootstrap')) {
./variable/variable_store/variable_store.module:    cache_set($cacheid, $variables, 'cache_bootstrap');
./variable/variable_store/variable_store.module:  cache_clear_all('variable:', 'cache_bootstrap', TRUE);
./variable/variable_store/variable_store.module:  cache_clear_all('variable:' . $realm . ':' . $key, 'cache_bootstrap');
./performance/performance.module:function performance_boot() {

So 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.

dlumberg’s picture

I'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.

cache_bootstrap(variables) was not cleared. APC cli uses a different   [warning]
memory storage then the webserver. For more info see:
http://drupal.org/node/1278232

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.

Growiel’s picture

We 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.

dlumberg’s picture

I had added this line to my settings.php

// USE APC for bootstrap
$conf['cache_class_cache_bootstrap'] = 'DrupalAPCCache';

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.

dlumberg’s picture

I 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:

  $items['elysia-cron'] = array(
    'description' => "Run all cron hooks in all active modules for specified site using elysia cron system. Use this instead of \"core-cron\" if elysia_cron module is installed",
    'callback'    => 'drush_elysia_cron_run_wrapper',
    'arguments' => array(),
    'bootstrap' => DRUSH_BOOTSTRAP_DRUPAL_FULL,
  );

Cross posted to issue in elysia_cron https://drupal.org/node/2023586

catch’s picture

Version: 8.x-dev » 7.x-dev
Issue tags: -cache, -drupal 7, -Needs backport to D7

That 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:

  /**
   * Overrides \Drupal\Core\Extension\ModuleHandler::getHookInfo().
   */
  public function getHookInfo() {
    // When this function is indirectly invoked from bootstrap_invoke_all() prior
    // to all modules being loaded, we do not want to cache an incomplete
    // hook_hookInfo() result, so instead return an empty array. This requires
    // bootstrap hook implementations to reside in the .module file, which is
    // optimal for performance anyway.
    if (!$this->loaded) {
      return array();
    }

moving back to Drupal 7.

netbear’s picture

The 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

cache_get('module_implements', 'cache_bootstrap'); 

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

/*
 * This is temporary implementation of hook_form_alter because of bug with module's hook_form_alter disappearing from cache
 */
function MY_THEME_form_alter(&$form, &$form_state, $form_id) {
  $comment_forms = array();
  foreach (node_type_get_types() as $type) {
    $comment_forms[] = "comment_node_{$type->type}_form";
  }
  if(in_array($form_id, $comment_forms)) {
    if(!isset($form['captcha'])) {
      captcha_form_alter($form, $form_state, $form_id);
    }
  }
}

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?

netbear’s picture

When 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.

David_Rothstein’s picture

hook_boot() runs during the bootstrap, so module_implements() could still be executed during an implementation of that hook, before all modules are loaded.

David_Rothstein’s picture

Issue summary: View changes

Fix comment links.

Solidmark’s picture

I 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.

joachim’s picture

Title: hook_form_alter diseapers from module_implements cache » hooks disappear from module_implements cache

There 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.

chx’s picture

joachim’s picture

It looks like it might be a duplicate.

catch’s picture

Status: Active » Closed (duplicate)
Molfar’s picture

Status: Closed (duplicate) » Active

This is not a duplicate. This topic is about randomly disappearing hooks. Not about bootstrap mode overwriting.

joachim’s picture

This to me looks like an effect of the bootstrap overwriting. Could you explain more why you think this is a different bug?

Fabianx’s picture

Status: Active » Closed (duplicate)

Closing again as duplicate, because I saw randomly disappearing hooks (fences not finding its own hooks ...) as well and the other patch fixed those.

codeelegance’s picture

Status: Closed (duplicate) » Active

I 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...

amit0212’s picture

Assigned: Unassigned » amit0212
Status: Active » Needs review

If 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');

joachim’s picture

Status: Needs review » Active

An issue should only be set to 'needs review' if there's a patch.

amit0212’s picture

Assigned: amit0212 » Unassigned
Fabianx’s picture

Assigned: Unassigned » Fabianx
Priority: Major » Critical

Okay, I found the problem:

- module_hook_info() is protected via:

 if (drupal_bootstrap(NULL, FALSE) != DRUPAL_BOOTSTRAP_FULL) {
    return array();
  }

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:

if (drupal_bootstrap_completed_phase() != DRUPAL_BOOTSTRAP_FULL) {
  return;
}
angrytoast’s picture

Adding 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?

angrytoast’s picture

Looking over the drupal_get_bootstrap_phase() function, it calls drupal_bootstrap(NULL, FALSE), and it is already used in other parts of core to check against the current phase. The function doc states:

The current phase is the one most recently completed by drupal_bootstrap().

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 call drupal_get_bootstrap_phase()rather than drupal_bootstrap(NULL, FALSE)

gambry’s picture

From 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. :(

jtwalters’s picture

@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.

gambry’s picture

RE #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.

  • Don't overload the system with hooks: we had a dynamic form ID, creating around 0.5k-1k different form IDs for the same form. Every form ID becomes a hook_form_FORM_ID_alter and so we had the module_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 the module_implements cache.
  • Don't use Drupal API in StackWiddleware services: we had a middleware altering the Drupal Page Cache service. We were using Route API and Entity API to evaluate some conditions. Although the first one is relatively safe to be used, the second requires Drupal to be fully bootstrapped, otherwise consequences may be unknown. Use low level API - i.e. Database API/PDO - to evaluate your conditions against Drupal entities
roi’s picture

Happens 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.

gambry’s picture

@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.

roi’s picture

@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.

gambry’s picture

@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 is views_query_substitutions and your module is missing.

If you are lucky you may get enough info to replicate this locally.

stephencamilo’s picture

Status: Needs review » Closed (won't fix)
hestenet’s picture

Status: Closed (won't fix) » Needs review

Reset issue status.