Queue Ringall strategy intermittent/unrepeatable problem

Asterisk Asterisk Support
#1

We have, in the past, run Asterisk 1.6, and when we updated to 1.8 we created a queue page for our employees to see, so maybe the issue has existed prior to 1.8 and we just began seeing it when we all had a queue monitor – anyways, we are now on Asterisk 11, and the issue persists.

What will happen: a call will queue up and ring however many available members there are, and say, 60 seconds in, only one member will keep ringing and the others will not. I began using logrotate and modified logger.conf to try and capture to verbose output. This is what I found:

[root@asterisk2 asterisk]# fgrep "C-0000672d" verbose-20130406 [Apr 5 16:02:58] VERBOSE[23538][C-0000672d] netsock2.c: == Using SIP RTP CoS mark 5 [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] pbx.c: -- Executing [REDACTED@incoming:1] Goto("SIP/metaswitch-00015649", "Main,REDACTED,1") in new stack [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] pbx.c: -- Goto (Main,REDACTED,1) [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] pbx.c: -- Executing [REDACTED@Main:1] Goto("SIP/metaswitch-00015649", "eagle-csr-queue,s,1") in new stack [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] pbx.c: -- Goto (eagle-csr-queue,s,1) [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] pbx.c: -- Executing [s@eagle-csr-queue:1] Answer("SIP/metaswitch-00015649", "") in new stack [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] pbx.c: -- Executing [s@eagle-csr-queue:2] GotoIf("SIP/metaswitch-00015649", "0?FORWARD,1") in new stack [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] pbx.c: -- Executing [s@eagle-csr-queue:3] Set("SIP/metaswitch-00015649", "CALLERID(num)=REDACTED-INCOMING") in new stack [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] pbx.c: -- Executing [s@eagle-csr-queue:4] Set("SIP/metaswitch-00015649", "MONITOR_FILENAME=/iscsi/recordings/hays-csr/20130405-160258-REDACTED-REDACTED-INCOMING-1365195778.87855") in new stack [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] pbx.c: -- Executing [s@eagle-csr-queue:5] Queue("SIP/metaswitch-00015649", "eagle-csr,tk,,,90") in new stack [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] res_musiconhold.c: -- Started music on hold, class 'eagle', on SIP/metaswitch-00015649 [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] netsock2.c: == Using SIP RTP CoS mark 5 [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] netsock2.c: == Using SIP RTP CoS mark 5 [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] netsock2.c: == Using SIP RTP CoS mark 5 [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] netsock2.c: == Using SIP RTP CoS mark 5 [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] netsock2.c: == Using SIP RTP CoS mark 5 [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] netsock2.c: == Using SIP RTP CoS mark 5 [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] app_queue.c: -- SIP/REDACTED-MEMBER-1-0001564f connected line has changed. Saving it until answer for SIP/metaswitch-00015649 [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] app_queue.c: -- SIP/REDACTED-MEMBER-2-0001564d connected line has changed. Saving it until answer for SIP/metaswitch-00015649 [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] app_queue.c: -- SIP/REDACTED-MEMBER-3-0001564c connected line has changed. Saving it until answer for SIP/metaswitch-00015649 [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] app_queue.c: -- SIP/REDACTED-MEMBER-4-0001564b connected line has changed. Saving it until answer for SIP/metaswitch-00015649 [Apr 5 16:02:58] VERBOSE[31628][C-0000672d] app_queue.c: -- SIP/REDACTED-MEMBER-5-0001564a connected line has changed. Saving it until answer for SIP/metaswitch-00015649 [Apr 5 16:02:59] VERBOSE[31628][C-0000672d] app_queue.c: -- SIP/REDACTED-MEMBER-4-0001564b is ringing [Apr 5 16:02:59] VERBOSE[31628][C-0000672d] app_queue.c: -- SIP/REDACTED-MEMBER-3-0001564c is ringing [Apr 5 16:02:59] VERBOSE[31628][C-0000672d] app_queue.c: -- SIP/REDACTED-MEMBER-5-0001564a is ringing [Apr 5 16:02:59] VERBOSE[31628][C-0000672d] app_queue.c: -- SIP/REDACTED-MEMBER-6-0001564e is ringing [Apr 5 16:02:59] VERBOSE[31628][C-0000672d] app_queue.c: -- SIP/REDACTED-MEMBER-2-0001564d is ringing [Apr 5 16:02:59] VERBOSE[31628][C-0000672d] app_queue.c: -- SIP/REDACTED-MEMBER-1-0001564f is ringing [Apr 5 16:03:59] VERBOSE[23538][C-0000672d] chan_sip.c: -- Got SIP response 486 "Busy Here" back from 192.168.3.4:5060 [Apr 5 16:03:59] VERBOSE[31628][C-0000672d] app_queue.c: -- SIP/REDACTED-MEMBER-5-0001564a is busy [Apr 5 16:03:59] VERBOSE[31628][C-0000672d] app_queue.c: -- Nobody picked up in 61000 ms [Apr 5 16:03:59] VERBOSE[23538][C-0000672d] chan_sip.c: -- Got SIP response 486 "Busy Here" back from 192.168.7.4:5060 [Apr 5 16:03:59] VERBOSE[31628][C-0000672d] app_queue.c: -- SIP/REDACTED-MEMBER-3-0001564c is busy [Apr 5 16:03:59] VERBOSE[31628][C-0000672d] app_queue.c: -- Nobody picked up in 61000 ms [Apr 5 16:03:59] VERBOSE[23538][C-0000672d] chan_sip.c: -- Got SIP response 486 "Busy Here" back from 192.168.10.44:5060 [Apr 5 16:03:59] VERBOSE[31628][C-0000672d] app_queue.c: -- SIP/REDACTED-MEMBER-4-0001564b is busy [Apr 5 16:03:59] VERBOSE[31628][C-0000672d] app_queue.c: -- Nobody picked up in 61000 ms [Apr 5 16:03:59] VERBOSE[23538][C-0000672d] chan_sip.c: -- Got SIP response 486 "Busy Here" back from 192.168.5.7:5060 [Apr 5 16:03:59] VERBOSE[31628][C-0000672d] app_queue.c: -- SIP/REDACTED-MEMBER-2-0001564d is busy [Apr 5 16:03:59] VERBOSE[31628][C-0000672d] app_queue.c: -- Nobody picked up in 61000 ms [Apr 5 16:03:59] VERBOSE[23538][C-0000672d] chan_sip.c: -- Got SIP response 486 "Busy Here" back from 192.168.4.136:5060 [Apr 5 16:03:59] VERBOSE[31628][C-0000672d] app_queue.c: -- SIP/REDACTED-MEMBER-1-0001564f is busy [Apr 5 16:03:59] VERBOSE[31628][C-0000672d] app_queue.c: -- Nobody picked up in 61000 ms [Apr 5 16:04:28] VERBOSE[31628][C-0000672d] app_queue.c: -- Nobody picked up in 90000 ms [Apr 5 16:04:28] VERBOSE[31628][C-0000672d] app_queue.c: -- Nobody picked up in 90000 ms [Apr 5 16:04:28] VERBOSE[31628][C-0000672d] res_musiconhold.c: -- Stopped music on hold on SIP/metaswitch-00015649 [Apr 5 16:04:28] VERBOSE[31628][C-0000672d] pbx.c: -- Executing [s@eagle-csr-queue:6] Playback("SIP/metaswitch-00015649", "eagle/voicemail") in new stack [Apr 5 16:04:28] WARNING[31628][C-0000672d] format_wav.c: Unexpected frequency mismatch 44100 (expecting 8000) [Apr 5 16:04:28] WARNING[31628][C-0000672d] file.c: Unable to open format wav [Apr 5 16:04:28] VERBOSE[31628][C-0000672d] file.c: -- <SIP/metaswitch-00015649> Playing 'eagle/voicemail.slin' (language 'en') [Apr 5 16:04:40] VERBOSE[31628][C-0000672d] pbx.c: == Spawn extension (eagle-csr-queue, s, 6) exited non-zero on 'SIP/metaswitch-00015649' [Apr 5 16:04:40] VERBOSE[31628][C-0000672d] pbx.c: -- Executing [h@eagle-csr-queue:1] Hangup("SIP/metaswitch-00015649", "") in new stack [Apr 5 16:04:40] VERBOSE[31628][C-0000672d] pbx.c: == Spawn extension (eagle-csr-queue, h, 1) exited non-zero on 'SIP/metaswitch-00015649'

The following bit does not happen for member 6:

…and it is member 6 that keeps ringing after all other agents say “Busy” for some unknown reason.

We are using all Adtran IP706 phones; could that have something to do with it, or is it the app_queue.c causing the issue?

#2

Bump :bulb:

#3

run the command 'queue show ’ to see the status of all members. How do you add the members to the Queue?

#4

Queue members were dynamically added/removed for some time until recently when I decided to make them static in queues.conf, but this issue has persisted either way.