'Oh you lazy cron!' – learning on Drupal cron issues

We’re still working with Drupal 6 at work, and we’re triggering our notifications and other cron related tasks through a small script that crontab is running, and with the help of drush at the command line. The following problem and description of the scenario we had applies to Drupal 7 too as these are pretty much close with regards to implementation.

Drupal’s cron job will most often run smoothly and without any issues, it will appear to “just work”. The reason for that is that behind the scenes, anything related to creating scheduled tasks in Drupal will have to implement hook_cron, and simply enough, not a lot of modules will be doing that. So when you first setup your Drupal application and get it to run, you’ll wrap up any issues with cron and from there it’s smooth sailing… Or not! There are practices you should be aware of when you program modules in Drupal that are not related to cron, yet can still mess it up.

So back to the story, at some point we noticed our notifications aren’t being sent out in our development environment, and because cron is responsible for running the notifications, then that’s the immediate suspect. Problem is, debugging cron isn’t that easy, mainly because Drupal will just fire off those hooks and you’ve got no idea where the culprit code is.

Search for the problem begins by checking quickly all the modules that implement hook_cron, primarily your very own and recently added modules are the prime suspects. If that yields no results, as did in my case you’re going to have to broaden the search and a good way to quickly figure out where this happens is by inspecting Drupal’s module.inc to catch the cron hook. One way of doing that is through a debugger, another quick and easy way is by using Drupal’s own watchdog (or PHP’s own errorlog) function to capture this data:

function module_invoke_all() {  
    $return = array();  
    foreach (module_implements($hook) as $module) {  
    $function = $module .'_'. $hook;  
    if ($hook == 'cron') watchdog('cron', "hit $module cron"); // add line to log in db log  
    ...  
    }  
}  

Inspecting the information there from the change or through the debugger we’ll be able to see which cron hook last ran successfully.

I will spare the rest of the debugging process but the research led to Drupal’s own implementation of hook_cron which further led to module calls of node_invoke and node_invoke_nodeapi where it was then failing. At that point, all custom, and recent changes to anything the codebase related to hook_nodeapi revealed the culprit:

function my_module_nodeapi($op...) {

    switch ($op) {

    case ‘view’:  
    drupal_goto(”);  
    break;  
    }  
}

This makes perfect sense. Nodes get loaded through the node_load() and the rest of Drupal’s hooks for the sake of handling the notifications, which in turn calls nodeapi hook all around, and having a drupal_goto() doesn’t really help drush when its running from the command line.

Lesson learned.