Transfers stopped working

stefanwild · May 17, 2019, 4:02pm

In testing, our FreePBX 14 installation worked very nicely with the paid Endpoint Manager, our Cisco SPA525G and SPA525G2 and a SIP trunk (all on PJSIP). Now, after deployment, we haven’t been able to get any transfers to work.

Specifically, after the Transfer button is pressed, the first (external) call goes on hold (music is played), but then as soon as dialing the second call starts (whether that’s another extension or an external call), the first call is disconnected, with a regular HANGUP being logged.

The only difference to the test setup is that the phones now are on a separate network that can’t connect to the internet. FreePBX is connected to both the internet and to the separate phone network via two different network interfaces.

dolesec · May 17, 2019, 4:36pm

determine if ## ext # works as expected for transfer using feature codes… if so , most likely something endpoint related , if not system or config

a call trace / pcap may help shed light on cause and resolution too

if your network changed check nat settings on ext’s and make sure that new network is defined in localnets of sip settings

stefanwild · May 17, 2019, 6:55pm

Unattended transfers with ## ext # work. We tried an attended transfer (which is what the Transfer button should be doing) with *2 ext # and that didn’t do anything at all.

Using the Transfer button, we’re also unable to do an attended transfer between all local extensions.

The new network is defined in localnets. Could you please point out how the extension’s NAT settings should be set?

We have a static public IP with 1:1 NAT via our Firewall to eth1 (172.17.189.5) on the FreePBX and a separately switched LAN 172.17.188.0/24 with all the phones, which is connected to eth0 on the FreePBX, but has not internet access. Pre-deployment, the test phones were connected to the same NATed LAN 172.17.189.0/24 with internet access that the FreePBX is connected to via eth1.

stefanwild · May 20, 2019, 7:49pm

Here’s the asterisk full log of one such interaction. Anonymized some data in there…

+12345678901 Is the external number calling into the PBX (public IP anonymized to 64.64.64.64) at +19876543210 (inbound via SIPtrunk)
User 1, extension 242 is dialed and a call established
User 1, extension 242 then hits the transfer button, starting an attended transfer
User 2, extension 227 is dialed by User 1, extension 242
As soon as extension 242 and 227 connect, the external call is hung up:

[2019-05-20 17:35:50] VERBOSE[8515] pbx_variables.c: Setting global variable 'SIPDOMAIN' to '64.64.64.64'
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:1] Set("PJSIP/SIPtrunk-00000144", "__DIRECTION=INBOUND") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:2] Gosub("PJSIP/SIPtrunk-00000144", "sub-record-check,s,1(in,+19876543210,dontcare)") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:1] GotoIf("PJSIP/SIPtrunk-00000144", "0?initialized") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:2] Set("PJSIP/SIPtrunk-00000144", "__REC_STATUS=INITIALIZED") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:3] Set("PJSIP/SIPtrunk-00000144", "NOW=1558373750") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:4] Set("PJSIP/SIPtrunk-00000144", "__DAY=20") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:5] Set("PJSIP/SIPtrunk-00000144", "__MONTH=05") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:6] Set("PJSIP/SIPtrunk-00000144", "__YEAR=2019") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:7] Set("PJSIP/SIPtrunk-00000144", "__TIMESTR=20190520-173550") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:8] Set("PJSIP/SIPtrunk-00000144", "__FROMEXTEN=unknown") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:9] Set("PJSIP/SIPtrunk-00000144", "__MON_FMT=wav") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:10] NoOp("PJSIP/SIPtrunk-00000144", "Recordings initialized") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:11] ExecIf("PJSIP/SIPtrunk-00000144", "0?Set(ARG3=dontcare)") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:12] Set("PJSIP/SIPtrunk-00000144", "REC_POLICY_MODE_SAVE=") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:13] ExecIf("PJSIP/SIPtrunk-00000144", "0?Set(REC_STATUS=NO)") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:14] GotoIf("PJSIP/SIPtrunk-00000144", "2?checkaction") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (sub-record-check,s,17)
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:17] GotoIf("PJSIP/SIPtrunk-00000144", "1?sub-record-check,in,1") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (sub-record-check,in,1)
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [in@sub-record-check:1] NoOp("PJSIP/SIPtrunk-00000144", "Inbound Recording Check to +19876543210") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [in@sub-record-check:2] Set("PJSIP/SIPtrunk-00000144", "FROMEXTEN=unknown") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [in@sub-record-check:3] ExecIf("PJSIP/SIPtrunk-00000144", "12?Set(FROMEXTEN=+12345678901)") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [in@sub-record-check:4] Gosub("PJSIP/SIPtrunk-00000144", "recordcheck,1(dontcare,in,+19876543210)") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("PJSIP/SIPtrunk-00000144", "Starting recording check against dontcare") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("PJSIP/SIPtrunk-00000144", "dontcare") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [recordcheck@sub-record-check:3] Return("PJSIP/SIPtrunk-00000144", "") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [in@sub-record-check:5] Return("PJSIP/SIPtrunk-00000144", "") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:3] Set("PJSIP/SIPtrunk-00000144", "CHANNEL(tonezone)=us") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:4] Set("PJSIP/SIPtrunk-00000144", "__FROM_DID=+19876543210") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:5] Set("PJSIP/SIPtrunk-00000144", "returnhere=1") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:6] Gosub("PJSIP/SIPtrunk-00000144", "app-blacklist-check,s,1()") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@app-blacklist-check:1] GotoIf("PJSIP/SIPtrunk-00000144", "0?blacklisted") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@app-blacklist-check:2] Set("PJSIP/SIPtrunk-00000144", "CALLED_BLACKLIST=1") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@app-blacklist-check:3] Return("PJSIP/SIPtrunk-00000144", "") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:7] Set("PJSIP/SIPtrunk-00000144", "CDR(did)=+19876543210") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:8] GotoIf("PJSIP/SIPtrunk-00000144", "0?") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:9] ExecIf("PJSIP/SIPtrunk-00000144", "1 ?Set(CALLERID(name)=+12345678901)") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:10] Set("PJSIP/SIPtrunk-00000144", "__MOHCLASS=") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:11] Ringing("PJSIP/SIPtrunk-00000144", "") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:12] Set("PJSIP/SIPtrunk-00000144", "__RINGINGSENT=TRUE") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:13] Set("PJSIP/SIPtrunk-00000144", "__REVERSAL_REJECT=FALSE") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:14] GotoIf("PJSIP/SIPtrunk-00000144", "1?post-reverse-charge") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (from-pstn,+19876543210,16)
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:16] NoOp("PJSIP/SIPtrunk-00000144", "") in new stack
[2019-05-20 17:35:50] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:17] Wait("PJSIP/SIPtrunk-00000144", "3") in new stack
[2019-05-20 17:35:53] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:18] Set("PJSIP/SIPtrunk-00000144", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
[2019-05-20 17:35:53] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:19] Set("PJSIP/SIPtrunk-00000144", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
[2019-05-20 17:35:53] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:20] Set("PJSIP/SIPtrunk-00000144", "CALLERID(name-pres)=allowed_not_screened") in new stack
[2019-05-20 17:35:53] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:21] Set("PJSIP/SIPtrunk-00000144", "CALLERID(num-pres)=allowed_not_screened") in new stack
[2019-05-20 17:35:53] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:22] NoOp("PJSIP/SIPtrunk-00000144", "CallerID Entry Point") in new stack
[2019-05-20 17:35:53] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:23] Set("PJSIP/SIPtrunk-00000144", "__CRM_DIRECTION=INBOUND") in new stack
[2019-05-20 17:35:53] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:24] Set("PJSIP/SIPtrunk-00000144", "__CRM_SOURCE=+12345678901") in new stack
[2019-05-20 17:35:53] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:25] Set("PJSIP/SIPtrunk-00000144", "__CRM_LINKEDID=1558373750.422") in new stack
[2019-05-20 17:35:53] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:26] ExecIf("PJSIP/SIPtrunk-00000144", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2019-05-20 17:35:53] VERBOSE[32757][C-000000d5] pbx.c: Executing [+19876543210@from-pstn:27] Goto("PJSIP/SIPtrunk-00000144", "ivr-1,s,1") in new stack
[2019-05-20 17:35:53] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (ivr-1,s,1)
[2019-05-20 17:35:53] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@ivr-1:1] Set("PJSIP/SIPtrunk-00000144", "INVALID_LOOPCOUNT=0") in new stack
[2019-05-20 17:35:53] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@ivr-1:2] Set("PJSIP/SIPtrunk-00000144", "_IVR_CONTEXT_ivr-1=") in new stack
[2019-05-20 17:35:53] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@ivr-1:3] Set("PJSIP/SIPtrunk-00000144", "_IVR_CONTEXT=ivr-1") in new stack
[2019-05-20 17:35:53] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@ivr-1:4] Set("PJSIP/SIPtrunk-00000144", "__IVR_RETVM=") in new stack
[2019-05-20 17:35:53] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@ivr-1:5] GotoIf("PJSIP/SIPtrunk-00000144", "0?skip") in new stack
[2019-05-20 17:35:53] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@ivr-1:6] Answer("PJSIP/SIPtrunk-00000144", "") in new stack
[2019-05-20 17:35:53] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@ivr-1:7] Wait("PJSIP/SIPtrunk-00000144", "1") in new stack
[2019-05-20 17:35:54] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@ivr-1:8] Set("PJSIP/SIPtrunk-00000144", "IVR_MSG=custom/Company_Intro") in new stack
[2019-05-20 17:35:54] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@ivr-1:9] Set("PJSIP/SIPtrunk-00000144", "TIMEOUT(digit)=3") in new stack
[2019-05-20 17:35:54] VERBOSE[32757][C-000000d5] func_timeout.c: Digit timeout set to 3.000
[2019-05-20 17:35:54] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@ivr-1:10] ExecIf("PJSIP/SIPtrunk-00000144", "1?Background(custom/Company_Intro)") in new stack
[2019-05-20 17:35:54] VERBOSE[32757][C-000000d5] file.c: <PJSIP/SIPtrunk-00000144> Playing 'custom/Company_Intro.slin' (language 'en')

stefanwild · May 20, 2019, 7:49pm

Log Part 2:

[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [242@ivr-1:1] GotoIf("PJSIP/SIPtrunk-00000144", "0?i,1") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [242@ivr-1:2] Macro("PJSIP/SIPtrunk-00000144", "blkvm-clr,") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-blkvm-clr:1] Set("PJSIP/SIPtrunk-00000144", "SHARED(BLKVM,)=") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-blkvm-clr:2] Set("PJSIP/SIPtrunk-00000144", "GOSUB_RETVAL=") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-blkvm-clr:3] MacroExit("PJSIP/SIPtrunk-00000144", "") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [242@ivr-1:3] Set("PJSIP/SIPtrunk-00000144", "__NODEST=") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [242@ivr-1:4] Goto("PJSIP/SIPtrunk-00000144", "from-did-direct,242,1") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (from-did-direct,242,1)
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [242@from-did-direct:1] GotoIf("PJSIP/SIPtrunk-00000144", "1?ext-local,242,1:followme-check,242,1") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (ext-local,242,1)
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [242@ext-local:1] Set("PJSIP/SIPtrunk-00000144", "__RINGTIMER=15") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [242@ext-local:2] Macro("PJSIP/SIPtrunk-00000144", "exten-vm,242,242,0,0,0") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:1] Macro("PJSIP/SIPtrunk-00000144", "user-callerid,") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:1] Set("PJSIP/SIPtrunk-00000144", "TOUCH_MONITOR=1558373750.422") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:2] Set("PJSIP/SIPtrunk-00000144", "AMPUSER=+12345678901") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("PJSIP/SIPtrunk-00000144", "0?report") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:4] ExecIf("PJSIP/SIPtrunk-00000144", "1?Set(REALCALLERIDNUM=+12345678901)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:5] Set("PJSIP/SIPtrunk-00000144", "AMPUSER=") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:6] GotoIf("PJSIP/SIPtrunk-00000144", "0?limit") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:7] Set("PJSIP/SIPtrunk-00000144", "AMPUSERCIDNAME=") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:8] ExecIf("PJSIP/SIPtrunk-00000144", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:9] GotoIf("PJSIP/SIPtrunk-00000144", "1?report") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (macro-user-callerid,s,16)
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:16] NoOp("PJSIP/SIPtrunk-00000144", "Macro Depth is 2") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:17] GotoIf("PJSIP/SIPtrunk-00000144", "1?report2:macroerror") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (macro-user-callerid,s,18)
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:18] GotoIf("PJSIP/SIPtrunk-00000144", "0?continue") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:19] ExecIf("PJSIP/SIPtrunk-00000144", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:20] Set("PJSIP/SIPtrunk-00000144", "__TTL=64") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:21] GotoIf("PJSIP/SIPtrunk-00000144", "1?continue") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (macro-user-callerid,s,37)
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:37] Set("PJSIP/SIPtrunk-00000144", "CALLERID(number)=+12345678901") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:38] Set("PJSIP/SIPtrunk-00000144", "CALLERID(name)=+12345678901") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:39] GotoIf("PJSIP/SIPtrunk-00000144", "0?cnum") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:40] Set("PJSIP/SIPtrunk-00000144", "CDR(cnam)=+12345678901") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:41] Set("PJSIP/SIPtrunk-00000144", "CDR(cnum)=+12345678901") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-user-callerid:42] Set("PJSIP/SIPtrunk-00000144", "CHANNEL(language)=en") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:2] Set("PJSIP/SIPtrunk-00000144", "RingGroupMethod=none") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:3] Set("PJSIP/SIPtrunk-00000144", "__EXTTOCALL=242") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:4] Set("PJSIP/SIPtrunk-00000144", "__PICKUPMARK=242") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:5] Set("PJSIP/SIPtrunk-00000144", "RT=15") in new stack
[2019-05-20 17:36:02] WARNING[32757][C-000000d5] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:6] ExecIf("PJSIP/SIPtrunk-00000144", "0?Macro(vm,242,DIRECTDIAL,)") in new stack
[2019-05-20 17:36:02] WARNING[32757][C-000000d5] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:02] WARNING[32757][C-000000d5] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:7] ExecIf("PJSIP/SIPtrunk-00000144", "0?MacroExit()") in new stack
[2019-05-20 17:36:02] WARNING[32757][C-000000d5] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:02] WARNING[32757][C-000000d5] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:8] ExecIf("PJSIP/SIPtrunk-00000144", "0?Gosub(ext-intercom,*80242,1())") in new stack
[2019-05-20 17:36:02] WARNING[32757][C-000000d5] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:02] WARNING[32757][C-000000d5] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:9] ExecIf("PJSIP/SIPtrunk-00000144", "0?MacroExit()") in new stack
[2019-05-20 17:36:02] WARNING[32757][C-000000d5] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:02] WARNING[32757][C-000000d5] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:10] ExecIf("PJSIP/SIPtrunk-00000144", "0?ChanSpy(PJSIP/242,q)") in new stack
[2019-05-20 17:36:02] WARNING[32757][C-000000d5] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:02] WARNING[32757][C-000000d5] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:11] ExecIf("PJSIP/SIPtrunk-00000144", "0?MacroExit()") in new stack
[2019-05-20 17:36:02] WARNING[32757][C-000000d5] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:12] ExecIf("PJSIP/SIPtrunk-00000144", "0?Macro(vm,242,DIRECTDIAL,)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:13] ExecIf("PJSIP/SIPtrunk-00000144", "0?MacroExit()") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:14] ExecIf("PJSIP/SIPtrunk-00000144", "0?Gosub(ext-intercom,*80242,1())") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:15] ExecIf("PJSIP/SIPtrunk-00000144", "0?MacroExit()") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:16] ExecIf("PJSIP/SIPtrunk-00000144", "0?ChanSpy(PJSIP/242,q)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:17] ExecIf("PJSIP/SIPtrunk-00000144", "0?MacroExit()") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:18] Gosub("PJSIP/SIPtrunk-00000144", "sub-record-check,s,1(exten,242,dontcare)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:1] GotoIf("PJSIP/SIPtrunk-00000144", "12?initialized") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (sub-record-check,s,10)
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:10] NoOp("PJSIP/SIPtrunk-00000144", "Recordings initialized") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:11] ExecIf("PJSIP/SIPtrunk-00000144", "0?Set(ARG3=dontcare)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:12] Set("PJSIP/SIPtrunk-00000144", "REC_POLICY_MODE_SAVE=") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:13] ExecIf("PJSIP/SIPtrunk-00000144", "0?Set(REC_STATUS=NO)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:14] GotoIf("PJSIP/SIPtrunk-00000144", "5?checkaction") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (sub-record-check,s,17)
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@sub-record-check:17] GotoIf("PJSIP/SIPtrunk-00000144", "1?sub-record-check,exten,1") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (sub-record-check,exten,1)
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [exten@sub-record-check:1] NoOp("PJSIP/SIPtrunk-00000144", "Exten Recording Check between +12345678901 and 242") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [exten@sub-record-check:2] Set("PJSIP/SIPtrunk-00000144", "CALLTYPE=external") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [exten@sub-record-check:3] ExecIf("PJSIP/SIPtrunk-00000144", "0?Set(CALLTYPE=)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [exten@sub-record-check:4] Set("PJSIP/SIPtrunk-00000144", "CALLEE=dontcare") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [exten@sub-record-check:5] ExecIf("PJSIP/SIPtrunk-00000144", "0?Set(CALLEE=dontcare)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [exten@sub-record-check:6] GotoIf("PJSIP/SIPtrunk-00000144", "1?callee") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (sub-record-check,exten,11)
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [exten@sub-record-check:11] Gosub("PJSIP/SIPtrunk-00000144", "recordcheck,1(dontcare,external,242)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("PJSIP/SIPtrunk-00000144", "Starting recording check against dontcare") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("PJSIP/SIPtrunk-00000144", "dontcare") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [recordcheck@sub-record-check:3] Return("PJSIP/SIPtrunk-00000144", "") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [exten@sub-record-check:12] Return("PJSIP/SIPtrunk-00000144", "") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:19] GotoIf("PJSIP/SIPtrunk-00000144", "1?macrodial") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (macro-exten-vm,s,25)
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:25] GosubIf("PJSIP/SIPtrunk-00000144", "0?clrheader,1()") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-exten-vm:26] Macro("PJSIP/SIPtrunk-00000144", "dial-one,15,HhTtr,242") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:1] Set("PJSIP/SIPtrunk-00000144", "DEXTEN=242") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:2] Set("PJSIP/SIPtrunk-00000144", "__CRM_SOURCE=+12345678901") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:3] ExecIf("PJSIP/SIPtrunk-00000144", "0?Set(__EXTTOCALL=242)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:4] Set("PJSIP/SIPtrunk-00000144", "DIALSTATUS_CW=") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:5] GosubIf("PJSIP/SIPtrunk-00000144", "0?screen,1()") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:6] GosubIf("PJSIP/SIPtrunk-00000144", "0?cf,1()") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:7] GotoIf("PJSIP/SIPtrunk-00000144", "1?skip1") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (macro-dial-one,s,10)
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:10] GotoIf("PJSIP/SIPtrunk-00000144", "0?nodial") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:11] GotoIf("PJSIP/SIPtrunk-00000144", "0?continue") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:12] Set("PJSIP/SIPtrunk-00000144", "EXTHASCW=ENABLED") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:13] GotoIf("PJSIP/SIPtrunk-00000144", "0?next1:cwinusebusy") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (macro-dial-one,s,25)
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:25] GotoIf("PJSIP/SIPtrunk-00000144", "0?next3:continue") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (macro-dial-one,s,27)
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:27] GotoIf("PJSIP/SIPtrunk-00000144", "0?nodial") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:28] GosubIf("PJSIP/SIPtrunk-00000144", "1?dstring,1():dlocal,1()") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:1] Set("PJSIP/SIPtrunk-00000144", "DSTRING=") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:2] Set("PJSIP/SIPtrunk-00000144", "DEVICES=242") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:3] ExecIf("PJSIP/SIPtrunk-00000144", "0?Return()") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:4] ExecIf("PJSIP/SIPtrunk-00000144", "0?Set(DEVICES=42)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:5] Set("PJSIP/SIPtrunk-00000144", "LOOPCNT=1") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:6] Set("PJSIP/SIPtrunk-00000144", "ITER=1") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:7] Set("PJSIP/SIPtrunk-00000144", "THISDIAL=PJSIP/242") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:8] GosubIf("PJSIP/SIPtrunk-00000144", "1?zap2dahdi,1()") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [zap2dahdi@macro-dial-one:1] ExecIf("PJSIP/SIPtrunk-00000144", "0?Return()") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [zap2dahdi@macro-dial-one:2] Set("PJSIP/SIPtrunk-00000144", "NEWDIAL=") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [zap2dahdi@macro-dial-one:3] Set("PJSIP/SIPtrunk-00000144", "LOOPCNT2=1") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [zap2dahdi@macro-dial-one:4] Set("PJSIP/SIPtrunk-00000144", "ITER2=1") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [zap2dahdi@macro-dial-one:5] Set("PJSIP/SIPtrunk-00000144", "THISPART2=PJSIP/242") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [zap2dahdi@macro-dial-one:6] ExecIf("PJSIP/SIPtrunk-00000144", "0?Set(THISPART2=DAHDIIP/242)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [zap2dahdi@macro-dial-one:7] Set("PJSIP/SIPtrunk-00000144", "NEWDIAL=PJSIP/242&") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [zap2dahdi@macro-dial-one:8] Set("PJSIP/SIPtrunk-00000144", "ITER2=2") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [zap2dahdi@macro-dial-one:9] GotoIf("PJSIP/SIPtrunk-00000144", "0?begin2") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [zap2dahdi@macro-dial-one:10] Set("PJSIP/SIPtrunk-00000144", "THISDIAL=PJSIP/242") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [zap2dahdi@macro-dial-one:11] Return("PJSIP/SIPtrunk-00000144", "") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:9] GotoIf("PJSIP/SIPtrunk-00000144", "0?docheck") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:10] NoOp("PJSIP/SIPtrunk-00000144", "Debug: Found PJSIP Destination PJSIP/242") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:11] GotoIf("PJSIP/SIPtrunk-00000144", "0?doset") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:12] NoOp("PJSIP/SIPtrunk-00000144", "Debug: Updating PJSIP Destination with PJSIP_DIAL_CONTACTS") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:13] Set("PJSIP/SIPtrunk-00000144", "THISDIAL=PJSIP/242/sip:[email protected]:5060") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:14] ExecIf("PJSIP/SIPtrunk-00000144", "0?Set(DIALSTATUS=CHANUNAVAIL)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:15] GotoIf("PJSIP/SIPtrunk-00000144", "0?skipset") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:16] Set("PJSIP/SIPtrunk-00000144", "DSTRING=PJSIP/242/sip:[email protected]:5060&") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:17] Set("PJSIP/SIPtrunk-00000144", "ITER=2") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:18] GotoIf("PJSIP/SIPtrunk-00000144", "0?begin") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:19] ExecIf("PJSIP/SIPtrunk-00000144", "0?Return()") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:20] Set("PJSIP/SIPtrunk-00000144", "DSTRING=PJSIP/242/sip:[email protected]:5060") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [dstring@macro-dial-one:21] Return("PJSIP/SIPtrunk-00000144", "") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:29] GotoIf("PJSIP/SIPtrunk-00000144", "0?nodial") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:30] GotoIf("PJSIP/SIPtrunk-00000144", "0?skiptrace") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:31] GosubIf("PJSIP/SIPtrunk-00000144", "1?ctset,1():ctclear,1()") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [ctset@macro-dial-one:1] Set("PJSIP/SIPtrunk-00000144", "DB(CALLTRACE/242)=+12345678901") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [ctset@macro-dial-one:2] Return("PJSIP/SIPtrunk-00000144", "") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:32] Set("PJSIP/SIPtrunk-00000144", "D_OPTIONS=HhTtr") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:33] GosubIf("PJSIP/SIPtrunk-00000144", "0?func-set-sipheader,s,1(Alert-Info,)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:34] NoOp("PJSIP/SIPtrunk-00000144", "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:35] ExecIf("PJSIP/SIPtrunk-00000144", "0?Set(ALERT_INFO=)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:36] ExecIf("PJSIP/SIPtrunk-00000144", "0?Set(ALERT_INFO=)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:37] ExecIf("PJSIP/SIPtrunk-00000144", "0?Set(ALERT_INFO=)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:38] ExecIf("PJSIP/SIPtrunk-00000144", "0?Set(ALERT_INFO=Normal;volume=)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:39] ExecIf("PJSIP/SIPtrunk-00000144", "0?Set(ALERT_INFO=Normal;volume=)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:40] GosubIf("PJSIP/SIPtrunk-00000144", "0?func-set-sipheader,s,1(Alert-Info,)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:41] ExecIf("PJSIP/SIPtrunk-00000144", "0?Set(CHANNEL(musicclass)=)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:42] GosubIf("PJSIP/SIPtrunk-00000144", "0?qwait,1()") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:43] Set("PJSIP/SIPtrunk-00000144", "__CWIGNORE=") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:44] Set("PJSIP/SIPtrunk-00000144", "__KEEPCID=TRUE") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:45] GotoIf("PJSIP/SIPtrunk-00000144", "0?usegoto,1") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:46] GotoIf("PJSIP/SIPtrunk-00000144", "1?godial") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (macro-dial-one,s,51)
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:51] Macro("PJSIP/SIPtrunk-00000144", "dialout-one-predial-hook,") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dialout-one-predial-hook:1] MacroExit("PJSIP/SIPtrunk-00000144", "") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:52] ExecIf("PJSIP/SIPtrunk-00000144", "1?Set(D_OPTIONS=HhtrI)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:53] NoOp("PJSIP/SIPtrunk-00000144", "") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:54] ExecIf("PJSIP/SIPtrunk-00000144", "0?Set(D_OPTIONS=HhtrIg)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-dial-one:55] Dial("PJSIP/SIPtrunk-00000144", "PJSIP/242/sip:[email protected]:5060,15,HhtrIb(func-apply-sipheaders^s^1)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] app_stack.c: PJSIP/242-00000145 Internal Gosub(func-apply-sipheaders,s,1) start
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf("PJSIP/242-00000145", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp("PJSIP/242-00000145", "Applying SIP Headers to channel PJSIP/242-00000145") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@func-apply-sipheaders:3] Set("PJSIP/242-00000145", "TECH=PJSIP") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@func-apply-sipheaders:4] Set("PJSIP/242-00000145", "SIPHEADERKEYS=") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@func-apply-sipheaders:5] While("PJSIP/242-00000145", "0") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] app_while.c: Jumping to priority 12
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@func-apply-sipheaders:13] Return("PJSIP/242-00000145", "") in new stack
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] app_stack.c: Spawn extension (from-internal, 242, 1) exited non-zero on 'PJSIP/242-00000145'
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] app_stack.c: PJSIP/242-00000145 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] app_dial.c: Called PJSIP/242/sip:[email protected]:5060
[2019-05-20 17:36:02] VERBOSE[29831] netsock2.c: Using SIP RTP Audio TOS bits 184
[2019-05-20 17:36:02] VERBOSE[29831] netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.
[2019-05-20 17:36:02] VERBOSE[29831] netsock2.c: Using SIP RTP Audio CoS mark 5
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] app_dial.c: Connected line update to PJSIP/SIPtrunk-00000144 prevented.
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] app_dial.c: PJSIP/242-00000145 is ringing
[2019-05-20 17:36:02] VERBOSE[32757][C-000000d5] app_dial.c: PJSIP/242-00000145 is ringing
[2019-05-20 17:36:04] VERBOSE[32757][C-000000d5] app_dial.c: PJSIP/242-00000145 answered PJSIP/SIPtrunk-00000144
[2019-05-20 17:36:04] VERBOSE[416][C-000000d5] bridge_channel.c: Channel PJSIP/242-00000145 joined 'simple_bridge' basic-bridge <6e2bbeb2-22e6-4f19-a146-2994d42b7574>
[2019-05-20 17:36:04] VERBOSE[32757][C-000000d5] bridge_channel.c: Channel PJSIP/SIPtrunk-00000144 joined 'simple_bridge' basic-bridge <6e2bbeb2-22e6-4f19-a146-2994d42b7574>

stefanwild · May 20, 2019, 7:50pm

Log Part 3:

[2019-05-20 17:36:46] VERBOSE[32757][C-000000d5] res_musiconhold.c: Started music on hold, class 'default', on channel 'PJSIP/SIPtrunk-00000144'
[2019-05-20 17:36:48] VERBOSE[10276] pbx_variables.c: Setting global variable 'SIPDOMAIN' to '172.17.188.1'
[2019-05-20 17:36:48] VERBOSE[10276] netsock2.c: Using SIP RTP Audio TOS bits 184
[2019-05-20 17:36:48] VERBOSE[10276] netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.
[2019-05-20 17:36:48] VERBOSE[10276] netsock2.c: Using SIP RTP Audio CoS mark 5
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [227@from-internal:1] GotoIf("PJSIP/242-00000146", "1?ext-local,227,1:followme-check,227,1") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx_builtins.c: Goto (ext-local,227,1)
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [227@ext-local:1] Set("PJSIP/242-00000146", "__RINGTIMER=15") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [227@ext-local:2] Macro("PJSIP/242-00000146", "exten-vm,227,227,0,0,0") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:1] Macro("PJSIP/242-00000146", "user-callerid,") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:1] Set("PJSIP/242-00000146", "TOUCH_MONITOR=1558373808.424") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:2] Set("PJSIP/242-00000146", "AMPUSER=242") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("PJSIP/242-00000146", "0?report") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:4] ExecIf("PJSIP/242-00000146", "1?Set(REALCALLERIDNUM=242)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:5] Set("PJSIP/242-00000146", "AMPUSER=242") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:6] GotoIf("PJSIP/242-00000146", "0?limit") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:7] Set("PJSIP/242-00000146", "AMPUSERCIDNAME=User 1") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:8] ExecIf("PJSIP/242-00000146", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:9] GotoIf("PJSIP/242-00000146", "0?report") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:10] Set("PJSIP/242-00000146", "AMPUSERCID=242") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:11] Set("PJSIP/242-00000146", "__DIAL_OPTIONS=HhTtr") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:12] Set("PJSIP/242-00000146", "CALLERID(all)="User 1" <242>") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:13] GotoIf("PJSIP/242-00000146", "0?limit") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:14] ExecIf("PJSIP/242-00000146", "0?Set(GROUP(concurrency_limit)=242)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:15] ExecIf("PJSIP/242-00000146", "0?Set(CHANNEL(language)=)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:16] NoOp("PJSIP/242-00000146", "Macro Depth is 2") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:17] GotoIf("PJSIP/242-00000146", "1?report2:macroerror") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx_builtins.c: Goto (macro-user-callerid,s,18)
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:18] GotoIf("PJSIP/242-00000146", "0?continue") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:19] ExecIf("PJSIP/242-00000146", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:20] Set("PJSIP/242-00000146", "__TTL=64") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:21] GotoIf("PJSIP/242-00000146", "1?continue") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx_builtins.c: Goto (macro-user-callerid,s,37)
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:37] Set("PJSIP/242-00000146", "CALLERID(number)=242") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:38] Set("PJSIP/242-00000146", "CALLERID(name)=User 1") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:39] GotoIf("PJSIP/242-00000146", "0?cnum") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:40] Set("PJSIP/242-00000146", "CDR(cnam)=User 1") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:41] Set("PJSIP/242-00000146", "CDR(cnum)=242") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-user-callerid:42] Set("PJSIP/242-00000146", "CHANNEL(language)=en") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:2] Set("PJSIP/242-00000146", "RingGroupMethod=none") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:3] Set("PJSIP/242-00000146", "__EXTTOCALL=227") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:4] Set("PJSIP/242-00000146", "__PICKUPMARK=227") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:5] Set("PJSIP/242-00000146", "RT=15") in new stack
[2019-05-20 17:36:48] WARNING[450][C-000000d6] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:6] ExecIf("PJSIP/242-00000146", "0?Macro(vm,227,DIRECTDIAL,)") in new stack
[2019-05-20 17:36:48] WARNING[450][C-000000d6] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:48] WARNING[450][C-000000d6] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:7] ExecIf("PJSIP/242-00000146", "0?MacroExit()") in new stack
[2019-05-20 17:36:48] WARNING[450][C-000000d6] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:48] WARNING[450][C-000000d6] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:8] ExecIf("PJSIP/242-00000146", "0?Gosub(ext-intercom,*80227,1())") in new stack
[2019-05-20 17:36:48] WARNING[450][C-000000d6] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:48] WARNING[450][C-000000d6] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:9] ExecIf("PJSIP/242-00000146", "0?MacroExit()") in new stack
[2019-05-20 17:36:48] WARNING[450][C-000000d6] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:48] WARNING[450][C-000000d6] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:10] ExecIf("PJSIP/242-00000146", "0?ChanSpy(PJSIP/227,q)") in new stack
[2019-05-20 17:36:48] WARNING[450][C-000000d6] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:48] WARNING[450][C-000000d6] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:11] ExecIf("PJSIP/242-00000146", "0?MacroExit()") in new stack
[2019-05-20 17:36:48] WARNING[450][C-000000d6] chan_sip.c: This function can only be used on SIP channels.
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:12] ExecIf("PJSIP/242-00000146", "0?Macro(vm,227,DIRECTDIAL,)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:13] ExecIf("PJSIP/242-00000146", "0?MacroExit()") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:14] ExecIf("PJSIP/242-00000146", "0?Gosub(ext-intercom,*80227,1())") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:15] ExecIf("PJSIP/242-00000146", "0?MacroExit()") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:16] ExecIf("PJSIP/242-00000146", "0?ChanSpy(PJSIP/227,q)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:17] ExecIf("PJSIP/242-00000146", "0?MacroExit()") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:18] Gosub("PJSIP/242-00000146", "sub-record-check,s,1(exten,227,dontcare)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@sub-record-check:1] GotoIf("PJSIP/242-00000146", "0?initialized") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@sub-record-check:2] Set("PJSIP/242-00000146", "__REC_STATUS=INITIALIZED") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@sub-record-check:3] Set("PJSIP/242-00000146", "NOW=1558373808") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@sub-record-check:4] Set("PJSIP/242-00000146", "__DAY=20") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@sub-record-check:5] Set("PJSIP/242-00000146", "__MONTH=05") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@sub-record-check:6] Set("PJSIP/242-00000146", "__YEAR=2019") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@sub-record-check:7] Set("PJSIP/242-00000146", "__TIMESTR=20190520-173648") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@sub-record-check:8] Set("PJSIP/242-00000146", "__FROMEXTEN=242") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@sub-record-check:9] Set("PJSIP/242-00000146", "__MON_FMT=wav") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@sub-record-check:10] NoOp("PJSIP/242-00000146", "Recordings initialized") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@sub-record-check:11] ExecIf("PJSIP/242-00000146", "0?Set(ARG3=dontcare)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@sub-record-check:12] Set("PJSIP/242-00000146", "REC_POLICY_MODE_SAVE=") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@sub-record-check:13] ExecIf("PJSIP/242-00000146", "0?Set(REC_STATUS=NO)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@sub-record-check:14] GotoIf("PJSIP/242-00000146", "5?checkaction") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx_builtins.c: Goto (sub-record-check,s,17)
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@sub-record-check:17] GotoIf("PJSIP/242-00000146", "1?sub-record-check,exten,1") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx_builtins.c: Goto (sub-record-check,exten,1)
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [exten@sub-record-check:1] NoOp("PJSIP/242-00000146", "Exten Recording Check between 242 and 227") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [exten@sub-record-check:2] Set("PJSIP/242-00000146", "CALLTYPE=internal") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [exten@sub-record-check:3] ExecIf("PJSIP/242-00000146", "0?Set(CALLTYPE=)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [exten@sub-record-check:4] Set("PJSIP/242-00000146", "CALLEE=dontcare") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [exten@sub-record-check:5] ExecIf("PJSIP/242-00000146", "0?Set(CALLEE=dontcare)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [exten@sub-record-check:6] GotoIf("PJSIP/242-00000146", "0?callee") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [exten@sub-record-check:7] GotoIf("PJSIP/242-00000146", "1?caller") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx_builtins.c: Goto (sub-record-check,exten,13)
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [exten@sub-record-check:13] Set("PJSIP/242-00000146", "RECMODE=dontcare") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [exten@sub-record-check:14] ExecIf("PJSIP/242-00000146", "0?Set(RECMODE=dontcare)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [exten@sub-record-check:15] ExecIf("PJSIP/242-00000146", "1?Set(RECMODE=dontcare)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [exten@sub-record-check:16] Gosub("PJSIP/242-00000146", "recordcheck,1(dontcare,internal,227)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("PJSIP/242-00000146", "Starting recording check against dontcare") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("PJSIP/242-00000146", "dontcare") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [recordcheck@sub-record-check:3] Return("PJSIP/242-00000146", "") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [exten@sub-record-check:17] Return("PJSIP/242-00000146", "") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:19] GotoIf("PJSIP/242-00000146", "1?macrodial") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx_builtins.c: Goto (macro-exten-vm,s,25)
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:25] GosubIf("PJSIP/242-00000146", "0?clrheader,1()") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-exten-vm:26] Macro("PJSIP/242-00000146", "dial-one,15,HhTtr,227") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:1] Set("PJSIP/242-00000146", "DEXTEN=227") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:2] Set("PJSIP/242-00000146", "__CRM_SOURCE=242") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:3] ExecIf("PJSIP/242-00000146", "0?Set(__EXTTOCALL=227)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:4] Set("PJSIP/242-00000146", "DIALSTATUS_CW=") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:5] GosubIf("PJSIP/242-00000146", "0?screen,1()") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:6] GosubIf("PJSIP/242-00000146", "0?cf,1()") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:7] GotoIf("PJSIP/242-00000146", "1?skip1") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx_builtins.c: Goto (macro-dial-one,s,10)
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:10] GotoIf("PJSIP/242-00000146", "0?nodial") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:11] GotoIf("PJSIP/242-00000146", "0?continue") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:12] Set("PJSIP/242-00000146", "EXTHASCW=ENABLED") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:13] GotoIf("PJSIP/242-00000146", "0?next1:cwinusebusy") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx_builtins.c: Goto (macro-dial-one,s,25)
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:25] GotoIf("PJSIP/242-00000146", "0?next3:continue") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx_builtins.c: Goto (macro-dial-one,s,27)
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:27] GotoIf("PJSIP/242-00000146", "0?nodial") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:28] GosubIf("PJSIP/242-00000146", "1?dstring,1():dlocal,1()") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:1] Set("PJSIP/242-00000146", "DSTRING=") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:2] Set("PJSIP/242-00000146", "DEVICES=227") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:3] ExecIf("PJSIP/242-00000146", "0?Return()") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:4] ExecIf("PJSIP/242-00000146", "0?Set(DEVICES=27)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:5] Set("PJSIP/242-00000146", "LOOPCNT=1") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:6] Set("PJSIP/242-00000146", "ITER=1") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:7] Set("PJSIP/242-00000146", "THISDIAL=PJSIP/227") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:8] GosubIf("PJSIP/242-00000146", "1?zap2dahdi,1()") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [zap2dahdi@macro-dial-one:1] ExecIf("PJSIP/242-00000146", "0?Return()") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [zap2dahdi@macro-dial-one:2] Set("PJSIP/242-00000146", "NEWDIAL=") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [zap2dahdi@macro-dial-one:3] Set("PJSIP/242-00000146", "LOOPCNT2=1") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [zap2dahdi@macro-dial-one:4] Set("PJSIP/242-00000146", "ITER2=1") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [zap2dahdi@macro-dial-one:5] Set("PJSIP/242-00000146", "THISPART2=PJSIP/227") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [zap2dahdi@macro-dial-one:6] ExecIf("PJSIP/242-00000146", "0?Set(THISPART2=DAHDIIP/227)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [zap2dahdi@macro-dial-one:7] Set("PJSIP/242-00000146", "NEWDIAL=PJSIP/227&") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [zap2dahdi@macro-dial-one:8] Set("PJSIP/242-00000146", "ITER2=2") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [zap2dahdi@macro-dial-one:9] GotoIf("PJSIP/242-00000146", "0?begin2") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [zap2dahdi@macro-dial-one:10] Set("PJSIP/242-00000146", "THISDIAL=PJSIP/227") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [zap2dahdi@macro-dial-one:11] Return("PJSIP/242-00000146", "") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:9] GotoIf("PJSIP/242-00000146", "0?docheck") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:10] NoOp("PJSIP/242-00000146", "Debug: Found PJSIP Destination PJSIP/227") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:11] GotoIf("PJSIP/242-00000146", "0?doset") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:12] NoOp("PJSIP/242-00000146", "Debug: Updating PJSIP Destination with PJSIP_DIAL_CONTACTS") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:13] Set("PJSIP/242-00000146", "THISDIAL=PJSIP/227/sip:[email protected]:5060") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:14] ExecIf("PJSIP/242-00000146", "0?Set(DIALSTATUS=CHANUNAVAIL)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:15] GotoIf("PJSIP/242-00000146", "0?skipset") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:16] Set("PJSIP/242-00000146", "DSTRING=PJSIP/227/sip:[email protected]:5060&") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:17] Set("PJSIP/242-00000146", "ITER=2") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:18] GotoIf("PJSIP/242-00000146", "0?begin") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:19] ExecIf("PJSIP/242-00000146", "0?Return()") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:20] Set("PJSIP/242-00000146", "DSTRING=PJSIP/227/sip:[email protected]:5060") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [dstring@macro-dial-one:21] Return("PJSIP/242-00000146", "") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:29] GotoIf("PJSIP/242-00000146", "0?nodial") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:30] GotoIf("PJSIP/242-00000146", "0?skiptrace") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:31] GosubIf("PJSIP/242-00000146", "1?ctset,1():ctclear,1()") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [ctset@macro-dial-one:1] Set("PJSIP/242-00000146", "DB(CALLTRACE/227)=242") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [ctset@macro-dial-one:2] Return("PJSIP/242-00000146", "") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:32] Set("PJSIP/242-00000146", "D_OPTIONS=HhTtr") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:33] GosubIf("PJSIP/242-00000146", "0?func-set-sipheader,s,1(Alert-Info,)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:34] NoOp("PJSIP/242-00000146", "Blind Transfer: , Attended Transfer: , User: 242, Alert Info: ") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:35] ExecIf("PJSIP/242-00000146", "1?Set(ALERT_INFO=)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:36] ExecIf("PJSIP/242-00000146", "0?Set(ALERT_INFO=)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:37] ExecIf("PJSIP/242-00000146", "0?Set(ALERT_INFO=)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:38] ExecIf("PJSIP/242-00000146", "0?Set(ALERT_INFO=Normal;volume=)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:39] ExecIf("PJSIP/242-00000146", "0?Set(ALERT_INFO=Normal;volume=)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:40] GosubIf("PJSIP/242-00000146", "0?func-set-sipheader,s,1(Alert-Info,)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:41] ExecIf("PJSIP/242-00000146", "0?Set(CHANNEL(musicclass)=)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:42] GosubIf("PJSIP/242-00000146", "0?qwait,1()") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:43] Set("PJSIP/242-00000146", "__CWIGNORE=") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:44] Set("PJSIP/242-00000146", "__KEEPCID=TRUE") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:45] GotoIf("PJSIP/242-00000146", "0?usegoto,1") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:46] GotoIf("PJSIP/242-00000146", "0?godial") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:47] Gosub("PJSIP/242-00000146", "sub-presencestate-display,s,1(227)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@sub-presencestate-display:1] Goto("PJSIP/242-00000146", "state-available,1") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx_builtins.c: Goto (sub-presencestate-display,state-available,1)
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [state-available@sub-presencestate-display:1] Set("PJSIP/242-00000146", "PRESENCESTATE_DISPLAY=(Available)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [state-available@sub-presencestate-display:2] Return("PJSIP/242-00000146", "") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:48] Set("PJSIP/242-00000146", "CONNECTEDLINE(name,i)=User 2(Available)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:49] Set("PJSIP/242-00000146", "CONNECTEDLINE(num)=227") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:50] Set("PJSIP/242-00000146", "D_OPTIONS=HhTtrI") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:51] Macro("PJSIP/242-00000146", "dialout-one-predial-hook,") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dialout-one-predial-hook:1] MacroExit("PJSIP/242-00000146", "") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:52] ExecIf("PJSIP/242-00000146", "0?Set(D_OPTIONS=HhtrII)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:53] NoOp("PJSIP/242-00000146", "") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:54] ExecIf("PJSIP/242-00000146", "0?Set(D_OPTIONS=HhTtrIg)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-dial-one:55] Dial("PJSIP/242-00000146", "PJSIP/227/sip:[email protected]:5060,15,HhTtrIb(func-apply-sipheaders^s^1)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] app_stack.c: PJSIP/227-00000147 Internal Gosub(func-apply-sipheaders,s,1) start
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf("PJSIP/227-00000147", "0?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp("PJSIP/227-00000147", "Applying SIP Headers to channel PJSIP/227-00000147") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@func-apply-sipheaders:3] Set("PJSIP/227-00000147", "TECH=PJSIP") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@func-apply-sipheaders:4] Set("PJSIP/227-00000147", "SIPHEADERKEYS=") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@func-apply-sipheaders:5] While("PJSIP/227-00000147", "0") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] app_while.c: Jumping to priority 12
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] pbx.c: Executing [s@func-apply-sipheaders:13] Return("PJSIP/227-00000147", "") in new stack
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] app_stack.c: Spawn extension (from-internal, 227, 1) exited non-zero on 'PJSIP/227-00000147'
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] app_stack.c: PJSIP/227-00000147 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] app_dial.c: Called PJSIP/227/sip:[email protected]:5060
[2019-05-20 17:36:48] VERBOSE[997] netsock2.c: Using SIP RTP Audio TOS bits 184
[2019-05-20 17:36:48] VERBOSE[997] netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.
[2019-05-20 17:36:48] VERBOSE[997] netsock2.c: Using SIP RTP Audio CoS mark 5
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] app_dial.c: Connected line update to PJSIP/242-00000146 prevented.
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] app_dial.c: PJSIP/227-00000147 is ringing
[2019-05-20 17:36:48] VERBOSE[450][C-000000d6] app_dial.c: PJSIP/227-00000147 is ringing
[2019-05-20 17:36:51] VERBOSE[450][C-000000d6] app_dial.c: PJSIP/227-00000147 answered PJSIP/242-00000146
[2019-05-20 17:36:51] VERBOSE[451][C-000000d6] bridge_channel.c: Channel PJSIP/227-00000147 joined 'simple_bridge' basic-bridge <483f8669-6250-4647-bf8a-62a391bf173d>
[2019-05-20 17:36:51] VERBOSE[450][C-000000d6] bridge_channel.c: Channel PJSIP/242-00000146 joined 'simple_bridge' basic-bridge <483f8669-6250-4647-bf8a-62a391bf173d>

stefanwild · May 20, 2019, 7:51pm

Log Part 4:

[2019-05-20 17:37:01] VERBOSE[450][C-000000d6] bridge_channel.c: Channel PJSIP/242-00000146 left 'simple_bridge' basic-bridge <483f8669-6250-4647-bf8a-62a391bf173d>
[2019-05-20 17:37:01] VERBOSE[450][C-000000d6] app_macro.c: Spawn extension (macro-dial-one, s, 55) exited non-zero on 'PJSIP/242-00000146' in macro 'dial-one'
[2019-05-20 17:37:01] VERBOSE[450][C-000000d6] app_macro.c: Spawn extension (macro-exten-vm, s, 26) exited non-zero on 'PJSIP/242-00000146' in macro 'exten-vm'
[2019-05-20 17:37:01] VERBOSE[450][C-000000d6] pbx.c: Spawn extension (ext-local, 227, 2) exited non-zero on 'PJSIP/242-00000146'
[2019-05-20 17:37:01] VERBOSE[450][C-000000d6] pbx.c: Executing [h@ext-local:1] Macro("PJSIP/242-00000146", "hangupcall,") in new stack
[2019-05-20 17:37:01] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("PJSIP/242-00000146", "1?theend") in new stack
[2019-05-20 17:37:01] VERBOSE[450][C-000000d6] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2019-05-20 17:37:01] VERBOSE[451][C-000000d6] bridge_channel.c: Channel PJSIP/227-00000147 left 'simple_bridge' basic-bridge <483f8669-6250-4647-bf8a-62a391bf173d>
[2019-05-20 17:37:01] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("PJSIP/242-00000146", "0?Set(CDR(recordingfile)=)") in new stack
[2019-05-20 17:37:01] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-hangupcall:4] NoOp("PJSIP/242-00000146", "PJSIP/227-00000147 montior file= ") in new stack
[2019-05-20 17:37:01] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-hangupcall:5] GotoIf("PJSIP/242-00000146", "1?skipagi") in new stack
[2019-05-20 17:37:01] VERBOSE[450][C-000000d6] pbx_builtins.c: Goto (macro-hangupcall,s,7)
[2019-05-20 17:37:01] VERBOSE[450][C-000000d6] pbx.c: Executing [s@macro-hangupcall:7] Hangup("PJSIP/242-00000146", "") in new stack
[2019-05-20 17:37:01] VERBOSE[450][C-000000d6] app_macro.c: Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'PJSIP/242-00000146' in macro 'hangupcall'
[2019-05-20 17:37:01] VERBOSE[450][C-000000d6] pbx.c: Spawn extension (ext-local, h, 1) exited non-zero on 'PJSIP/242-00000146'
[2019-05-20 17:37:02] VERBOSE[416][C-000000d5] bridge_channel.c: Channel PJSIP/242-00000145 left 'simple_bridge' basic-bridge <6e2bbeb2-22e6-4f19-a146-2994d42b7574>
[2019-05-20 17:37:02] VERBOSE[416][C-000000d5] app_stack.c: PJSIP/242-00000145 Internal Gosub(crm-hangup,s,1) start
[2019-05-20 17:37:02] VERBOSE[416][C-000000d5] pbx.c: Executing [s@crm-hangup:1] NoOp("PJSIP/242-00000145", "Sending Hangup to CRM") in new stack
[2019-05-20 17:37:02] VERBOSE[416][C-000000d5] pbx.c: Executing [s@crm-hangup:2] NoOp("PJSIP/242-00000145", "HANGUP CAUSE: 16") in new stack
[2019-05-20 17:37:02] VERBOSE[416][C-000000d5] pbx.c: Executing [s@crm-hangup:3] ExecIf("PJSIP/242-00000145", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2019-05-20 17:37:02] VERBOSE[416][C-000000d5] pbx.c: Executing [s@crm-hangup:4] NoOp("PJSIP/242-00000145", "MASTER CHANNEL: 1558373762.423 = 1558373750.422") in new stack
[2019-05-20 17:37:02] VERBOSE[416][C-000000d5] pbx.c: Executing [s@crm-hangup:5] GotoIf("PJSIP/242-00000145", "1?return") in new stack
[2019-05-20 17:37:02] VERBOSE[416][C-000000d5] pbx_builtins.c: Goto (crm-hangup,s,8)
[2019-05-20 17:37:02] VERBOSE[416][C-000000d5] pbx.c: Executing [s@crm-hangup:8] Return("PJSIP/242-00000145", "") in new stack
[2019-05-20 17:37:02] VERBOSE[416][C-000000d5] app_stack.c: Spawn extension (from-internal, , 1) exited non-zero on 'PJSIP/242-00000145'
[2019-05-20 17:37:02] VERBOSE[416][C-000000d5] app_stack.c: PJSIP/242-00000145 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] bridge_channel.c: Channel PJSIP/SIPtrunk-00000144 left 'simple_bridge' basic-bridge <6e2bbeb2-22e6-4f19-a146-2994d42b7574>
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] res_musiconhold.c: Stopped music on hold on PJSIP/SIPtrunk-00000144
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] app_macro.c: Spawn extension (macro-dial-one, s, 55) exited non-zero on 'PJSIP/SIPtrunk-00000144' in macro 'dial-one'
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] app_macro.c: Spawn extension (macro-exten-vm, s, 26) exited non-zero on 'PJSIP/SIPtrunk-00000144' in macro 'exten-vm'
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] pbx.c: Spawn extension (ext-local, 242, 2) exited non-zero on 'PJSIP/SIPtrunk-00000144'
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [h@ext-local:1] Macro("PJSIP/SIPtrunk-00000144", "hangupcall,") in new stack
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("PJSIP/SIPtrunk-00000144", "1?theend") in new stack
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("PJSIP/SIPtrunk-00000144", "0?Set(CDR(recordingfile)=)") in new stack
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-hangupcall:4] NoOp("PJSIP/SIPtrunk-00000144", "PJSIP/242-00000145 montior file= ") in new stack
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-hangupcall:5] GotoIf("PJSIP/SIPtrunk-00000144", "1?skipagi") in new stack
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] pbx_builtins.c: Goto (macro-hangupcall,s,7)
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@macro-hangupcall:7] Hangup("PJSIP/SIPtrunk-00000144", "") in new stack
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] app_macro.c: Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'PJSIP/SIPtrunk-00000144' in macro 'hangupcall'
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] pbx.c: Spawn extension (ext-local, h, 1) exited non-zero on 'PJSIP/SIPtrunk-00000144'
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] app_stack.c: PJSIP/SIPtrunk-00000144 Internal Gosub(crm-hangup,s,1) start
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@crm-hangup:1] NoOp("PJSIP/SIPtrunk-00000144", "Sending Hangup to CRM") in new stack
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@crm-hangup:2] NoOp("PJSIP/SIPtrunk-00000144", "HANGUP CAUSE: 16") in new stack
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@crm-hangup:3] ExecIf("PJSIP/SIPtrunk-00000144", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@crm-hangup:4] NoOp("PJSIP/SIPtrunk-00000144", "MASTER CHANNEL: 1558373750.422 = 1558373750.422") in new stack
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@crm-hangup:5] GotoIf("PJSIP/SIPtrunk-00000144", "0?return") in new stack
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@crm-hangup:6] Set("PJSIP/SIPtrunk-00000144", "__CRM_HANGUP=1") in new stack
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@crm-hangup:7] AGI("PJSIP/SIPtrunk-00000144", "sangomacrm.agi") in new stack
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] res_agi.c: <PJSIP/SIPtrunk-00000144>AGI Script sangomacrm.agi completed, returning 0
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] pbx.c: Executing [s@crm-hangup:8] Return("PJSIP/SIPtrunk-00000144", "") in new stack
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] app_stack.c: Spawn extension (ext-local, h, 1) exited non-zero on 'PJSIP/SIPtrunk-00000144'
[2019-05-20 17:37:02] VERBOSE[32757][C-000000d5] app_stack.c: PJSIP/SIPtrunk-00000144 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=

stefanwild · May 22, 2019, 10:52am

Tested putting a phone onto the NATed network 172.17.189.0/24 (just changed the registration info manually) and were able to do an attended transfer of an external call to another external number. That was something that also won’t work when the phones are on the separate phone network 172.17.188.0/24.

Before I hook up the phone network to our firewall to allow internet access, are there any settings I could try to make this work through the PBX? Clearly some part of the process is trying to circumvent the PBX and establishing a direct connection when transferring. I want to say I’ve tried changing contact rewriting and forcing symmetric RTP previously, but those seem like candidates.

Any suggestions?

stefanwild · May 22, 2019, 3:43pm

Looks like this combination of extension (advanced) settings is working:
46%20AM

system · May 29, 2019, 3:44pm

This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.