[Home]

Summary:ASTERISK-12255: ap_queue hangs up caller
Reporter:snyfer (snyfer)Labels:
Date Opened:2008-06-24 01:44:22Date Closed:2008-07-01 16:08:47
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Applications/app_queue
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:ap_queue hangs up the caller after a queuemember answered even, if the queuemember did not hear the anouncement of the queue!

So if a queuemember answeres a call -> hears the holdtime -> waits for the anouncement and hangs up at that point, the caller is hung up,
instead of getting back in the queue and waiting for the next agent (member) to call!

This worked in asterisk v1.2.x and does not anymore in v1.6.0 Beta 9

Comments:By: Mark Michelson (mmichelson) 2008-06-24 11:47:56

I tried this and did not have the behavior you describe. Do you use the 'n' option for your queue? This was the only way I was able to make that behavior occur.
By: snyfer (snyfer) 2008-06-25 02:30:22

Thank you.

no we do not use the n flag.

       Retries do work - when nobody picks up the call!

But when a member picks up the call and hangs it up again before he heared the anouncement the caller gets hung up - instead of getting back into the queue (wich is a must, because he did not speak to anybody yet) !


This is a great problem because a call gets dropped and the caller gets no feedback at all. He hears ringing or music first, then gets hung up from one second to the other.

Example:
call for queue 123
queue 123 has the member 888
member 888 is ringing
member 888 answers the call and gets the chance to cancel by pressing 1
member 888 cancels the call
member 888 is busy
Member 888 hangs up (before anouncement of the queue is played)
the caller (should now get back into the queue) is hung up.


this did work in 1.2 the correct way. Now it does not anymore.

There is no possibillity to realize any call canceling for members until calls get back into the queue on hangup before the anouncement has been played to the member.
By: snyfer (snyfer) 2008-06-25 08:15:21

Hello!

i just found out, that not only queue is hanging up but also retrydial and dial do ignore the g flag and hang up after a call.

here is what happens:

-- Executing [s@macro-agent_rufen:24] RetryDial("SIP/selfnet.at-08286340", "stille,1,1,SIP/mts,20,grtThH") in new stack
 == Using SIP RTP CoS mark 5
   -- Called mts
   -- SIP/mts-08297a90 is ringing
   -- SIP/mts-08297a90 answered SIP/selfnet.at-08286340

***
now the two are connected and the called partie hangs up. because of the g flag the caller should get to the next extension in the dialplan. But Asterisk hangs up the caller and then goes on in the dialplan without the caller and callee!!!
***

   -- <SIP/selfnet.at-08286340> Playing 'stille.ulaw' (language 'de')
   -- Started music on hold, class 'dicoremiturl', on channel 'SIP/selfnet.at-08286340'
   -- Stopped music on hold on SIP/selfnet.at-08286340
 == Spawn extension (macro-agent_rufen, s, 24) exited non-zero on 'SIP/selfnet.at-08286340' in macro 'agent_rufen'
 == Spawn extension (macro-agent_rufen, s, 24) exited non-zero on 'SIP/selfnet.at-08286340'
server*CLI>



what is going on here?
This is nearly the same problem as described for the ap_queue above!
Is the g flag disabled?

Thank you for your help.
Martin
By: Mark Michelson (mmichelson) 2008-06-25 09:06:12

For the test I ran, I had the member pick up the phone and hang up before the announce file played. I noticed these two steps in your example:

"member 888 answers the call and gets the chance to cancel by pressing 1
member 888 cancels the call"

This is the only difference I can see between your scenario and mine. How are you providing the member with this option? Are you using Local channels for your queue members? Are you using a Local channel to call into the queue?

The problem with app_dial is unrelated to the app_queue issue and should be filed in a separate bug.
By: Mark Michelson (mmichelson) 2008-06-25 09:32:10

I just ran another test where I used a Local channel for my queue member and this time app_queue behaved exactly like you stated. I will work on making a fix.
By: Mark Michelson (mmichelson) 2008-06-25 09:40:54

Nevermind. It turns out that I had set the 'n' option in the queue, so that's why the caller was being hung up.

So, I'm back to square one on this one. If you could upload your queues.conf and the relevant portions of extensions.conf, perhaps I will be able to reproduce this here.

Also, it may be helpful to see the entries in the queue_log generated from one of these failed calls, the value of the QUEUESTATUS variable after the failure, and the output on the console during a failed call.
By: snyfer (snyfer) 2008-06-26 01:05:16

Hello,

okay I collected all the stuff.
before you check all that things please notice, that I found something out while testing again and again.

This may be a good hint:

When I activate report holdtime - and hang up bevore hearing the holdtime - it works and the calller gets back into the queue.

When I turn off reporting holdtime - and hang up bevore the anouncement - the caller is hung up!

This shows that asterisk is only checking if the holdtime has been played already and not if the anouncement has been played! (in v1.2 astterisk checked also the anouncement if there was no reporting holdtime activated)


We are using local channels yes. Only way to get possibillity to clone callbacklogin - I hate, that this has been removed :-(

configurations:


extensions.conf:
exten => 43123077,1,Macro(queue,thinking,tThH,60)





macro-queue:

;some variablesettings...

exten => s,21,Queue(${queuename},ctThH,,beep,60)

exten => s,22,Noop(Queuestatus is ${QUEUESTATUS} ...)





Agent local called channel:

exten => 555,1,Macro(call_agent,555,extension_screening,SIP/mts,de)





Macro-call_agent:

;some Data checking and variable setting

exten => s,11,Dial(${ARG3},${queuetimeout},${queueflags}M(extension_screening))

exten => s,12,Macroexit()





Macro-extension_screening:

exten => s,1,Set(CHANNEL(language)=${ARG3}) ; set agents language and Wait just a giffy

exten => s,2,Read(saycaller,${callfor},1,noanswer,1,1) ; Check to see if they press 8

exten => s,3,GotoIf($[${EXISTS(${saycaller})}]?4:6)

exten => s,4,GotoIf($[${saycaller} = 8 ]?5:6) ;busy if they press 8

exten => s,5,Busy()

exten => s,6,MacroExit()





queue.conf:
[thinking]

maxlen=8

strategy=ringall

retry=2

joinwhenempty=strict

leavewhenempty=strict

servicelevel=60

timeout=25

context=agent_logic

musicclass=thinking

ringinuse=no

monitor-format=wav

timeoutrestart=yes

;reportholdtime=yes

;when we activate reporting holdtime it works!


Queue_log:
1214456593|1214456579.5|thinking|local/555@agent_logic|ADDMEMBER|

1214456593|1214456579.5|dicore|local/555@agent_logic|ADDMEMBER|

1214456606|1214456602.8|thinking|NONE|ENTERQUEUE||069912008888

1214456611|1214456602.8|thinking|local/555@agent_logic|CONNECT|5|1214456606.9|3

1214456611|1214456602.8|thinking|local/555@agent_logic|COMPLETEAGENT|5|0|1





cli during the call: (please note, that after disconnection of the called partie asterisk goes on as nothing had happened)



   -- Executing [s@macro-queue:21] Queue("SIP/selfnet.at-0828f408", "thinking,ctThH,,beep,60") in new stack
   -- Started music on hold, class 'thinking', on channel 'SIP/selfnet.at-0828f408'
   -- Executing [555@agent_logic:1] Macro("Local/555@agent_logic-7450;2", "call_agent,555,extension_screening,SIP/mts,de") in new stack
...
   -- Executing [s@macro-call_agent:11] Dial("Local/555@agent_logic-7450;2", "SIP/mts,60,tThHM(extension_screening,555,1214459820,de)") in new stack
 == Using SIP RTP CoS mark 5
   -- Called mts
   -- SIP/mts-082a0188 is ringing
   -- Local/555@agent_logic-7450;1 is ringing
   -- SIP/mts-082a0188 answered Local/555@agent_logic-7450;2
   -- Executing [s@macro-extension_screening:1] Set("SIP/mts-082a0188", "CHANNEL(language)=de") in new stack
   -- Executing [s@macro-extension_screening:2] Read("SIP/mts-082a0188", "saycaller,callforthinking,1,noanswer,1,1") in new stack
   -- Accepting a maximum of 1 digits.
   -- <SIP/mts-082a0188> Playing 'callforthinking.slin' (language 'de')
   -- User disconnected
   -- Local/555@agent_logic-7450;1 answered SIP/selfnet.at-0828f408
   -- <Local/555@agent_logic-7450;1> Playing 'beep.gsm' (language 'en')
   -- Stopped music on hold on SIP/selfnet.at-0828f408
 == Spawn extension (macro-call_agent, s, 11) exited non-zero on 'Local/555@agent_logic-7450;2' in macro 'call_agent'
 == Spawn extension (macro-call_agent, s, 11) exited non-zero on 'Local/555@agent_logic-7450;2'
   -- Executing [h@macro-call_agent:1] MacroExit("Local/555@agent_logic-7450;2", "") in new stack
 == Spawn extension (macro-call_agent, h, 1) exited non-zero on 'Local/555@agent_logic-7450;2'
 == Spawn extension (macro-queue, s, 21) exited non-zero on 'SIP/selfnet.at-0828f408' in macro 'queue'
 == Spawn extension (macro-queue, s, 21) exited non-zero on 'SIP/selfnet.at-0828f408'
   -- Executing [h@macro-queue:1] NoOp("SIP/selfnet.at-0828f408", "Queuestatus is  ...") in new stack
   -- Executing [h@macro-queue:2] Hangup("SIP/selfnet.at-0828f408", "") in new stack
 == Spawn extension (macro-queue, h, 2) exited non-zero on 'SIP/selfnet.at-0828f408'
server*CLI> exit
server:~#



-
I hope you can find the problem now and fix it. Thank you very much for your help.

best regards
Martin
By: Mark Michelson (mmichelson) 2008-06-27 09:06:03

Thanks very much for the information. I will work on a fix as soon as possible!
By: Mark Michelson (mmichelson) 2008-06-27 10:45:20

After many unsuccessful attempts, I finally have traced the problem to its source. The only way to make this happen is to specify an overriding announcement to the Queue() application. In your case, you provided "beep" as that argument. If you do not specify this argument and instead set announce=beep in queues.conf, then the hangup does not occur. This is...bizarre to say the least. Fix coming shortly.
By: Mark Michelson (mmichelson) 2008-06-27 11:28:00

Further investigation has shown that it in fact is not the announce-override which is causing the problem, but rather a sinister race condition. A short announce file, like "beep", will cause the undesired hangup to occur, while a long announce file, like "queue-thankyou" will not cause the undesired hangup to occur.
By: snyfer (snyfer) 2008-06-27 13:02:54

this is... truly bizarre!
thanks, that you found the problem. Great. Hope you can solve it :-9

have a nice weekend!
Martin
By: Mark Michelson (mmichelson) 2008-06-27 17:15:22

All right, so I worked on this issue all day. There are some weird things happening, that's for sure. But, here are a few of the things I've observed.

1. The first second or so of audio during a queue announcement is not heard by the queue member if that queue member is a local channel.

2. The "beep" sound is short enough that it cannot be heard at all by the queue member when he picks up the phone.

3. It would seem that as long as the announce file being played for the queue member is longer than the silence period at the beginning of the file, the bug does not happen when the member hangs up before the file is played. If the file is too short, then the error reported occurs.

At this point, I have not yet solved the mystery of the missing audio, and I have not figured out a good way to accurately resolve this issue.

I have, however, found two workarounds. One is to use a longer announce file as I described above. Another option is to add a short delay after the member answers the phone using the memberdelay option in queues.conf. Setting memberdelay=1 will suffice.
By: snyfer (snyfer) 2008-06-27 23:08:50

Great!
the workarround with memberdelay = 1 works perfectly.
We will use this, until there is a fix for that problem.
thank you and good luck fo finding a solution :-)
By: Mark Michelson (mmichelson) 2008-06-28 16:48:24

I have finally found the source of the problem. The simple answer is that there is a built-in 500 ms delay when a channel answers in 1.6.0. This delay is not in 1.2 or 1.4. app_queue plays the "beep" file during this delay and actually finishes playing it before the delay has finished. During this delay, all frames sent to the channel are handled by the core and dropped. Because of this, the hangup is not detected until the calling and called channels are bridged. At this point, app_queue thinks that the caller has successfully contacted a queue member, the queue member has hung up, and the caller can safely be removed from the queue. If, however, the sound file played is longer than the 500 ms delay, then the channel driver would alert the core that the channel has been hung up, app_queue would then detect the hangup during the playback, and app_queue would return the caller to the queue.

I don't know why this 500 ms delay was added yet, but I assume it was done with good intentions in mind. I will start querying developers about why the delay was added and if there is a reasonable way to work around this delay from within app_queue.
By: Mark Michelson (mmichelson) 2008-07-01 16:07:41

I will be committing a fix very shortly which solves this issue. Thanks for the bug report.
By: Digium Subversion (svnbot) 2008-07-01 16:08:45

Repository: asterisk
Revision: 127157

U   trunk/main/channel.c

------------------------------------------------------------------------
r127157 | mmichelson | 2008-07-01 16:08:44 -0500 (Tue, 01 Jul 2008) | 8 lines

Place the delay in __ast_answer prior to the channel-specific answer
callback. This change differs from commit 127113 in that now the
channel is not set to AST_STATE_UP until after the answer callback.

(closes issue ASTERISK-12255)
Reported by: snyfer


------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=127157