Summary:ASTERISK-19097: Click To Call Busy Destination Results In Hangup
Reporter:William Roush (wdroush)Labels:
Date Opened:2011-12-22 09:12:52.000-0600Date Closed:2012-02-20 09:31:40.000-0600
Versions: Frequency of
Environment:CentOS5, FreePBX, x64 BuildAttachments:( 0) full
Description:I found this on FreePBX, but I'm sure the issue lies lower on the pole than that, when using click to call software (in my case, iSymphony), if the destination is busy, the PBX will hang up the destination end of the call before I pick up my end, so when I do pick up my end, my phone immediately hangs up.

-- Executing [s@macro-dial-one:46] ExecIf("Local/1000@from-internal-0dde;1", "1?Set(DIALSTATUS=NOANSWER)") in new stack
-- Executing [s@macro-dial-one:47] NoOp("Local/1000@from-internal-0dde;1", "Returned from dial-one with nothing to call and DIALSTATUS: NOANSWER") in new stack
-- Executing [s@macro-dial-one:48] MacroExit("Local/1000@from-internal-0dde;1", "") in new stack
-- Executing [s@macro-exten-vm:15] GotoIf("Local/1000@from-internal-0dde;1", "0?exit") in new stack
-- Executing [s@macro-exten-vm:16] Set("Local/1000@from-internal-0dde;1", "SV_DIALSTATUS=NOANSWER") in new stack
-- Executing [s@macro-exten-vm:17] GosubIf("Local/1000@from-internal-0dde;1", "0?docfu,1()") in new stack
-- Executing [s@macro-exten-vm:18] GosubIf("Local/1000@from-internal-0dde;1", "0?docfb,1()") in new stack
-- Executing [s@macro-exten-vm:19] Set("Local/1000@from-internal-0dde;1", "DIALSTATUS=NOANSWER") in new stack
-- Executing [s@macro-exten-vm:20] ExecIf("Local/1000@from-internal-0dde;1", "0?MacroExit()") in new stack
-- Executing [s@macro-exten-vm:21] GotoIf("Local/1000@from-internal-0dde;1", "1?s-NOANSWER,1") in new stack
-- Goto (macro-exten-vm,s-NOANSWER,1)
-- Executing [s-NOANSWER@macro-exten-vm:1] GotoIf("Local/1000@from-internal-0dde;1", "0?exit,1") in new stack
-- Executing [s-NOANSWER@macro-exten-vm:2] PlayTones("Local/1000@from-internal-0dde;1", "congestion") in new stack
-- Executing [s-NOANSWER@macro-exten-vm:3] Congestion("Local/1000@from-internal-0dde;1", "10") in new stack
-- Executing [h@macro-dial-one:1] Macro("Local/1000@from-internal-0dde;2", "hangupcall,") in new stack
-- Executing [s@macro-hangupcall:1] GotoIf("Local/1000@from-internal-0dde;2", "1?theend") in new stack
-- Goto (macro-hangupcall,s,3)
-- Executing [s@macro-hangupcall:3] Hangup("Local/1000@from-internal-0dde;2", "") in new stack
== Spawn extension (macro-hangupcall, s, 3) exited non-zero on 'Local/1000@from-internal-0dde;2' in macro 'hangupcall'
== Spawn extension (macro-dial-one, h, 1) exited non-zero on 'Local/1000@from-internal-0dde;2'
== Spawn extension (macro-dial-one, s, 42) exited non-zero on 'Local/1000@from-internal-0dde;2' in macro 'dial-one'
== Spawn extension (macro-exten-vm, s, 14) exited non-zero on 'Local/1000@from-internal-0dde;2' in macro 'exten-vm'
== Spawn extension (ext-local, 1000, 2) exited non-zero on 'Local/1000@from-internal-0dde;2'
== Spawn extension (macro-exten-vm, s-NOANSWER, 3) exited non-zero on 'Local/1000@from-internal-0dde;1' in macro 'exten-vm'
== Spawn extension (from-internal, 1001, 2) exited non-zero on 'Local/1000@from-internal-0dde;1'

FreePBX's thread on it:


The desired behavior would be the PBX playing a busy signal of course.

It should be completely reproducible by creating an extension with no voicemail (it will always return busy if there is no phone registered with it), and do a click-to-call using any software.
Comments:By: Matt Jordan (mjordan) 2011-12-30 16:03:49.043-0600

What this log snippet shows is that Asterisk attempted to indicate a Congestion [1] status to a local channel with a timeout of 10 seconds.  When that was finished, it proceeded to the hangup extension (h) as the channel was being hung up.

Note that a local channel is an internal construct to Asterisk and doesn't specify what "Congestion" actually means.  In this context, a Congestion frame is passed from the local channel to whatever channel is the local channel's owner - in general, this would be whatever channel is communicating with your external application.  Since you didn't specify what technology that is (SIP, IAX2 are both supported by iSymphony) then I'm not sure what "Congestion" will mean to it either.  However, since there is a timeout associated with the Congestion application, if you don't have anything for that channel to communicate with within that time period, then obviously nothing will be relayed either.

So that's back to the dialplan.

As it is, Asterisk is doing exactly what its being told to do.  If, however, you feel that's not the case, then a debug log (with timestamps) demonstrating that Asterisk not forwarding the Congestion status, or that the applications are not behaving as documented, would be needed.

[1] https://wiki.asterisk.org/wiki/display/AST/Application_Congestion

By: William Roush (wdroush) 2011-12-30 18:25:23.054-0600

Below is a full debug log (I believe), I wouldn't say that Asterisk is _documented_ to not behave this way (it is somewhat an edge case, but in our office we use click-to-call a lot and could see this in call centers easily), but it definitely can lead to end user confusion and I'd say is improper handling of the situation.

Now if joining two callers into a channel is actually dictated more by configs than by the core of Asterisk, I'll go bug the FreePBX guys (or just find out what needs to be done and suggest it end up in their build).

Sorry for even tossing the tiny part that iSymphony was interested in, I should have known when I dumped it in here that you want a full debug log and of the _entire_ session.

-- Snipped, was CLI --

By: William Roush (wdroush) 2011-12-30 18:33:13.012-0600

-T only seems to output timestamps _sometimes_, is there something I'm missing or is this good enough?

By: Leif Madsen (leifmadsen) 2012-01-03 10:17:32.003-0600

Also note that it is best practice to place your debug output into a text file and attach it to the issue to make scrolling more manageable.

By: Matt Jordan (mjordan) 2012-01-03 10:55:23.338-0600

Nope, that's your CLI output.  This document will provide instructions on how to collect debugging logs from an Asterisk machine for the purpose of helping bug marshals troubleshoot an issue: https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information

By: William Roush (wdroush) 2012-01-03 13:03:36.758-0600

Attached full debug log.

By: William Roush (wdroush) 2012-01-03 13:04:20.711-0600

Sorry about that, first time actually getting internal debug reports. Here ya go, thanks for your time.

If I'm not mistaken, it seems to end the bridge early (not expected) immediately after I pick up, which causes the hangup macro to fire (as expected), but I'm definitely interested in what you guys find being as I'd love to learn more and appreciate the work you all put towards this project.

By: Leif Madsen (lmadsen) 2012-02-16 07:14:49.344-0600

Actually if you're using the Local channel and it is not set with the /n on the end, then the Local channel is optimized away, in which case I would actually expect that to happen.

(Note I didn't look at where you're seeing the "bridge end early" as the file was quite large with all the manager output, and I couldn't easily find where you were talking about.)

Based on what I'm seeing here, I believe Asterisk is working as expected and that this issue should be closed out, and the discussion brought to the appropriate mailing lists (asterisk-users)

By: Matt Jordan (mjordan) 2012-02-20 09:31:40.242-0600

Closing based on Leif's feedback that this behavior is expected and not a bug.

If you test without the /n option on the local channel and find that the behavior is still the same, please let a bug marshall know on #asterisk-bugs or in the asterisk-users mailing list and we can revisit this issue.