We have random 503 errors on the server for the pages like user/login with the php fatal error in the logs.

This issue is not consistent and I have not found exact steps to reproduce it.

My guess that it may appear only when authcache is used in combination with domain access module (as we have) or any other module that is included from in settings.php.

I was not able to reproduce issue locally, but see a potential problem using the drupal_get_path_alias() function on exit, that may also be related to that hook_exist is executed on cached page.

Do you think it may be reasonable to do full bootstrap in _authcache_shutdown_save_page and if no - what can be an alternative?

Support from Acquia helps fund testing for Drupal Acquia logo

Comments

dasha_v’s picture

Status: Active » Needs review
FileSize
348 bytes

I have concerns about full bootstrap, but have no other solution. Please review.

znerol’s picture

Ok, lets figure that out. Core calls the exit-hook in four different places (git grep -n -p -C3 invoke.*exit):

ajax_footer()

includes/ajax.inc-561- * @see drupal_page_footer()
includes/ajax.inc-562- */
includes/ajax.inc=563=function ajax_footer() {
includes/ajax.inc:564:  // Even for Ajax requests, invoke hook_exit() implementations. There may be
includes/ajax.inc-565-  // modules that need very fast Ajax responses, and therefore, run Ajax
includes/ajax.inc-566-  // requests with an early bootstrap.
includes/ajax.inc-567-  if (drupal_get_bootstrap_phase() == DRUPAL_BOOTSTRAP_FULL && (!defined('MAINTENANCE_MODE') || MAINTENANCE_MODE != 'update')) {
includes/ajax.inc:568:    module_invoke_all('exit');
includes/ajax.inc-569-  }
includes/ajax.inc-570-
includes/ajax.inc-571-  // Commit the user session. See above comment about the possibility of this

Interesting fact here: The hook gets only invoked when drupal is fully bootstrapped. Therefore it cannot be the cause of the problem.

_drupal_bootstrap_page_cache()

includes/bootstrap.inc=2320=function _drupal_bootstrap_page_cache() {
--
includes/bootstrap.inc-2359-      // If the skipping of the bootstrap hooks is not enforced, call
includes/bootstrap.inc-2360-      // hook_exit.
includes/bootstrap.inc-2361-      if (variable_get('page_cache_invoke_hooks', TRUE)) {
includes/bootstrap.inc:2362:        bootstrap_invoke_all('exit');
includes/bootstrap.inc-2363-      }
includes/bootstrap.inc-2364-      // We are done.
includes/bootstrap.inc-2365-      exit;

Rereading this function I think the following circumstances can lead to the invocation with low bootstrap level:

  1. There is no session-cookie on the request, i.e. the user is anonymous.
  2. The page exists in the page cache, however...
  3. ... authcache does not deliver it because the browser sent a nocache or nocache_temp cookie.
  4. One of the variables page_cache_without_database or cache is set to TRUE.

In this case it would be possible that a cached page is delivered by _drupal_bootstrap_page_cache() and hook_exit gets invoked.

Would you mind placing the following snipped into your settings.php and report back whether this solves the problem:

$conf['page_cache_without_database'] = FALSE;
$conf['cache'] = FALSE;

drupal_page_footer()

includes/common.inc=2688=function drupal_page_footer() {
includes/common.inc-2689-  global $user;
includes/common.inc-2690-
includes/common.inc:2691:  module_invoke_all('exit');
includes/common.inc-2692-
includes/common.inc-2693-  // Commit the user session, if needed.
includes/common.inc-2694-  drupal_session_commit();

This is where the hook is invoked after a page has been rendered using a full bootstrap. I do not think that this invocation causes problems.

drupal_exit()
includes/common.inc=2721=function drupal_exit($destination = NULL) {
includes/common.inc-2722-  if (drupal_get_bootstrap_phase() == DRUPAL_BOOTSTRAP_FULL) {
includes/common.inc-2723-    if (!defined('MAINTENANCE_MODE') || MAINTENANCE_MODE != 'update') {
includes/common.inc:2724:      module_invoke_all('exit', $destination);
includes/common.inc-2725-    }
includes/common.inc-2726-    drupal_session_commit();
includes/common.inc-2727-  }

This one is again guarded against low bootstrap levels.

BTW: I guess the patch from #1 was intended for another issue...

dasha_v’s picture

Right, my mistake with the path. Unfortunately can not delete it.

As I said, as I was not able to reproduce this consistently I put this on hold. It is not in core, and not on authcache, it is somewhere in combination of other contributed modules with it.

Today, accidentally I've found that the reason why drupal_get_bootstrap_phase() == DRUPAL_BOOTSTRAP_FULL that you assume is safe can be not working.

It is in autologout module, here:

/**
 * Implements hook_init().
 */
function autologout_init() {
...
...
      // User has changed so force Drupal to remake decisions based on user.
      global $theme, $theme_key;
      drupal_static_reset();
      $theme = NULL;
      $theme_key = NULL;
      menu_set_custom_theme();
      drupal_theme_initialize();
      _autologout_inactivity_message();
...
...

As you see - it is doing drupal_theme_initialize, that has these code inside:


/**
 * Initializes the theme system by loading the theme.
 */
function drupal_theme_initialize() {
...
...
  drupal_bootstrap(DRUPAL_BOOTSTRAP_DATABASE);

And now, as a result drupal_get_bootstrap_phase() will have it as DRUPAL_BOOTSTRAP_DATABASE (I assume).

dasha_v’s picture

It is still not clear for me why this happened, but here is initial path that was lost.

znerol’s picture

There was a very similar problem in the 2.x-dev branch: #2075603: Fatal error if authcache_exit is invoked when not fully bootstrapped. The culprit was the shurly-module, looking up short-urls from within hook_boot and then calling hook_exit from there.

I my opinion it is saver to not store a page to the cache, when DRUPAL_BOOTSTRAP_FULL was not reached before hook_exit gets called. What do you think?

Concerning bootstrapping: When hook_init is called the bootstrapping level is guaranteed to be DRUPAL_BOOTSTRAP_FULL. Also it only can rise from lover to higher levels. When drupal_bootstrap(DRUPAL_BOOTSTRAP_DATABASE); is called from a higher level, no action will be performed.

dasha_v’s picture

Thank you! #5 make perfect sense.

znerol’s picture

@dasha_v: Does it also fix the problem you reported?

znerol’s picture

Committed and pushed: 6cbdf62.

znerol’s picture

Version: 7.x-1.4 » 7.x-1.x-dev
Issue summary: View changes
Status: Needs review » Fixed
znerol’s picture

Status: Fixed » Closed (fixed)

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