Summary:	ASTERISK-22056: Asterisk 11.4.0 : Queue RINGNOANSWER wrong ring time when one of the peer becomes unresponsive
Reporter:	Nikita Zogas (nikita.zogas)	Labels:
Date Opened:	2013-07-09 07:00:19	Date Closed:	2013-09-04 19:11:25
Priority:	Critical	Regression?
Status:	Closed/Complete	Components:	Applications/app_queue
Versions:	11.4.0	Frequency of Occurrence	One Time
Related Issues:	is related to ASTERISK-22189 Wrap up time is ignored for queue members who are members in multiple queues is related to ASTERISK-24310 CLONE - Wrap up time is ignored for queue members who are members in multiple queues
Environment:	CentOS release 6.4 (Final), CPU info: Intel(R) Xeon(R) CPU E31220 @ 3.10GHz	Attachments:	( 0) database_screen_2013-06-21_09-53-09.jpg ( 1) extensions_tr.conf ( 2) log_extract.jpg ( 3) queues_settings_mysql1.txt
Description:	When Queue application dials to one agent (peer) which becomes unresponsive during call, another agent's phone rings for remaining time of queue_timeout but still logs full timeout to second agent. To illustrate, I attach screenshots of MySQL database and full log extract. Here is what is seen in the log: [Jun 21 09:53:09] VERBOSE[14467][C-00004b41] pbx.c:     -- Executing [2@sodra-ivr-work:2] Queue("SIP/testlink-00005981", "pasalpos") in new stack [Jun 21 09:53:09] VERBOSE[14467][C-00004b41] res_musiconhold.c:     -- Started music on hold, class 'default', on SIP/testlink-00005981 [Jun 21 09:53:09] WARNING[14467][C-00004b41] translate.c: no samples for alawtolin [Jun 21 09:53:09] VERBOSE[14469][C-00004b41] pbx.c:     -- Executing [316@agents:1] NoOp("Local/316@agents-00003418;2", "Dial to agent 316") in new stack [Jun 21 09:53:09] VERBOSE[14469][C-00004b41] pbx.c:     -- Executing [316@agents:2] Dial("Local/316@agents-00003418;2", "SIP/316") in new stack [Jun 21 09:53:09] VERBOSE[14469][C-00004b41] netsock2.c:   == Using SIP RTP CoS mark 5 [Jun 21 09:53:09] VERBOSE[14469][C-00004b41] app_dial.c:     -- Called SIP/316 SIP/316 is called and then got message in the log: [Jun 21 09:53:15] WARNING[5650] chan_sip.c: Retransmission timeout reached on transmission 1e3ed80f5a8fd5976b56602868f6501a@192.168.88.2:5060 for seqno 102 (Critical Request) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions Packet timed out after 6399ms with no response [Jun 21 09:53:15] WARNING[5650] chan_sip.c: Hanging up call 1e3ed80f5a8fd5976b56602868f6501a@192.168.88.2:5060 - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions). [Jun 21 09:53:15] VERBOSE[14469][C-00004b41] app_dial.c:   == Everyone is busy/congested at this time (1:0/0/1) [Jun 21 09:53:15] VERBOSE[14469][C-00004b41] pbx.c:     -- Executing [316@agents:3] Hangup("Local/316@agents-00003418;2", "") in new stack [Jun 21 09:53:15] VERBOSE[14469][C-00004b41] pbx.c:   == Spawn extension (agents, 316, 3) exited non-zero on 'Local/316@agents-00003418;2' [Jun 21 09:53:15] VERBOSE[14467][C-00004b41] app_queue.c:     -- Nobody picked up in 6000 ms then starts new call, as you see, call start and end difference is 2 seconds whereas Asterisk states "Nobody picked up in 8000 ms" [Jun 21 09:53:15] VERBOSE[14475][C-00004b41] pbx.c:     -- Executing [330@agents:1] NoOp("Local/330@agents-00003419;2", "Dial to agent 330") in new stack [Jun 21 09:53:15] VERBOSE[14475][C-00004b41] pbx.c:     -- Executing [330@agents:2] Dial("Local/330@agents-00003419;2", "SIP/330") in new stack [Jun 21 09:53:15] VERBOSE[14475][C-00004b41] netsock2.c:   == Using SIP RTP CoS mark 5 [Jun 21 09:53:15] VERBOSE[14475][C-00004b41] app_dial.c:     -- Called SIP/330 [Jun 21 09:53:15] VERBOSE[14475][C-00004b41] app_dial.c:     -- SIP/330-00005983 is ringing [Jun 21 09:53:15] VERBOSE[14467][C-00004b41] app_queue.c:     -- Local/330@agents-00003419;1 is ringing [Jun 21 09:53:16] VERBOSE[14449][C-00004b40] pbx.c:     -- Executing [s@sodra-ivr-work:10] BackGround("OOH323/avaya1-10151", "sodra4") in new stack [Jun 21 09:53:16] VERBOSE[14449][C-00004b40] file.c:     -- <OOH323/avaya1-10151> Playing 'sodra4.slin' (language 'en') [Jun 21 09:53:17] VERBOSE[14467][C-00004b41] app_queue.c:     -- Nobody picked up in 8000 ms [Jun 21 09:53:17] VERBOSE[14475][C-00004b41] pbx.c:   == Spawn extension (agents, 330, 2) exited non-zero on 'Local/330@agents-00003419;2' [Jun 21 09:53:20] VERBOSE[14437][C-00004b39] res_musiconhold.c:     -- Started music on hold, class 'default', on Local/320@agents-00003414;2 Steps to reproduce (likely): 1. Use Queue() application and 2 logged agents 2. Force one agent to become unresponsive (e.g. unplug Ethernet cable of VoIP phone if HW phone is used)
Comments:	By: Matt Jordan (mjordan) 2013-07-15 16:12:27.492-0500 Can you attach your full {{queues.conf}} as well as your {{extensions.conf}}? I'd like to confirm the timeout values and the queue configuration. By: Nikita Zogas (nikita.zogas) 2013-07-16 00:59:04.354-0500 Since we use queues from MySQL database, I attache output of SELECT * FROM realtime_queues table. By: Rusty Newton (rnewton) 2013-08-05 18:17:40.510-0500 @Nikita Can you reproduce this when adding only the member devices to the queue and not using Local channels or Agents? I did some testing with this and was unable to reproduce. By: Matt Jordan (mjordan) 2013-08-21 11:15:13.984-0500 This *may* be related to ASTERISK-22189. Can you try the patch on that issue and see if it resolves the problem? By: Rusty Newton (rnewton) 2013-09-04 19:11:25.033-0500 Reporter no longer responding and I couldn't reproduce this one specifically. Closing out.