FreePBX appears to stop communicating with Asterisk


(Jon) #1

Inbound Call Centre environment.
700 DID, 250 Queues (Ring-All configuration), 1 SIP trunk, 70 Devices, 70 users, average 4000 inbound calls/24 hrs, peak calls probably never exceeds 50-60 simultaneous. Average number of “day” shift users logged in would be around 25-35.

Ususally runs on a Sangoma Blue Box (Freepbx Appliance 1000)
Quad core Xeon, 16 GB ram, dual 250 GB SSD’s etc.
FreePBX 13/Asterisk 13

Has been running well since 2017 but recently occasionally stops processing new calls. Usually requires a reboot to resolve and then it’s away again till the next time which could be a day or a week away.
It doesn’t seem to coincide with peak call times but is always during “day” shift which means the most users are logged on.

I’ve had Sangoma look at it and the first thing was to prune the size of the CDR and CEL databases. This has helped, but the problem persists.
They are pretty sure that it isn’t a hardware problem.

As well as the call processing issue, web access the the FreePBX GUI is incredibly slow at times and operators are having difficulty logging in/out. Can take 30+ seconds to do this. Other FreePBX *code functions are affected ie Pauseun-pause call-recording.
Suggestion was possibly related to AGI scripts which have been worked on extensively (apparently).

Sangoma’s last suggestion was to update to FreePBX 15/Asterisk 16.
This has been done using a G6 HP ML350 server with similar spec’s to the Blue Box.

However, the same problems are apparent today after the migration.

It would seem the issue is load related. ie at 4am, web access is fine but gets slower as the day progresses.

I’m open to any suggestions as to where to look and what information would be required to reach conclusion.

Thanks


#2

I suggest sysstat, it wont isolate the problem directly but will show what resources are being stretched and when, memory, cpu, io, net . .


(Jon) #3

Thanks Dicko.
First time i’ve used this tool
(sampled at 10 minute intervals for the day)

A quick look with sar -u (CPU) shows nothing less than 45% idle. It looks ok

Same quick look with sar -r (Memory) tells a different tale although i could be reading this incorrectly.
Seems that %memused is about 51% in non-peak periods but rises to over 95-99% for a 50 minute period mid-morning which coincides with max number of incoming calls for the day.
Another 40 minute period of >97%memused a few hours later which required a reboot to allow incoming calls again.
After that, %memused dropped to 12% then gradually rose to over 99% a few hours later then dropping away to around 49% where it seems to be stable. (6pm local time)

Could be our smoking gun ??

Next question is: what is the best process to monitor what is hogging memory to this degree.


#4

I would start off looking for anything java, it has that reputation.
Asterisk itself is quite light-weight, So look at any AGI stuff or backend reporting going on.


(TheJames) #5

Isymfony call panel should be the only java


(Jon) #6

Thanks, this is new field of endevour for me but here goes.

Call Centre is winding down for the day. Memory usage is steady at around 36-37%, dropping occasionally to 0.3%

htop is reporting /usr/sbin/asterisk -f -U asterisk -G asterisk -vvvg -c as using 36.9%
I have no idea what this means.
There seems to be a varying number of PID’s (10-20 or more) involved.

top is less verbose, but agrees. asterisk (one PID) is up for 36.9% of the total memory.

no sign of anything else of significance. The odd mysql line occasionally as you would expect.

CPU is ~280% as calls come in and ring to the agents, dropping away to ~12% on answer.

I guess we can take a look at a busy period tomorrow and see if there are similarities or if another process makes an appearance.


(Jon) #7

Managed to get a look this morning and can see memory usage is fairly constant at 65-75% in non-peak hours.
Mid-morning and mid-afternoon, memory usage climbs to above 98% then drops away to under 10% before rising again.
This is consistent with other days as well so begs the question is there a scheduled task running every 6 hours ?
I’ll take a look at 21:00 tonight.

Htop reports
/usr/sbin/asterisk -f -U asterisk -G asterisk -vvvg -c running consistently and when memory usage hits the high numbers
/usr/libexec/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=usr/mysql/plugin --log-error (there may be more but its off the screenshot) makes an appearance.
When the used memory settles to a low figure
/usr/sbin/asterisk -f -U asterisk -G asterisk -vvvg -c is the main process shown.

So many questions…
Is the system just under-gunned and running out of memory in the heavy traffic times, or is this indicative of an underlying problem ?

If it’s just a performance issue, are these some of the possible causes ?
Queues are set to ring-all, changing this is (currently) non-negotiable with the customer.
Call recording is “Yes” at Inbound routes and “Don’t care” on the queues.
As this was a v13 install, all the zero duration calls to the agents who don’t pickup a call are recorded along with the one actual call. I think we can switch this off in v15. that’ll be helpful
As well i see call recordings are all gsm format. Whilst appreciating this means less storage space being used, does it introduce an unwanted overhead into system operation ?
Lastly, i was wrong previously, the server it’s on at present actually has 24 GB ram not 16 GB. I can look at increasing this if required, but 24 GB does seem to be a pretty healthy amount.

As before, any suggestion is welcome.


#8

Using only g711 and recording to .wav will minimize both cpu and memory requirements. I’n surprised that your machine is struggling given its specs and load though.


(Jon) #9

Your surprise is shared by many here as well. 8 CPU cores & 24GB of memory shouldn’t be raising a sweat with this number of calls.

I’ve just been looking at the system logs around the mid-morning incident today. It clearly shows an Asterisk restart but i can’t see what led up to this.

Disclaimer: my expertise with Asterisk log files is next to zero…


#10

Post some log lines just prior to the restart and Is there any bitching in /var/log/messages when asterisk restarted


(Jon) #11

What’s the best way to post log files ?
Just cut & paste seem a little “agricultural”


#12

Pastebin of your flavor

grep -C 200 [time of reboot ] /var/log/asterisk/full | pastebinit 

sort of thing


(Jon) #13

need to work on my pastebinit skills.
Anyway, here’s what /var/log/messages has to say about the morning’s episode

Mar 25 08:25:01 freepbx auditd[785]: Audit daemon rotating log files
Mar 25 08:32:57 freepbx systemd-logind: Removed session 9345.
Mar 25 09:35:33 freepbx chronyd[877]: Selected source 132.181.2.72
Mar 25 09:54:49 freepbx kernel: letschat invoked oom-killer: gfp_mask=0x201da, order=0, oom_score_adj=0
Mar 25 09:54:49 freepbx kernel: letschat cpuset=/ mems_allowed=0
Mar 25 09:54:49 freepbx kernel: CPU: 0 PID: 3437 Comm: letschat Kdump: loaded Tainted: G IOE ------------ 3.10.0-1127.19.1.el7.x86_64 #1
Mar 25 09:54:49 freepbx kernel: Hardware name: HP ProLiant ML350 G6, BIOS D22 05/21/2018
Mar 25 09:54:49 freepbx kernel: Call Trace:
Mar 25 09:54:49 freepbx kernel: [] dump_stack+0x19/0x1b
Mar 25 09:54:49 freepbx kernel: [] dump_header+0x90/0x229
Mar 25 09:54:49 freepbx kernel: [] ? ktime_get_ts64+0x52/0xf0
Mar 25 09:54:49 freepbx kernel: [] oom_kill_process+0x25e/0x3f0
Mar 25 09:54:49 freepbx kernel: [] ? cpuset_mems_allowed_intersects+0x21/0x30
Mar 25 09:54:49 freepbx kernel: [] ? oom_unkillable_task+0xcd/0x120
Mar 25 09:54:49 freepbx kernel: [] ? find_lock_task_mm+0x56/0xc0
Mar 25 09:54:49 freepbx kernel: [] out_of_memory+0x4b6/0x4f0
Mar 25 09:54:49 freepbx kernel: [] __alloc_pages_slowpath+0x5db/0x729
Mar 25 09:54:49 freepbx kernel: [] __alloc_pages_nodemask+0x436/0x450
Mar 25 09:54:49 freepbx kernel: [] alloc_pages_current+0x98/0x110
Mar 25 09:54:49 freepbx kernel: [] __page_cache_alloc+0x97/0xb0
Mar 25 09:54:49 freepbx kernel: [] filemap_fault+0x270/0x420
Mar 25 09:54:49 freepbx kernel: [] __xfs_filemap_fault+0x7e/0x1d0 [xfs]
Mar 25 09:54:49 freepbx kernel: [] xfs_filemap_fault+0x2c/0x30 [xfs]
Mar 25 09:54:49 freepbx kernel: [] __do_fault.isra.61+0x8a/0x100
Mar 25 09:54:49 freepbx kernel: [] do_read_fault.isra.63+0x4c/0x1b0
Mar 25 09:54:49 freepbx kernel: [] handle_mm_fault+0xa20/0xfb0
Mar 25 09:54:49 freepbx kernel: [] __do_page_fault+0x213/0x500
Mar 25 09:54:49 freepbx kernel: [] do_page_fault+0x35/0x90
Mar 25 09:54:49 freepbx kernel: [] ? error_swapgs+0xaa/0xc0
Mar 25 09:54:49 freepbx kernel: [] page_fault+0x28/0x30
Mar 25 09:54:49 freepbx kernel: Mem-Info:
Mar 25 09:54:49 freepbx kernel: active_anon:5412686 inactive_anon:510173 isolated_anon:0#012 active_file:4023 inactive_file:4076 isolated_file:29#012 unevictable:0 dirty:2 writeback:0 unstable:0#012 slab_reclaimable:30007 slab_unreclaimable:23754#012 mapped:9500 shmem:9178 pagetables:40379 bounce:0#012 free:41296 free_pcp:1341 free_cma:0
Mar 25 09:54:49 freepbx kernel: Node 0 DMA free:15820kB min:40kB low:48kB high:60kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15992kB managed:15908kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:16kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
Mar 25 09:54:49 freepbx kernel: lowmem_reserve[]: 0 3441 23915 23915
Mar 25 09:54:49 freepbx kernel: Node 0 DMA32 free:91572kB min:9716kB low:12144kB high:14572kB active_anon:2764788kB inactive_anon:588328kB active_file:1668kB inactive_file:1520kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:3774592kB managed:3527140kB mlocked:0kB dirty:0kB writeback:0kB mapped:5124kB shmem:5156kB slab_reclaimable:15628kB slab_unreclaimable:12228kB kernel_stack:2480kB pagetables:30152kB unstable:0kB bounce:0kB free_pcp:2264kB local_pcp:120kB free_cma:0kB writeback_tmp:0kB pages_scanned:6422 all_unreclaimable? yes
Mar 25 09:54:49 freepbx kernel: lowmem_reserve[]: 0 0 20474 20474
Mar 25 09:54:50 freepbx kernel: Node 0 Normal free:57792kB min:57820kB low:72272kB high:86728kB active_anon:18885956kB inactive_anon:1452364kB active_file:14424kB inactive_file:14784kB unevictable:0kB isolated(anon):0kB isolated(file):116kB present:21364732kB managed:20965740kB mlocked:0kB dirty:8kB writeback:0kB mapped:32876kB shmem:31556kB slab_reclaimable:104400kB slab_unreclaimable:82772kB kernel_stack:13280kB pagetables:131364kB unstable:0kB bounce:0kB free_pcp:3100kB local_pcp:464kB free_cma:0kB writeback_tmp:0kB pages_scanned:49970 all_unreclaimable? yes
Mar 25 09:54:50 freepbx kernel: lowmem_reserve[]: 0 0 0 0
Mar 25 09:54:50 freepbx kernel: Node 0 DMA: 14kB (U) 18kB (U) 016kB 032kB 164kB (U) 1128kB (U) 1256kB (U) 0512kB 11024kB (U) 12048kB (M) 34096kB (M) = 15820kB
Mar 25 09:54:50 freepbx kernel: Node 0 DMA32: 644
4kB (UEM) 5978kB (UEM) 70016kB (UEM) 31432kB (UEM) 23664kB (UEM) 93128kB (UEM) 52256kB (UEM) 11512kB (UEM) 151024kB (UEM) 12048kB (M) 04096kB = 91960kB
Mar 25 09:54:50 freepbx kernel: Node 0 Normal: 18184kB (UE) 59858kB (UEM) 17116kB (U) 032kB 064kB 0128kB 0256kB 0512kB 01024kB 02048kB 0*4096kB = 57888kB
Mar 25 09:54:50 freepbx kernel: Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB
Mar 25 09:54:50 freepbx kernel: Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
Mar 25 09:54:50 freepbx kernel: 18073 total pagecache pages
Mar 25 09:54:50 freepbx kernel: 908 pages in swap cache
Mar 25 09:54:50 freepbx kernel: Swap cache stats: add 7862179, delete 7861354, find 2480432/2704020
Mar 25 09:54:50 freepbx kernel: Free swap = 0kB
Mar 25 09:54:50 freepbx kernel: Total swap = 12386300kB
Mar 25 09:54:50 freepbx kernel: 6288829 pages RAM
Mar 25 09:54:50 freepbx kernel: 0 pages HighMem/MovableOnly
Mar 25 09:54:50 freepbx kernel: 161632 pages reserved
Mar 25 09:54:50 freepbx kernel: [ pid ] uid tgid total_vm rss nr_ptes swapents oom_score_adj name
Mar 25 09:54:50 freepbx kernel: [ 604] 0 604 33630 12091 72 60 0 systemd-journal
Mar 25 09:54:50 freepbx kernel: [ 624] 0 624 86509 0 33 149 0 lvmetad
Mar 25 09:54:50 freepbx kernel: [ 634] 0 634 11317 15 23 205 -1000 systemd-udevd
Mar 25 09:54:50 freepbx kernel: [ 785] 0 785 13883 30 27 82 -1000 auditd
Mar 25 09:54:50 freepbx kernel: [ 810] 994 810 153062 92 63 1798 0 polkitd
Mar 25 09:54:50 freepbx kernel: [ 811] 0 811 5418 57 15 33 0 irqbalance
Mar 25 09:54:50 freepbx kernel: [ 813] 0 813 3760 12 13 68 0 incrond
Mar 25 09:54:50 freepbx kernel: [ 814] 32 814 17320 22 37 119 0 rpcbind
Mar 25 09:54:50 freepbx kernel: [ 818] 81 818 14565 91 32 72 -900 dbus-daemon
Mar 25 09:54:50 freepbx kernel: [ 820] 0 820 1767 30 9 16 0 mdadm
Mar 25 09:54:50 freepbx kernel: [ 831] 0 831 6654 55 20 92 0 systemd-logind
Mar 25 09:54:50 freepbx kernel: [ 833] 70 833 15052 36 32 81 0 avahi-daemon
Mar 25 09:54:50 freepbx kernel: [ 838] 70 838 15020 7 31 91 0 avahi-daemon
Mar 25 09:54:50 freepbx kernel: [ 877] 991 877 29452 54 28 81 0 chronyd
Mar 25 09:54:50 freepbx kernel: [ 1181] 0 1181 28231 34 59 244 -1000 sshd
Mar 25 09:54:50 freepbx kernel: [ 1186] 99 1186 13475 20 31 81 0 dnsmasq
Mar 25 09:54:50 freepbx kernel: [ 1187] 0 1187 143575 117 96 2737 0 tuned
Mar 25 09:54:50 freepbx kernel: [ 1191] 990 1191 36788 308 19 1182 0 redis-server
Mar 25 09:54:50 freepbx kernel: [ 1192] 0 1192 92750 6475 87 463 0 rsyslogd
Mar 25 09:54:50 freepbx kernel: [ 1199] 0 1199 6792 4 18 63 0 xinetd
Mar 25 09:54:50 freepbx kernel: [ 1224] 0 1224 66920 237 90 6107 0 python3.6
Mar 25 09:54:50 freepbx kernel: [ 1225] 0 1225 156194 628 223 1764 0 httpd
Mar 25 09:54:50 freepbx kernel: [ 1247] 0 1247 6477 15 18 47 0 atd
Mar 25 09:54:50 freepbx kernel: [ 1252] 0 1252 31604 143 20 58 0 crond
Mar 25 09:54:50 freepbx kernel: [ 1325] 0 1325 27551 11 10 31 0 agetty
Mar 25 09:54:50 freepbx kernel: [ 1358] 27 1358 28353 14 13 72 0 mysqld_safe
Mar 25 09:54:50 freepbx kernel: [ 1652] 27 1652 1205876 93154 403 28912 0 mysqld
Mar 25 09:54:50 freepbx kernel: [ 1808] 0 1808 22426 18 42 242 0 master
Mar 25 09:54:50 freepbx kernel: [ 1810] 89 1810 22496 25 42 247 0 qmgr
Mar 25 09:54:50 freepbx kernel: [ 1828] 184 1828 120485 1273 90 6411 0 mongod
Mar 25 09:54:50 freepbx kernel: [ 1948] 995 1948 49524 77 52 1053 0 pnp_server
Mar 25 09:54:50 freepbx kernel: [ 2072] 995 2072 253416 4157 127 6800 0 PM2 v4.5.0: God
Mar 25 09:54:50 freepbx kernel: [ 2097] 0 2097 39327 93 83 283 0 sshd
Mar 25 09:54:50 freepbx kernel: [ 2152] 0 2152 28886 59 15 74 0 bash
Mar 25 09:54:50 freepbx kernel: [ 2650] 0 2650 28853 49 11 39 0 safe_asterisk
Mar 25 09:54:50 freepbx kernel: [ 2881] 995 2881 255143 10672 125 896 0 node /var/www/h
Mar 25 09:54:50 freepbx kernel: [ 3437] 995 3437 319489 6829 234 20323 0 letschat
Mar 25 09:54:50 freepbx kernel: [ 8693] 0 8693 39360 75 79 286 0 sshd
Mar 25 09:54:50 freepbx kernel: [ 9048] 0 9048 28886 13 14 107 0 bash
Mar 25 09:54:50 freepbx kernel: [31546] 995 31546 188741 1844 260 5458 0 httpd
Mar 25 09:54:50 freepbx kernel: [10267] 995 10267 185978 1848 251 4935 0 httpd
Mar 25 09:54:50 freepbx kernel: [28328] 0 28328 30799 299 16 40 0 htop
Mar 25 09:54:50 freepbx kernel: [19627] 995 19627 188664 3961 259 3311 0 httpd
Mar 25 09:54:50 freepbx kernel: [31214] 995 31214 9343014 5272770 16607 2929415 0 asterisk
Mar 25 09:54:50 freepbx kernel: [28168] 995 28168 188722 3934 259 3329 0 httpd
Mar 25 09:54:50 freepbx kernel: [30739] 995 30739 186013 3907 252 3041 0 httpd
Mar 25 09:54:50 freepbx kernel: [30746] 995 30746 188663 3818 258 3412 0 httpd
Mar 25 09:54:50 freepbx kernel: [ 4627] 0 4627 40560 156 35 74 0 top
Mar 25 09:54:50 freepbx kernel: [28733] 995 28733 183643 1958 237 3064 0 httpd
Mar 25 09:54:50 freepbx kernel: [ 3040] 995 3040 275025 15286 163 1386 0 node /var/www/h
Mar 25 09:54:50 freepbx kernel: [28643] 995 28643 182623 2654 235 1365 0 httpd
Mar 25 09:54:50 freepbx kernel: [26600] 995 26600 185437 3749 249 3008 0 httpd
Mar 25 09:54:50 freepbx kernel: [27313] 995 27313 121271 545 143 4163 0 php
Mar 25 09:54:50 freepbx kernel: [27314] 995 27314 121271 545 143 4163 0 php
Mar 25 09:54:50 freepbx kernel: [27315] 995 27315 121271 43 140 4603 0 php
Mar 25 09:54:50 freepbx kernel: [27317] 995 27317 121271 549 144 4097 0 php
Mar 25 09:54:50 freepbx kernel: [27318] 995 27318 121271 575 143 4131 0 php
Mar 25 09:54:50 freepbx kernel: [27321] 995 27321 121271 546 144 4162 0 php
Mar 25 09:54:50 freepbx kernel: [27322] 995 27322 121271 549 144 4097 0 php
Mar 25 09:54:50 freepbx kernel: [27327] 995 27327 121271 549 141 4097 0 php
Mar 25 09:54:50 freepbx kernel: [27461] 995 27461 121271 43 145 4603 0 php
Mar 25 09:54:50 freepbx kernel: [27462] 995 27462 121271 545 147 4164 0 php
Mar 25 09:54:50 freepbx kernel: [27464] 995 27464 121271 546 141 4161 0 php
Mar 25 09:54:50 freepbx kernel: [28491] 89 28491 22452 51 43 238 0 pickup
Mar 25 09:54:50 freepbx kernel: [ 6088] 995 6088 182603 2573 231 1364 0 httpd
Mar 25 09:54:50 freepbx kernel: [ 6104] 995 6104 182613 2539 232 1427 0 httpd
Mar 25 09:54:50 freepbx kernel: [ 6109] 995 6109 183221 3139 232 1360 0 httpd
Mar 25 09:54:50 freepbx kernel: [ 6111] 995 6111 185439 5103 248 1669 0 httpd
Mar 25 09:54:50 freepbx kernel: [23302] 0 23302 45625 232 45 43 0 crond
Mar 25 09:54:50 freepbx kernel: [23305] 995 23305 28320 73 13 0 0 sh
Mar 25 09:54:50 freepbx kernel: [23414] 995 23414 128085 11544 157 0 0 php
Mar 25 09:54:50 freepbx kernel: [27257] 995 27257 121271 4685 142 0 0 php
Mar 25 09:54:50 freepbx kernel: [27609] 995 27609 121271 4647 141 0 0 php
Mar 25 09:54:50 freepbx kernel: [27616] 995 27616 121271 4675 140 0 0 php
Mar 25 09:54:50 freepbx kernel: [27619] 995 27619 121271 4685 146 0 0 php
Mar 25 09:54:50 freepbx kernel: [27622] 995 27622 121271 4684 144 0 0 php
Mar 25 09:54:50 freepbx kernel: [27626] 995 27626 121271 4668 143 0 0 php
Mar 25 09:54:50 freepbx kernel: [27646] 995 27646 121271 4684 141 0 0 php
Mar 25 09:54:50 freepbx kernel: [27653] 995 27653 111859 2816 127 0 0 php
Mar 25 09:54:50 freepbx kernel: [27658] 995 27658 121271 4685 146 0 0 php
Mar 25 09:54:51 freepbx kernel: [27806] 995 27806 121271 4692 141 0 0 php
Mar 25 09:54:51 freepbx kernel: [27807] 995 27807 121271 4692 142 0 0 php
Mar 25 09:54:51 freepbx kernel: [27814] 995 27814 121271 4693 146 0 0 php
Mar 25 09:54:51 freepbx kernel: [27865] 995 27865 121271 4682 143 0 0 php
Mar 25 09:54:51 freepbx kernel: [27995] 995 27995 121271 4646 144 0 0 php
Mar 25 09:54:51 freepbx kernel: [28012] 995 28012 121271 4669 142 0 0 php
Mar 25 09:54:51 freepbx kernel: [28255] 995 28255 121271 4675 145 0 0 php
Mar 25 09:54:51 freepbx kernel: [28412] 995 28412 121271 4675 145 0 0 php
Mar 25 09:54:51 freepbx kernel: [28455] 995 28455 121271 4675 142 0 0 php
Mar 25 09:54:51 freepbx kernel: [28468] 995 28468 121271 4676 143 0 0 php
Mar 25 09:54:51 freepbx kernel: [28481] 995 28481 121399 4849 141 0 0 php
Mar 25 09:54:51 freepbx kernel: [28586] 995 28586 120759 4129 140 0 0 php
Mar 25 09:54:51 freepbx kernel: [28598] 995 28598 121271 4680 143 0 0 php
Mar 25 09:54:51 freepbx kernel: [28599] 995 28599 120759 4129 144 0 0 php
Mar 25 09:54:51 freepbx kernel: [28600] 995 28600 120759 4129 145 0 0 php
Mar 25 09:54:51 freepbx kernel: [28601] 995 28601 120759 4128 142 0 0 php
Mar 25 09:54:51 freepbx kernel: [28602] 995 28602 120759 4128 143 0 0 php
Mar 25 09:54:51 freepbx kernel: [28604] 995 28604 120759 4129 141 0 0 php
Mar 25 09:54:51 freepbx kernel: [28606] 995 28606 121271 4662 143 0 0 php
Mar 25 09:54:51 freepbx kernel: [28608] 995 28608 120759 4129 141 0 0 php
Mar 25 09:54:51 freepbx kernel: [28610] 995 28610 120759 4129 143 0 0 php
Mar 25 09:54:51 freepbx kernel: [28612] 995 28612 120759 4129 139 0 0 php
Mar 25 09:54:51 freepbx kernel: [28617] 995 28617 120759 4129 140 0 0 php
Mar 25 09:54:51 freepbx kernel: [28619] 995 28619 121271 4680 142 0 0 php
Mar 25 09:54:51 freepbx kernel: [28623] 995 28623 120759 4129 141 0 0 php
Mar 25 09:54:51 freepbx kernel: [28625] 995 28625 121271 4678 147 0 0 php
Mar 25 09:54:51 freepbx kernel: [28630] 995 28630 121271 4678 142 0 0 php
Mar 25 09:54:51 freepbx kernel: [28637] 995 28637 121271 4668 143 0 0 php
Mar 25 09:54:51 freepbx kernel: [28713] 995 28713 121271 4678 145 0 0 php
Mar 25 09:54:51 freepbx kernel: [28720] 995 28720 121271 4678 148 0 0 php
Mar 25 09:54:51 freepbx kernel: [28743] 0 28743 45625 232 45 43 0 crond
Mar 25 09:54:51 freepbx kernel: [28744] 0 28744 45625 232 45 43 0 crond
Mar 25 09:54:51 freepbx kernel: [28745] 0 28745 45625 232 45 43 0 crond
Mar 25 09:54:51 freepbx kernel: [28746] 995 28746 28320 44 13 0 0 sh
Mar 25 09:54:51 freepbx kernel: [28747] 995 28747 28320 44 13 0 0 sh
Mar 25 09:54:51 freepbx kernel: [28748] 995 28748 28320 43 13 0 0 sh
Mar 25 09:54:51 freepbx kernel: [28750] 995 28750 124027 7416 151 0 0 php
Mar 25 09:54:51 freepbx kernel: [28751] 995 28751 125237 8708 151 0 0 check_system_se
Mar 25 09:54:51 freepbx kernel: [28865] 995 28865 121271 4643 146 0 0 php
Mar 25 09:54:51 freepbx kernel: [28867] 995 28867 120759 4085 143 0 0 php
Mar 25 09:54:51 freepbx kernel: [28868] 995 28868 121271 4642 146 0 0 php
Mar 25 09:54:51 freepbx kernel: [28869] 995 28869 120759 4084 138 0 0 php
Mar 25 09:54:51 freepbx kernel: [28870] 995 28870 121271 4679 144 0 0 php
Mar 25 09:54:51 freepbx kernel: [28871] 995 28871 121271 4643 143 0 0 php
Mar 25 09:54:51 freepbx kernel: [28873] 995 28873 121271 4676 146 0 0 php
Mar 25 09:54:51 freepbx kernel: [28878] 995 28878 121271 4643 141 0 0 php
Mar 25 09:54:51 freepbx kernel: [28881] 995 28881 121271 4643 144 0 0 php
Mar 25 09:54:51 freepbx kernel: [28902] 995 28902 121271 4642 146 0 0 php
Mar 25 09:54:51 freepbx kernel: [28906] 995 28906 121271 4643 140 0 0 php
Mar 25 09:54:51 freepbx kernel: [28908] 995 28908 121271 4642 146 0 0 php
Mar 25 09:54:51 freepbx kernel: [28928] 995 28928 121271 4643 145 0 0 php
Mar 25 09:54:51 freepbx kernel: [28934] 995 28934 121271 4642 145 0 0 php
Mar 25 09:54:51 freepbx kernel: [28943] 995 28943 121271 4643 143 0 0 php
Mar 25 09:54:51 freepbx kernel: [28957] 995 28957 121271 4642 143 0 0 php
Mar 25 09:54:51 freepbx kernel: [29056] 995 29056 120759 4127 139 0 0 php
Mar 25 09:54:51 freepbx kernel: [29057] 995 29057 120759 4127 144 0 0 php
Mar 25 09:54:51 freepbx kernel: [29058] 995 29058 120759 4126 141 0 0 php
Mar 25 09:54:51 freepbx kernel: [29062] 995 29062 120759 4096 141 0 0 php
Mar 25 09:54:51 freepbx kernel: [29063] 995 29063 120759 4127 145 0 0 php
Mar 25 09:54:51 freepbx kernel: [29064] 995 29064 120759 4127 146 0 0 php
Mar 25 09:54:51 freepbx kernel: [29065] 995 29065 120759 4126 141 0 0 php
Mar 25 09:54:51 freepbx kernel: [29066] 995 29066 120759 4126 144 0 0 php
Mar 25 09:54:51 freepbx kernel: [29067] 995 29067 120759 4117 143 0 0 php
Mar 25 09:54:51 freepbx kernel: [29068] 995 29068 120759 4127 143 0 0 php
Mar 25 09:54:51 freepbx kernel: [29069] 995 29069 120759 4127 143 0 0 php
Mar 25 09:54:51 freepbx kernel: [29073] 995 29073 120759 4127 142 0 0 php
Mar 25 09:54:51 freepbx kernel: [29074] 995 29074 120759 4126 141 0 0 php
Mar 25 09:54:51 freepbx kernel: [29075] 995 29075 120759 4127 144 0 0 php
Mar 25 09:54:51 freepbx kernel: [29076] 995 29076 120759 4127 141 0 0 php
Mar 25 09:54:51 freepbx kernel: [29077] 995 29077 120759 4126 146 0 0 php
Mar 25 09:54:51 freepbx kernel: [29130] 995 29130 120721 4159 141 0 0 php
Mar 25 09:54:51 freepbx kernel: [29150] 995 29150 120759 4124 140 0 0 php
Mar 25 09:54:51 freepbx kernel: [29167] 995 29167 120759 4124 146 0 0 php
Mar 25 09:54:51 freepbx kernel: [29402] 995 29402 120759 4127 146 0 0 php
Mar 25 09:54:51 freepbx kernel: [29405] 995 29405 120759 4127 143 0 0 php
Mar 25 09:54:51 freepbx kernel: [29406] 995 29406 120759 4127 146 0 0 php
Mar 25 09:54:51 freepbx kernel: [29407] 995 29407 120759 4121 144 0 0 php
Mar 25 09:54:51 freepbx kernel: [29408] 995 29408 120759 4127 141 0 0 php
Mar 25 09:54:51 freepbx kernel: [29411] 995 29411 120759 4128 139 0 0 php
Mar 25 09:54:51 freepbx kernel: [29413] 995 29413 120759 4115 141 0 0 php
Mar 25 09:54:51 freepbx kernel: [29415] 995 29415 120759 4116 140 0 0 php
Mar 25 09:54:51 freepbx kernel: [29418] 995 29418 120759 4124 144 0 0 php
Mar 25 09:54:51 freepbx kernel: [29440] 995 29440 120439 3790 141 0 0 php
Mar 25 09:54:51 freepbx kernel: [29450] 995 29450 120439 3790 143 0 0 php
Mar 25 09:54:51 freepbx kernel: [29454] 995 29454 120439 3818 142 0 0 php
Mar 25 09:54:51 freepbx kernel: [29455] 995 29455 120439 3791 140 0 0 php
Mar 25 09:54:51 freepbx kernel: [29456] 995 29456 120439 3791 139 0 0 php
Mar 25 09:54:51 freepbx kernel: [29457] 995 29457 120439 3791 142 0 0 php
Mar 25 09:54:51 freepbx kernel: [29458] 995 29458 120439 3791 139 0 0 php
Mar 25 09:54:51 freepbx kernel: [29472] 995 29472 120439 3790 141 0 0 php
Mar 25 09:54:51 freepbx kernel: [29473] 995 29473 120439 3791 140 0 0 php
Mar 25 09:54:51 freepbx kernel: [29474] 995 29474 120439 3818 142 0 0 php
Mar 25 09:54:51 freepbx kernel: [29475] 995 29475 120439 3796 142 0 0 php
Mar 25 09:54:51 freepbx kernel: [29476] 995 29476 120439 3791 145 0 0 php
Mar 25 09:54:51 freepbx kernel: [29477] 995 29477 120439 3818 146 0 0 php
Mar 25 09:54:51 freepbx kernel: [29478] 995 29478 120439 3818 141 0 0 php
Mar 25 09:54:51 freepbx kernel: [29479] 995 29479 120439 3790 140 0 0 php
Mar 25 09:54:51 freepbx kernel: [29480] 995 29480 120439 3791 138 0 0 php
Mar 25 09:54:51 freepbx kernel: [29481] 995 29481 120439 3791 144 0 0 php
Mar 25 09:54:51 freepbx kernel: [29482] 995 29482 120439 3796 139 0 0 php
Mar 25 09:54:51 freepbx kernel: [29483] 995 29483 120439 3790 145 0 0 php
Mar 25 09:54:51 freepbx kernel: [29487] 995 29487 120439 3791 141 0 0 php
Mar 25 09:54:51 freepbx kernel: [29488] 995 29488 120439 3818 139 0 0 php
Mar 25 09:54:51 freepbx kernel: [29489] 995 29489 120439 3791 138 0 0 php
Mar 25 09:54:51 freepbx kernel: [29499] 995 29499 120439 3818 141 0 0 php
Mar 25 09:54:51 freepbx kernel: [29529] 995 29529 119448 2769 140 0 0 php
Mar 25 09:54:51 freepbx kernel: [29530] 995 29530 119448 2769 138 0 0 php
Mar 25 09:54:51 freepbx kernel: [29585] 995 29585 61225 609 72 0 0 php
Mar 25 09:54:51 freepbx kernel: [29587] 995 29587 61225 609 73 0 0 php
Mar 25 09:54:51 freepbx kernel: [29639] 995 29639 18102 311 39 0 0 sangomacrm.agi
Mar 25 09:54:51 freepbx kernel: [29640] 995 29640 2391 36 9 0 0 sh
Mar 25 09:54:51 freepbx kernel: [29641] 995 29641 2391 36 10 0 0 sh
Mar 25 09:54:51 freepbx kernel: [29642] 995 29642 2391 36 10 0 0 sh
Mar 25 09:54:51 freepbx kernel: Out of memory: Kill process 31214 (asterisk) score 891 or sacrifice child
Mar 25 09:54:52 freepbx kernel: Killed process 31214 (asterisk), UID 995, total-vm:37372056kB, anon-rss:21091080kB, file-rss:0kB, shmem-rss:0kB
Mar 25 09:56:32 freepbx kernel: TCP: request_sock_TCP: Possible SYN flooding on port 5038. Sending cookies. Check SNMP counters.


(Jon) #14

/var/log/asterisk/full around 0954

[2021-03-25 09:54:46] VERBOSE[27921][C-0000113a] app_mixmonitor.c: End MixMonitor Recording Local/352@from-queue-000104bc;2
[2021-03-25 09:54:46] WARNING[31341] chan_sip.c: Autodestruct on dialog ‘070880224374e2727960beac71aaa81c@27.111.14.66’ with owner SIP/02825582324-0000cbd2 in place (Method: BYE). Rescheduling destruction for 10000 ms
[2021-03-25 09:54:47] WARNING[31341] chan_sip.c: Autodestruct on dialog ‘03b0d01423aef43d01254647206af43e@27.111.14.66’ with owner SIP/02825582324-0000cbfb in place (Method: BYE). Rescheduling destruction for 10000 ms
[2021-03-25 09:54:48] WARNING[31341] chan_sip.c: Autodestruct on dialog ‘035e1b855fa553fb076b0ed669447bb5@27.111.14.66’ with owner SIP/02825582324-0000cb5f in place (Method: BYE). Rescheduling destruction for 10000 ms
[2021-03-25 09:54:48] WARNING[31341] chan_sip.c: Autodestruct on dialog ‘54fada243dae1bcf3bf9e1c53ff85392@27.111.14.66’ with owner SIP/02825582324-0000cc21 in place (Method: BYE). Rescheduling destruction for 10000 ms
[2021-03-25 09:54:56] Asterisk 16.15.1 built by mockbuild @ jenkins7 on a x86_64 running Linux on 2020-12-23 15:37:11 UTC
[2021-03-25 09:54:56] VERBOSE[29763] message.c: Message handler ‘dialplan’ registered.
[2021-03-25 09:54:56] VERBOSE[29763] pbx_functions.c: Registered custom function ‘MESSAGE’
[2021-03-25 09:54:56] VERBOSE[29763] pbx_functions.c: Registered custom function ‘MESSAGE_DATA’
[2021-03-25 09:54:56] VERBOSE[29763] pbx_app.c: Registered application ‘MessageSend’
[2021-03-25 09:54:56] VERBOSE[29763] manager.c: Manager registered action MessageSend
[2021-03-25 09:54:56] VERBOSE[29763] channel.c: Registered channel type ‘Surrogate’ (Surrogate channel used to pull channel from an application)
[2021-03-25 09:54:56] VERBOSE[29763] manager.c: Manager registered action BridgeTechnologyList
[2021-03-25 09:54:56] VERBOSE[29763] manager.c: Manager registered action BridgeTechnologySuspend
[2021-03-25 09:54:56] VERBOSE[29763] manager.c: Manager registered action BridgeTechnologyUnsuspend
[2021-03-25 09:54:56] VERBOSE[29763] dns_core.c: Registered DNS resolver ‘system’ with priority ‘2147483647’
[2021-03-25 09:54:56] VERBOSE[29763] pbx.c: Asterisk PBX Core Initializing
[2021-03-25 09:54:56] VERBOSE[29763] pbx.c: Registering builtin functions:
[2021-03-25 09:54:56] VERBOSE[29763] pbx_functions.c: Registered custom function ‘EXCEPTION’
[2021-03-25 09:54:56] VERBOSE[29763] pbx_functions.c: Registered custom function ‘TESTTIME’
[2021-03-25 09:54:56] VERBOSE[29763] manager.c: Manager registered action ShowDialPlan


(Rob Thomas) #15

I think this explains your problem. Your machine doesn’t have enough memory. WHY it doesn’t have enough memory is a different question.


#16

My guess, yes oom, but why ?

Mar 25 09:54:51 freepbx kernel: [29529] 995 29529 119448 2769 140 0 0 php
Mar 25 09:54:51 freepbx kernel: [29530] 995 29530 119448 2769 138 0 0 php
Mar 25 09:54:51 freepbx kernel: [29585] 995 29585 61225 609 72 0 0 php
Mar 25 09:54:51 freepbx kernel: [29587] 995 29587 61225 609 73 0 0 php
Mar 25 09:54:51 freepbx kernel: [29639] 995 29639 18102 311 39 0 0 sangomacrm.agi
Mar 25 09:54:51 freepbx kernel: [29640] 995 29640 2391 36 9 0 0 sh
Mar 25 09:54:51 freepbx kernel: [29641] 995 29641 2391 36 10 0 0 sh
Mar 25 09:54:51 freepbx kernel: [29642] 995 29642 2391 36 10 0 0 sh
Mar 25 09:54:51 freepbx kernel: Out of memory: Kill process 31214 (asterisk) score 891 or sacrifice child
Mar 25 09:54:52 freepbx kernel: Killed process 31214 (asterisk), UID 995, total-vm:37372056kB, anon-rss:21091080kB, file-rss:0kB, shmem-rss:0kB
Mar 25 09:56:32 freepbx kernel: TCP: request_sock_TCP: Possible SYN flooding on port 5038. Sending cookies. Check SNMP counters.

Would lead me to suspect that xmpp had a brainfart and sent lots of php processes to AMI all at the same time


(Itzik) #17

If you don’t have it yet enabled, enable FastAGI under advanced settings and restart the PBX.

Then, uninstall any module you don’t use. If you don’t need SangomaCRM, Zulu, iSymphony, SIP Station etc uninstall it


#18

Particularly xmpp (letschat)


(Jon) #19

No doubt it’s an oom issue, but yes why ?
When is 24 GB not enough ?

Remember this (well i think it’s the same issue, definitely the same symptoms) has happened on a Sangoma Blue Box running v13 and now on an HP server running v15.


#20

Well xmpp caused the oom handler to begin, is that avalanche of php processes letschat ? I don’t know. Do you use it?