BlindTransfer Event not Fired

FreePBX Development
#1

I have a system that does not fire the BlindTransfer event. The transfer works perfectly, but from the CLI output below the transfer is happening in from-internal context and not “TRANSFER_CONTEXT = from-internal-xfer” as it says in extensions_additional.conf. Attended Transfer event fires and is in context from-internal-xfer.

[2018-10-05 01:57:48] VERBOSE[11727][C-00000005] app_while.c: Jumping to priority 7
[2018-10-05 01:57:48] VERBOSE[11727][C-00000005] pbx.c: Executing [[email protected]:8] ExecIf("SIP/1184-00000010", "0?SIPRemoveHeader(Alert-Info:)") in new stack
[2018-10-05 01:57:48] VERBOSE[11727][C-00000005] pbx.c: Executing [[email protected]:9] Return("SIP/1184-00000010", "") in new stack
[2018-10-05 01:57:48] VERBOSE[11727][C-00000005] app_stack.c: Spawn extension (from-internal, 1184, 1) exited non-zero on 'SIP/1184-00000010'
[2018-10-05 01:57:48] VERBOSE[11727][C-00000005] app_stack.c: SIP/1184-00000010 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2018-10-05 01:57:48] VERBOSE[11727][C-00000005] app_dial.c: Called SIP/1184
[2018-10-05 01:57:48] VERBOSE[11712][C-00000005] app_queue.c: Local/[email protected];1 is ringing
[2018-10-05 01:57:48] VERBOSE[11727][C-00000005] app_dial.c: SIP/1184-00000010 answered Local/[email protected];2
[2018-10-05 01:57:48] VERBOSE[11727][C-00000005] pbx.c: Executing [[email protected]:1] ExecIf("SIP/1184-00000010", "0?Set(CDR(recordingfile)=.wav)") in new stack
[2018-10-05 01:57:48] VERBOSE[11727][C-00000005] pbx.c: Executing [[email protected]:2] Set("SIP/1184-00000010", "__MACRO_RESULT=") in new stack
[2018-10-05 01:57:48] VERBOSE[11727][C-00000005] pbx.c: Executing [[email protected]:3] Set("SIP/1184-00000010", "CFIGNORE=") in new stack
[2018-10-05 01:57:49] VERBOSE[11727][C-00000005] pbx.c: Executing [[email protected]:4] Set("SIP/1184-00000010", "MASTER_CHANNEL(CFIGNORE)=") in new stack
[2018-10-05 01:57:49] VERBOSE[11727][C-00000005] pbx.c: Executing [[email protected]:5] Set("SIP/1184-00000010", "FORWARD_CONTEXT=from-internal") in new stack
[2018-10-05 01:57:49] VERBOSE[11727][C-00000005] pbx.c: Executing [[email protected]:6] Set("SIP/1184-00000010", "MASTER_CHANNEL(FORWARD_CONTEXT)=from-internal") in new stack
[2018-10-05 01:57:49] VERBOSE[11727][C-00000005] pbx.c: Executing [[email protected]:7] Macro("SIP/1184-00000010", "blkvm-clr,") in new stack
[2018-10-05 01:57:49] VERBOSE[11727][C-00000005] pbx.c: Executing [[email protected]:1] Set("SIP/1184-00000010", "SHARED(BLKVM,SIP/switch-in-0000000f)=") in new stack
[2018-10-05 01:57:49] VERBOSE[11727][C-00000005] pbx.c: Executing [[email protected]:2] Set("SIP/1184-00000010", "GOSUB_RETVAL=") in new stack
[2018-10-05 01:57:49] VERBOSE[11727][C-00000005] pbx.c: Executing [[email protected]:3] MacroExit("SIP/1184-00000010", "") in new stack
[2018-10-05 01:57:49] VERBOSE[11727][C-00000005] pbx.c: Executing [[email protected]:8] NoOp("SIP/1184-00000010", "[TRACE](3) DIALEDPEERNUMBER: 1184 CID: "Devin Murphy" <1184>") in new stack
[2018-10-05 01:57:49] VERBOSE[11727][C-00000005] pbx.c: Executing [[email protected]:9] ExecIf("SIP/1184-00000010", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(num))=1184)") in new stack
[2018-10-05 01:57:49] VERBOSE[11727][C-00000005] pbx.c: Executing [[email protected]:10] ExecIf("SIP/1184-00000010", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(name))=Devin Murphy)") in new stack
[2018-10-05 01:57:49] VERBOSE[11712][C-00000005] app_queue.c: Local/[email protected];1 answered SIP/switch-in-0000000f
[2018-10-05 01:57:49] VERBOSE[11712][C-00000005] res_musiconhold.c: Stopped music on hold on SIP/switch-in-0000000f
[2018-10-05 01:57:49] VERBOSE[11730][C-00000005] bridge_channel.c: Channel SIP/1184-00000010 joined 'simple_bridge' basic-bridge <e714d32e-8a09-4e28-b6f5-efa29d0de1b1>
[2018-10-05 01:57:49] VERBOSE[11727][C-00000005] bridge_channel.c: Channel Local/[email protected]0000000c;2 joined 'simple_bridge' basic-bridge <e714d32e-8a09-4e28-b6f5-efa29d0de1b1>
[2018-10-05 01:57:49] VERBOSE[11733][C-00000005] bridge_channel.c: Channel Local/[email protected];1 joined 'simple_bridge' basic-bridge <84e45c41-380d-45d8-b140-97ef1d879913>
[2018-10-05 01:57:49] VERBOSE[11712][C-00000005] bridge_channel.c: Channel SIP/switch-in-0000000f joined 'simple_bridge' basic-bridge <84e45c41-380d-45d8-b140-97ef1d879913>
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] bridge_channel.c: Channel SIP/switch-in-0000000f left 'simple_bridge' basic-bridge <84e45c41-380d-45d8-b140-97ef1d879913>
[2018-10-05 01:58:00] VERBOSE[11733][C-00000005] bridge_channel.c: Channel Local/[email protected];1 left 'simple_bridge' basic-bridge <84e45c41-380d-45d8-b140-97ef1d879913>
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:1] Goto("SIP/switch-in-0000000f", "from-internal,,1") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx_builtins.c: Goto (from-internal,331333,1)
[2018-10-05 01:58:00] VERBOSE[11727][C-00000005] bridge_channel.c: Channel Local/[email protected];2 left 'simple_bridge' basic-bridge <e714d32e-8a09-4e28-b6f5-efa29d0de1b1>
[2018-10-05 01:58:00] VERBOSE[11730][C-00000005] bridge_channel.c: Channel SIP/1184-00000010 left 'simple_bridge' basic-bridge <e714d32e-8a09-4e28-b6f5-efa29d0de1b1>
[2018-10-05 01:58:00] VERBOSE[11727][C-00000005] app_macro.c: Spawn extension (macro-dial-one, s, 54) exited non-zero on 'Local/[email protected];2' in macro 'dial-one'
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:1] Macro("SIP/switch-in-0000000f", "user-callerid,") in new stack
[2018-10-05 01:58:00] VERBOSE[11727][C-00000005] app_macro.c: Spawn extension (macro-exten-vm, s, 27) exited non-zero on 'Local/[email protected];2' in macro 'exten-vm'
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:1] Set("SIP/switch-in-0000000f", "TOUCH_MONITOR=1538719059.39") in new stack
[2018-10-05 01:58:00] VERBOSE[11727][C-00000005] pbx.c: Spawn extension (ext-local, 1184, 2) exited non-zero on 'Local/[email protected];2'
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:2] Set("SIP/switch-in-0000000f", "AMPUSER=7277248006") in new stack
[2018-10-05 01:58:00] VERBOSE[11727][C-00000005] pbx.c: Executing [[email protected]:1] Macro("Local/[email protected];2", "hangupcall,") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:3] GotoIf("SIP/switch-in-0000000f", "0?report") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:4] ExecIf("SIP/switch-in-0000000f", "0?Set(REALCALLERIDNUM=7277248006)") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:5] Set("SIP/switch-in-0000000f", "AMPUSER=") in new stack
[2018-10-05 01:58:00] VERBOSE[11727][C-00000005] pbx.c: Executing [[email protected]:1] GotoIf("Local/[email protected];2", "1?theend") in new stack
[2018-10-05 01:58:00] VERBOSE[11727][C-00000005] pbx_builtins.c: Goto (macro-hangupcall,s,4)
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:6] GotoIf("SIP/switch-in-0000000f", "0?limit") in new stack
[2018-10-05 01:58:00] VERBOSE[11727][C-00000005] pbx.c: Executing [[email protected]:4] ExecIf("Local/[email protected];2", "0?Set(CDR(recordingfile)=)") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:7] Set("SIP/switch-in-0000000f", "AMPUSERCIDNAME=") in new stack
[2018-10-05 01:58:00] VERBOSE[11727][C-00000005] pbx.c: Executing [[email protected]:5] Hangup("Local/[email protected];2", "") in new stack
[2018-10-05 01:58:00] VERBOSE[11727][C-00000005] app_macro.c: Spawn extension (macro-hangupcall, s, 5) exited non-zero on 'Local/[email protected];2' in macro 'hangupcall'
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:8] ExecIf("SIP/switch-in-0000000f", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
[2018-10-05 01:58:00] VERBOSE[11727][C-00000005] pbx.c: Spawn extension (ext-local, h, 1) exited non-zero on 'Local/[email protected];2'
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:9] GotoIf("SIP/switch-in-0000000f", "1?report") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx_builtins.c: Goto (macro-user-callerid,s,17)
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:17] NoOp("SIP/switch-in-0000000f", "Macro Depth is 1") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:18] GotoIf("SIP/switch-in-0000000f", "1?report2:macroerror") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx_builtins.c: Goto (macro-user-callerid,s,19)
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:19] GotoIf("SIP/switch-in-0000000f", "0?continue") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:20] ExecIf("SIP/switch-in-0000000f", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:21] Set("SIP/switch-in-0000000f", "__TTL=63") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:22] GotoIf("SIP/switch-in-0000000f", "1?continue") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx_builtins.c: Goto (macro-user-callerid,s,38)
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:38] Set("SIP/switch-in-0000000f", "CALLERID(number)=7277248006") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:39] Set("SIP/switch-in-0000000f", "CALLERID(name)=TST7277248006") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:40] GotoIf("SIP/switch-in-0000000f", "0?cnum") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:41] Set("SIP/switch-in-0000000f", "CDR(cnam)=TST7277248006") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:42] Set("SIP/switch-in-0000000f", "CDR(cnum)=7277248006") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:43] Set("SIP/switch-in-0000000f", "CHANNEL(language)=en") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:44] NoOp("SIP/switch-in-0000000f", "[TRACE](3) Using CallerID "TST7277248006" <7277248006>") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:2] Answer("SIP/switch-in-0000000f", "") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:3] Macro("SIP/switch-in-0000000f", "blkvm-set,reset") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:1] ExecIf("SIP/switch-in-0000000f", "0?Set(__BLKVM_CHANNEL=SIP/switch-in-0000000f)") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:2] Set("SIP/switch-in-0000000f", "SHARED(BLKVM,SIP/switch-in-0000000f)=TRUE") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:3] Set("SIP/switch-in-0000000f", "GOSUB_RETVAL=TRUE") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:4] MacroExit("SIP/switch-in-0000000f", "") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:4] ExecIf("SIP/switch-in-0000000f", "0?Set(_DIAL_OPTIONS=TtrM(auto-blkvm)M(auto-blkvm))") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:5] Set("SIP/switch-in-0000000f", "__NODEST=331333") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:6] Set("SIP/switch-in-0000000f", "QCIDPP=TST") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:7] Set("SIP/switch-in-0000000f", "VQ_CIDPP=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:8] ExecIf("SIP/switch-in-0000000f", "1?Macro(prepend-cid,TST)") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:1] GotoIf("SIP/switch-in-0000000f", "0?REPCID") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:2] GotoIf("SIP/switch-in-0000000f", "0?REPCID") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:3] NoOp("SIP/switch-in-0000000f", "[TRACE](3) Current RGPREFIX is TST....stripping from CallerID") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:4] Set("SIP/switch-in-0000000f", "CALLERID(name)=7277248006") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:5] Set("SIP/switch-in-0000000f", "_RGPREFIX=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:6] Set("SIP/switch-in-0000000f", "_RGPREFIX=TST") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:7] Set("SIP/switch-in-0000000f", "CALLERID(name)=TST7277248006") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:9] Set("SIP/switch-in-0000000f", "QAINFO=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:10] Set("SIP/switch-in-0000000f", "VQ_AINFO=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:11] ExecIf("SIP/switch-in-0000000f", "0?Set(__ALERT_INFO=)") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:12] Set("SIP/switch-in-0000000f", "QJOINMSG=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:13] Set("SIP/switch-in-0000000f", "VQ_JOINMSG=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:14] Set("SIP/switch-in-0000000f", "QRETRY=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:15] Set("SIP/switch-in-0000000f", "VQ_RETRY=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:16] Set("SIP/switch-in-0000000f", "QOPTIONS=t") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:17] Set("SIP/switch-in-0000000f", "VQ_OPTIONS=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:18] Set("SIP/switch-in-0000000f", "QGOSUB=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:19] Set("SIP/switch-in-0000000f", "VQ_GOSUB=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:20] Set("SIP/switch-in-0000000f", "QAGI=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:21] Set("SIP/switch-in-0000000f", "VQ_AGI=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:22] Set("SIP/switch-in-0000000f", "QRULE=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:23] Set("SIP/switch-in-0000000f", "VQ_RULE=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:24] Set("SIP/switch-in-0000000f", "QPOSITION=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:25] Set("SIP/switch-in-0000000f", "VQ_POSITION=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:26] Gosub("SIP/switch-in-0000000f", "sub-record-check,s,1(q,331333,force)") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:1] GotoIf("SIP/switch-in-0000000f", "10?initialized") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx_builtins.c: Goto (sub-record-check,s,10)
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:10] NoOp("SIP/switch-in-0000000f", "Recordings initialized") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:11] ExecIf("SIP/switch-in-0000000f", "0?Set(ARG3=dontcare)") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:12] Set("SIP/switch-in-0000000f", "REC_POLICY_MODE_SAVE=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:13] ExecIf("SIP/switch-in-0000000f", "0?Set(REC_STATUS=NO)") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:14] GotoIf("SIP/switch-in-0000000f", "1?checkaction") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx_builtins.c: Goto (sub-record-check,s,17)
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:17] GotoIf("SIP/switch-in-0000000f", "0?sub-record-check,q,1") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:18] NoOp("SIP/switch-in-0000000f", "Generic q Recording Check - 7277248006 331333") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:19] Gosub("SIP/switch-in-0000000f", "recordcheck,1(force,q,331333)") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:1] NoOp("SIP/switch-in-0000000f", "Starting recording check against force") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:2] Goto("SIP/switch-in-0000000f", "force") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx_builtins.c: Goto (sub-record-check,recordcheck,5)
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:5] Set("SIP/switch-in-0000000f", "__REC_POLICY_MODE=FORCE") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:6] GotoIf("SIP/switch-in-0000000f", "1?startrec") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx_builtins.c: Goto (sub-record-check,recordcheck,16)
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:16] NoOp("SIP/switch-in-0000000f", "Starting recording: q, 331333") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:17] Set("SIP/switch-in-0000000f", "AUDIOHOOK_INHERIT(MixMonitor)=yes") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:18] Set("SIP/switch-in-0000000f", "__CALLFILENAME=q-331333-7277248006-20181005-015739-1538719059.39") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:19] MixMonitor("SIP/switch-in-0000000f", "2018/10/05/q-331333-7277248006-20181005-015739-1538719059.39.wav,abi(LOCAL_MIXMON_ID),/usr/local/parselog/update_mix_mixmonitor.pl ^{UNIQUEID} ^{MIXMONITOR_FILENAME}") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:20] Set("SIP/switch-in-0000000f", "__MIXMON_ID=0x7f01f40ddf20") in new stack
[2018-10-05 01:58:00] VERBOSE[11744][C-00000005] app_mixmonitor.c: Begin MixMonitor Recording SIP/switch-in-0000000f
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:21] Set("SIP/switch-in-0000000f", "__RECORD_ID=SIP/switch-in-0000000f") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:22] Set("SIP/switch-in-0000000f", "__REC_STATUS=RECORDING") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:23] Set("SIP/switch-in-0000000f", "CDR(recordingfile)=q-331333-7277248006-20181005-015739-1538719059.39.wav") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:24] Return("SIP/switch-in-0000000f", "") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:20] Return("SIP/switch-in-0000000f", "") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:27] Set("SIP/switch-in-0000000f", "__CWIGNORE=TRUE") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:28] ExecIf("SIP/switch-in-0000000f", "0?Playback(, )") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:29] QueueLog("SIP/switch-in-0000000f", "331333,1538719059.39,NONE,DID,5134499884") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:30] Set("SIP/switch-in-0000000f", "QAANNOUNCE=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:31] Set("SIP/switch-in-0000000f", "VQ_AANNOUNCE=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:32] Set("SIP/switch-in-0000000f", "QMOH=nexthold-generic") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:33] Set("SIP/switch-in-0000000f", "VQ_MOH=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:34] ExecIf("SIP/switch-in-0000000f", "1?Set(__MOHCLASS=nexthold-generic)") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:35] ExecIf("SIP/switch-in-0000000f", "1?Set(CHANNEL(musicclass)=nexthold-generic)") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:36] Set("SIP/switch-in-0000000f", "QMAXWAIT=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:37] Set("SIP/switch-in-0000000f", "VQ_MAXWAIT=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:38] Set("SIP/switch-in-0000000f", "QUEUENUM=331333") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:39] Set("SIP/switch-in-0000000f", "QUEUEJOINTIME=1538719080") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [[email protected]:40] Queue("SIP/switch-in-0000000f", "331333,t,,,,,,,,") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] res_musiconhold.c: Started music on hold, class 'nexthold-generic', on channel 'SIP/switch-in-0000000f'
[2018-10-05 01:58:00] VERBOSE[11746][C-00000005] pbx.c: Executing [[email protected]:1] Set("Local/[email protected];2", "QAGENT=1162") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] app_queue.c: Called Local/[email protected]/n
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] app_queue.c:     -- LazyMembers debugging - Numbusies: 0, Nummems: 1
[2018-10-05 01:58:00] VERBOSE[11746][C-00000005] pbx.c: Executing [[email protected]:2] Set("Local/[email protected];2", "__FROMQ=true") in new stack
[2018-10-05 01:58:00] VERBOSE[11746][C-00000005] pbx.c: Executing [[email protected]:3] GotoIf("Local/[email protected];2", "0?hangup") in new stack
[2018-10-05 01:58:00] VERBOSE[11746][C-00000005] pbx.c: Executing [[email protected]:4] GotoIf("Local/[email protected];2", "1?331333,1:hangup") in new stack
[2018-10-05 01:58:00] VERBOSE[11746][C-00000005] pbx_builtins.c: Goto (from-queue,331333,1)
[2018-10-05 01:58:00] VERBOSE[11746][C-00000005] pbx.c: Executing [[email protected]:1] Goto("Local/[email protected];2", "from-internal,1162,1") in new stack
[2018-10-05 01:58:00] VERBOSE[11746][C-00000005] pbx_builtins.c: Goto (from-internal,1162,1)

Also, the uniqueid channel variable for the call is the same for the blind transferring agent and receiving agent for the call. BlindTransfer and AttendedTansfer both show up in CLI> manager show events, but the BlindTransfer event never fires. Does not matter if sent from phone with ## or AMI with Redirect.

Also, I get 2 CDR records with same uniqueid, and both have context “from-internal-xfer” but that context is NOT found anywhere in verbose CLI output above.

2018-10-05 03:17:37	"TST7277248006" <7277248006>	7277248006	331333	from-internal-xfer	SIP/switch-in-00000015	Local/[email protected];1	Queue	331332,t,,,,,,,,	26	26	ANSWERED	3		1538723857.53		5134499884		7277248006	7277248006			
2018-10-05 03:18:03	"TST7277248006" <7277248006>	7277248006	331333	from-internal-xfer	SIP/switch-in-00000015	Local/[email protected];1	Queue	331333,t,,,,,,,,	6	6	ANSWERED	3		1538723857.53		5134499884	q-331333-7277248006-20181005-031737-1538723857.53.wav	7277248006	TST7277248006

Can anyone help me get a BlindTransfer Event?

#2

BTW: There is no [from-queue-custom] context and nothing in globals_custom.conf.

#3

OK, first don’t use the logs. They don’t have all the verbosity for this kind of debugging the call. Second, you need to understand the contexts and how Asterisk contexts work.

[from-internal]
include => from-internal-noxfer
include => from-internal-xfer
include => bad-number ; auto-generated
exten => h,1,Macro(hangupcall)

[from-internal-noxfer]
include => from-internal-noxfer-custom
include => from-internal-noxfer-additional ; auto-generated
exten => h,1,Macro(hangupcall)

[from-internal-xfer]
include => from-internal-custom
include => from-internal-additional ; auto-generated
exten => h,1,Macro(hangupcall)

Then the actual [from-internal-additional] has about 3 dozen include statements in it that list all the contexts a call would go through looking for matches. The log out will show you what context the call is in during the call. Using “from-internal” means all the available contexts will be checked for that call to match.

Do this again, make a blind transfer between two extensions but this time do: asterisk -rvvvvvvvvvvv

That will raise the verbosity during the call LIVE so you can see more details.

#4

Thanks, Tom.

I had channels confused when generating the ## redirect via AMI.

I have confirmed that when I use

$astman->Redirect($CallData[‘chan’],’’,$ext,‘from-queue’,‘1’);

the transfer works fine but I do not get the event.

If I use

$astman->PlayDTMF($CallData[‘AgentChan’],$digit); and send ##$ext

it works and I get the event.

At least I did on a few tests. Working more on it today.

Now, I am suspicious that this may possibly have some relationship to changes I made to php-asmanager.php. But playing DTMFs down the agent channel seems to be the only way I can reliably control transfers via AMI.

Here’s what I inserted at line 1330:

// BEGIN Added by Jerry Riggin 2018-07-19 ============================
function Atxfer($channel, $exten, $context, $priority) {
return $this-&gt;send_request('Atxfer', array('Channel'=&gt;$channel, 'Exten'=&gt;$exten,
'Context'=&gt;$context, 'Priority'=&gt;$priority));
}
function CancelAtxfer($channel) {
return $this-&gt;send_request('CancelAtxfer', array('Channel'=&gt;$channel));
}
function PlayDTMF($channel, $digit) {
return $this-&gt;send_request('PlayDTMF', array('Channel'=&gt;$channel, 'Digit'=&gt;$digit));
}
function QueuePause($interface,$paused,$reason) {
return $this-&gt;send_request('QueuePause', array('Channel'=&gt;$channel, 'Interface'=&gt;$interface, 'Paused'=&gt;$paused, 'Reason'=&gt;$reason));
}
/* 
function ExtensionState($exten,$context) {
return $this-&gt;send_request('ExtensionState', array('Exten'=&gt;$exten, 'Context'=&gt;$Context));
}
*/
// END Added by Jerry Riggin 2018-07-19 ============================

Of the added functions, only PlayDTMF and QueuePause work correctly. Atxfer does a successful transfer but it cannot cancelled with CancelAtxfer or PlayDTMF *5. So I make the attended transfer by sending DTMFs down agent channel, and then CancelAtxfer then up everybody. So I cancel the transfer with PlayDTMF *5 and it works correctly.

So, I have a workaround to control transfers successfully via AMI, but it is not exactly eleagant.

#5

Why don’t you ask for these functions to be added to the underlying library?

#6

Thanks, Andrew. I will make a feature request for the transfer functions. It is apparently more complex than I anticipated. At least PlayDTMF is working to control transers and QueuePause works as expected.

#7

@jerryriggin I think I see the problem here. While Redirect does “transfer” a call, it is not a really a transfer and therefore also not a BlindTransfer. Redirect causes the Rename and Newexten events to be triggered. You were looking for the wrong event.

1 Like
#8

Yes, excellent point. I also discovered that if I use Action: BlindTransfer instead of Action: Redirect I get BlindTransfer event. Who would have thought? I should really stop writing code after 1:00 AM.

2 Likes