If a hook_info hook uses entity_get_info() this will result in an incomplete module_implements() cache:

  1. _drupal_bootstrap_full() calls file_get_stream_wrappers()
  2. file_get_stream_wrappers() calls module_invoke_all()
  3. module_invoke_all() calls module_implements()
  4. module_implements() calls module_hook_info()
  5. module_hook_info() initializes a static $hook_info array and runs any X_hook_info() it can find
  6. some module's X_hook_info() uses entity_get_info()
  7. entity_get_info() calls module_invoke_all()
  8. module_invoke_all() calls module_implements()
  9. module_implements() (which caches its result) calls module_hook_info()
  10. module_hook_info() returns the empty static array because it was initialized
  11. module_implements() keeps a bad implementations cache

All of this can result in weird behavior. I found that after an apachesolr module update (which now uses entity_get_info in its hook_info) that my field labels all got the same translation as the first field in the form. This was caused by i18n not being able to find submodules which implement i18n_object_info hooks.

These issues are related:

http://drupal.org/node/968264
http://drupal.org/node/1410256

I think we simply can't allow any hook_hook_info() to use entity_get_info() or any other function which leads up to module_hook_info()?

Issue fork drupal-1415278

Command icon Show commands

Start within a Git clone of the project using the version control instructions.

Or, if you do not have SSH keys set up on git.drupalcode.org:

Support from Acquia helps fund testing for Drupal Acquia logo

Comments

Jose Reyero’s picture

Yes, and there are also similar issues related with when hooks are being called. I.e. some hooks being called on bootstrap phase (not all modules available yet) may result on corrupted (mostly incomplete) static caches, some of which are then cached into the db.

We need at the very least some documentation on when is safe to call which hooks and which hooks can call other hooks.

Some of the 'rules' could be:
- Modules in hook_boot() shouldn't trigger invokation of any other hook (nor generally call other modules' functions)
- Functions like module_invoke_all() shouldn't be called from bootstrap, unless used for bootstrap hooks. Related #578044: move module_invoke_all() out of the reach of hook_boot()

One idea: Hooks could have some 'level' meaning hooks with lower level can't call hooks with higher level. This level could 'propagate' to functions triggering that hook. Example:
- hook_boot() or other bootstrap hooks should be level 0
- hook_hook_info() should be level 1 (it cannot be called from hook_boot())
- hook_entity_info() should be level 2 (Then hook_hook_info() cannot call hook_entity_info())
- Other hooks using entity_get_info() should have a level > 2
- Etc...

kenorb’s picture

andypost’s picture

Version: 7.x-dev » 8.x-dev
Priority: Normal » Major

This is major and D8 staff also related #968264: hook_hook_info() can lead to an infinite loop

andypost’s picture

I got this trouble when some module has notice inside (my case the same constant defined twice) backtrace is
module_load_all()
- drupal_load() - hit notice -> watchdog()
-- watchdog() calls module_implements() -> module_hook_info() (static cache generated from incomplete loaded modules)
...
system runs with incomplete module_hook_info() and caches wrong module_implements()

andypost’s picture

Version: 8.x-dev » 7.x-dev

D8 has protection within module_hook_info() to return empty array if not all modules loaded

tim.plunkett’s picture

Priority: Major » Normal

I don't think this is a major bug, core doesn't do this. If anything it could just be documentation.

roderik’s picture

True, but documentation alone doesn't keep people from doing this. The problem is that it makes people's sites break in unpredictable and hard to trace ways.

A patch to at least not cache incomplete module_implements() data, is uploaded to #496170-14: module_implements() cache can be polluted by module_invoke_all() being called (in)directly prior to full bootstrap completion.

pounard’s picture

This bug is quite important to solve, I did trigger it on a production site and it results on an incomplete hook_hook_info() cache, which involves an incomplete module_implements() cache, which leads to serious data inconsistencies in our case, this needs to be solved.

petr.hajek’s picture

This is relatively unpleasant bug for debugging. I had a problem with undefined variable in the .module file root. Because of it Drupal wanted to log "Notice: Undefined variable..." and called sequence: _drupal_error_handler(), _drupal_error_handler_real(),_drupal_log_error(), watchdog(),module_implements(),module_hook_info() - which cached hook_info into persistent cache. But only few modules were loaded that time, because this Notice was triggered in the module loading process (after include of .module file). So since then my site was missing many hooks (till clear of persistent cache) and worked oddly.

I suggest attached patch which doens't allow to cache hook_info till all modules are loaded.

joelpittet’s picture

Status: Active » Needs review

See if testbot likes it, setting to needs review

Status: Needs review » Needs work

The last submitted patch, 10: 1415278-10.patch, failed testing.

The last submitted patch, 10: 1415278-10.patch, failed testing.

The last submitted patch, 10: 1415278-10.patch, failed testing.

petr.hajek’s picture

I am not sure about the testbots results, because 3 test runs ended with different results, so I even don't know what to fix. On my local enviroment tests of core ends with different results (test failures) even without my patch. Can you give me feedback about the tests please?

The last submitted patch, 10: 1415278-10.patch, failed testing.

petr.hajek’s picture

Status: Needs work » Needs review

tests passed finally.

Phizes’s picture

We have been using this production for some months now. It has resolved an issue we were having where tokens were not being replaced, and the metatag module was "losing" it's configuration. The site is heavily bloated, and without this patch the cached item is often incomplete of all hook implementations.

I believe that this patch is critical to a stable Drupal 7 site. (At least when the site is bloated to an extent which is difficult to describe.)

Phizes’s picture

Priority: Normal » Major
Status: Needs review » Reviewed & tested by the community

We've continued to have this running in production without issue, I have triggered a few more tests even though I'm moving this to being reviewed.

james.williams’s picture

Wow, this has been RTBC for a while. The patch has helped resolve issues I immediately ran into with PHP 8, because deprecation warnings were being logged early in bootstrap, causing the cache of hooks to be broken - see #3305946-16: [PHP 8.1] TypeError: Unsupported operand types: array + null in RulesData::addSiteMetadata()

What do we need to do to progress this?

voleger made their first commit to this issue’s fork.

voleger’s picture

Patch #10 helped me to fix an error on the Drupal 7.94 project with PHP 8.1 and modules entity and og

EntityMetadataWrapperException: Entity property og_user_node doesn't support writing. in EntityStructureWrapper->setProperty() (line 519 of /var/www/html/sites/all/modules/entity/includes/entity.wrapper.inc).
which appears when the administrator requests a user edit form.

Rerolled #10 against the latest 7.x branch in MR 3458

mcdruid’s picture

Thanks for the reroll. However could we please stick to patches rather than MRs for D7 core issues, especially when there are already patches.. switching from patches to an MR makes review harder (for me at least).

I've tweaked the comment a little but that's all. The interdiff is against the reroll.

I think this looks good, and I've certainly come across very tricky to debug problems when something causes an incomplete cache entry.

Over to @poker10 for final review and commit if he's happy.

poker10’s picture

Assigned: poker10 » Unassigned
Status: Reviewed & tested by the community » Needs review
FileSize
1.1 KB

As this does not have any test added, I tried to test this manually according to the steps from issue summary (see the uploaded patch). When I added entity_get_info(); call to the module_test_hook_info() (see ModuleUnitTest::testModuleImplements()), then I get an error TypeError: array_keys(): Argument #1 ($array) must be of type array, null given in array_keys() (line 7401 of includes/common.inc with and without the patch #24 (tested locally on PHP 8.1 / PostgreSQL).

So I think that the patch is probably not fixing the issue mentioned in the issue summary, but some other issue/s (see comments #10, #18, #20). In this case I am probably OK with commiting this, but we need to update Issue summary and Issue title about what exactly we are fixing (and ideally include a test for this).

If this fixes entity_get_info(); in hook_hook_info() problem, then I would be happy to see a failing test-only patch and green fix+test patch for this.

Some other notes to consider:

There is a very similar issue here: #1934192: hooks disappear from module_implements cache, which tries to handle it a bit sooner. Is that a duplicate? It seems to me that both issues tries to verify if all modules are loaded (but different ways).

Also there was another possible duplicate: #968264: hook_hook_info() can lead to an infinite loop, which @catch closed (for D8) as Works as designed. Therefore it seems more likely as "Don't do this" with possible warning in the documentation.

---------

Bottom line:

1. I still think we should make this caching more robust and fix cases like #18 and #20 (caused by watchdog calls / deprecation warnings), because these are causing for example tokens to disappear (I experienced this personally on some sites doing upgrades to PHP 8.1). But we should consider if this (#24) is the right approach or this: #1934192: hooks disappear from module_implements cache.

2. If the fix from the point 1 does not fix also entity_get_info(); in hook_hook_info() problem, then I am not sure if we should try to fix it at any cost - probably a mention in the documentation (e.g "Don't do this") will be sufficient.

Status: Needs review » Needs work

The last submitted patch, 25: 1415278-25-do-not-use.patch, failed testing. View results

poker10’s picture

Test failed on DrupalCI as well.

Adding another related/duplicate issue.