It appears that sometimes module_invoke_all('entity_property_info') is being called before all of the "modules/$module.info" files are included. Sometimes this bad list of implementations gets saved to the cache by module_implements().

In my case we are using EntityMetadataWrapper on nodes on every page. This bad cache entry is causing all future page requests to fatal error (since as far as Entity module is concerned, the node entity type doesn't exist). The only solution is to clear the 'module_implements' entry from 'cache_bootstrap' and wait a few days until the error happens again.

I realize that the current release is RC3, so our first step will be to upgrade.

Support from Acquia helps fund testing for Drupal Acquia logo

Comments

fago’s picture

Status: Active » Postponed (maintainer needs more info)

Question is when the wrong cache entry is written. That might be the result from some wrong use. We need to track the source down and see what's wrong there.

dalin’s picture

I've hacked module_implements() to add some extra logging and a backtrace when the bad cache entry is written. I'll keep you updated.

dalin’s picture

Priority: Major » Critical
Status: Postponed (maintainer needs more info) » Needs review
FileSize
517 bytes

Turned out to be very simple: module_invoke_all('entity_property_info') was being called when entity.info.inc was not included.

dalin’s picture

Alternatively, since there's no guarantee that module_invoke_all('entity_property_info') will not be called from another module, it might be an idea to just move all functions (not objects) from entity.info.inc to entity.module.

dalin’s picture

And, for reference, here's the backtrace that helped find the problem:

WD debug: node_entity_property_info does not exist  #0 /home/droth/web/eca/includes/module.inc(855): module_implements('entity_property...')                          [error]
#1 /home/droth/web/eca/sites/all/modules/contrib/entity/includes/entity.property.inc(37): module_invoke_all('entity_property...')
#2 /home/droth/web/eca/sites/all/modules/contrib/entity/views/entity.views.inc(399): entity_get_property_info('field_collectio...')
#3 /home/droth/web/eca/sites/all/modules/contrib/entity/views/entity.views.inc(385): EntityDefaultViewsController->schema_fields()
#4 /home/droth/web/eca/sites/all/modules/contrib/entity/views/entity.views.inc(33): EntityDefaultViewsController->views_data()
#5 [internal function]: entity_views_data()
#6 /home/droth/web/eca/includes/module.inc(858): call_user_func_array('entity_views_da...', Array)
#7 /home/droth/web/eca/sites/all/modules/contrib/views/includes/cache.inc(30): module_invoke_all('views_data')
#8 /home/droth/web/eca/sites/all/modules/contrib/views/views.module(1175): _views_fetch_data('field_data_fiel...', false, false)
#9 /home/droth/web/eca/sites/all/modules/contrib/views/views.module(1506): views_fetch_data('field_data_fiel...', false)
#10 /home/droth/web/eca/sites/all/modules/contrib/views/includes/view.inc(589): views_move_table('field_data_fiel...')
#11 /home/droth/web/eca/sites/all/modules/contrib/views/includes/view.inc(644): view->fix_missing_relationships()
#12 /home/droth/web/eca/sites/all/modules/contrib/views/plugins/views_plugin_display_page.inc(58): view->init_handlers()
#13 /home/droth/web/eca/sites/all/modules/contrib/views/includes/view.inc(1352): views_plugin_display_page->execute_hook_menu(Array)
#14 /home/droth/web/eca/sites/all/modules/contrib/views/views.module(349): view->execute_hook_menu('page', Array)
#15 /home/droth/web/eca/includes/module.inc(1057): views_menu_alter(Array, NULL, NULL)
#16 /home/droth/web/eca/includes/menu.inc(2740): drupal_alter('menu', Array)
#17 /home/droth/web/eca/includes/menu.inc(2700): menu_router_build()
#18 /home/droth/web/eca/includes/common.inc(7312): menu_rebuild()
#19 /usr/share/php/drush/commands/core/cache.drush.inc(236): drupal_flush_all_caches()
#20 [internal function]: drush_cache_clear_both()
#21 /usr/share/php/drush/includes/drush.inc(792): call_user_func_array('drush_cache_cle...', Array)
#22 /usr/share/php/drush/commands/core/cache.drush.inc(79): drush_op('drush_cache_cle...')
#23 [internal function]: drush_cache_command_clear('all')
#24 /usr/share/php/drush/includes/command.inc(324): call_user_func_array('drush_cache_com...', Array)
#25 /usr/share/php/drush/includes/command.inc(198): _drush_invoke_hooks('cache_command_c...', Array, 'cache')
#26 [internal function]: drush_command('all')
#27 /usr/share/php/drush/includes/command.inc(165): call_user_func_array('drush_command', Array)
#28 /usr/share/php/drush/drush.php(90): drush_dispatch(Array)
#29 /usr/share/php/drush/drush.php(59): _drush_bootstrap_and_dispatch()
#30 /usr/share/php/drush/drush.php(14): drush_main()
#31 {main}
bulldozer2003’s picture

Version: 7.x-1.0-rc1 » 7.x-1.0
Status: Needs review » Active

I've unfortunately experienced this bizarre problem as well. Searching for the error yields many people clueless as to the cause. I was for a long time as well. Usually they have it fix itself, likely when the module implementation cache is reset.

My manual fix was to run module_implements('entity_property_info', FALSE, TRUE); which resets the implementation cache.

I am using Entity 7.x-1.0, I will have to test against the latest dev. I can produce this every time I clear the cache on my development site.

dalin’s picture

Status: Active » Needs review

I think this still needs to be "needs review" since there's a patch that fixes the issue, but people need to try it out, verify that it works, and verify that it is the best way to fix the problem.

bulldozer2003’s picture

Status: Needs review » Active

The patch in #3 doesn't solve my problem. After clearing caches, entity still disappears from the output of module_implements('entity_property_info');

Whoops, hadn't refreshed since I last posted. But I think going back to active is valid since the patch didn't resolve. I would need to comment again to move it to needs work.

dalin’s picture

Status: Active » Needs work

In that case the proper status would be "needs work":
https://drupal.org/node/156119

bulldozer2003’s picture

Status: Needs work » Reviewed & tested by the community

I take that back. This does alleviate my problems with exceptions. I'm still not sure if the other errors I am having are entity related or not but they're not caused by this module.

fago’s picture

Status: Reviewed & tested by the community » Postponed (maintainer needs more info)

It appears that sometimes module_invoke_all('entity_property_info') is being called before all of the "modules/$module.info" files are included. Sometimes this bad list of implementations gets saved to the cache by module_implements().

Yeah, but this should be auto-loaded thanks to our hook_hook_info() entry. Maybe somehow that ends up broken in your case? I do not see a problem with our implemenation here?

benjy’s picture

Version: 7.x-1.0 » 7.x-1.3
Issue summary: View changes
Status: Postponed (maintainer needs more info) » Needs work
FileSize
9.14 KB

This is still definitely an issue. I had it today and the patch attached would fix the issue but It's not the solution to the root cause.

Basically entity.info.inc never gets included because hook_hook_info() never fires. Another solution that also worked for me was changing the weight in the database. I could reliably changed entity.module weight to -1 the problem would be fixed, back to 0 and it's broken again. I thought it would be a conflict with the system module but changing the system module weight didn't affect the issue.

I've attached a list of enabled modules from my site in case anyone wants to try and track this down further.

One symptom of this bug is that entity_metadata_wrapper doesn't' work at all for core entity types such as node.

benjy’s picture

OK, I tracked the core of this problem down.

define('SOME_LINK', url('sites/default/themes/custom_theme/images/pin.png', array('absolute' => TRUE)));

Someone had put a call to "url" outside of any functions, just at the top of the module file. This could have been any function that causes the module_implements cache to be loaded.

I tracked it down with this little snippet.

<?php

$results = db_select('system', 's')->fields('s')->execute()->fetchAllAssoc('name');

foreach ($results as $filename => $row) {
  if ($filename == "entity" || !$row->status) {
    continue;
  }

  drush_print("Trying $filename");

  $weight = $row->weight + 1;
  db_update('system')
  	->fields(array('weight' => $weight))
  	->condition('filename', $row->filename)
  	->execute();

  if (emwWorks()) {
    echo "$filename broke emw";
    break;
  }
}


function emwWorks() {
  try {
    drupal_flush_all_caches();
    drupal_http_request('http://example.com');
    $node = entity_metadata_wrapper('node', node_load(1));
    $node->nid->value();
    return true;
  }
  catch (Exception $e) {
    return false;
  }
}
?>

To run it, save as script.php and use drush, drush scr script.php

I think this should probably be closed (Works as designed)?

steinmb’s picture

Version: 7.x-1.3 » 7.x-1.x-dev
Priority: Critical » Major
Related issues: +#2953345: entity.info.inc not loaded at correct time, +#2954835: Properties are not available

I also experienced. Posted my findings in #2953345: entity.info.inc not loaded at correct time - I also went ahead and changed that issue one into a support issue. Perhaps some of the maintainers could shed some light on this issue, now that we know what cause it. I think this might be a weakness in this module. It was the only module as far as I could see failing. We could go ahead and close this issue but on the other hand, there is some good in there work done by @benjy trying to track down the problem. One a larger site, it is not easy to track down.

david.hughes’s picture

I ran into a similar problem to this, found this issue with a patch that at request-time recovers the entity_property_info if the cached value was set to an empty array for whatever reason. Patch in #2 of https://www.drupal.org/project/entity/issues/2629982 fixes this.