By WeaveGeek on

(Moving to a new topic, because I noticed that I was writing in a topic that had Drupal 5.x taxonomy. My issue is on a Drupal 6.9 server.)

Cron is getting stuck.

The current behavior is that I fight with it, deleting variables and the cache and every once in a while I can get cron to run manually. Once. Then it’s stuck again and I get the dreaded: “Attempting to re-run cron while it is already running” warning.

Here's the history:
-------------------------------

  • For weeks I’ve been running cron.php manually using http://www.weavezinedev.com /cron.php and it’s been flawless
  • About 5 days ago, it got stuck (I wasn’t checking reports then, so didn’t realize.)
  • Went on Drupal.org to research and learned about going in Devel/variable and deleting cron_semaphor and cron_last. Sometimes this unsticks Cron.php, sometimes it doesn’t.
  • Disabled suspect modules: Update Status, Backup And Migrate (didn’t help)
  • Set Search indexing to 10 items per Cron
  • Deleted Cache (for a while tried running without caching, but that didn’t seem to help) Sometimes clearing the cache unsticks cron, sometimes it doesn’t.

I checked the changelog I’ve been keeping for site development, and the things that happened around the time cron stopped working were:

  • Added advertisements (about 20-30) using the Advertisement module
  • Added a bunch of content manually (about 40 body texts)
  • Imported about 40 WordPress blog posts and their comments using the “WordPress Import” module (Note: this generated errors when it ran, but the content showed up.)

Working against me is that some articles on the site are quite long. (11+ pages printed out) and the fact that my host (SiteGround) won’t let me up the php max_execution_time in php.ini

Thoughts? Advice?

Also, probably not related but FYI, I set up a crontab using cPanel, and get the following error when it runs. I’ve contacted the SiteGround’s tech support about this and they’re working with me to fix it.

-------------------------------------------------------------------------
Looking up www.weavezinedev.com
Making HTTP connection to www.weavezinedev.com Sending HTTP request.
HTTP request sent; waiting for response.
Alert!: Unexpected network read error; connection aborted.
Can't Access `http://www.weavezinedev.com/cron.php'
Alert!: Unable to access document.

lynx: Can't access startfile
-------------------------------------------------------------------------

Two final questions:

  1. Cron.php is supposed to finish executing within 30 seconds, right? I’m not hurting anything if after 2-3 minutes I’ve going in and deleting the cron_semaphore and cron_last variable, am I?
  2. I've seen mention in some forum topics about a Cron log? I'm not finding anything like that in my Drupal admin or in the files in my Drupal install directory. Does it exist? If so, can someone give me a pointer? I'd love to have more information about where exactly Cron.php (aka bootstrap.inc) is failing.
⋅ Categories: Drupal 6.x

Comments

pbarnett’s picture

pbarnett commented

I had a similar problem on my 5.x installation; I finally debugged it by saving a copy of includes/module.inc and then changing module_invoke_all to read :-

<?php
function module_invoke_all() {
  $args = func_get_args();
  $hook = array_shift($args);
  $return = array();
  foreach (module_implements($hook) as $module) {
    if ($hook == 'cron') {
      $now = microtime(true);
      watchdog('module_invoke_all',"calling $module");
    }
    $function = $module .'_'. $hook;
    $result = call_user_func_array($function, $args);
    if ($hook == 'cron') {
      $now = microtime(true) - $now;
      $now = number_format($now, 5);
      watchdog('module_invoke_all',"return from $module after $now sec.");
    }
    if (isset($result) && is_array($result)) {
      $return = array_merge($return, $result);
    }
    else if (isset($result)) {
      $return[] = $result;
    }
  }

  return $return;
}
?>

This left entries in the log showing calls to, and the return from, the various modules with a cron hook.

Pete.

WeaveGeek’s picture

WeaveGeek commented

Pete,

Thanks for the logging snippet! I got the same bit of code from a Drupal buddy and it made all the difference. I hope something like this makes it into Drupal 7. Cron is such a black box without some sort of log to show you where it's breaking.

So, with cron logging installed, it took about two minutes to clear out the cron_semaphore one last time, re-run cron and identify the problem module. On my server, ad_cache_memcache, was not returning during cron runs and leaving the cron_semaphore set. I can disable it and cron runs just fine, both manually and from an automated crontab. I can enable it and watch cron break again, with all the symptoms above. It's great to be able to toggle the repro!

Thanks for taking the time to stop and help a newbie out!

The past two days of debugging and research have really taught me a lot about cron. Whew!

pbarnett’s picture

pbarnett commented

Glad I could help!

I had the same problem myself, and the code change was the only way to debug the issue.

I agree that it would be enormously useful to be able to toggle logging of cron invocations - perhaps you should suggest it?

Pete.

adshill’s picture

adshill commented

Guys I'm having the same problems... I added the code as specified and am now looking for the output in the logs... but which logs can I find this in? Watchdog reports the same old problem and doesn't give any more info.

Thanks,

Adam

pbarnett’s picture

pbarnett commented

Watchdog as in 'recent log entries', right?

Should be right there; see http://mongolia.charityrallies.org/sites/all/files/Screenshot-9.png

Pete.

jdench’s picture

jdench commented

I also found this very helpful as it allowed me to identify the problem module. However I am at a loss to know what to do next - the problem module is simplenews - which is called but doesn't return.

I am on drupal 5, have been using simplenews for several months, this is the first time simplenews itself has caused the cron to hang.

My situation right now is that half the mail from a simplenews bulletin has gone out and the rest is stuck.

Any suggestions?

pbarnett’s picture

pbarnett commented

Best to post this question in the simplenews list of issues.

Having said that, the last stable release of the 5.x version is eight months behind the 6.x release candidate; we abandoned it a while ago due to the lack of control over the mailouts, which were at best ugly HTML, and used phplist and the Drupal phplist module instead.

It's not an ideal solution, but we're relatively happy with it; there's a very apparent dropoff in support of 5.x modules...

Pete.

abqaria’s picture

abqaria commented

I used this code on drupal 6

and waiting for anything to appear on the log entries

cron is now stuck

i think i will take time to get unstuck

then i need to re run it and watch the log entries

dries arnolds’s picture

dries arnolds
Primary language Dutch
Location 🇳🇱 Amsterdam
commented

The code pbarnett posted is for D5. I tried it on D6 but got errors all over the place. Does anyone have a similar code that is D6 compatible? I'm also trying to solve this problem, and finding the source would be a good start.

pbarnett’s picture

pbarnett commented

I modified module.inc (after saving a copy of the original) on a D6 test site, adding the same code as I used for D5.

It works fine for me... the modified function is -

<?php
function module_invoke_all() {
  $args = func_get_args();
  $hook = $args[0];
  unset($args[0]);
  $return = array();
  foreach (module_implements($hook) as $module) {
    $function = $module .'_'. $hook;
    if ($hook == 'cron') {
      $now = microtime(true);
      watchdog('module_invoke_all',"calling $module");
    }
    $result = call_user_func_array($function, $args);
    if ($hook == 'cron') {
      $now = microtime(true) - $now;
      $now = number_format($now, 5);
      watchdog('module_invoke_all',"return from $module after $now sec.");
    }
    if (isset($result) && is_array($result)) {
      $return = array_merge_recursive($return, $result);
    }
    else if (isset($result)) {
      $return[] = $result;
    }
  }

  return $return;
}
?>

Pete.

dries arnolds’s picture

dries arnolds
Primary language Dutch
Location 🇳🇱 Amsterdam
commented

Thanks Pete, I really appreciate this. Big help with this elusive problem.

dduane’s picture

dduane commented

So good of you to post this for those of us who're running 6.x and have been running afoul of this problem. (Mine seems to have been caused by a recent install of Lucene: now at least I should be able to work out which node is making the trouble.)

Thanks again! D.

pbarnett’s picture

pbarnett commented

Hey, no problem...

It's helped me troubleshoot more dodgy code (mostly mine) than a little!

Pete.

Sc0tt’s picture

Sc0tt commented

Thanks for the code snippet. I think it will help me debug what is happening with my cron error. I got the following error while running cron using the code snippit ubove for D6:

Fatal error: Cannot redeclare module_invoke_all() (previously declared in /home/fillmor1/public_html/newsite/includes/module.inc:13) in /home/fillmor1/public_html/newsite/includes/module.inc on line 503

Here is something strange. I backed out the code changes to module.inc and I still get the error. Is there some cache to clear?

Thanks for any help on this,
Scott

Drupal 6.14
Cron maintenance tasks Last run 8 hours 38 min ago
You can run cron manually.
MySQL database 5.0.77mm0.1
PHP 5.2.9
PHP memory limit 96M
PHP register globals Disabled
Unicode library PHP Mbstring Extension
Update notifications Enabled
Upload progress Not enabled
Web server Apache/1.3.41 (Unix) mod_auth_passthrough/1.8 mod_log_bytes/1.2 mod_bwlimited/1.4 FrontPage/5.0.2.2635.SR1.2 mod_ssl/2.8.31 OpenSSL/0.9.8b mod_status/0.2mm
cURL Library 7.15.5
jQuery UI 1.6

Sc0tt’s picture

Sc0tt commented

It was a caching problem in firefox. Worked fine in IE so I cleared firefox browser cache and it fixed the problem.

Sorry for the confusion,
Scott

pbarnett’s picture

pbarnett commented

No problem; your post will help anyone with the same issue!

Pete.

jim22’s picture

jim22 commented

I tried this snippit for D6 in the include/module.inc file and got this error;

Parse error: syntax error, unexpected T_VARIABLE in /examplesite.com/module.inc on line 477

Thanks, Pete, for any help. I've been struggling with cron for at least a week.

pbarnett’s picture

pbarnett commented

What's on that line? Could you post the function and indicate which line it is?

Pete.

jruberto’s picture

jruberto commented

[solved] Was experiencing this same problem, and I imagine that in many cases around version upgrades it is caused by faulty node content.

To troubleshoot cron problem:

- Add watchdog debug to module.inc & run cron (see pbarnett above) to identify which module is crashing (probably search)

- Add watchdog debug to search.module (or other applicable module) in search_cron() & run cron to identify what is causing search to crash (probably node)

- Add watchdog debug to node.module in the loop at the bottom of node_update_index to identify which node is causing search indexing to crash. Look at offending node. Slap forehead, delete or repair offending node (in my case I had a PHP node which called a function in a module that no longer existed in my new install)

If the problem is in other modules, debug accordingly. Cheers, j

p.s. it is worth noting that the watchdog entry "Cron run exceeded the time limit and was aborted." is mistaken -- this happens almost immediately & the failure is not a timeout. heading over to search.module (or maybe cron) to file a bug report.

[edit] follow bug report at http://drupal.org/node/744276

izmeez’s picture

izmeez commented

subscribing

UNarmed’s picture

UNarmed commented

Really hope i manage to track down the problem because this thing is starting to drive me nuts!

pbarnett’s picture

pbarnett commented

Good luck - the advice on this page should help!

UNarmed’s picture

UNarmed commented

Ok thanks i tried the code. My log ended with:

module_invoke_al 09/22/2010 - 11:03 calling update

Here is a image of the entire log http://www.ehbeat.com/clients/CronLog.jpg

So is it some update module causing the issue?

Why i run cron again my log does not show the module_invoke_al stuff anymore and i just get good old "Attempting to re-run cron while it is already running"

UNarmed’s picture

UNarmed commented

Finnaly i have it workign again! The code posted by pbarnett helped me figure out it was the update status module causing the problems. Just Disabeling the module didnt do the trick however. I then had to go into the database and run the following to delete some tables. 

DELETE FROM variable WHERE name="cron_semaphore";
DELETE FROM variable WHERE name = "cron_last";

Thanks you saved me the little sanity i have left =]

UNarmed’s picture

UNarmed commented

Sigh looks like i could only run it once and now its broken again ...

pbarnett’s picture

pbarnett commented

You'll need to clear the cron_semaphore again...

UNarmed’s picture

UNarmed commented

Ok so does that mean i need to clear it each time i want to run cron?

pbarnett’s picture

pbarnett commented

No, that shouldn't be necessary once cron is completing successfully.

UNarmed’s picture

UNarmed commented

Great it is working =] Looks like cron is running 100% now, thanks a lot for all the help.

favosys’s picture

favosys commented

I'm going to try this but I might have another problem, when I run www.mysite.com/cron.php it redirects to the home page and if I go to the recent log entries it doesn't say anything about running cron. But if I go to status report (again it doesn't say there that I just ran cron) and I click "run cron manually" then it works fine the page reloads and says cron was run 1 sec ago and if I go to recent log entries it says cron run completed. So is run cron manually the same as running cron.php? Because that means there is no problem with the cron process itself or modules not returning etc. Then what is the problem??

jruberto’s picture

jruberto commented

sounds like it could be a weird/broken apache configuration?

can you successfully visit update.php or xmlrpc.php?

(and no, the run cron link on the status page is not the same as accessing /cron.php)

Anonymous’s picture

Anonymous (not verified) commented

running these two lines from above in the DB query worked for me. thanks

DELETE FROM variable WHERE name="cron_semaphore";
DELETE FROM variable WHERE name = "cron_last";

RmrJmrGrl’s picture

RmrJmrGrl commented

Same problem with cron stuck. I ran a select *FROM variable WHERE name="cron_semaphore" to see what was in the database and there isn't anything there. So, what does the delete statement remove?

sjtout’s picture

sjtout commented

I'd like to try this, as cron is failing, but the module.inc for my site -- a recent 6.26 installation, already has a module_invoke_all() -- should I remove that one?

-- subsequent edit: sorry I misunderstood; going to try replacing the module_invoke_all() that's already in module.inc with the code above. Thanks.