Anyone who's worked with Drupal a while knows how frustrating it can be trying to debug problems with cron.

The problem is, there's no way of knowing which module is running cron, how long it runs for and at which point cron is failing across all the available hook_cron implementations.

The attached patches provide a "debug mode" checkbox on the admin cron settings form which records detailed timing information about cron runs for each module, to the watchdog - when enabled.

I've been successfully using this patch for a while now to debug cron and have found it very helpful, as have many others on irc. and would like to commit it to benefit others.

Please review, provide any feedback and commit if possible.

cheers,

David

CommentFileSizeAuthor
#5 cron-settings-checkbox.png23.49 KBdavidwhthomas
#5 sample-watchdog-cron-log.png147.01 KBdavidwhthomas
#1 cron-log-information.png165.4 KBdavidwhthomas
D7-enable-cron-debug-mode.patch2.19 KBdavidwhthomas
Support from Acquia helps fund testing for Drupal Acquia logo

Comments

davidwhthomas’s picture

davidwhthomas CreditAttribution: davidwhthomas commented
FileSize
cron-log-information.png165.4 KB

The attached screenshot shows sample logging information under recent log entries for cron.

smittles-1’s picture

smittles-1 CreditAttribution: smittles-1 commented

This snippet is exceptionally helpful, especially as somebody who is using a hosted solution without shell access. Thanks so much!

darrylh’s picture

darrylh CreditAttribution: darrylh commented

I've used this with Drupal 6, and it makes debugging cron issues so much easier. Recommended.

davidwhthomas’s picture

davidwhthomas CreditAttribution: davidwhthomas commented
Status: Needs review » Reviewed & tested by the community
davidwhthomas’s picture

davidwhthomas CreditAttribution: davidwhthomas commented
Title: Enable optional cron debug logging » Enable optional cron debug mode
FileSize
sample-watchdog-cron-log.png147.01 KB
cron-settings-checkbox.png23.49 KB

A couple more screenshots using the current D7 patch attached.

One shows the cron information logged to watchdog, the other shows the cron debug mode settings checkbox.

DT

Dries’s picture

Dries CreditAttribution: Dries commented
Priority: Normal » Minor

My expectations for the 'Debug mode' setting were off. The patch did not implement what I was expecting. I wonder if other people felt the same? Furthermore, I'm not sure this is all that useful.

davidwhthomas’s picture

davidwhthomas CreditAttribution: davidwhthomas commented

Hi there Dries, thanks very much for the reply.

Can you please elaborate more on what your expectations would be for a cron debug mode?

The main benefit of this patch comes from being able to tell what module is running cron, for how long it runs and at which point cron halts. Otherwise, if module_invoke_all('cron') fails at some point, it's very difficult to know where.

In that way, it's very useful for debugging hook_cron related issues such as an update status timeout, an apachesolr index bottleneck or similar timing / timeout issue. You can also use it, when cron needs to run often, to ascertain how long cron runs for and adjust cron run frequency to suit.

thoughts appreciated,

cheers,

David

davidwhthomas’s picture

davidwhthomas CreditAttribution: davidwhthomas commented

Just an update, a quick google search shows around 18,000 hits on drupal.org related to 'cron problems'
I do feel a significant portion of those issues could be debugged and solved with the above patch
http://www.google.com/search?q=site%3Adrupal.org+cron+problem

tstoeckler’s picture

tstoeckler
he/him
Primary language German
Location Essen, Germany
CreditAttribution: tstoeckler commented

I would think most of the problems are related to actually setting up cron, not debugging it.

Also, maybe this would be a better fit for devel module than core.

catch’s picture

catch
he/him
Primary language English
CreditAttribution: catch commented
Version: 7.x-dev » 8.x-dev
Status: Reviewed & tested by the community » Needs review

Please don't mark your own patches rtbc.

davidwhthomas’s picture

davidwhthomas CreditAttribution: davidwhthomas commented

@catch, oh, I was under the impression that if a patch passed all automated tests and was reviewed by two separate people, it was ok to change the status to 'reviewed and tested by the community' there.

I also see you've pushed this back to 8.x-dev.

I actually created a patch and issue for 8.x earlier, but as it got no response, posted in 7.x instead.

That post is here: http://drupal.org/node/1143082

But yeah, I thought this patch was a good idea but sounds like it's flopped, oh well will continue to use on my own projects.

regs,

DT

davidwhthomas’s picture

davidwhthomas CreditAttribution: davidwhthomas commented
Version: 8.x-dev » 7.x-dev

Changing back to D7 as it has passed the automated tests, so other people can find this and because there is a separate issue/patch posted for D8

catch’s picture

catch
he/him
Primary language English
CreditAttribution: catch commented
Status: Needs review » Closed (duplicate)

There should only be one issue, I didn't realise there were two when I moved this to 8.x. So marking this as duplicate of #1143082: Optional timing and logging of cron jobs..

davidwhthomas’s picture

davidwhthomas CreditAttribution: davidwhthomas commented

Any hints as to why this issue can't be considered for D7?

tstoeckler’s picture

tstoeckler
he/him
Primary language German
Location Essen, Germany
CreditAttribution: tstoeckler commented

@davidwhthomas: Before the issue can be considered for Drupal 7, it must be committed to Drupal 8. That's our development policy. If a patch does get committed to Drupal 8 in the other issue, that issue will be moved to Drupal 7.

davidwhthomas’s picture

davidwhthomas CreditAttribution: davidwhthomas commented

@tstoeckler, ah thanks for your kind explanation, will leave it there for now.