FreePBX | Register | Issues | Wiki | Portal | Support

BlindTransfer Event not Fired

asterisk
Tags: #<Tag:0x00007f749de956d8>

(Jerry Riggin) #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 [s@func-apply-sipheaders: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 [s@func-apply-sipheaders: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/1184@from-queue-0000000c;1 is ringing
[2018-10-05 01:57:48] VERBOSE[11727][C-00000005] app_dial.c: SIP/1184-00000010 answered Local/1184@from-queue-0000000c;2
[2018-10-05 01:57:48] VERBOSE[11727][C-00000005] pbx.c: Executing [s@macro-auto-blkvm: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 [s@macro-auto-blkvm:2] Set("SIP/1184-00000010", "__MACRO_RESULT=") in new stack
[2018-10-05 01:57:48] VERBOSE[11727][C-00000005] pbx.c: Executing [s@macro-auto-blkvm:3] Set("SIP/1184-00000010", "CFIGNORE=") in new stack
[2018-10-05 01:57:49] VERBOSE[11727][C-00000005] pbx.c: Executing [s@macro-auto-blkvm:4] Set("SIP/1184-00000010", "MASTER_CHANNEL(CFIGNORE)=") in new stack
[2018-10-05 01:57:49] VERBOSE[11727][C-00000005] pbx.c: Executing [s@macro-auto-blkvm: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 [s@macro-auto-blkvm: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 [s@macro-auto-blkvm:7] Macro("SIP/1184-00000010", "blkvm-clr,") in new stack
[2018-10-05 01:57:49] VERBOSE[11727][C-00000005] pbx.c: Executing [s@macro-blkvm-clr: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 [s@macro-blkvm-clr:2] Set("SIP/1184-00000010", "GOSUB_RETVAL=") in new stack
[2018-10-05 01:57:49] VERBOSE[11727][C-00000005] pbx.c: Executing [s@macro-blkvm-clr:3] MacroExit("SIP/1184-00000010", "") in new stack
[2018-10-05 01:57:49] VERBOSE[11727][C-00000005] pbx.c: Executing [s@macro-auto-blkvm: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 [s@macro-auto-blkvm: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 [s@macro-auto-blkvm: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/1184@from-queue-0000000c;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/1184@from-queue-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/1184@from-queue-0000000c;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/1184@from-queue-0000000c;1 left 'simple_bridge' basic-bridge <84e45c41-380d-45d8-b140-97ef1d879913>
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-queue: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/1184@from-queue-0000000c;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/1184@from-queue-0000000c;2' in macro 'dial-one'
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal: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/1184@from-queue-0000000c;2' in macro 'exten-vm'
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [s@macro-user-callerid: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/1184@from-queue-0000000c;2'
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [s@macro-user-callerid:2] Set("SIP/switch-in-0000000f", "AMPUSER=7277248006") in new stack
[2018-10-05 01:58:00] VERBOSE[11727][C-00000005] pbx.c: Executing [h@ext-local:1] Macro("Local/1184@from-queue-0000000c;2", "hangupcall,") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("SIP/switch-in-0000000f", "0?report") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid:5] Set("SIP/switch-in-0000000f", "AMPUSER=") in new stack
[2018-10-05 01:58:00] VERBOSE[11727][C-00000005] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("Local/1184@from-queue-0000000c;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 [s@macro-user-callerid:6] GotoIf("SIP/switch-in-0000000f", "0?limit") in new stack
[2018-10-05 01:58:00] VERBOSE[11727][C-00000005] pbx.c: Executing [s@macro-hangupcall:4] ExecIf("Local/1184@from-queue-0000000c;2", "0?Set(CDR(recordingfile)=)") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [s@macro-user-callerid:7] Set("SIP/switch-in-0000000f", "AMPUSERCIDNAME=") in new stack
[2018-10-05 01:58:00] VERBOSE[11727][C-00000005] pbx.c: Executing [s@macro-hangupcall:5] Hangup("Local/1184@from-queue-0000000c;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/1184@from-queue-0000000c;2' in macro 'hangupcall'
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [s@macro-user-callerid: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/1184@from-queue-0000000c;2'
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid:19] GotoIf("SIP/switch-in-0000000f", "0?continue") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid:21] Set("SIP/switch-in-0000000f", "__TTL=63") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid:40] GotoIf("SIP/switch-in-0000000f", "0?cnum") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [331333@from-internal:2] Answer("SIP/switch-in-0000000f", "") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal: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 [s@macro-blkvm-set: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 [s@macro-blkvm-set: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 [s@macro-blkvm-set: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 [s@macro-blkvm-set:4] MacroExit("SIP/switch-in-0000000f", "") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal: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 [331333@from-internal:5] Set("SIP/switch-in-0000000f", "__NODEST=331333") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:6] Set("SIP/switch-in-0000000f", "QCIDPP=TST") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:7] Set("SIP/switch-in-0000000f", "VQ_CIDPP=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal: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 [s@macro-prepend-cid:1] GotoIf("SIP/switch-in-0000000f", "0?REPCID") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [s@macro-prepend-cid:2] GotoIf("SIP/switch-in-0000000f", "0?REPCID") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [s@macro-prepend-cid: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 [s@macro-prepend-cid: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 [s@macro-prepend-cid:5] Set("SIP/switch-in-0000000f", "_RGPREFIX=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [s@macro-prepend-cid:6] Set("SIP/switch-in-0000000f", "_RGPREFIX=TST") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [s@macro-prepend-cid: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 [331333@from-internal:9] Set("SIP/switch-in-0000000f", "QAINFO=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:10] Set("SIP/switch-in-0000000f", "VQ_AINFO=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal: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 [331333@from-internal:12] Set("SIP/switch-in-0000000f", "QJOINMSG=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:13] Set("SIP/switch-in-0000000f", "VQ_JOINMSG=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:14] Set("SIP/switch-in-0000000f", "QRETRY=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:15] Set("SIP/switch-in-0000000f", "VQ_RETRY=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:16] Set("SIP/switch-in-0000000f", "QOPTIONS=t") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:17] Set("SIP/switch-in-0000000f", "VQ_OPTIONS=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:18] Set("SIP/switch-in-0000000f", "QGOSUB=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:19] Set("SIP/switch-in-0000000f", "VQ_GOSUB=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:20] Set("SIP/switch-in-0000000f", "QAGI=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:21] Set("SIP/switch-in-0000000f", "VQ_AGI=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:22] Set("SIP/switch-in-0000000f", "QRULE=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:23] Set("SIP/switch-in-0000000f", "VQ_RULE=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:24] Set("SIP/switch-in-0000000f", "QPOSITION=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:25] Set("SIP/switch-in-0000000f", "VQ_POSITION=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal: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 [s@sub-record-check: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 [s@sub-record-check:10] NoOp("SIP/switch-in-0000000f", "Recordings initialized") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check: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 [recordcheck@sub-record-check:24] Return("SIP/switch-in-0000000f", "") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [s@sub-record-check:20] Return("SIP/switch-in-0000000f", "") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:27] Set("SIP/switch-in-0000000f", "__CWIGNORE=TRUE") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:28] ExecIf("SIP/switch-in-0000000f", "0?Playback(, )") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal: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 [331333@from-internal:30] Set("SIP/switch-in-0000000f", "QAANNOUNCE=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:31] Set("SIP/switch-in-0000000f", "VQ_AANNOUNCE=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal: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 [331333@from-internal:33] Set("SIP/switch-in-0000000f", "VQ_MOH=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal: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 [331333@from-internal: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 [331333@from-internal:36] Set("SIP/switch-in-0000000f", "QMAXWAIT=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:37] Set("SIP/switch-in-0000000f", "VQ_MAXWAIT=") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:38] Set("SIP/switch-in-0000000f", "QUEUENUM=331333") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal:39] Set("SIP/switch-in-0000000f", "QUEUEJOINTIME=1538719080") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] pbx.c: Executing [331333@from-internal: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 [1162@from-queue:1] Set("Local/1162@from-queue-0000000d;2", "QAGENT=1162") in new stack
[2018-10-05 01:58:00] VERBOSE[11712][C-00000005] app_queue.c: Called Local/1162@from-queue/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 [1162@from-queue:2] Set("Local/1162@from-queue-0000000d;2", "__FROMQ=true") in new stack
[2018-10-05 01:58:00] VERBOSE[11746][C-00000005] pbx.c: Executing [1162@from-queue:3] GotoIf("Local/1162@from-queue-0000000d;2", "0?hangup") in new stack
[2018-10-05 01:58:00] VERBOSE[11746][C-00000005] pbx.c: Executing [1162@from-queue:4] GotoIf("Local/1162@from-queue-0000000d;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 [331333@from-queue:1] Goto("Local/1162@from-queue-0000000d;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/1184@from-queue-00000010;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/1162@from-queue-00000011;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?


(Jerry Riggin) #2

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


(Tom Ray) #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.


(Jerry Riggin) #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.


(Andrew Nagy) #5

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


(Jerry Riggin) #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.


(Tom Ray) #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.


(Jerry Riggin) #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.