Enabling some modules that have dependencies on other modules can lead to a completely broken site. Something goes wrong while resolving and enabling the dependencies.

Steps to reproduce:
* Download Rules 2 for Drupal 7 http://drupal.org/project/rules
* Download Entity API http://drupal.org/project/entity
* Enable Rules2 and confirm enabling the dependencies Entity Metadata and Entity CRUD API
* This produces a fatal error all over your site.

Workaround:
* Enable Entity Metadata and Entity CRUD API separately _before_ you enable Rules2 and everything works as expected.

Rules implements hook_init(), so maybe that hook is called before the dependencies are resolved - just a guess.

Support from Acquia helps fund testing for Drupal Acquia logo

Comments

Berdir’s picture

Status: Active » Needs review
FileSize
2.1 KB
591 bytes

Ok, I found the issue. It's the entity cache.

rules2 implements hook_watchdog() and then tries to get entity information.

It is a bit tricky to reproduce manually because it does work once the modules have been installed correctly once, because the entity cache actually contains the information about those entities at that point.

Therefore, I'm attaching a hacked version of the Module dependency test which uses rules and the entity modules. That one fails without the changes in module.inc but obviously needs those modules to be present so it can only be manually tested.

We probably need a proper test case for this.

Status: Needs review » Needs work

The last submitted patch, clear_entity_cache_with_test.patch, failed testing.

klausi’s picture

Issue tags: +Needs tests

The first patch works fine for me and fixes the bug. There is already a system_dependency_test.module, should we implement hook_watchdog() there and try to access entity information?

fago’s picture

Hm, shouldn't it suffice to implement a module providing a new entity and checking for the existence of the new entity_info directly after enabling the module?

klausi’s picture

@fago: I played around a little bit and wrote a test case to check the entity information right after enabling the module. This works without the patch from Berdir, so no, this is not sufficient. Maybe I haven't tested it the way you meant to.

fago’s picture

Hm, strange. Probably you should invoke entity_get_info() before calling module_invoke too, so you make sure the cache is actually filled.

fago’s picture

Strange, I just installed a new site and I didn't experience any problems!?

klausi’s picture

Is still broken for me on a clean Drupal install.

klausi’s picture

Status: Needs work » Needs review
FileSize
3.53 KB
3.05 KB

Some further tests. The first one passes and does not trigger the error, the second one uses the module page for module enabling and fails. I'm curios what test-bot thinks about it.

Problem: in order to use the test modules on the modules page they need to be visible, which is ugly.
I'm not sure about where to put these tests, so filenames are not final.

Status: Needs review » Needs work

The last submitted patch, 742972-entity-cache-test-full.patch, failed testing.

Berdir’s picture

+++ modules/simpletest/tests/entity_cache.test
@@ -0,0 +1,24 @@
+  function setUp() {
+    parent::setUp('entity_cache_test');
+  }

Try it without that part. This already enables the test module, and the module_enable() call in your code doesn't doanything then...

Powered by Dreditor.

klausi’s picture

Status: Needs work » Needs review
FileSize
3.92 KB

*facepalm*
You are absolutely right, I just overlooked that.

This patch now finally works for me and catches the bug with a proper test.

klausi’s picture

Title: Module dependencies are not enabled before module install » Entity cache produces errors during module enabling
fago’s picture

Status: Needs review » Needs work

oh, of course.. Great that we have a working test case now. The fix is simple and looks fine, but the test case needs some work:

* The test case does not really test the entity cache, it tests module enabling and makes sure the entity cache is fine. Thus I think the test case should put to the other module enable tests.
* @entity_cache_test_watchdog() - we need to document why this is there and what it does. Else that's just confusing for anyone reading the code.

klausi’s picture

Status: Needs work » Needs review
FileSize
3.64 KB

addressed points from #14.

catch’s picture

Status: Needs review » Needs work

Please use entity_info_cache_clear() which encapsulates the drupal_static_reset() and the cache_clear_all().

Also I feel like module.inc shouldn't know anything about entities - i.e. this should be a hook implementation (system_modules_enabled()?), but I have doubts that actually fix the bug given the general mess in module enabling.

klausi’s picture

Status: Needs work » Needs review
FileSize
3.58 KB

now using entity_info_cache_clear().

As far as I can see implementing hook_modules_enabled() will be too late, as watchdog() is called before in module_enable().

catch’s picture

Title: Entity cache produces errors during module enabling » Clear entity info cache during module enable
Status: Needs review » Reviewed & tested by the community

Yeah let's deal with interdependencies between includes in another issue, probably D8. It would also be nice to only clear this cache if the module being enabled implements hook_entity_info() or hook_entity_info_alter(), but that's not worth special casing here given all the other stuff that gets cleared regardless.

catch’s picture

Title: Clear entity info cache during module enable » HEAD BROKEN: Clear entity info cache during module enable

Looks like the patch was committed here along with another commit, without adding the new test module. So we either need to roll back the patch or commit the test module.

webchick’s picture

Title: HEAD BROKEN: Clear entity info cache during module enable » Clear entity info cache during module enable
Status: Reviewed & tested by the community » Fixed

Committed to HEAD!

Status: Fixed » Closed (fixed)

Automatically closed -- issue fixed for 2 weeks with no activity.

sun’s picture

#910190: Entire schema cache needlessly loaded on all pages reveals that blatantly assuming a completed installation in hook_watchdog() is a weird assumption. This patch does not even check the actual watchdog message, so it expects that any watchdog message is the watchdog message this test is targeting. I'm not sure what exactly has been tried to asserted here.

/**
 * Implements hook_watchdog().
 *
 * This function is called during module_enable() and tries to access entity
 * information provided by the module this one depends on. The information is
 * stored in a temporary system variable and is later analyzed in the test
 * case.
 *
 * @see EnableDisableTestCase::testEntityCache()
 */
function entity_cache_test_watchdog() {
  $info = entity_get_info('entity_cache_test');
  variable_set('entity_cache_test', $info);
}
sun’s picture

Status: Closed (fixed) » Needs work
+++ modules/simpletest/tests/entity_cache_test.module
@@ -0,0 +1,22 @@
+function entity_cache_test_watchdog() {

+++ modules/simpletest/tests/entity_cache_test_dependency.module
@@ -0,0 +1,19 @@
+      'base table' => 'entity_cache_test',

1) So this should have been hook_modules_installed().

2) It's invalid do define a base table that does not exist.

My patch over in #910190: Entire schema cache needlessly loaded on all pages corrects this.

+++ modules/system/system.test
@@ -157,6 +157,16 @@ class EnableDisableTestCase extends ModuleTestCase {
+    $this->assertNotNull($info, t('Entity information must not be NULL'));

assertNotNull()? That does not assert any expectation.

Powered by Dreditor.

klausi’s picture

#910190: Entire schema cache needlessly loaded on all pages reveals that blatantly assuming a completed installation in hook_watchdog() is a weird assumption.

Why? If a hook in a module is called a developer should be able to assume that the own module has been installed completely with dependencies. Otherwise we should document extensively that hook_watchdog() is an exception and gets called randomly. Now that would be weird to me.

klausi’s picture

Status: Needs work » Needs review
FileSize
1.63 KB

This patch does not even check the actual watchdog message, so it expects that any watchdog message is the watchdog message this test is targeting

The test case was designed to trigger just a single watchdog message (during module_enable()). As far as I can see there are 2 watchdog() calls now, so we want to make sure that we call watchdog() only after the module was installed and enabled completely. In my opinion hook_watchdog() should be safe with the downside of delaying the watchdog() calls to the end of module_enable().

Patch attached.

sun’s picture

Status: Needs review » Needs work

Thanks!

As far as I can see there are 2 watchdog() calls now, so we want to make sure that we call watchdog() only after the module was installed

For that, we don't have to change the watchdog invocations, but have to fix the entity_cache_test_watchdog() implementation instead. Additionally,

- change the assertNotNull() to something that actually asserts an expectation (I think you are expecting a fully loaded and fully usable entity info array - that is what needs to be asserted accordingly, if so).

- remove the 'base table' from hook_entity_info().

- Heavily improve the comments on entity_cache_test_watchdog() to let readers understand why this test looks a bit weird.

klausi’s picture

Priority: Critical » Normal
Status: Needs work » Needs review
FileSize
2.1 KB

Not critical anymore, as we just want to improve the test here.

I'm not sure how to improve the comments .. what would you like to see?

sun’s picture

Status: Needs review » Needs work
+++ modules/simpletest/tests/entity_cache_test.module
@@ -9,14 +9,17 @@
+ * This hook is called during module_enable() and tries to access entity
+ * information provided by the module this one depends on, which should be
+ * available. The information is stored in a temporary system variable and is
+ * later analyzed in the test case.

Can we clarify this a bit more? Instead of telling what it does (already visible in the code), we need to explain the "why" + expectations. Something along the lines of:

This hook is called during module_enable() and since this hook implementation is invoked, we have to expect that this module and dependent modules have been properly installed already, so we expect to be able to retrieve the entity information that has been registered by the required dependency module.

+++ modules/system/system.test
@@ -161,11 +161,14 @@ class EnableDisableTestCase extends ModuleTestCase {
-    $this->assertNotNull($info, t('Entity information must not be NULL'));
+    $this->assertEqual($info['label'], 'Entity Cache Test', 'Entity info label is correct.');
+    $this->assertEqual($info['controller class'], 'DrupalDefaultEntityController', 'Entity controller class info is correct.');

Much better, thank you!

Powered by Dreditor.

klausi’s picture

Status: Needs work » Needs review
FileSize
2.25 KB

Alright, how about this?

sun’s picture

Status: Needs review » Reviewed & tested by the community
Issue tags: -Needs tests

Much better, thank you!

sun’s picture

#29: 742972-entity-cache-test.patch queued for re-testing.

webchick’s picture

Status: Reviewed & tested by the community » Fixed

Committed to HEAD. Thanks!

Status: Fixed » Closed (fixed)

Automatically closed -- issue fixed for 2 weeks with no activity.