Asterisk PJSIP stops responding to all traffic

We’re running into a problem now where Asterisk stops responding to all SIP traffic until it’s restarted. The logs are not providing any data to go off of that’s worth anything (see below), and once the Asterisk process is restarted, all the call traffic comes back to life.

We’re running Asterisk certified/13.8-cert2.

[Dec 28 19:02:08] VERBOSE[27209][C-000006b4] pbx.c: Executing [35@queuemetrics:6] Hangup(“Local/35@queuemetrics-00000265;2”, “”) in new stack
[Dec 28 19:02:08] VERBOSE[27209][C-000006b4] pbx.c: Spawn extension (queuemetrics, 35, 6) exited non-zero on ‘Local/35@queuemetrics-00000265;2’
[Dec 28 19:02:08] VERBOSE[27208][C-000006b5] pbx.c: Spawn extension (queuemetrics, 10, 2) exited non-zero on ‘Local/35@queuemetrics-00000265;1’
[Dec 28 19:02:25] VERBOSE[26145][C-0000062c] bridge_channel.c: Channel PJSIP/5707-00000543 left ‘simple_bridge’ basic-bridge <3aed451b-45b6-4bd7-8dac-07f76c81f394>
[Dec 28 19:02:25] VERBOSE[26094][C-0000062c] bridge_channel.c: Channel PJSIP/procinctus1-00000542 left ‘simple_bridge’ basic-bridge <3aed451b-45b6-4bd7-8dac-07f76c81f394>
[Dec 28 19:02:25] VERBOSE[26094][C-0000062c] pbx.c: Spawn extension (SQQ_Direct2, s, 16) exited non-zero on ‘PJSIP/procinctus1-00000542’
[Dec 28 19:02:25] VERBOSE[26102][C-0000062c] app_mixmonitor.c: MixMonitor close filestream (mixed)
[Dec 28 19:02:25] VERBOSE[26102][C-0000062c] app_mixmonitor.c: End MixMonitor Recording PJSIP/procinctus1-00000542
[Dec 28 19:02:59] VERBOSE[2277] asterisk.c: Remote UNIX connection
[Dec 28 19:02:59] VERBOSE[27254] asterisk.c: Remote UNIX connection disconnected
[Dec 28 19:03:01] VERBOSE[2277] asterisk.c: Remote UNIX connection
[Dec 28 19:03:01] VERBOSE[27276] asterisk.c: Remote UNIX connection disconnected
[Dec 28 19:04:03] VERBOSE[27358] manager.c: Manager ‘admin’ logged on from 127.0.0.1
[Dec 28 19:04:03] VERBOSE[27360][C-000006b6] pbx.c: Executing [32@queuemetrics:1] Answer(“Local/32@queuemetrics-00000266;2”, “”) in new stack
[Dec 28 19:04:03] VERBOSE[27359] dial.c: Called 32@queuemetrics/n
[Dec 28 19:04:03] VERBOSE[27359] dial.c: Local/32@queuemetrics-00000266;1 answered
[Dec 28 19:04:03] VERBOSE[27359][C-000006b7] pbx.c: Executing [10@queuemetrics:1] Answer(“Local/32@queuemetrics-00000266;1”, “”) in new stack
[Dec 28 19:04:03] VERBOSE[27359][C-000006b7] pbx.c: Executing [10@queuemetrics:2] Wait(“Local/32@queuemetrics-00000266;1”, “10”) in new stack
[Dec 28 19:04:03] VERBOSE[27358] manager.c: Manager ‘admin’ logged off from 127.0.0.1
[Dec 28 19:04:04] VERBOSE[27360][C-000006b6] pbx.c: Executing [32@queuemetrics:2] NoOp(“Local/32@queuemetrics-00000266;2”, " "QM: Pausing Agent/2081 at extension PJSIP/2081 with pause reason ‘24’ made by ‘Agent/2081’ " ") in new stack
[Dec 28 19:04:04] VERBOSE[27360][C-000006b6] pbx.c: Executing [32@queuemetrics:3] PauseQueueMember(“Local/32@queuemetrics-00000266;2”, “,PJSIP/2081”) in new stack
[Dec 28 19:04:04] VERBOSE[27360][C-000006b6] pbx.c: Executing [32@queuemetrics:4] System(“Local/32@queuemetrics-00000266;2”, " echo “|1482951843.4471|NONE|Agent/2081|PAUSEREASON|24” >> /var/log/asterisk/queue_log ") in new stack
[Dec 28 19:04:04] VERBOSE[27360][C-000006b6] pbx.c: Executing [32@queuemetrics:5] Hangup(“Local/32@queuemetrics-00000266;2”, “”) in new stack
[Dec 28 19:04:04] VERBOSE[27360][C-000006b6] pbx.c: Spawn extension (queuemetrics, 32, 5) exited non-zero on ‘Local/32@queuemetrics-00000266;2’
[Dec 28 19:04:04] VERBOSE[27359][C-000006b7] pbx.c: Spawn extension (queuemetrics, 10, 2) exited non-zero on ‘Local/32@queuemetrics-00000266;1’
[Dec 28 19:04:04] VERBOSE[2277] asterisk.c: Remote UNIX connection
[Dec 28 19:04:08] VERBOSE[27363] asterisk.c: Remote UNIX connection disconnected
[Dec 28 19:04:12] VERBOSE[2270] asterisk.c: Asterisk uncleanly ending (0).
[Dec 28 19:04:12] VERBOSE[2270] asterisk.c: Executing last minute cleanups
[Dec 28 19:04:12] VERBOSE[2270] res_musiconhold.c: Destroying musiconhold processes
[Dec 28 19:04:12] VERBOSE[2270] manager.c: Manager unregistered action DBGet
[Dec 28 19:04:12] VERBOSE[2270] manager.c: Manager unregistered action DBPut
[Dec 28 19:04:12] VERBOSE[2270] manager.c: Manager unregistered action DBDel
[Dec 28 19:04:12] VERBOSE[2270] manager.c: Manager unregistered action DBDelTree
[Dec 28 19:04:13] Asterisk certified/13.8-cert2 built by root @ server on a x86_64 running Linux on 2016-10-27 21:51:21 UTC
[Dec 28 19:04:13] VERBOSE[27487] manager.c: Manager registered action DBGet
[Dec 28 19:04:13] VERBOSE[27487] manager.c: Manager registered action DBPut
[Dec 28 19:04:13] VERBOSE[27487] manager.c: Manager registered action DBDel
[Dec 28 19:04:13] VERBOSE[27487] manager.c: Manager registered action DBDelTree```

Saw this in the logs . .

[Dec 28 18:49:51] WARNING[2298] taskprocessor.c: The ‘pjsip/distributor-000000df’ task processor queue reached 500 scheduled tasks.
[Dec 28 18:51:28] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:51:28] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:51:29] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:51:31] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:51:35] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:51:39] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:51:43] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:51:47] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:51:51] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:51:55] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:51:59] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:52:23] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:52:24] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:52:25] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:52:27] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:52:31] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:52:35] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:52:37] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:52:38] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:52:39] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:52:39] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:52:41] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:52:43] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:52:45] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:52:47] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:52:49] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:52:51] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:52:53] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:52:55] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:52:57] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:01] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:04] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:05] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:05] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:06] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:08] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:09] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:12] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:12] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:13] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:14] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:16] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:16] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:20] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:20] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:24] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:24] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:28] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:28] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:32] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:32] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:36] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:36] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:40] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:42] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:42] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:43] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:44] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:45] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:49] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:53] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:53:57] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:54:01] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:54:05] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:54:09] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:54:13] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:54:23] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:54:24] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:54:25] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:54:27] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:54:31] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:54:35] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:54:39] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:54:43] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:54:47] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:54:51] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request
[Dec 28 18:54:55] ERROR[2298] res_pjsip/pjsip_distributor.c: Could not find matching INVITE transaction for CANCEL request

Reading up on Mr. Mudgett’s ‘Asterisk Task Processor Queue Size Warnings’ blog post.

I believe this to be related to the SIP threadpool’s queue, because we’re seeing 503s coming from Asterisk.

This is a highly utilized server with a ton of memory and processing a ton of calls.

Any recommendations as to what configuration options should I look at to resolve would be appreciated (while I google for them).

any thoughts on this . .

[system]
type=system

threadpool_initial_size=50
threadpool_auto_increment=10
threadpool_idle_timeout=120
threadpool_max_size=150

Potentially related to this, https://issues.asterisk.org/jira/browse/ASTERISK-25655 ?

It seems to be very related, and the issue is still open. Are you running an Asterisk version higher than 13.6.0, or 13.7.0

We’re running Asterisk certified/13.8-cert2

As you already read here this issue could be as a result, the symptoms of overloading your Asterisk installation have changed. An early symptom of an overloaded system is when task processors start queueing an excessive number of tasks to process. If the overload conditions are not relieved then later symptoms can include high CPU utilization and/or high memory consumption due to extremely large queues.

Have you try to add more resources to your system or distribute the work load between multiple servers.

Remmber You can see some task processor statistics by executing the CLI command “core show taskprocessors”. , Use the task processor names help identify modules in Asterisk that are bottle necks on your system.

Also it is recommended

  • Disable features you do not need. It is important that if you do not need features like Homer(HEP), CDR, CEL, or AMI that you do not enable them and for HEP you shouldn’t load those modules either.

yes, I read the blog post already and have made the appropriate tweaks to pjsip.conf.

[system]
type=system

threadpool_initial_size=50
threadpool_auto_increment=10
threadpool_idle_timeout=120
threadpool_max_size=150

Hoping to get some feedback on those settings from Josh :slight_smile:

@jcolp is the man :wink:

Those settings are fine. Any further tweaks would require investigation into what exactly is being processed so slowly by examining a console log and backtrace at the point in time when it is happening.