Cron problemen debuggen

Ingediend door Donny op vr, 15/02/2013 - 07:41

Zowat iedere Drupaller zal de melding 'Attempting to re-run cron while it is already running' al wel eens zijn tegen gekomen. Tijdens het lopen van cron zijn er problemen opgetreden waardoor niet alle cronjobs succesvol zijn uitgevoerd, cron is blijven 'hangen' en zal daardoor niet opnieuw zal opstarten.

Om nu te gaan onderzoeken waar het probleem juist zit zijn er natuurlijk verschillende methodes, één van de meest gebruikte zal vermoedelijk zijn door het aanbrengen van debug code en cron via drush te laten lopen.

Cron gaat niet opnieuw willen starten omdat de variabele 'cron_semaphore' niet is verwijderd. (Normaal gebeurt dit op het einde van het lopen van cron)

Gelukkig voorziet Drush enkele commando's om snel variabelen in te stellen of te verwijderen. Gebruik vget om ze op te vragen, vset om ze in te stellen en vdel om ze te verwijderen. Met volgend commando verwijder je de variabele en zal cron terug kunnen starten:

drush vdel cron_semaphore -y

Indien je ook het tijdstip wenst weg te gooien wanneer cron voor de laatste keer liep kan je dat als volgt doen:

drush vdel cron_last -y

Nu cron terug kan starten wil het natuurlijk nog niet zeggen dat het probleem van de baan is. Daar dienen we eerste de oorzaak voor te vinden. Om te zien welke modules op jouw website gebruik maken van cron kan je volgende regel uitvoeren:

drush php-eval 'print_r(module_implements("cron"));'

Misschien kreeg je al een idee waar de oorzaak zou kunnen liggen door bovenstaande lijst te zien, zo niet dan gaan we een stapje verder en gaan we tijdelijk even de Drupal Core hacken om zo proberen te achterhalen waar er een probleem zou kunnen zitten.

Voor Drupal 6:

Zoek in het bestand includes/module.inc voor de volgende regels (rond lijn 820):

foreach (module_implements($hook) as $module) {
    $function = $module . '_' . $hook;

En verander het naar onderstaande regels:

foreach (module_implements($hook) as $module) {
  $function = $module . '_' . $hook;
  if ($hook == 'cron') :
    echo $module . ' memory usage: ' . memory_get_usage() . '
    ';
  endif;

Voor Drupal 7

Open het bestand includes/common.inc en zoek voor volgende regels (Rond lijn 5144):

try {
        module_invoke($module, 'cron');
      }
      catch (Exception $e) {
        watchdog_exception('cron', $e);
      }

En pas aan als volgt:

try {
        module_invoke($module, 'cron');
        echo $module . ' memory usage: ' . memory_get_usage() . '
        ';

      }
      catch (Exception $e) {
        watchdog_exception('cron', $e);
      }

 

Voer nu drush cron opnieuw uit.

Voor onderstaand voorbeeld heb ik wat foutieve PHP code in een node gestoken. De grootste oorzaak van cron problemen zit meestal bij foutieve PHP code in nodes waardoor dit een probleem zal geven wanneer de zoekmodule deze probeert te indexeren. Daarnaast is een andere veelvoorkomende oorzaak het toevoegen van redirects in je code. Bv met hulp van drupal_goto()

Drush cron issues

Als we daarop even de search module uitschakelen (drush dis search -y) dan zien we dat cron zonder problemen doorlopen wordt. 

Drush cron zonder zoekmodule

Als je al een vermoeden hebt dat het gaat om problemen met het indexeren van nodes voor de zoekmodule kan je natuurlijk ook even alleen die cronjob laten lopen. (drush search-index)

Drush cron search probleem

In dit geval gaat het dus om een node die voor problemen zorgt tijdens het indexeren, dit kunnen we verder onderzoeken door een nieuwe debug message toe te voegen.

Open het bestand modules/node/node.module en zoek naar volgende regels (Rond lijn 2645):

function node_update_index() {
  $limit = (int)variable_get('search_cron_limit', 100);

  $result = db_query_range("SELECT n.nid FROM {node} n LEFT JOIN {search_dataset} d ON d.type = 'node' AND d.sid = n.nid WHERE d.sid IS NULL OR d.reindex <> 0 ORDER BY d.reindex ASC, n.nid ASC", 0, $limit, array(), array('target' => 'slave'));

  foreach ($result as $node) {
    _node_index_node($node);
  }
}

Voeg volgende regel toe:

function node_update_index() {
  $limit = (int)variable_get('search_cron_limit', 100);

  $result = db_query_range("SELECT n.nid FROM {node} n LEFT JOIN {search_dataset} d ON d.type = 'node' AND d.sid = n.nid WHERE d.sid IS NULL OR d.reindex <> 0 ORDER BY d.reindex ASC, n.nid ASC", 0, $limit, array(), array('target' => 'slave'));

  foreach ($result as $node) {
     print 'node nid ' . $node->nid . '
    ';

    _node_index_node($node);
  }
}

Als je nu opnieuw drush search-index uitvoert dan krijg je de node nid te zien waar het allemaal misloopt. Zie onderstaand voorbeeld waar in mijn geval node 330 de foutieve PHP code bevat.

Drush search index defecte node nid

Het toeval moet lukken dat tijdens het schrijven van deze blogpost mijn collega Wim me attent maakte op de module cron_debug. Hiermee is het net iets eenvoudiger om te zien welke module voor problemen zorgt tijdens het lopen van cron :)

Via de interface kan je kiezen welke cronjob je wenst te laten lopen, als je daarna naar de logs gaat kijken zal het laatst toegevoegde record dat zijn van de module die voor problemen zorgt, in dit geval "Starting cron for search module."

Vergeet zeker niet al je Drupal Core hacks terug ongedaan te maken.

Labels