I started seeing an error that was caused because the hook_info in bootstrap cache was missing data.

The problem is that if the hook_info cache is built/rebuilt before module_load_all (the method that loads all the .module files and direct module dependencies) has completed some modules will not get their hook_info's into the cache.

How can this happen?

In module_load_all:

function module_load_all($bootstrap = FALSE) {
  static $has_run = FALSE;

  if (isset($bootstrap)) {
    foreach (module_list(TRUE, $bootstrap) as $module) {
      drupal_load('module', $module);
    }
    // $has_run will be TRUE if $bootstrap is FALSE.
    $has_run = !$bootstrap;
  }
  return $has_run;
}

In my case, a warning was being issued inside drupal_load when loading one of the modules.

This is triggering the error handling system, that does a watchdog() call.

Inside watchdog():

    // Call the logging hooks to log/process the message
    foreach (module_implements('watchdog') as $module) {
      module_invoke($module, 'watchdog', $log_entry);
    }

Then module_invoke's inners is triggering the hook_info cache building (if not built already).

module_implements() is calling module_hook_info() to see if the watchdog hook has been implemented by any module, and if the hook_info cache is not built, the following code that is building the hook_info cache will not take into account modules that have not yet been through drupal_load:

foreach (module_list() as $module) {
        $function = $module . '_hook_info';
        if (function_exists($function)) {
          $result = $function();
          if (isset($result) && is_array($result)) {
            $hook_info = array_merge_recursive($hook_info, $result);
          }
        }
      }

Of course no warning should be issued during module_load_all() but if that happens, this needs to be more robust. And maybe watchdog should be one of the first modules in the module_load_all().

Needs some more investigation.

Comments

david_garcia’s picture

Issue summary: View changes
david_garcia’s picture

There's some sort of protection against this in module_hook_info() where this is skipped in all bootstrap phases prior to DRUPAL_BOOTSTRAP_FULL:


  // This function is indirectly invoked from bootstrap_invoke_all(), in which
  // case common.inc, subsystems, and modules are not loaded yet, so it does not
  // make sense to support hook groups resp. lazy-loaded include files prior to
  // full bootstrap.
  if (drupal_bootstrap(NULL, FALSE) != DRUPAL_BOOTSTRAP_FULL) {
    return array();
  }

But if the failing module_load_all() is happening inside _drupal_bootstrap_full(), then we are out of luck.

david_garcia’s picture

Title: Inconsistent hook_info cached if there's an error/warning during module_load_all » Incomplete hook_info cached if there's an error/warning during module_load_all

To reproduce this add code to a .module file that issues a warning, such as including a non existent file.

david_garcia’s picture

dan_investopedia’s picture

I believe we are running into this problem. What's frustrating is that the incomplete hook_info problem only occurs occasionally. By that, I mean do the following:
1. Clear the cache
2. Hit some page that causes hook_info to be called
Everything is ok

If I repeat steps 1 and 2 over and over no code changes, eventually, I get incomplete hook_info cached. If there is a warning or error during module_load_all, I cannot understand why it does not occur consistently and deterministically.

Has anyone made progress on this issue?

angrytoast’s picture

sarathkm’s picture

While performing cache clear from site backend, the cache is not updating fully.

Only when we do drush cc all then its work and issue is resolved.