[asterisk-bugs] [JIRA] (ASTERISK-22189) Wrap up time is ignored for queue members who are members in multiple queues
Matt Jordan (JIRA)
noreply at issues.asterisk.org
Fri Jul 26 09:29:10 CDT 2013
[ https://issues.asterisk.org/jira/browse/ASTERISK-22189?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=208244#comment-208244 ]
Matt Jordan edited comment on ASTERISK-22189 at 7/26/13 9:28 AM:
-----------------------------------------------------------------
So I thought this would be easy to reproduce. Unfortunately, my first crack at it didn't reproduce it.
{noformat:title=queues.conf}
[sales]
strategy=ringall
announce=sales
musicclass = default
monitor-type=MixMonitor
monitor-format=wav
member => Local/digium01 at agents
wrapuptime = 15
[support]
strategy=ringall
announce=support
musicclass = default
member => Local/digium01 at agents
timeout = 5
retry = 15
wrapuptime = 30
{noformat}
{noformat|title=extensions.conf}
[default]
exten => 5000,1,NoOp()
exten => 5000,n,Queue(sales)
[agents]
exten => digium01,hint,SIP/digium01
exten => digium01,1,NoOp()
same => n,Dial(SIP/digium01,15,hHkKtT)
same => n,Hangup()
{noformat}
In the log snippet below, two calls are made.
# In the first call, SIP/digium02 calls the Queue at 5000. This creates a Local channel that dials SIP/digium01. The two are bridged, talk for a bit, and SIP/digium02 hangs up. The call ends at approximately 09:23:30.
# In the second call, SIP/digium02 calls the Queue at 5000 again. They hang out in the Queue because the only channel member was the Local channel to SIP/digium01 - which implies the wrapup time is being honored for the queue. Note that the time at which SIP/digium01 is dialed by the Local channel agent is 09:23:47, which is 15 seconds from when the second call attempt was made. That might be a little wonky in that the wrapup time probably should have started from when the last call terminated, but since no one was in the queue any more when that happened, the check probably started from when the next call entered the queue. Regardless, wrapup time for the queue was honored.
{noformat|title=messages}
[Jul 26 09:23:19] VERBOSE[26930] config.c: == Parsing '/etc/asterisk/logger.conf': Found
[Jul 26 09:23:19] VERBOSE[26930] logger.c: Asterisk Queue Logger restarted
[Jul 26 09:23:22] VERBOSE[26945][C-00000004] netsock2.c: == Using SIP RTP CoS mark 5
[Jul 26 09:23:22] VERBOSE[27102][C-00000004] pbx.c: -- Executing [5000 at default:1] NoOp("SIP/digium02-00000008", "") in new stack
[Jul 26 09:23:22] VERBOSE[27102][C-00000004] pbx.c: -- Executing [5000 at default:2] Queue("SIP/digium02-00000008", "sales") in new stack
[Jul 26 09:23:22] VERBOSE[27102][C-00000004] res_musiconhold.c: -- Started music on hold, class 'default', on SIP/digium02-00000008
[Jul 26 09:23:22] VERBOSE[27103][C-00000004] pbx.c: -- Executing [digium01 at agents:1] NoOp("Local/digium01 at agents-00000004;2", "") in new stack
[Jul 26 09:23:22] VERBOSE[27103][C-00000004] pbx.c: -- Executing [digium01 at agents:2] Dial("Local/digium01 at agents-00000004;2", "SIP/digium01,15,hHkKtT") in new stack
[Jul 26 09:23:22] VERBOSE[27103][C-00000004] netsock2.c: == Using SIP RTP CoS mark 5
[Jul 26 09:23:22] VERBOSE[27103][C-00000004] app_dial.c: -- Called SIP/digium01
[Jul 26 09:23:22] VERBOSE[27102][C-00000004] app_queue.c: -- Local/digium01 at agents-00000004;1 connected line has changed. Saving it until answer for SIP/digium02-00000008
[Jul 26 09:23:22] VERBOSE[27102][C-00000004] app_queue.c: -- Local/digium01 at agents-00000004;1 connected line has changed. Saving it until answer for SIP/digium02-00000008
[Jul 26 09:23:22] VERBOSE[27103][C-00000004] app_dial.c: -- SIP/digium01-00000009 is ringing
[Jul 26 09:23:22] VERBOSE[27102][C-00000004] app_queue.c: -- Local/digium01 at agents-00000004;1 is ringing
[Jul 26 09:23:25] VERBOSE[27102][C-00000004] app_queue.c: -- Local/digium01 at agents-00000004;1 connected line has changed. Saving it until answer for SIP/digium02-00000008
[Jul 26 09:23:25] VERBOSE[27103][C-00000004] app_dial.c: -- SIP/digium01-00000009 answered Local/digium01 at agents-00000004;2
[Jul 26 09:23:25] VERBOSE[27102][C-00000004] app_queue.c: -- Local/digium01 at agents-00000004;1 answered SIP/digium02-00000008
[Jul 26 09:23:25] VERBOSE[27102][C-00000004] res_musiconhold.c: -- Stopped music on hold on SIP/digium02-00000008
[Jul 26 09:23:25] VERBOSE[27105][C-00000004] app_mixmonitor.c: == Begin MixMonitor Recording SIP/digium02-00000008
[Jul 26 09:23:25] VERBOSE[27103][C-00000004] pbx.c: == Spawn extension (agents, digium01, 2) exited non-zero on 'Local/digium01 at agents-00000004;2'
[Jul 26 09:23:30] VERBOSE[27102][C-00000004] pbx.c: -- Executing [h at default:1] NoOp("SIP/digium02-00000008", "") in new stack
[Jul 26 09:23:30] VERBOSE[27102][C-00000004] pbx.c: -- Executing [h at default:2] Wait("SIP/digium02-00000008", "10") in new stack
[Jul 26 09:23:30] VERBOSE[27102][C-00000004] pbx.c: == Spawn extension (default, h, 2) exited non-zero on 'SIP/digium02-00000008'
[Jul 26 09:23:30] VERBOSE[27102][C-00000004] pbx.c: == Spawn extension (default, 5000, 2) exited non-zero on 'SIP/digium02-00000008'
[Jul 26 09:23:30] VERBOSE[27105][C-00000004] app_mixmonitor.c: == MixMonitor close filestream (mixed)
[Jul 26 09:23:30] VERBOSE[27105][C-00000004] app_mixmonitor.c: == End MixMonitor Recording SIP/digium02-00000008
[Jul 26 09:23:32] VERBOSE[26945][C-00000005] netsock2.c: == Using SIP RTP CoS mark 5
[Jul 26 09:23:32] VERBOSE[27107][C-00000005] pbx.c: -- Executing [5000 at default:1] NoOp("SIP/digium02-0000000a", "") in new stack
[Jul 26 09:23:32] VERBOSE[27107][C-00000005] pbx.c: -- Executing [5000 at default:2] Queue("SIP/digium02-0000000a", "sales") in new stack
[Jul 26 09:23:32] VERBOSE[27107][C-00000005] res_musiconhold.c: -- Started music on hold, class 'default', on SIP/digium02-0000000a
[Jul 26 09:23:47] VERBOSE[27119][C-00000005] pbx.c: -- Executing [digium01 at agents:1] NoOp("Local/digium01 at agents-00000005;2", "") in new stack
[Jul 26 09:23:47] VERBOSE[27119][C-00000005] pbx.c: -- Executing [digium01 at agents:2] Dial("Local/digium01 at agents-00000005;2", "SIP/digium01,15,hHkKtT") in new stack
[Jul 26 09:23:47] VERBOSE[27119][C-00000005] netsock2.c: == Using SIP RTP CoS mark 5
[Jul 26 09:23:47] VERBOSE[27119][C-00000005] app_dial.c: -- Called SIP/digium01
[Jul 26 09:23:47] VERBOSE[27107][C-00000005] app_queue.c: -- Local/digium01 at agents-00000005;1 connected line has changed. Saving it until answer for SIP/digium02-0000000a
[Jul 26 09:23:47] VERBOSE[27107][C-00000005] app_queue.c: -- Local/digium01 at agents-00000005;1 connected line has changed. Saving it until answer for SIP/digium02-0000000a
[Jul 26 09:23:47] VERBOSE[27119][C-00000005] app_dial.c: -- SIP/digium01-0000000b is ringing
[Jul 26 09:23:47] VERBOSE[27107][C-00000005] app_queue.c: -- Local/digium01 at agents-00000005;1 is ringing
[Jul 26 09:23:50] VERBOSE[27107][C-00000005] app_queue.c: -- Local/digium01 at agents-00000005;1 connected line has changed. Saving it until answer for SIP/digium02-0000000a
[Jul 26 09:23:50] VERBOSE[27119][C-00000005] app_dial.c: -- SIP/digium01-0000000b answered Local/digium01 at agents-00000005;2
[Jul 26 09:23:50] VERBOSE[27107][C-00000005] app_queue.c: -- Local/digium01 at agents-00000005;1 answered SIP/digium02-0000000a
[Jul 26 09:23:50] VERBOSE[27107][C-00000005] res_musiconhold.c: -- Stopped music on hold on SIP/digium02-0000000a
[Jul 26 09:23:50] VERBOSE[27120][C-00000005] app_mixmonitor.c: == Begin MixMonitor Recording SIP/digium02-0000000a
[Jul 26 09:23:51] VERBOSE[27119][C-00000005] pbx.c: == Spawn extension (agents, digium01, 2) exited non-zero on 'Local/digium01 at agents-00000005;2'
[Jul 26 09:23:54] VERBOSE[27107][C-00000005] pbx.c: -- Executing [h at default:1] NoOp("SIP/digium02-0000000a", "") in new stack
[Jul 26 09:23:54] VERBOSE[27107][C-00000005] pbx.c: -- Executing [h at default:2] Wait("SIP/digium02-0000000a", "10") in new stack
[Jul 26 09:23:54] VERBOSE[27107][C-00000005] pbx.c: == Spawn extension (default, h, 2) exited non-zero on 'SIP/digium02-0000000a'
[Jul 26 09:23:54] VERBOSE[27107][C-00000005] pbx.c: == Spawn extension (default, 5000, 2) exited non-zero on 'SIP/digium02-0000000a'
[Jul 26 09:23:54] VERBOSE[27120][C-00000005] app_mixmonitor.c: == MixMonitor close filestream (mixed)
[Jul 26 09:23:54] VERBOSE[27120][C-00000005] app_mixmonitor.c: == End MixMonitor Recording SIP/digium02-0000000a
{noformat}
was (Author: mjordan):
So I thought this would be easy to reproduce. Unfortunately, my first crack at it didn't reproduce it.
{noformat|title=queues.conf}
[sales]
strategy=ringall
announce=sales
musicclass = default
monitor-type=MixMonitor
monitor-format=wav
member => Local/digium01 at agents
wrapuptime = 15
[support]
strategy=ringall
announce=support
musicclass = default
member => Local/digium01 at agents
timeout = 5
retry = 15
wrapuptime = 30
{noformat}
{noformat|title=extensions.conf}
[default]
exten => 5000,1,NoOp()
exten => 5000,n,Queue(sales)
[agents]
exten => digium01,hint,SIP/digium01
exten => digium01,1,NoOp()
same => n,Dial(SIP/digium01,15,hHkKtT)
same => n,Hangup()
{noformat}
In the log snippet below, two calls are made.
# In the first call, SIP/digium02 calls the Queue at 5000. This creates a Local channel that dials SIP/digium01. The two are bridged, talk for a bit, and SIP/digium02 hangs up. The call ends at approximately 09:23:30.
# In the second call, SIP/digium02 calls the Queue at 5000 again. They hang out in the Queue because the only channel member was the Local channel to SIP/digium01 - which implies the wrapup time is being honored for the queue. Note that the time at which SIP/digium01 is dialed by the Local channel agent is 09:23:47, which is 15 seconds from when the second call attempt was made. That might be a little wonky in that the wrapup time probably should have started from when the last call terminated, but since no one was in the queue any more when that happened, the check probably started from when the next call entered the queue. Regardless, wrapup time for the queue was honored.
{noformat|title=messages}
[Jul 26 09:23:19] VERBOSE[26930] config.c: == Parsing '/etc/asterisk/logger.conf': Found
[Jul 26 09:23:19] VERBOSE[26930] logger.c: Asterisk Queue Logger restarted
[Jul 26 09:23:22] VERBOSE[26945][C-00000004] netsock2.c: == Using SIP RTP CoS mark 5
[Jul 26 09:23:22] VERBOSE[27102][C-00000004] pbx.c: -- Executing [5000 at default:1] NoOp("SIP/digium02-00000008", "") in new stack
[Jul 26 09:23:22] VERBOSE[27102][C-00000004] pbx.c: -- Executing [5000 at default:2] Queue("SIP/digium02-00000008", "sales") in new stack
[Jul 26 09:23:22] VERBOSE[27102][C-00000004] res_musiconhold.c: -- Started music on hold, class 'default', on SIP/digium02-00000008
[Jul 26 09:23:22] VERBOSE[27103][C-00000004] pbx.c: -- Executing [digium01 at agents:1] NoOp("Local/digium01 at agents-00000004;2", "") in new stack
[Jul 26 09:23:22] VERBOSE[27103][C-00000004] pbx.c: -- Executing [digium01 at agents:2] Dial("Local/digium01 at agents-00000004;2", "SIP/digium01,15,hHkKtT") in new stack
[Jul 26 09:23:22] VERBOSE[27103][C-00000004] netsock2.c: == Using SIP RTP CoS mark 5
[Jul 26 09:23:22] VERBOSE[27103][C-00000004] app_dial.c: -- Called SIP/digium01
[Jul 26 09:23:22] VERBOSE[27102][C-00000004] app_queue.c: -- Local/digium01 at agents-00000004;1 connected line has changed. Saving it until answer for SIP/digium02-00000008
[Jul 26 09:23:22] VERBOSE[27102][C-00000004] app_queue.c: -- Local/digium01 at agents-00000004;1 connected line has changed. Saving it until answer for SIP/digium02-00000008
[Jul 26 09:23:22] VERBOSE[27103][C-00000004] app_dial.c: -- SIP/digium01-00000009 is ringing
[Jul 26 09:23:22] VERBOSE[27102][C-00000004] app_queue.c: -- Local/digium01 at agents-00000004;1 is ringing
[Jul 26 09:23:25] VERBOSE[27102][C-00000004] app_queue.c: -- Local/digium01 at agents-00000004;1 connected line has changed. Saving it until answer for SIP/digium02-00000008
[Jul 26 09:23:25] VERBOSE[27103][C-00000004] app_dial.c: -- SIP/digium01-00000009 answered Local/digium01 at agents-00000004;2
[Jul 26 09:23:25] VERBOSE[27102][C-00000004] app_queue.c: -- Local/digium01 at agents-00000004;1 answered SIP/digium02-00000008
[Jul 26 09:23:25] VERBOSE[27102][C-00000004] res_musiconhold.c: -- Stopped music on hold on SIP/digium02-00000008
[Jul 26 09:23:25] VERBOSE[27105][C-00000004] app_mixmonitor.c: == Begin MixMonitor Recording SIP/digium02-00000008
[Jul 26 09:23:25] VERBOSE[27103][C-00000004] pbx.c: == Spawn extension (agents, digium01, 2) exited non-zero on 'Local/digium01 at agents-00000004;2'
[Jul 26 09:23:30] VERBOSE[27102][C-00000004] pbx.c: -- Executing [h at default:1] NoOp("SIP/digium02-00000008", "") in new stack
[Jul 26 09:23:30] VERBOSE[27102][C-00000004] pbx.c: -- Executing [h at default:2] Wait("SIP/digium02-00000008", "10") in new stack
[Jul 26 09:23:30] VERBOSE[27102][C-00000004] pbx.c: == Spawn extension (default, h, 2) exited non-zero on 'SIP/digium02-00000008'
[Jul 26 09:23:30] VERBOSE[27102][C-00000004] pbx.c: == Spawn extension (default, 5000, 2) exited non-zero on 'SIP/digium02-00000008'
[Jul 26 09:23:30] VERBOSE[27105][C-00000004] app_mixmonitor.c: == MixMonitor close filestream (mixed)
[Jul 26 09:23:30] VERBOSE[27105][C-00000004] app_mixmonitor.c: == End MixMonitor Recording SIP/digium02-00000008
[Jul 26 09:23:32] VERBOSE[26945][C-00000005] netsock2.c: == Using SIP RTP CoS mark 5
[Jul 26 09:23:32] VERBOSE[27107][C-00000005] pbx.c: -- Executing [5000 at default:1] NoOp("SIP/digium02-0000000a", "") in new stack
[Jul 26 09:23:32] VERBOSE[27107][C-00000005] pbx.c: -- Executing [5000 at default:2] Queue("SIP/digium02-0000000a", "sales") in new stack
[Jul 26 09:23:32] VERBOSE[27107][C-00000005] res_musiconhold.c: -- Started music on hold, class 'default', on SIP/digium02-0000000a
[Jul 26 09:23:47] VERBOSE[27119][C-00000005] pbx.c: -- Executing [digium01 at agents:1] NoOp("Local/digium01 at agents-00000005;2", "") in new stack
[Jul 26 09:23:47] VERBOSE[27119][C-00000005] pbx.c: -- Executing [digium01 at agents:2] Dial("Local/digium01 at agents-00000005;2", "SIP/digium01,15,hHkKtT") in new stack
[Jul 26 09:23:47] VERBOSE[27119][C-00000005] netsock2.c: == Using SIP RTP CoS mark 5
[Jul 26 09:23:47] VERBOSE[27119][C-00000005] app_dial.c: -- Called SIP/digium01
[Jul 26 09:23:47] VERBOSE[27107][C-00000005] app_queue.c: -- Local/digium01 at agents-00000005;1 connected line has changed. Saving it until answer for SIP/digium02-0000000a
[Jul 26 09:23:47] VERBOSE[27107][C-00000005] app_queue.c: -- Local/digium01 at agents-00000005;1 connected line has changed. Saving it until answer for SIP/digium02-0000000a
[Jul 26 09:23:47] VERBOSE[27119][C-00000005] app_dial.c: -- SIP/digium01-0000000b is ringing
[Jul 26 09:23:47] VERBOSE[27107][C-00000005] app_queue.c: -- Local/digium01 at agents-00000005;1 is ringing
[Jul 26 09:23:50] VERBOSE[27107][C-00000005] app_queue.c: -- Local/digium01 at agents-00000005;1 connected line has changed. Saving it until answer for SIP/digium02-0000000a
[Jul 26 09:23:50] VERBOSE[27119][C-00000005] app_dial.c: -- SIP/digium01-0000000b answered Local/digium01 at agents-00000005;2
[Jul 26 09:23:50] VERBOSE[27107][C-00000005] app_queue.c: -- Local/digium01 at agents-00000005;1 answered SIP/digium02-0000000a
[Jul 26 09:23:50] VERBOSE[27107][C-00000005] res_musiconhold.c: -- Stopped music on hold on SIP/digium02-0000000a
[Jul 26 09:23:50] VERBOSE[27120][C-00000005] app_mixmonitor.c: == Begin MixMonitor Recording SIP/digium02-0000000a
[Jul 26 09:23:51] VERBOSE[27119][C-00000005] pbx.c: == Spawn extension (agents, digium01, 2) exited non-zero on 'Local/digium01 at agents-00000005;2'
[Jul 26 09:23:54] VERBOSE[27107][C-00000005] pbx.c: -- Executing [h at default:1] NoOp("SIP/digium02-0000000a", "") in new stack
[Jul 26 09:23:54] VERBOSE[27107][C-00000005] pbx.c: -- Executing [h at default:2] Wait("SIP/digium02-0000000a", "10") in new stack
[Jul 26 09:23:54] VERBOSE[27107][C-00000005] pbx.c: == Spawn extension (default, h, 2) exited non-zero on 'SIP/digium02-0000000a'
[Jul 26 09:23:54] VERBOSE[27107][C-00000005] pbx.c: == Spawn extension (default, 5000, 2) exited non-zero on 'SIP/digium02-0000000a'
[Jul 26 09:23:54] VERBOSE[27120][C-00000005] app_mixmonitor.c: == MixMonitor close filestream (mixed)
[Jul 26 09:23:54] VERBOSE[27120][C-00000005] app_mixmonitor.c: == End MixMonitor Recording SIP/digium02-0000000a
{noformat}
> Wrap up time is ignored for queue members who are members in multiple queues
> ----------------------------------------------------------------------------
>
> Key: ASTERISK-22189
> URL: https://issues.asterisk.org/jira/browse/ASTERISK-22189
> Project: Asterisk
> Issue Type: Bug
> Security Level: None
> Components: Applications/app_queue
> Affects Versions: 1.8.23.0, 11.3.0, 11.4.0, 11.5.0
> Reporter: Matt Jordan
>
> Queue members who happen to be in multiple queues at the same time don't have any wrap up time. This problem appears to have become more prevalent since Asterisk 11.3.0.
> This may be related to the backing out of the patch on ASTERISK-16115.
> Reported by Tony Lewis of FreePBX.
> (*NOTE*: I'll update this issue with some logs/dialplan in a bit)
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.asterisk.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
More information about the asterisk-bugs
mailing list