I am now getting the following error in my logs when there are very few subscriptions in the queue it seems:
Subscriptions cannot send any notifications because its cron job time is 0!
When I get this, queue items are not sent, nor are they deleted from the queue. It seems nothing at all happens because it thinks the job time available is 0. I cannot test to see if this will persist with large numbers of queue items until Monday... but I'll report back then if you haven't caught the error cause by then.
I don't think anything has changed except that I upgraded from Drupal 6.13 to 6.14.
Comments
Comment #1
salvisAre you sure you haven't set the cron job time to 0 yourself?
Or is some other cron process eating up all the available time? Try removing
//TEST:on line 52 of subscriptions_mail.module.The showing of this message should be in no way related to the number of pending notifications.
Comment #2
chawl commentedSame here.
If I set this:
to this:
in "subscriptions_mail.module", warning disappeared and mails are sent.
This blind attempt:
did not help. ini_get gets correct max_execution_time from php.ini by the way. Previous dev was OK.
Any suggestions? Tx.
PHP 5.2.10, D 6.14
Comment #3
salvisIt seems you're contradicting yourself here, or am I misunderstanding?
Please log the value that you get from
ini_get('max_execution_time')and tell us!Comment #4
chawl commentedOk. This:
gives "120string".
Edit: Uncommenting TEST gives:
Manaually setting variable to 120 gives:
There's something absurd, I am confused also.
Comment #5
gregarios commentedI have this setting:
Maximum percent of cron job time to use: 50No other processes were using any cron time... the cron run only took about 10 seconds to complete.
Comment #6
salvis#4: this is what we have:
The echoes give you '120string', but the watchdog entry gives you an empty string for $total_seconds???
Please try changing the first line to
Comment #7
gregarios commentedI just checked, and even the variable table shows this:
subscriptions_cron_percent | s:2:"50"I'm kind of in a pickle here too... I need to get this weekly out today, and I can't get them to leave the queue...
Any workarounds out there? How and where does that manual setting work that Chawl did?
Comment #8
gregarios commentedI removed the
//TEST:from line 52, and ran cron.Here is what the log said:
Subscriptions has -2.26702 of seconds available.Comment #9
CalebD commentedI'm also having this problem. It began happening after I updated to Drupal 6.14 on morning of September 17th. Uncommenting line 52 gives me a very similar message to gregarios'. For some reason ini_get('max_execution_time') is returning an empty string. I also tried the following:
Which worked as expected (30 was printed, which is the correct value as reported by phpinfo();).
It seems like Drupal 6.14 introduced something that is causing this, but I'm not sure what yet.
Comment #10
gregarios commentedI made a test php page with nothing but this in it:
and it returns the correct number.
I decided to try a modification to your code and put this in your module instead:
$total_seconds = round(ini_get('max_execution_time'));...and it produces the number 0, instead of an empty variable. This pretty much proves that the
ini_get('max_execution_time');is not working correctly from within the module, and maybe all of Drupal, for some reason.My only thought on a workaround would be to have a separate function get the max execution time somehow, then store it in a variable instead of looking it up each time.
The Drupal 6.14 release was a security release... and by chance maybe they disabled something, or made access to the ini_get limited in some way? If you go into the Drupal status page and see the PHP info, the correct execution time is listed in there. Take a look in their code and see if they are doing it a different way somehow?
Comment #11
chawl commented@salvis:Nope, I have tried this on another test page and got "120string", sorry for confusion, I have copy-pasted the line casually and constructed test for it. As I have said in #2, (int) does not help also.
D 6.14 seems to be the cause anyway. I suspected if some methods are restricted on 6.14 and dug a bit, but other "ini_get()" using modules (user, system, color and many ".inc"s) seem to be working properly.
Another mystery.
Comment #12
gregarios commentedI temporarily resorted to using this in place of the problem code, substituting my actual max execution time manually:
The next cron run things started flowing again. You can call it the Roto-Rooter workaround.
;-)Comment #13
introfini commentedI also get an empty string on ini_get('max_execution_time') on Drupal 6.14
Comment #14
introfini commentedI think the problem was found:
http://drupal.org/node/580508
http://drupal.org/node/582070
Comment #15
chawl commentedNice catch. In fact Feed API's suggested patch for the same problem seems crude, not far away from hardcoding a number.
Then "Romans should demand tribune" on Drupal > Issues. 6.15 seems soon.
Comment #16
jrglasgow commentedWe cannot let this remain depending on a fix to me made in core. Even if a change has been made in core to fix this error it won't be in another release until a security update. It seems to me that we cannot afford to wait on that so here is a patch provides the crude solution that was proposed for FeedAPI.
I feel that even a crude solution is better than no solution at all.
Comment #17
salvisI'm sorry, I've been off-line shortly. Thank you all for pursuing this!
Yes, this issue is caused by the core patch that was committed in #193383-106: set_time_limit: Centralize calls and prevent warnings and errors and delivered with 6.14.
Here's the work-around that I'll commit to Subscriptions: change
to
in subscriptions_mail.module. This is in line with what the core fix does, which has already been committed.
Comment #18
gregarios commentedYour fix works for me. Does that "core fix" mean they will be releasing a Drupal 6.15 soon?
Comment #19
salvisI suggested they should in #193383-124: set_time_limit: Centralize calls and prevent warnings and errors, but I wish they'd also clean up another mess ASAP that was introduced with 6.14.
OTOH you may as well patch core now. The core fix is trivial and simply reverts to what it was before 6.14. You can't go wrong with it.
Comment #20
toemaz commentedThe solution in #17 worked for me. Thanks salvis.
Comment #21
salvisThanks for the feedback, gregarios and toemaz.
Committed to the just-released 6.x-1.1.
@jrglasgow: Thanks for providing a working patch. Rather than setting Subscriptions to a fixed 120 seconds (50% of 240), it uses an administrator-controlled variable percentage of 240.
Comment #23
saepl commentedwow, what a life saver this post is! Number #17 worked for me.
Comment #24
salvisWhy didn't you just update to 6.x-1.1?