When you run a cron that brings back a PHP error (in my case, an undefined function) you are presented with a WSOD and the following error in watchdog,

"Cron run exceeded the time limit and was aborted."

There are two solutions here and I am more than happy to explore either one but wanted to get more community input.

We can generalize the shutdown_function error message to include PHP errors and other things we may not expect.

Or, we can try and catch the error for them by doing something similar to the following. 

if ($semaphore = variable_get('cron_semaphore', FALSE)) {
   //Find their max execution time and take our "best guess" if this is truly the problem
  if(time() - $semaphore > (ini_get('max_execution_time') - 2)) {
    watchdog('cron', t('Cron run exceeded the time limit and was aborted.'), WATCHDOG_WARNING); 
  else
    watchdog('cron', t('Cron run aborted.  Please check for syntax errors in all hook_cron calls.'), WATCHDOG_ERROR);
}

Clearly its not a perfect solution and I'm hoping someone can improve upon it but its a step in the right direction and would have saved me some time debugging my code.

I will be more than happy to roll the patches for 5, 6, 7 if we can decide on the right solution.

Thanks,
Chris Ridenour

Comments

cridenour’s picture

cridenour CreditAttribution: cridenour commented

A link to the current shutdown function: http://api.drupal.org/api/function/drupal_cron_cleanup/

cridenour’s picture

cridenour CreditAttribution: cridenour commented

Bumping because I still think this is an issue and would welcome any feedback to the validity of the problem.

seanburlington’s picture

seanburlington CreditAttribution: seanburlington commented
Priority: Minor » Normal

I agree this is a bug

The error message does not provide the correct analysis of what happened and may prevent people looking for the true cause of the problem.

If cron_semaphore is still set at cleanup all it means is that cron did not complete - it provides no indication as to why.

Another cause of this can be a call to drupal_goto

I'd suggest

if ($semaphore = variable_get('cron_semaphore', FALSE)) {
   //Find their max execution time and take our "best guess" if this is truly the problem
  if(time() - $semaphore > (ini_get('max_execution_time') - 2)) {
    watchdog('cron', t('Cron run exceeded the time limit and was aborted.'), WATCHDOG_WARNING);
  } else {
    watchdog('cron', t('Cron run aborted Abnormally.'), WATCHDOG_ERROR);
}

I hit this problem is some inherited custom code - but it exists in relation to other modules - see #453286: drupal_goto breaks cron.php

jhodgdon’s picture

jhodgdon
she/her
Primary language English
CreditAttribution: jhodgdon commented

Just a note that there are two underlying known issues in search indexing that can cause these types of errors, which I agree should be reported better in the logs (as asked for on this issue):
#752184: Keep running cron when bad PHP content is encountered
#286263: Make search indexing smart to handle nodes wth php redirects

gpk’s picture

gpk CreditAttribution: gpk commented

Yes it would be worth fixing this, the message about the time limit does set you off on the wrong track if in fact something else is the problem.

Suggest using $_SERVER['REQUEST_TIME'] instead of $semaphore in the calculation, in case of a slow bootstrap which would otherwise interfere with the calculation.

cridenour’s picture

cridenour CreditAttribution: cridenour commented

Glad to see some activity on this issue.

Based on some comments across the issues linked - and updated for D7.

if ($semaphore = variable_get('cron_semaphore', FALSE)) {
   //Find their max execution time and take our "best guess" if this is truly the problem
  if(time() - $_SERVER['REQUEST_TIME'] > (ini_get('max_execution_time') - 2)) {
    watchdog('cron', t('Cron run exceeded the time limit and was aborted.'), array(), WATCHDOG_WARNING); 
  else
    watchdog('cron', t('Cron run was aborted due to an error or infinite loop.'), array(), WATCHDOG_ERROR);
}
Berdir’s picture

Berdir
Primary language German
Location Switzerland
CreditAttribution: Berdir commented
Status: Active » Postponed (maintainer needs more info)

The function is actually pointless in 7.x because it's using the lock system now, which has it's own shutdown handling. See #1775488: drupal_cron_cleanup is not converted to lock. That does not add a message anywhere, though. Marking as needs more info, not sure if this should be changed back to 6.x but the chances of this (a user interface test change) being added to it are close to 0.