Cron crashing : PHP FATAL: Allowed memory size of [x] bytes exhausted (tried to allocate [x+y] bytes)

cramermp · October 18, 2023, 4:03pm

System with latest FreePBX (16.0.40.7), latest updates. I get the above message with the default 512M php memory limit for freepbx. Then I increase to 2048M, and now it takes 4 times longer and still crashes with the same message, this time with a limit closer to 2048M. This now happens every 10 minutes or so, up from 3.5 minute frequency at 512M. I have about 8 calendars on o365 that we sync via oauth, 20 phones or so. We run w/ TLS encryption turned on for many of our calls. This system has 4 cores and 6gb memory, but i’d like to take the cores down to 2 (bumped to 4 because of the cpu usage issues, no real change).

asterisk 25502 98.2 3.0 700620 181948 ? R 10:46 1:09 php /usr/local/sbin/fwconsole job --run --quiet

Something to do with the fwconsole job command. If I run fwconsole job --list I get a list of jobs, but only if the current ‘job --run’ isn’t going, so I have to wait for a crash to get that info.

Here’s the full crash dump in the email from the cron daemon:

PHP Fatal error:  Allowed memory size of 2147483648 bytes exhausted (tried to allocate 2147483656 bytes) in /var/www/html/admin/modules/calendar/IcalParser/IcalRangedParser.php on line 114
PHP Stack trace:
PHP   1. {main}() /var/lib/asterisk/bin/fwconsole:0
PHP   2. FreePBX\Console\Application\FWApplication->run() /var/lib/asterisk/bin/fwconsole:163
PHP   3. FreePBX\Console\Application\FWApplication->doRun() /var/www/html/admin/libraries/Composer/vendor/symfony/console/Application.php:148
PHP   4. FreePBX\Console\Application\FWApplication->doRunCommand() /var/www/html/admin/libraries/Composer/vendor/symfony/console/Application.php:255
PHP   5. FreePBX\Console\Command\Job->run() /var/www/html/admin/libraries/Composer/vendor/symfony/console/Application.php:992
PHP   6. FreePBX\Console\Command\Job->execute() /var/www/html/admin/libraries/Composer/vendor/symfony/console/Command/Command.php:255
PHP   7. FreePBX\Console\Command\Job->runJobs() /var/www/html/admin/libraries/Console/Job.class.php:66
PHP   8. FreePBX\Console\Command\Job->FreePBX\Console\Command\{closure:/var/www/html/admin/libraries/Console/Job.class.php:227-229}() /var/www/html/admin/libraries/Console/Job.class.php:175
PHP   9. call_user_func_array:{/var/www/html/admin/libraries/Console/Job.class.php:228}() /var/www/html/admin/libraries/Console/Job.class.php:228
PHP  10. FreePBX\modules\Calendar\Job::run() /var/www/html/admin/libraries/Console/Job.class.php:228
PHP  11. FreePBX\modules\Calendar->sync() /var/www/html/admin/modules/calendar/Job.php:9
PHP  12. malkusch\lock\mutex\FlockMutex->synchronized() /var/www/html/admin/modules/calendar/Calendar.class.php:686
PHP  13. call_user_func:{/var/www/html/admin/libraries/Composer/vendor/malkusch/lock/classes/mutex/LockMutex.php:39}() /var/www/html/admin/libraries/Composer/vendor/malkusch/lock/classes/mutex/LockMutex.php:39
PHP  14. FreePBX\modules\Calendar->FreePBX\modules\{closure:/var/www/html/admin/modules/calendar/Calendar.class.php:667-686}() /var/www/html/admin/libraries/Composer/vendor/malkusch/lock/classes/mutex/LockMutex.php:39
PHP  15. FreePBX\modules\Calendar\drivers\Oauth->processCalendar() /var/www/html/admin/modules/calendar/Calendar.class.php:679
PHP  16. FreePBX\modules\Calendar\drivers\Oauth->saveiCal() /var/www/html/admin/modules/calendar/drivers/Oauth.php:102
PHP  17. FreePBX\modules\Calendar\drivers\Oauth->buildCache() /var/www/html/admin/modules/calendar/drivers/Base.php:186
PHP  18. FreePBX\modules\Calendar\IcalParser\IcalRangedParser->parseString() /var/www/html/admin/modules/calendar/drivers/Base.php:209
PHP  19. FreePBX\modules\Calendar\IcalParser\IcalRangedParser->parseRecurrences() /var/www/html/admin/modules/calendar/vendor/om/icalparser/src/IcalParser.php:116
PHP  20. array_push() /var/www/html/admin/modules/calendar/IcalParser/IcalRangedParser.php:114

And my job list:

[root@localhost ~]# fwconsole job --list
+----+----------------+-----------------------------------+--------------+---------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------+
| ID | Module         | Job                               | Cron         | Next Run            | Action                                                                                                                                                                           | Enabled |
+----+----------------+-----------------------------------+--------------+---------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------+
| 66 | pbxmfa         | checkUserTrustedDevicesAndLicense | 0 0 * * *    | 2023-10-19 00:00:00 | Class: FreePBX\modules\Pbxmfa\Job                                                                                                                                                | No      |
| 1  | sysadmin       | checkportal                       | @daily       | 2023-10-19 00:00:00 | Command: [ -e /var/www/html/admin/modules/sysadmin/bin/check_portal.php ] && /var/www/html/admin/modules/sysadmin/bin/check_portal.php                                           | Yes     |
| 2  | sysadmin       | ddnsupdate                        | */60 * * * * | 2023-10-18 11:00:00 | Class: FreePBX\modules\Sysadmin\Job\DdnsUpdate                                                                                                                                   | Yes     |
| 3  | sysadmin       | checkstorage                      | @hourly      | 2023-10-18 11:00:00 | Command: [ -x /var/lib/asterisk/bin/storage.php ] && /var/lib/asterisk/bin/storage.php                                                                                           | Yes     |
| 5  | calendar       | sync                              | * * * * *    | 2023-10-18 10:52:00 | Class: FreePBX\modules\Calendar\Job                                                                                                                                              | Yes     |
| 7  | timeconditions | schedtc                           | */15 * * * * | 2023-10-18 11:00:00 | Class: FreePBX\modules\Timeconditions\Job                                                                                                                                        | Yes     |
| 8  | dashboard      | scheduler                         | * * * * *    | 2023-10-18 10:52:00 | Class: FreePBX\modules\Dashboard\Job                                                                                                                                             | Yes     |
| 24 | iotserver      | checkGuestUserStatus              | 0 2 * * *    | 2023-10-19 02:00:00 | Command: [ -x /var/www/html/admin/modules/iotserver/bin/check_guest_users_status.php ] && /var/www/html/admin/modules/iotserver/bin/check_guest_users_status.php 2>&1 >/dev/null | No      |
| 25 | iotserver      | checkLicense                      | 0 1 * * *    | 2023-10-19 01:00:00 | Command: [ -x /var/www/html/admin/modules/iotserver/bin/check_license.php ] && /var/www/html/admin/modules/iotserver/bin/check_license.php 2>&1 >/dev/null                       | No      |
| 26 | iotserver      | checkCertificate                  | 0 2 * * *    | 2023-10-19 02:00:00 | Command: [ -x /var/www/html/admin/modules/iotserver/bin/check_certificates.php ] && /var/www/html/admin/modules/iotserver/bin/check_certificates.php 2>&1 >/dev/null             | No      |
| 27 | iotserver      | refreshTimezoneOffsets            | 0 4 * * *    | 2023-10-19 04:00:00 | Command: [ -x /var/www/html/admin/modules/iotserver/bin/refresh_tzoffsets.php ] && /var/www/html/admin/modules/iotserver/bin/refresh_tzoffsets.php 2>&1 >/dev/null               | No      |
| 28 | iotserver      | checkSystemSettings               | */1 * * * *  | 2023-10-18 10:52:00 | Command: [ -x /var/www/html/admin/modules/iotserver/bin/check_system_settings.php ] && /var/www/html/admin/modules/iotserver/bin/check_system_settings.php 2>&1 >/dev/null       | No      |
| 29 | iotserver      | checkSystemSettingsSh             | */1 * * * *  | 2023-10-18 10:52:00 | Command: [ -x /var/www/html/admin/modules/iotserver/bin/check_system_settings.sh ] && /var/www/html/admin/modules/iotserver/bin/check_system_settings.sh 2>&1 >/dev/null         | No      |
| 31 | endpoint       | clearcdr                          | 5 * * * *    | 2023-10-18 11:05:00 | Class: FreePBX\modules\Endpoint\Job                                                                                                                                              | Yes     |
| 41 | oc             | health                            | @daily       | 2023-10-19 00:00:00 | Command: /usr/local/sbin/fwconsole oracle health --logs > /dev/null 2>&1                                                                                                         | Yes     |
| 42 | pms            | wu_alert                          | * * * * *    | 2023-10-18 10:52:00 | Class: FreePBX\modules\Pms\Job                                                                                                                                                   | No      |
| 43 | pms            | mk_dirty                          | @daily       | 2023-10-19 00:00:00 | Command: /usr/local/sbin/fwconsole pms mk_dirty > /dev/null 2>&1                                                                                                                 | No      |
| 45 | sangomaconnect | sync                              | */5 * * * *  | 2023-10-18 10:55:00 | Command: /var/www/html/admin/modules/sangomaconnect/bin/keep_alive.php 2>&1 >/dev/null                                                                                           | Yes     |
| 46 | sangomaconnect | checkSSL                          | 0 2 * * *    | 2023-10-19 02:00:00 | Command: /var/www/html/admin/modules/sangomaconnect/bin/check_certificates_sc.php 2>&1 >/dev/null                                                                                | Yes     |
| 47 | sangomaconnect | checkLicense                      | 0 1 * * *    | 2023-10-19 01:00:00 | Command: /var/www/html/admin/modules/sangomaconnect/bin/check_license_sc.php                                                                                                     | Yes     |
| 48 | sangomaconnect | clean                             | @daily       | 2023-10-19 00:00:00 | Command: /usr/local/sbin/fwconsole sc cleanGarbageDeviceData 2>&1 > /dev/null                                                                                                    | Yes     |
| 49 | sangomaconnect | cleanupOldChats                   | @daily       | 2023-10-19 00:00:00 | Command: /var/www/html/admin/modules/sangomaconnect/bin/cleanup_sangoma_phone_chats.php 2>&1 >/dev/null                                                                          | Yes     |
| 51 | restapps       | deletesymlinks                    | 0 1 * * *    | 2023-10-19 01:00:00 | Command: /usr/local/sbin/fwconsole phoneapps --deletesymlinks                                                                                                                    | Yes     |
| 60 | firewall       | firewall                          | */15 * * * * | 2023-10-18 11:00:00 | Command: [ -e /etc/asterisk/firewall.enabled ] && touch /var/spool/asterisk/incron/firewall.firewall                                                                             | Yes     |
| 61 | firewall       | syncIDetection                    | */5 * * * *  | 2023-10-18 10:55:00 | Command: [ -e /sbin/fwconsole ] && /sbin/fwconsole firewall sync                                                                                                                 | Yes     |
| 67 | sysadmin       | updatelicense                     | @daily       | 2023-10-19 00:00:00 | Command: [ -x /var/lib/asterisk/agi-bin/update_license.php ] && /var/lib/asterisk/agi-bin/update_license.php --delay                                                             | Yes     |
| 68 | sipstation     | check                             | @daily       | 2023-10-19 00:00:00 | Command: [ -x /var/lib/asterisk/bin/freepbx_sipstation_check ] && /var/lib/asterisk/bin/freepbx_sipstation_check 2>&1 > /dev/null                                                | Yes     |
| 70 | cdr            | cleanTransientCDRData             | @monthly     | 2023-11-01 00:00:00 | Class: FreePBX\modules\Cdr\Job                                                                                                                                                   | Yes     |
+----+----------------+-----------------------------------+--------------+---------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------+

And top:

top - 10:56:23 up 15:44,  1 user,  load average: 1.00, 0.97, 0.95
Tasks: 145 total,   2 running, 143 sleeping,   0 stopped,   0 zombie
%Cpu(s): 25.3 us,  0.1 sy,  0.0 ni, 74.6 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :  5944596 total,  1179936 free,  1975424 used,  2789236 buff/cache
KiB Swap:   786428 total,   786428 free,        0 used.  3653888 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
26351 asterisk  20   0 1093836 536256  15540 R  99.7  9.0   4:10.20 php
 2165 asterisk  20   0 3350432 103792  24996 S   0.7  1.7   5:06.82 asterisk
26796 root      20   0  160040   2256   1536 R   0.7  0.0   0:00.03 top
 2044 root      20   0 1821160  16628   2484 S   0.3  0.3   1:37.93 fail2ban-server
 4832 asterisk  20   0 1235236  61244  12952 S   0.3  1.0   1:21.15 node /var/www/h
 4924 asterisk  20   0 1083024  62200  14616 S   0.3  1.0   1:27.20 node /var/www/h
 5039 asterisk  20   0 1134588 123096  15796 S   0.3  2.1   1:43.28 node /var/www/h
    1 root      20   0  191124   4148   2612 S   0.0  0.1   0:02.29 systemd

cramermp · October 18, 2023, 5:01pm

Okay, so I realized I was really just trying to shortcut the process of running fwconsole job --disable x over and over, trial and error.

I started with the likely suspects based on the wording in the crash dump, and disabled job 5, the oauth enabled calendar sync. This stopped the crashing and high cpu usage by php, just by disabling the one job.

I have the calendars all set to sync once / hour. What are the system requirements for calendar sync with, say, 10 calendars?

cramermp · October 18, 2023, 7:15pm

Looks like I spoke too soon. The process continued to spike, but every 15 minutes. The only 15 minute periodic job (the same php task was spiking) was ‘timeconditions.’ Great. Well, disabled that, now… now it’s clean. Now it doesn’t spike and crash. I’m guessing this has to do with timeconditions using the calendars that sync with outlook?

I kinda need those calendars to work; what do I need to do to get these working without crashing or overloading my system?

kierknoby · October 18, 2023, 8:03pm

Have you run the command service httpd restart after increasing the php memory limit?

cramermp · October 18, 2023, 8:05pm

Yes, I increased the memory x4, and the crash remained, but took almost 4x as long to display a message, this time including the new memory limit in the crash screen.

PHP Fatal error:  Allowed memory size of 2147483648 bytes exhausted (tried to allocate 2147483656 bytes) in /var/www/html/admin/modules/calendar/IcalParser/IcalRangedParser.php on line 114
PHP Stack trace:

vs. before:

PHP Fatal error:  Allowed memory size of 536870912 bytes exhausted (tried to allocate 536870920 bytes) in /var/www/html/admin/modules/calendar/IcalParser/IcalRangedParser.php on line 114

cramermp · October 18, 2023, 8:07pm

Perhaps I need to give this thing 24gb and increase the php memory limit to 18000M? The 100% cpu usage is something i’d like to reduce too. I tried using ‘cpulimit’ on the ‘php’ process but it had no effect.

cramermp · October 19, 2023, 5:28pm

This appears to be a bug in the edge version. I found the system I was working on was in ‘edge’ mode (advanced settings), so I disabled that and did a download/install of the calendar module. This was version 16.0.26. After changing back to the ‘stable’ track on 16.0.21 the php process only takes up 10% periodically and works normally.

system · October 26, 2023, 5:29pm

This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.