Ticket #4053 (closed Bugs: fixed)

Opened 2 years ago

Last modified 2 years ago

Blind transfers initiated from calling party aren't disconncted

Reported by: rsw686 Assigned to: p_lindheimer
Priority: major Milestone: 2.7
Component: Core Version: 2.6-branch
Keywords: Cc:
Confirmation: Confirmed SVN Revision (if applicable):
Backend Engine: All Backend Engine Version:

Description (Last modified by p_lindheimer)

Employee A calls a customer and talks for a few minutes. The customer asks to talk to someone in another depart. Employee A does a blind transfer with ## to Employee B. The result is Employee B is connected to the customer. However Employee A receives the all circuits are busy now message. Or if the Employee A called another internal number and transferred they get their voicemail. What should happen is Employee A is disconnected. I was originally using Asterisk 1.6.1.4, but have tested Asterisk 1.6.1.14 and 1.6.1.15-RC2 with the same result.

The CRUX of the issue is a bug in Asterisk that can result in calls continuing with status of NOANSWER because of the following related bugs:

https://issues.asterisk.org/view.php?id=16856
https://issues.asterisk.org/view.php?id=14555

The information below was originally submitted by the author and being left for completeness but is rather confusing as they have non-standard dialplan included. The comments at the end of the ticket clarify the issue.

I had grab an exert from a test system with no outside lines. I called 8688 from 8678 and then hit ##4078532 which initiates a blind transfer to voicemail. Below is the dialplan for the transfer to VM and the override for macro-vm for Exchange UM. 

[from-internal-custom]
; Blind transfer call to voicemail with ##407XXXX
exten => _407NXXX,1,Noop(Transfering call to voicemail box ${EXTEN:3:4})
exten => _407NXXX,n,SIPAddHeader(Diversion: <tel:${EXTEN:3:4}>\;reason=no-answer\;screen=no\;privacy=off)
exten => _407NXXX,n,Dial(SIP/exchange-vm)
exten => _407NXXX,n,Hangup

[macro-vm]
; ARG1 - extension
; ARG2 - DIRECTDIAL/BUSY
; ARG3 - RETURN makes macro return, otherwise hangup
exten => s,1,Macro(user-callerid,SKIPTTL)
;
; If BLKVM_OVERRIDE is set, then someone told us to block calls from going to
; voicemail. This variable is reset by the answering channel so subsequent
; transfers will properly function.
;
exten => s,n,GotoIf($["foo${DB(${BLKVM_OVERRIDE})}" != "fooTRUE"]?vmx,1)
;
; we didn't branch so block this from voicemail
;
exten => s,n,Noop(CAME FROM: ${NODEST} - Blocking VM cause of key: ${DB(BLKVM_OVERRIDE)})

exten => vmx,1,GotoIf($["${ARG2}" = "DIRECTDIAL"]?3)
exten => vmx,2,SIPAddHeader(Diversion: <tel:${ARG1}>\;reason=no-answer\;screen=no\;privacy=off)
exten => vmx,3,Dial(SIP/exchange-vm)
exten => vxm,4,Hangup

    -- <SIP/8678-0000000f> Playing 'pbx-transfer.ulaw' (language 'en')
    -- Stopped music on hold on SIP/8688-00000010
    -- Transferring SIP/8688-00000010 to '4078532' (context from-internal-xfer) priority 1
    -- Executing [h@macro-dial:1] Macro("SIP/8678-0000000f", "hangupcall") in new stack
    -- Executing [s@macro-hangupcall:1] ResetCDR("SIP/8678-0000000f", "w") in new stack
    -- Executing [4078532@from-internal-xfer:1] NoOp("SIP/8688-00000010", "Transfering call to voicemail box 8532") in new stack
    -- Executing [4078532@from-internal-xfer:2] SIPAddHeader("SIP/8688-00000010", "Diversion: <tel:8532>\;reason=no-answer\;screen=no\;privacy=off") in new stack
    -- Executing [4078532@from-internal-xfer:3] Dial("SIP/8688-00000010", "SIP/exchange-vm") in new stack
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- Called exchange-vm
    -- Got SIP response 302 "Moved Temporarily" back from 10.9.1.13
    -- Now forwarding SIP/8688-00000010 to 'SIP/::::TCP@10.9.1.13:5067' (thanks to SIP/exchange-vm-00000011)
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- SIP/10.9.1.13:5067-00000012 is ringing
    -- Executing [s@macro-hangupcall:2] NoCDR("SIP/8678-0000000f", "") in new stack
    -- Executing [s@macro-hangupcall:3] GotoIf("SIP/8678-0000000f", "1?skiprg") in new stack
    -- Goto (macro-hangupcall,s,6)
    -- Executing [s@macro-hangupcall:6] GotoIf("SIP/8678-0000000f", "0?skipblkvm") in new stack
    -- Executing [s@macro-hangupcall:7] NoOp("SIP/8678-0000000f", "Cleaning Up Block VM Flag: BLKVM/8688/SIP/8678-0000000f") in new stack
    -- Executing [s@macro-hangupcall:8] DBdel("SIP/8678-0000000f", "BLKVM/8688/SIP/8678-0000000f") in new stack
    -- DBdel: family=BLKVM, key=8688/SIP/8678-0000000f
    -- DBdel: Error deleting key from database.
    -- Executing [s@macro-hangupcall:9] GotoIf("SIP/8678-0000000f", "0?theend") in new stack
    -- Executing [s@macro-hangupcall:10] DBdel("SIP/8678-0000000f", "FM/DND/8688/SIP/8678-0000000f") in new stack
    -- DBdel: family=FM, key=DND/8688/SIP/8678-0000000f
    -- DBdel: Error deleting key from database.
    -- Executing [s@macro-hangupcall:11] Hangup("SIP/8678-0000000f", "") in new stack
  == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/8678-0000000f' in macro 'hangupcall'
  == Spawn extension (macro-dial, h, 1) exited non-zero on 'SIP/8678-0000000f'
    -- Executing [s@macro-dial:8] Set("SIP/8678-0000000f", "DIALSTATUS=ANSWER") in new stack
    -- Executing [s@macro-dial:9] GosubIf("SIP/8678-0000000f", "0?ANSWER,1") in new stack
    -- Executing [8688@from-internal:17] Goto("SIP/8678-0000000f", "nextstep") in new stack
    -- Goto (from-internal,8688,19)
    -- Executing [8688@from-internal:19] Set("SIP/8678-0000000f", "RingGroupMethod=") in new stack
    -- Executing [8688@from-internal:20] GotoIf("SIP/8678-0000000f", "0?nodest") in new stack
    -- Executing [8688@from-internal:21] Set("SIP/8678-0000000f", "__NODEST=") in new stack
    -- Executing [8688@from-internal:22] DBdel("SIP/8678-0000000f", "BLKVM/8688/SIP/8678-0000000f") in new stack
    -- DBdel: family=BLKVM, key=8688/SIP/8678-0000000f
    -- DBdel: Error deleting key from database.
    -- Executing [8688@from-internal:23] Goto("SIP/8678-0000000f", "ext-local,vmu8688,1") in new stack
    -- Goto (ext-local,vmu8688,1)
    -- Executing [vmu8688@ext-local:1] Macro("SIP/8678-0000000f", "vm,8688,NOANSWER,") in new stack
    -- Executing [s@macro-vm:1] Macro("SIP/8678-0000000f", "user-callerid,SKIPTTL") in new stack
    -- Executing [s@macro-user-callerid:1] Set("SIP/8678-0000000f", "AMPUSER=8678") in new stack
    -- Executing [s@macro-user-callerid:2] GotoIf("SIP/8678-0000000f", "0?report") in new stack
    -- Executing [s@macro-user-callerid:3] ExecIf("SIP/8678-0000000f", "0?Set(REALCALLERIDNUM=8678)") in new stack
    -- Executing [s@macro-user-callerid:4] Set("SIP/8678-0000000f", "AMPUSER=8678") in new stack
    -- Executing [s@macro-user-callerid:5] Set("SIP/8678-0000000f", "AMPUSERCIDNAME=Ryan Wagoner") in new stack
    -- Executing [s@macro-user-callerid:6] GotoIf("SIP/8678-0000000f", "0?report") in new stack
    -- Executing [s@macro-user-callerid:7] Set("SIP/8678-0000000f", "AMPUSERCID=8678") in new stack
    -- Executing [s@macro-user-callerid:8] Set("SIP/8678-0000000f", "CALLERID(all)="Ryan Wagoner" <8678>") in new stack
    -- Executing [s@macro-user-callerid:9] Set("SIP/8678-0000000f", "REALCALLERIDNUM=8678") in new stack
    -- Executing [s@macro-user-callerid:10] ExecIf("SIP/8678-0000000f", "0?Set(CHANNEL(language)=)") in new stack
    -- Executing [s@macro-user-callerid:11] GotoIf("SIP/8678-0000000f", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,20)
    -- Executing [s@macro-user-callerid:20] NoOp("SIP/8678-0000000f", "Using CallerID "Ryan Wagoner" <8678>") in new stack
    -- Executing [s@macro-vm:2] GotoIf("SIP/8678-0000000f", "1?vmx,1") in new stack
    -- Goto (macro-vm,vmx,1)
    -- Executing [vmx@macro-vm:1] GotoIf("SIP/8678-0000000f", "0?3") in new stack
    -- Executing [vmx@macro-vm:2] SIPAddHeader("SIP/8678-0000000f", "Diversion: <tel:8688>\;reason=no-answer\;screen=no\;privacy=off") in new stack
    -- Executing [vmx@macro-vm:3] Dial("SIP/8678-0000000f", "SIP/exchange-vm") in new stack
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- Called exchange-vm
    -- SIP/10.9.1.13:5067-00000012 answered SIP/8688-00000010
    -- Got SIP response 302 "Moved Temporarily" back from 10.9.1.13
    -- Now forwarding SIP/8678-0000000f to 'SIP/::::TCP@10.9.1.13:5067' (thanks to SIP/exchange-vm-00000013)
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- SIP/10.9.1.13:5067-00000014 is ringing
    -- SIP/10.9.1.13:5067-00000014 answered SIP/8678-0000000f
    -- Started music on hold, class 'default', on SIP/10.9.1.13:5067-00000014
    -- Executing [h@from-internal-xfer:1] Macro("SIP/8688-00000010", "hangupcall") in new stack
    -- Executing [s@macro-hangupcall:1] ResetCDR("SIP/8688-00000010", "w") in new stack
    -- Executing [s@macro-hangupcall:2] NoCDR("SIP/8688-00000010", "") in new stack
    -- Executing [s@macro-hangupcall:3] GotoIf("SIP/8688-00000010", "1?skiprg") in new stack
    -- Goto (macro-hangupcall,s,6)
    -- Executing [s@macro-hangupcall:6] GotoIf("SIP/8688-00000010", "1?skipblkvm") in new stack
    -- Goto (macro-hangupcall,s,9)
    -- Executing [s@macro-hangupcall:9] GotoIf("SIP/8688-00000010", "1?theend") in new stack
    -- Goto (macro-hangupcall,s,11)
    -- Executing [s@macro-hangupcall:11] Hangup("SIP/8688-00000010", "") in new stack
  == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/8688-00000010' in macro 'hangupcall'
  == Spawn extension (from-internal-xfer, 4078532, 3) exited non-zero on 'SIP/8688-00000010'
    -- Stopped music on hold on SIP/10.9.1.13:5067-00000014
  == Spawn extension (macro-vm, vmx, 3) exited non-zero on 'SIP/8678-0000000f' in macro 'vm'
  == Spawn extension (ext-local, vmu8688, 1) exited non-zero on 'SIP/8678-0000000f'

The key part is when it starts dialing after initiating a hangup. Not sure why this is happening. 

    -- Executing [s@macro-hangupcall:11] Hangup("SIP/8678-0000000f", "") in new stack
  == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/8678-0000000f' in macro 'hangupcall'
  == Spawn extension (macro-dial, h, 1) exited non-zero on 'SIP/8678-0000000f'
    -- Executing [s@macro-dial:8] Set("SIP/8678-0000000f", "DIALSTATUS=ANSWER") in new stack

Change History

02/17/10 18:13:50 changed by p_lindheimer

  • status changed from new to closed.
  • resolution set to invalid.
  • component changed from - choose - to Core.
  • milestone changed from 2.8 to 2.7.

Not sure what you are doing with your customer dialplan you have added but if you want to get any traction determining if there is a bug for something like this, adding custom dialplan is not the way to do it. You can go into the forums and try to get assistance if you need to do something custom.

As far as ## transfer functionality, I just tested your scenario on Asterisk 1.4, calling to an outside line, then hitting ## ans transferring to another extension. Worked fine. I also did several other permutations.

The ## transfer is used widely and if it were not working, there would probably be a lot more noise going on to that effect.

I'm not sure if this should be closed as worksforme (which it does) or invalid, but given the custom dialplan that was listed above, I'll close it invalid. I'll also note that I have not dug through your code to see what you are doing, unfortunately I don't have the time to figure out what you are trying to achieve but as mentioned, it is best to discuss in the forum and leave the bugs to stock dialplan and code.

02/18/10 12:27:02 changed by rsw686

This happens on a production box with no custom dialplan code. I am using Asterisk 1.6.1.4 which might be the problem as you tested with Asterisk 1.4. I can't get a clean section of log off that box due to the high volume of calls. I'll rebuild my test box with a clean install of Asterisk 1.6.1 and test again. I didn't think the small section of custom code would be a problem since it doesn't do anything besides dialing Exchange UM vs the internal voicemail. It could be something wrong with Asterisk 1.6.1.

02/18/10 12:48:19 changed by p_lindheimer

As mentioned, I don't have time to dig through seeing what is going on when I see things like: 

    -- Executing [4078532@from-internal-xfer:2] SIPAddHeader("SIP/8688-00000010", "Diversion: <tel:8532>\;reason=no-answer\;screen=no\;privacy=off") in new stack

in the log which I guarantee is not from FreePBX code. If it happens on a 'clean' system then it probably is something in Asterisk anyhow because the only other way I could see such a scenario occurring from dialplan is if there was some 'h' (hangup) dialplan that caught the terminated call upon transferring and resulted in some new activity.

02/23/10 22:33:58 changed by rsw686

I tested on a clean install and posted on the forum. Output from the Asterisk console for making an external call and blind transferring to the the parking lot is shown.

http://www.freepbx.org/forum/freepbx/users/caller-initiated-blind-transfer-dont-disconnect

I found the issue. In macro-dialout-trunk it is returning a dial status of ANSWER. This isn't handled so it thinks the call failed and tries again. I copied the macro to extensions_override_freepbx.conf, added the below, and everything is working.

exten => s-ANSWER,1,Noop(Dial completed with trunk reporting ANSWER - hanging up) exten => s-ANSWER,n,Macro(hangupcall,)

I'm not sure if the behavior changed in Asterisk 1.6.1 for Dial from Asterisk 1.4 which you tested.

02/24/10 07:32:24 changed by rsw686

I opened a bug report on Asterisk as well.

https://issues.asterisk.org/view.php?id=16856

Then received a response that it existed in Asterisk 1.4.26 and up.

https://issues.asterisk.org/view.php?id=14555

Could you please add the two line fix to macro-dialout-trunk so this can be resolved for everyone?

02/24/10 10:03:32 changed by p_lindheimer

  • status changed from closed to reopened.
  • resolution deleted.

These issues look like and Asterisk bug. I'll reopen this ticket and review the fix you propose as an Asterisk work-around. We need to make sure the proposed work-around does not impact other operations. If it does not then we can consider applying it given the Asterisk issue appears to exist in a broad range of Asterisk versions and is not resolved as of today.

02/25/10 11:23:45 changed by p_lindheimer

  • confirmation changed from Unreviewed to Confirmed.
  • description changed.

02/25/10 11:45:37 changed by p_lindheimer

  • status changed from reopened to closed.
  • resolution set to fixed.

(In [8930]) closes #4053 and updated macro-dialout-enum to be consistent with new format of macro-dialout-trunk

03/18/10 15:41:44 changed by rsw686

I just noticed that macro-dial has the same issue. Would it be possible to implement this workaround here as well?

[Mar 18 16:35:05] VERBOSE[9856] pbx.c: -- Executing [s@macro-dial:8] Set("SIP/1500-000014b6", "DIALSTATUS=ANSWER") in new stack

03/18/10 19:15:56 changed by p_lindheimer

rsw686,

please open a new bug for that, reference this ticket in it, and put a summary of the change we did or even better, a link to the changesets. You can reference a ticket here by putting #4053 and a changeset by typing it with a leading r, such as r8930 they will be turned into links automatically.

Thanks.