Possible for historic scheduled reminder to be sent multiple times if cron job does not complete properly
When the Send Scheduled Reminders
job runs, the process fails with errors like the following (reported by our Cron Daemon):
PHP Fatal error: Allowed memory size of 134217728 bytes exhausted (tried to allocate 245760 bytes) in /home/cses_org_uk/public_html/administrator/components/com_civicrm/civicrm/CRM/Utils/Cache/SqlGroup.php on line 184
If attempting to invoke the job manually from the scheduled jobs admin page, we get an HTTP 500 error and the following entries in the error_log:
[Thu Aug 25 19:51:26.801469 2022] [fcgid:warn] [pid 27274] [client 79.69.229.183:51994] mod_fcgid: read data timeout in 301 seconds, referer: https://cses.org.uk/administrator/?option=com_civicrm&task=civicrm/admin/job&action=view&reset=1&context=joblog&id=9
[Thu Aug 25 19:51:26.819905 2022] [core:error] [pid 27274] [client 79.69.229.183:51994] End of script output before headers: index.php, referer: https://cses.org.uk/administrator/?option=com_civicrm&task=civicrm/admin/job&action=view&reset=1&context=joblog&id=9
We can see that the job is starting but never finishing from the log:
The scheduled reminders do seem to be sending successfully, however. Other cron jobs also seem to complete successfully.
This issue seemed to start recently with an unplanned, emergency server migration. It's a virtual server so notionally everything is the same, but there may be some other factor at play here (CiviCRM upgrade, change to one of the reminder templates etc). I have double-checked PHP resource limits (256M memory, 300 second timeout i.e. more than enough) and MySQL settings and can't find anything amiss.
The error occurs at the following line in SQLGroup.php
:
private function reobjectify($value) {
return is_object($value) ? unserialize(serialize($value)) : $value; // This line fails
}
It seems as though serialize()
is failing: whatever value is at fault, it was previously unserialize()
d successfully to read it out of the cache in the first place. What does this function actually do - why the round trip??
I attempted to debug with some judicious error_log()
immediately before and after this line to see which cache value was causing the memory leak, but to no avail. No error_log was written before the crash (although many previous successful calls to the function were logged).
This is on CiviCRM 5.50.4. I will attempt an upgrade soon to see if this fixes it, and will continue to investigate / try to narrow down / work out how to reproduce.