Never ending saga of a remote extension

AsherN · June 11, 2020, 5:04pm

I have an interesting dilemma.

I’m setting up a new PBX for a client. FreePBX 15 behind a Sophos firewall. Similar setup we have in our office.

I have my office phone on my desk at home. Grandstream 2160, connected to my office PBX, works fine.

The client’s firewall is setup the same way except for one thing. The office restricts SIP/RTP to my home IP. The client’s Sophos passes ALL SIP/RTP to the PBX, with the responsive firewall on.

The FreePBX configuration is identical.

I have Zoiper on my iPhone.
If I’m on LTE, both outbound and inbound calls work fine. RTP debug shows sending RTP packets to and from my phone’s IP.

If I’m on Wifi, outbound calls work fine, RTP packets to and from my house’s public IP.
Inbound calls have no audio. RTP only send to my home public IP.

Zoiper is set to use a STUN server.

Any thoughts?

dicko · June 11, 2020, 7:27pm

Without any logs, all thoughts will be guesses.

AsherN · June 11, 2020, 8:17pm

Which logs do you need?

cynjut · June 11, 2020, 8:18pm

One way audio is almost always a NAT issue. This sounds exactly like a NAT issue. Try enabling NAT in Zoiper and see if that helps.

dicko · June 11, 2020, 8:36pm

The ones that show the problem, usually a snip from /var/log/asterisk/full

arielgrin · June 12, 2020, 12:42pm

In my experience, Zoiper always needs that the extension is set to NAT=yes in order for it to work correctly.

AsherN · June 12, 2020, 4:07pm

Accepting AUTHENTICATED call from 184.75.213.210:4569:
– > requested format = ulaw,
– > requested prefs = (ulaw|g729),
– > actual format = ulaw,
– > host prefs = (ulaw),
– > priority = mine
– Executing [6475551212@from-trunk:1] NoOp(“IAX2/voipms-2589”, “Catch-All DID Match - Found 6475551212 - You probably want a DID for this.”) in new stack
– Executing [6475551212@from-trunk:2] Set(“IAX2/voipms-2589”, “__FROM_DID=6475551212”) in new stack
– Executing [6475551212@from-trunk:3] Goto(“IAX2/voipms-2589”, “ext-did,s,1”) in new stack
– Goto (ext-did,s,1)
– Executing [s@ext-did:1] Set(“IAX2/voipms-2589”, “__DIRECTION=INBOUND”) in new stack
– Executing [s@ext-did:2] Gosub(“IAX2/voipms-2589”, “sub-record-check,s,1(in,s,dontcare)”) in new stack
– Executing [s@sub-record-check:1] GotoIf(“IAX2/voipms-2589”, “0?initialized”) in new stack
– Executing [s@sub-record-check:2] Set(“IAX2/voipms-2589”, “__REC_STATUS=INITIALIZED”) in new stack
– Executing [s@sub-record-check:3] Set(“IAX2/voipms-2589”, “NOW=1591977777”) in new stack
– Executing [s@sub-record-check:4] Set(“IAX2/voipms-2589”, “__DAY=12”) in new stack
– Executing [s@sub-record-check:5] Set(“IAX2/voipms-2589”, “__MONTH=06”) in new stack
– Executing [s@sub-record-check:6] Set(“IAX2/voipms-2589”, “__YEAR=2020”) in new stack
– Executing [s@sub-record-check:7] Set(“IAX2/voipms-2589”, “__TIMESTR=20200612-160257”) in new stack
– Executing [s@sub-record-check:8] Set(“IAX2/voipms-2589”, “__FROMEXTEN=unknown”) in new stack
– Executing [s@sub-record-check:9] Set(“IAX2/voipms-2589”, “__MON_FMT=wav”) in new stack
– Executing [s@sub-record-check:10] NoOp(“IAX2/voipms-2589”, “Recordings initialized”) in new stack
– Executing [s@sub-record-check:11] ExecIf(“IAX2/voipms-2589”, “0?Set(ARG3=dontcare)”) in new stack
– Executing [s@sub-record-check:12] Set(“IAX2/voipms-2589”, “REC_POLICY_MODE_SAVE=”) in new stack
– Executing [s@sub-record-check:13] ExecIf(“IAX2/voipms-2589”, “0?Set(REC_STATUS=NO)”) in new stack
– Executing [s@sub-record-check:14] GotoIf(“IAX2/voipms-2589”, “2?checkaction”) in new stack
– Goto (sub-record-check,s,17)
– Executing [s@sub-record-check:17] GotoIf(“IAX2/voipms-2589”, “1?sub-record-check,in,1”) in new stack
– Goto (sub-record-check,in,1)
– Executing [in@sub-record-check:1] NoOp(“IAX2/voipms-2589”, “Inbound Recording Check to s”) in new stack
– Executing [in@sub-record-check:2] Set(“IAX2/voipms-2589”, “FROMEXTEN=unknown”) in new stack
– Executing [in@sub-record-check:3] ExecIf(“IAX2/voipms-2589”, “10?Set(FROMEXTEN=9055551212)”) in new stack
– Executing [in@sub-record-check:4] Gosub(“IAX2/voipms-2589”, “recordcheck,1(dontcare,in,s)”) in new stack
– Executing [recordcheck@sub-record-check:1] NoOp(“IAX2/voipms-2589”, “Starting recording check against dontcare”) in new stack
– Executing [recordcheck@sub-record-check:2] Goto(“IAX2/voipms-2589”, “dontcare”) in new stack
– Goto (sub-record-check,recordcheck,3)
– Executing [recordcheck@sub-record-check:3] Return(“IAX2/voipms-2589”, “”) in new stack
– Executing [in@sub-record-check:5] Return(“IAX2/voipms-2589”, “”) in new stack
– Executing [s@ext-did:3] Set(“IAX2/voipms-2589”, “CHANNEL(tonezone)=us”) in new stack
– Executing [s@ext-did:4] ExecIf(“IAX2/voipms-2589”, “0?Set(__FROM_DID=s)”) in new stack
– Executing [s@ext-did:5] Set(“IAX2/voipms-2589”, “returnhere=1”) in new stack
– Executing [s@ext-did:6] Gosub(“IAX2/voipms-2589”, “app-blacklist-check,s,1()”) in new stack
– Executing [s@app-blacklist-check:1] GotoIf(“IAX2/voipms-2589”, “0?blacklisted”) in new stack
– Executing [s@app-blacklist-check:2] Set(“IAX2/voipms-2589”, “CALLED_BLACKLIST=1”) in new stack
– Executing [s@app-blacklist-check:3] Return(“IAX2/voipms-2589”, “”) in new stack
– Executing [s@ext-did:7] Set(“IAX2/voipms-2589”, “CDR(did)=6475551212”) in new stack
– Executing [s@ext-did:8] GotoIf(“IAX2/voipms-2589”, “0?”) in new stack
– Executing [s@ext-did:9] ExecIf(“IAX2/voipms-2589”, “0 ?Set(CALLERID(name)=9055551212)”) in new stack
– Executing [s@ext-did:10] Set(“IAX2/voipms-2589”, “CHANNEL(musicclass)=Downie”) in new stack
– Executing [s@ext-did:11] Set(“IAX2/voipms-2589”, “__MOHCLASS=Downie”) in new stack
– Executing [s@ext-did:12] Set(“IAX2/voipms-2589”, “__REVERSAL_REJECT=FALSE”) in new stack
– Executing [s@ext-did:13] GotoIf(“IAX2/voipms-2589”, “1?post-reverse-charge”) in new stack
– Goto (ext-did,s,15)
– Executing [s@ext-did:15] NoOp(“IAX2/voipms-2589”, “”) in new stack
– Executing [s@ext-did:16] Set(“IAX2/voipms-2589”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack
– Executing [s@ext-did:17] Set(“IAX2/voipms-2589”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack
– Executing [s@ext-did:18] Set(“IAX2/voipms-2589”, “CALLERID(name-pres)=allowed_not_screened”) in new stack
– Executing [s@ext-did:19] Set(“IAX2/voipms-2589”, “CALLERID(num-pres)=allowed_not_screened”) in new stack
– Executing [s@ext-did:20] NoOp(“IAX2/voipms-2589”, “CallerID Entry Point”) in new stack
– Executing [s@ext-did:21] Set(“IAX2/voipms-2589”, “__CRM_DIRECTION=INBOUND”) in new stack
– Executing [s@ext-did:22] Set(“IAX2/voipms-2589”, “__CRM_SOURCE=9055551212”) in new stack
– Executing [s@ext-did:23] Set(“IAX2/voipms-2589”, “__CRM_LINKEDID=1591977777.291”) in new stack
– Executing [s@ext-did:24] AGI(“IAX2/voipms-2589”, “agi://127.0.0.1/sangomacrm.agi,true”) in new stack
– <IAX2/voipms-2589>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
– Executing [s@ext-did:25] ExecIf(“IAX2/voipms-2589”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
– Executing [s@ext-did:26] Goto(“IAX2/voipms-2589”, “ivr-1,s,1”) in new stack
– Goto (ivr-1,s,1)
– Executing [s@ivr-1:1] Set(“IAX2/voipms-2589”, “TIMEOUT_LOOPCOUNT=0”) in new stack
– Executing [s@ivr-1:2] Set(“IAX2/voipms-2589”, “INVALID_LOOPCOUNT=0”) in new stack
– Executing [s@ivr-1:3] Set(“IAX2/voipms-2589”, “_IVR_CONTEXT_ivr-1=”) in new stack
– Executing [s@ivr-1:4] Set(“IAX2/voipms-2589”, “_IVR_CONTEXT=ivr-1”) in new stack
– Executing [s@ivr-1:5] Set(“IAX2/voipms-2589”, “__IVR_RETVM=”) in new stack
– Executing [s@ivr-1:6] GotoIf(“IAX2/voipms-2589”, “0?skip”) in new stack
– Executing [s@ivr-1:7] Answer(“IAX2/voipms-2589”, “”) in new stack
– Executing [s@ivr-1:8] Set(“IAX2/voipms-2589”, “IVR_MSG=custom/DWF_Phone_Message_2020”) in new stack
– Executing [s@ivr-1:9] Set(“IAX2/voipms-2589”, “TIMEOUT(digit)=3”) in new stack
– Digit timeout set to 3.000
– Executing [s@ivr-1:10] ExecIf(“IAX2/voipms-2589”, “1?Background(custom/DWF_Phone_Message_2020)”) in new stack
– <IAX2/voipms-2589> Playing ‘custom/DWF_Phone_Message_2020.slin’ (language ‘en’)
– Executing [31@ivr-1:1] GotoIf(“IAX2/voipms-2589”, “0?i,1”) in new stack
– Executing [31@ivr-1:2] Macro(“IAX2/voipms-2589”, “blkvm-clr,”) in new stack
– Executing [s@macro-blkvm-clr:1] Set(“IAX2/voipms-2589”, “SHARED(BLKVM,)=”) in new stack
– Executing [s@macro-blkvm-clr:2] Set(“IAX2/voipms-2589”, “GOSUB_RETVAL=”) in new stack
– Executing [s@macro-blkvm-clr:3] MacroExit(“IAX2/voipms-2589”, “”) in new stack
– Executing [31@ivr-1:3] Set(“IAX2/voipms-2589”, “__NODEST=”) in new stack
– Executing [31@ivr-1:4] Goto(“IAX2/voipms-2589”, “from-did-direct,31,1”) in new stack
– Goto (from-did-direct,31,1)
– Executing [31@from-did-direct:1] GotoIf(“IAX2/voipms-2589”, “1?ext-local,31,1:followme-check,31,1”) in new stack
– Goto (ext-local,31,1)
– Executing [31@ext-local:1] Set(“IAX2/voipms-2589”, “__RINGTIMER=15”) in new stack
– Executing [31@ext-local:2] ExecIf(“IAX2/voipms-2589”, “0?Set(__CWIGNORE=)”) in new stack
– Executing [31@ext-local:3] Macro(“IAX2/voipms-2589”, “exten-vm,novm,31,0,0,0”) in new stack
– Executing [s@macro-exten-vm:1] Macro(“IAX2/voipms-2589”, “user-callerid,”) in new stack
– Executing [s@macro-user-callerid:1] Set(“IAX2/voipms-2589”, “TOUCH_MONITOR=1591977777.291”) in new stack
– Executing [s@macro-user-callerid:2] Set(“IAX2/voipms-2589”, “AMPUSER=9055551212”) in new stack
– Executing [s@macro-user-callerid:3] Set(“IAX2/voipms-2589”, “HOTDESCKCHAN=voipms-2589”) in new stack
– Executing [s@macro-user-callerid:4] Set(“IAX2/voipms-2589”, “HOTDESKEXTEN=voipms”) in new stack
– Executing [s@macro-user-callerid:5] Set(“IAX2/voipms-2589”, “HOTDESKCALL=0”) in new stack
– Executing [s@macro-user-callerid:6] ExecIf(“IAX2/voipms-2589”, “0?Set(HOTDESKCALL=1)”) in new stack
– Executing [s@macro-user-callerid:7] ExecIf(“IAX2/voipms-2589”, “0?Set(CALLERID(name)=)”) in new stack
– Executing [s@macro-user-callerid:8] GotoIf(“IAX2/voipms-2589”, “0?report”) in new stack
– Executing [s@macro-user-callerid:9] ExecIf(“IAX2/voipms-2589”, “1?Set(REALCALLERIDNUM=9055551212)”) in new stack
– Executing [s@macro-user-callerid:10] Set(“IAX2/voipms-2589”, “AMPUSER=”) in new stack
– Executing [s@macro-user-callerid:11] GotoIf(“IAX2/voipms-2589”, “0?limit”) in new stack
– Executing [s@macro-user-callerid:12] Set(“IAX2/voipms-2589”, “AMPUSERCIDNAME=”) in new stack
– Executing [s@macro-user-callerid:13] ExecIf(“IAX2/voipms-2589”, “0?Set(__CIDMASQUERADING=TRUE)”) in new stack
– Executing [s@macro-user-callerid:14] GotoIf(“IAX2/voipms-2589”, “1?report”) in new stack
– Goto (macro-user-callerid,s,22)
– Executing [s@macro-user-callerid:22] NoOp(“IAX2/voipms-2589”, “Macro Depth is 2”) in new stack
– Executing [s@macro-user-callerid:23] GotoIf(“IAX2/voipms-2589”, “1?report2:macroerror”) in new stack
– Goto (macro-user-callerid,s,24)
– Executing [s@macro-user-callerid:24] GotoIf(“IAX2/voipms-2589”, “0?continue”) in new stack
– Executing [s@macro-user-callerid:25] ExecIf(“IAX2/voipms-2589”, “1?Set(__CALLEE_ACCOUNCODE=)”) in new stack
– Executing [s@macro-user-callerid:26] Set(“IAX2/voipms-2589”, “__TTL=64”) in new stack
– Executing [s@macro-user-callerid:27] GotoIf(“IAX2/voipms-2589”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,43)
– Executing [s@macro-user-callerid:43] Set(“IAX2/voipms-2589”, “CALLERID(number)=9055551212”) in new stack
– Executing [s@macro-user-callerid:44] Set(“IAX2/voipms-2589”, “CALLERID(name)=Adam S”) in new stack
– Executing [s@macro-user-callerid:45] GotoIf(“IAX2/voipms-2589”, “0?cnum”) in new stack
– Executing [s@macro-user-callerid:46] Set(“IAX2/voipms-2589”, “CDR(cnam)=Adam S”) in new stack
– Executing [s@macro-user-callerid:47] Set(“IAX2/voipms-2589”, “CDR(cnum)=9055551212”) in new stack
– Executing [s@macro-user-callerid:48] Set(“IAX2/voipms-2589”, “CHANNEL(language)=en”) in new stack
– Executing [s@macro-exten-vm:2] Set(“IAX2/voipms-2589”, “RingGroupMethod=none”) in new stack
– Executing [s@macro-exten-vm:3] Set(“IAX2/voipms-2589”, “__EXTTOCALL=31”) in new stack
– Executing [s@macro-exten-vm:4] Set(“IAX2/voipms-2589”, “__PICKUPMARK=31”) in new stack
– Executing [s@macro-exten-vm:5] Set(“IAX2/voipms-2589”, “RT=”) in new stack
[2020-06-12 16:03:04] WARNING[2912][C-00000120]: chan_sip.c:23255 func_header_read: This function can only be used on SIP channels.
– Executing [s@macro-exten-vm:6] ExecIf(“IAX2/voipms-2589”, “0?Macro(vm,novm,DIRECTDIAL,)”) in new stack
[2020-06-12 16:03:04] WARNING[2912][C-00000120]: chan_sip.c:23255 func_header_read: This function can only be used on SIP channels.
[2020-06-12 16:03:04] WARNING[2912][C-00000120]: chan_sip.c:23255 func_header_read: This function can only be used on SIP channels.
– Executing [s@macro-exten-vm:7] ExecIf(“IAX2/voipms-2589”, “0?MacroExit()”) in new stack
[2020-06-12 16:03:04] WARNING[2912][C-00000120]: chan_sip.c:23255 func_header_read: This function can only be used on SIP channels.
[2020-06-12 16:03:04] WARNING[2912][C-00000120]: chan_sip.c:23255 func_header_read: This function can only be used on SIP channels.
– Executing [s@macro-exten-vm:8] ExecIf(“IAX2/voipms-2589”, “0?Gosub(ext-intercom,*8031,1())”) in new stack
[2020-06-12 16:03:04] WARNING[2912][C-00000120]: chan_sip.c:23255 func_header_read: This function can only be used on SIP channels.
[2020-06-12 16:03:04] WARNING[2912][C-00000120]: chan_sip.c:23255 func_header_read: This function can only be used on SIP channels.
– Executing [s@macro-exten-vm:9] ExecIf(“IAX2/voipms-2589”, “0?MacroExit()”) in new stack
[2020-06-12 16:03:04] WARNING[2912][C-00000120]: chan_sip.c:23255 func_header_read: This function can only be used on SIP channels.
[2020-06-12 16:03:04] WARNING[2912][C-00000120]: chan_sip.c:23255 func_header_read: This function can only be used on SIP channels.
– Executing [s@macro-exten-vm:10] ExecIf(“IAX2/voipms-2589”, “0?ChanSpy(PJSIP/31,q)”) in new stack
[2020-06-12 16:03:04] WARNING[2912][C-00000120]: chan_sip.c:23255 func_header_read: This function can only be used on SIP channels.
[2020-06-12 16:03:04] WARNING[2912][C-00000120]: chan_sip.c:23255 func_header_read: This function can only be used on SIP channels.
– Executing [s@macro-exten-vm:11] ExecIf(“IAX2/voipms-2589”, “0?MacroExit()”) in new stack
[2020-06-12 16:03:04] WARNING[2912][C-00000120]: chan_sip.c:23255 func_header_read: This function can only be used on SIP channels.
[2020-06-12 16:03:04] ERROR[2912][C-00000120]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
– Executing [s@macro-exten-vm:12] ExecIf(“IAX2/voipms-2589”, “0?Macro(vm,novm,DIRECTDIAL,)”) in new stack
[2020-06-12 16:03:04] ERROR[2912][C-00000120]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2020-06-12 16:03:04] ERROR[2912][C-00000120]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
– Executing [s@macro-exten-vm:13] ExecIf(“IAX2/voipms-2589”, “0?MacroExit()”) in new stack
[2020-06-12 16:03:04] ERROR[2912][C-00000120]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2020-06-12 16:03:04] ERROR[2912][C-00000120]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
– Executing [s@macro-exten-vm:14] ExecIf(“IAX2/voipms-2589”, “0?Gosub(ext-intercom,*8031,1())”) in new stack
[2020-06-12 16:03:04] ERROR[2912][C-00000120]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2020-06-12 16:03:04] ERROR[2912][C-00000120]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
– Executing [s@macro-exten-vm:15] ExecIf(“IAX2/voipms-2589”, “0?MacroExit()”) in new stack
[2020-06-12 16:03:04] ERROR[2912][C-00000120]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2020-06-12 16:03:04] ERROR[2912][C-00000120]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
– Executing [s@macro-exten-vm:16] ExecIf(“IAX2/voipms-2589”, “0?ChanSpy(PJSIP/31,q)”) in new stack
[2020-06-12 16:03:04] ERROR[2912][C-00000120]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
[2020-06-12 16:03:04] ERROR[2912][C-00000120]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
– Executing [s@macro-exten-vm:17] ExecIf(“IAX2/voipms-2589”, “0?MacroExit()”) in new stack
[2020-06-12 16:03:04] ERROR[2912][C-00000120]: res_pjsip_header_funcs.c:454 func_read_header: This function requires a PJSIP channel.
– Executing [s@macro-exten-vm:18] Gosub(“IAX2/voipms-2589”, “sub-record-check,s,1(exten,31,dontcare)”) in new stack
– Executing [s@sub-record-check:1] GotoIf(“IAX2/voipms-2589”, “10?initialized”) in new stack
– Goto (sub-record-check,s,10)
– Executing [s@sub-record-check:10] NoOp(“IAX2/voipms-2589”, “Recordings initialized”) in new stack
– Executing [s@sub-record-check:11] ExecIf(“IAX2/voipms-2589”, “0?Set(ARG3=dontcare)”) in new stack
– Executing [s@sub-record-check:12] Set(“IAX2/voipms-2589”, “REC_POLICY_MODE_SAVE=”) in new stack
– Executing [s@sub-record-check:13] ExecIf(“IAX2/voipms-2589”, “0?Set(REC_STATUS=NO)”) in new stack
– Executing [s@sub-record-check:14] GotoIf(“IAX2/voipms-2589”, “5?checkaction”) in new stack
– Goto (sub-record-check,s,17)
– Executing [s@sub-record-check:17] GotoIf(“IAX2/voipms-2589”, “1?sub-record-check,exten,1”) in new stack
– Goto (sub-record-check,exten,1)
– Executing [exten@sub-record-check:1] NoOp(“IAX2/voipms-2589”, “Exten Recording Check between 9055551212 and 31”) in new stack
– Executing [exten@sub-record-check:2] Set(“IAX2/voipms-2589”, “CALLTYPE=external”) in new stack
– Executing [exten@sub-record-check:3] ExecIf(“IAX2/voipms-2589”, “0?Set(CALLTYPE=)”) in new stack
– Executing [exten@sub-record-check:4] Set(“IAX2/voipms-2589”, “CALLEE=dontcare”) in new stack
– Executing [exten@sub-record-check:5] ExecIf(“IAX2/voipms-2589”, “0?Set(CALLEE=dontcare)”) in new stack
– Executing [exten@sub-record-check:6] GotoIf(“IAX2/voipms-2589”, “1?callee”) in new stack
– Goto (sub-record-check,exten,11)
– Executing [exten@sub-record-check:11] Gosub(“IAX2/voipms-2589”, “recordcheck,1(dontcare,external,31)”) in new stack
– Executing [recordcheck@sub-record-check:1] NoOp(“IAX2/voipms-2589”, “Starting recording check against dontcare”) in new stack
– Executing [recordcheck@sub-record-check:2] Goto(“IAX2/voipms-2589”, “dontcare”) in new stack
– Goto (sub-record-check,recordcheck,3)
– Executing [recordcheck@sub-record-check:3] Return(“IAX2/voipms-2589”, “”) in new stack
– Executing [exten@sub-record-check:12] Return(“IAX2/voipms-2589”, “”) in new stack
– Executing [s@macro-exten-vm:19] GotoIf(“IAX2/voipms-2589”, “1?macrodial”) in new stack
– Goto (macro-exten-vm,s,25)
– Executing [s@macro-exten-vm:25] GosubIf(“IAX2/voipms-2589”, “0?clrheader,1()”) in new stack
– Executing [s@macro-exten-vm:26] Macro(“IAX2/voipms-2589”, “dial-one,HhTtr,31”) in new stack
– Executing [s@macro-dial-one:1] Set(“IAX2/voipms-2589”, “DEXTEN=31”) in new stack
– Executing [s@macro-dial-one:2] Set(“IAX2/voipms-2589”, “__CRM_SOURCE=9055551212”) in new stack
– Executing [s@macro-dial-one:3] ExecIf(“IAX2/voipms-2589”, “0?Set(__EXTTOCALL=31)”) in new stack
– Executing [s@macro-dial-one:4] Set(“IAX2/voipms-2589”, “DIALSTATUS_CW=”) in new stack
– Executing [s@macro-dial-one:5] GosubIf(“IAX2/voipms-2589”, “0?screen,1()”) in new stack
– Executing [s@macro-dial-one:6] GosubIf(“IAX2/voipms-2589”, “0?cf,1()”) in new stack
– Executing [s@macro-dial-one:7] GotoIf(“IAX2/voipms-2589”, “1?skip1”) in new stack
– Goto (macro-dial-one,s,10)
– Executing [s@macro-dial-one:10] GotoIf(“IAX2/voipms-2589”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:11] GotoIf(“IAX2/voipms-2589”, “0?continue”) in new stack
– Executing [s@macro-dial-one:12] Set(“IAX2/voipms-2589”, “EXTHASCW=ENABLED”) in new stack
– Executing [s@macro-dial-one:13] GotoIf(“IAX2/voipms-2589”, “0?next1:cwinusebusy”) in new stack
– Goto (macro-dial-one,s,25)
– Executing [s@macro-dial-one:25] GotoIf(“IAX2/voipms-2589”, “0?next3:continue”) in new stack
– Goto (macro-dial-one,s,27)
– Executing [s@macro-dial-one:27] GotoIf(“IAX2/voipms-2589”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:28] GosubIf(“IAX2/voipms-2589”, “1?dstring,1():dlocal,1()”) in new stack
– Executing [dstring@macro-dial-one:1] Set(“IAX2/voipms-2589”, “DSTRING=”) in new stack
– Executing [dstring@macro-dial-one:2] Set(“IAX2/voipms-2589”, “DEVICES=31”) in new stack
– Executing [dstring@macro-dial-one:3] ExecIf(“IAX2/voipms-2589”, “0?Return()”) in new stack
– Executing [dstring@macro-dial-one:4] ExecIf(“IAX2/voipms-2589”, “0?Set(DEVICES=1)”) in new stack
– Executing [dstring@macro-dial-one:5] Set(“IAX2/voipms-2589”, “LOOPCNT=1”) in new stack
– Executing [dstring@macro-dial-one:6] Set(“IAX2/voipms-2589”, “ITER=1”) in new stack
– Executing [dstring@macro-dial-one:7] Set(“IAX2/voipms-2589”, “THISDIAL=PJSIP/31”) in new stack
– Executing [dstring@macro-dial-one:8] GotoIf(“IAX2/voipms-2589”, “0?docheck”) in new stack
– Executing [dstring@macro-dial-one:9] NoOp(“IAX2/voipms-2589”, “Debug: Found PJSIP Destination PJSIP/31”) in new stack
– Executing [dstring@macro-dial-one:10] GotoIf(“IAX2/voipms-2589”, “0?doset”) in new stack
– Executing [dstring@macro-dial-one:11] NoOp(“IAX2/voipms-2589”, “Debug: Updating PJSIP Destination with PJSIP_DIAL_CONTACTS”) in new stack
– Executing [dstring@macro-dial-one:12] Set(“IAX2/voipms-2589”, “THISDIAL=PJSIP/31/sip:31@<my_public_IP>:51330;rinstance=704d51a758b29e8f”) in new stack
– Executing [dstring@macro-dial-one:13] ExecIf(“IAX2/voipms-2589”, “0?Set(DIALSTATUS=CHANUNAVAIL)”) in new stack
– Executing [dstring@macro-dial-one:14] GotoIf(“IAX2/voipms-2589”, “0?skipset”) in new stack
– Executing [dstring@macro-dial-one:15] Set(“IAX2/voipms-2589”, “DSTRING=PJSIP/31/sip:31@<my_public_IP>:51330;rinstance=704d51a758b29e8f&”) in new stack
– Executing [dstring@macro-dial-one:16] Set(“IAX2/voipms-2589”, “ITER=2”) in new stack
– Executing [dstring@macro-dial-one:17] GotoIf(“IAX2/voipms-2589”, “0?begin”) in new stack
– Executing [dstring@macro-dial-one:18] ExecIf(“IAX2/voipms-2589”, “0?Return()”) in new stack
– Executing [dstring@macro-dial-one:19] Set(“IAX2/voipms-2589”, “DSTRING=PJSIP/31/sip:31@<my_public_IP>:51330;rinstance=704d51a758b29e8f”) in new stack
– Executing [dstring@macro-dial-one:20] Return(“IAX2/voipms-2589”, “”) in new stack
– Executing [s@macro-dial-one:29] GotoIf(“IAX2/voipms-2589”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:30] GotoIf(“IAX2/voipms-2589”, “0?skiptrace”) in new stack
– Executing [s@macro-dial-one:31] GosubIf(“IAX2/voipms-2589”, “1?ctset,1():ctclear,1()”) in new stack
– Executing [ctset@macro-dial-one:1] Set(“IAX2/voipms-2589”, “DB(CALLTRACE/31)=9055551212”) in new stack
– Executing [ctset@macro-dial-one:2] Return(“IAX2/voipms-2589”, “”) in new stack
– Executing [s@macro-dial-one:32] Set(“IAX2/voipms-2589”, “D_OPTIONS=HhTtr”) in new stack
– Executing [s@macro-dial-one:33] GosubIf(“IAX2/voipms-2589”, “0?func-set-sipheader,s,1(Alert-Info,)”) in new stack
– Executing [s@macro-dial-one:34] NoOp(“IAX2/voipms-2589”, "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
– Executing [s@macro-dial-one:35] ExecIf(“IAX2/voipms-2589”, “0?Set(ALERT_INFO=)”) in new stack
– Executing [s@macro-dial-one:36] ExecIf(“IAX2/voipms-2589”, “0?Set(ALERT_INFO=)”) in new stack
– Executing [s@macro-dial-one:37] ExecIf(“IAX2/voipms-2589”, “0?Set(ALERT_INFO=)”) in new stack
– Executing [s@macro-dial-one:38] ExecIf(“IAX2/voipms-2589”, “0?Set(ALERT_INFO=Normal;volume=)”) in new stack
– Executing [s@macro-dial-one:39] ExecIf(“IAX2/voipms-2589”, “0?Set(ALERT_INFO=Normal;volume=)”) in new stack
– Executing [s@macro-dial-one:40] GosubIf(“IAX2/voipms-2589”, “0?func-set-sipheader,s,1(Alert-Info,)”) in new stack
– Executing [s@macro-dial-one:41] ExecIf(“IAX2/voipms-2589”, “1?Set(CHANNEL(musicclass)=Downie)”) in new stack
– Executing [s@macro-dial-one:42] GosubIf(“IAX2/voipms-2589”, “0?qwait,1()”) in new stack
– Executing [s@macro-dial-one:43] Set(“IAX2/voipms-2589”, “__CWIGNORE=”) in new stack
– Executing [s@macro-dial-one:44] Set(“IAX2/voipms-2589”, “__KEEPCID=TRUE”) in new stack
– Executing [s@macro-dial-one:45] GotoIf(“IAX2/voipms-2589”, “0?usegoto,1”) in new stack
– Executing [s@macro-dial-one:46] GotoIf(“IAX2/voipms-2589”, “1?godial”) in new stack
– Goto (macro-dial-one,s,51)
– Executing [s@macro-dial-one:51] Macro(“IAX2/voipms-2589”, “dialout-one-predial-hook,”) in new stack
– Executing [s@macro-dialout-one-predial-hook:1] MacroExit(“IAX2/voipms-2589”, “”) in new stack
– Executing [s@macro-dial-one:52] ExecIf(“IAX2/voipms-2589”, “1?Set(D_OPTIONS=HhtrI)”) in new stack
– Executing [s@macro-dial-one:53] ExecIf(“IAX2/voipms-2589”, “0?Set(CWRING=r(callwaiting)):Set(CWRING=)”) in new stack
– Executing [s@macro-dial-one:54] NoOp(“IAX2/voipms-2589”, “”) in new stack
– Executing [s@macro-dial-one:55] ExecIf(“IAX2/voipms-2589”, “0?Set(D_OPTIONS=HhtrIg)”) in new stack
– Executing [s@macro-dial-one:56] Dial(“IAX2/voipms-2589”, “PJSIP/31/sip:31@<my_public_IP>:51330;rinstance=704d51a758b29e8f,HhtrIb(func-apply-sipheaders^s^1)”) in new stack
– PJSIP/31-0000011d Internal Gosub(func-apply-sipheaders,s,1) start
– Executing [s@func-apply-sipheaders:1] ExecIf(“PJSIP/31-0000011d”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
– Executing [s@func-apply-sipheaders:2] NoOp(“PJSIP/31-0000011d”, “Applying SIP Headers to channel PJSIP/31-0000011d”) in new stack
– Executing [s@func-apply-sipheaders:3] Set(“PJSIP/31-0000011d”, “TECH=PJSIP”) in new stack
– Executing [s@func-apply-sipheaders:4] Set(“PJSIP/31-0000011d”, “SIPHEADERKEYS=”) in new stack
– Executing [s@func-apply-sipheaders:5] While(“PJSIP/31-0000011d”, “0”) in new stack
– Jumping to priority 13
– Executing [s@func-apply-sipheaders:14] Return(“PJSIP/31-0000011d”, “”) in new stack
== Spawn extension (from-internal, 31, 1) exited non-zero on ‘PJSIP/31-0000011d’
– PJSIP/31-0000011d Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
– Called PJSIP/31/sip:31@<my_public_IP>:51330;rinstance=704d51a758b29e8f
== Using SIP RTP Audio TOS bits 184
== Using SIP RTP Audio TOS bits 184 in TCLASS field.
== Using SIP RTP Audio CoS mark 5
– Connected line update to IAX2/voipms-2589 prevented.
– PJSIP/31-0000011d is ringing
– PJSIP/31-0000011d is ringing
– PJSIP/31-0000011d answered IAX2/voipms-2589
– Channel PJSIP/31-0000011d joined ‘simple_bridge’ basic-bridge <4658fc16-0481-4e9f-a848-9bc8d0daff4c>
– Channel IAX2/voipms-2589 joined ‘simple_bridge’ basic-bridge <4658fc16-0481-4e9f-a848-9bc8d0daff4c>
Sent RTP packet to <my_public_IP>:35654 (type 00, seq 010483, ts 000160, len 000160)

Sent RTP packet to <my_public_IP>:35654 (type 00, seq 010545, ts 010080, len 000160)
– Channel IAX2/voipms-2589 left ‘simple_bridge’ basic-bridge <4658fc16-0481-4e9f-a848-9bc8d0daff4c>
== Spawn extension (macro-dial-one, s, 56) exited non-zero on ‘IAX2/voipms-2589’ in macro ‘dial-one’
== Spawn extension (macro-exten-vm, s, 26) exited non-zero on ‘IAX2/voipms-2589’ in macro ‘exten-vm’
== Spawn extension (ext-local, 31, 3) exited non-zero on ‘IAX2/voipms-2589’
– Executing [h@ext-local:1] Macro(“IAX2/voipms-2589”, “hangupcall,”) in new stack
– Executing [s@macro-hangupcall:1] GotoIf(“IAX2/voipms-2589”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,3)
– Executing [s@macro-hangupcall:3] ExecIf(“IAX2/voipms-2589”, “0?Set(CDR(recordingfile)=)”) in new stack
– Channel PJSIP/31-0000011d left ‘simple_bridge’ basic-bridge <4658fc16-0481-4e9f-a848-9bc8d0daff4c>
– PJSIP/31-0000011d Internal Gosub(crm-hangup,s,1) start
– Executing [s@crm-hangup:1] NoOp(“PJSIP/31-0000011d”, “Sending Hangup to CRM”) in new stack
– Executing [s@crm-hangup:2] NoOp(“PJSIP/31-0000011d”, “HANGUP CAUSE: 16”) in new stack
– Executing [s@crm-hangup:3] ExecIf(“PJSIP/31-0000011d”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
– Executing [s@crm-hangup:4] NoOp(“PJSIP/31-0000011d”, “MASTER CHANNEL: 1591977784.292 = 1591977777.291”) in new stack
– Executing [s@crm-hangup:5] GotoIf(“PJSIP/31-0000011d”, “1?return”) in new stack
– Goto (crm-hangup,s,8)
– Executing [s@crm-hangup:8] Return(“PJSIP/31-0000011d”, “”) in new stack
== Spawn extension (from-internal, , 1) exited non-zero on ‘PJSIP/31-0000011d’
– PJSIP/31-0000011d Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
– Executing [s@macro-hangupcall:4] NoOp(“IAX2/voipms-2589”, "PJSIP/31-0000011d montior file= ") in new stack
– Executing [s@macro-hangupcall:5] GotoIf(“IAX2/voipms-2589”, “1?skipagi”) in new stack
– Goto (macro-hangupcall,s,7)
– Executing [s@macro-hangupcall:7] Hangup(“IAX2/voipms-2589”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 7) exited non-zero on ‘IAX2/voipms-2589’ in macro ‘hangupcall’
== Spawn extension (ext-local, h, 1) exited non-zero on ‘IAX2/voipms-2589’
– IAX2/voipms-2589 Internal Gosub(crm-hangup,s,1) start
– Executing [s@crm-hangup:1] NoOp(“IAX2/voipms-2589”, “Sending Hangup to CRM”) in new stack
– Executing [s@crm-hangup:2] NoOp(“IAX2/voipms-2589”, “HANGUP CAUSE: 16”) in new stack
– Executing [s@crm-hangup:3] ExecIf(“IAX2/voipms-2589”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
– Executing [s@crm-hangup:4] NoOp(“IAX2/voipms-2589”, “MASTER CHANNEL: 1591977777.291 = 1591977777.291”) in new stack
– Executing [s@crm-hangup:5] GotoIf(“IAX2/voipms-2589”, “0?return”) in new stack
– Executing [s@crm-hangup:6] Set(“IAX2/voipms-2589”, “__CRM_HANGUP=1”) in new stack
– Executing [s@crm-hangup:7] AGI(“IAX2/voipms-2589”, “agi://127.0.0.1/sangomacrm.agi”) in new stack
– <IAX2/voipms-2589>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
– Executing [s@crm-hangup:8] Return(“IAX2/voipms-2589”, “”) in new stack
== Spawn extension (ext-local, h, 1) exited non-zero on ‘IAX2/voipms-2589’
– IAX2/voipms-2589 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
– Hungup ‘IAX2/voipms-2589’

dicko · June 12, 2020, 4:36pm

IAX2 does all its signaling and media over port udp/4569 make sure your firewall is passing it without mangling it

AsherN · June 12, 2020, 5:01pm

It is

dicko · June 12, 2020, 5:02pm

Post the logs from /var/log/asterisk/full instead of from the console to include the timestamps . . .

AsherN · June 12, 2020, 5:26pm

[2020-06-12 17:20:20] VERBOSE[11635] chan_iax2.c: Accepting AUTHENTICATED call from 184.75.213.210:4569:
> requested format = ulaw,
> requested prefs = (ulaw|g729),
> actual format = ulaw,
> host prefs = (ulaw),
> priority = mine
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [6475551212@from-trunk:1] NoOp(“IAX2/voipms-12305”, “Catch-All DID Match - Found 6475551212 - You probably want a DID for this.”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [6475551212@from-trunk:2] Set(“IAX2/voipms-12305”, “__FROM_DID=6475551212”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [6475551212@from-trunk:3] Goto(“IAX2/voipms-12305”, “ext-did,s,1”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (ext-did,s,1)
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:1] Set(“IAX2/voipms-12305”, “__DIRECTION=INBOUND”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:2] Gosub(“IAX2/voipms-12305”, “sub-record-check,s,1(in,s,dontcare)”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:1] GotoIf(“IAX2/voipms-12305”, “0?initialized”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:2] Set(“IAX2/voipms-12305”, “__REC_STATUS=INITIALIZED”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:3] Set(“IAX2/voipms-12305”, “NOW=1591982420”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:4] Set(“IAX2/voipms-12305”, “__DAY=12”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:5] Set(“IAX2/voipms-12305”, “__MONTH=06”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:6] Set(“IAX2/voipms-12305”, “__YEAR=2020”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:7] Set(“IAX2/voipms-12305”, “__TIMESTR=20200612-172020”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:8] Set(“IAX2/voipms-12305”, “__FROMEXTEN=unknown”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:9] Set(“IAX2/voipms-12305”, “__MON_FMT=wav”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:10] NoOp(“IAX2/voipms-12305”, “Recordings initialized”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:11] ExecIf(“IAX2/voipms-12305”, “0?Set(ARG3=dontcare)”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:12] Set(“IAX2/voipms-12305”, “REC_POLICY_MODE_SAVE=”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:13] ExecIf(“IAX2/voipms-12305”, “0?Set(REC_STATUS=NO)”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:14] GotoIf(“IAX2/voipms-12305”, “2?checkaction”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (sub-record-check,s,17)
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:17] GotoIf(“IAX2/voipms-12305”, “1?sub-record-check,in,1”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (sub-record-check,in,1)
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [in@sub-record-check:1] NoOp(“IAX2/voipms-12305”, “Inbound Recording Check to s”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [in@sub-record-check:2] Set(“IAX2/voipms-12305”, “FROMEXTEN=unknown”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [in@sub-record-check:3] ExecIf(“IAX2/voipms-12305”, “10?Set(FROMEXTEN=9055551212)”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [in@sub-record-check:4] Gosub(“IAX2/voipms-12305”, “recordcheck,1(dontcare,in,s)”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp(“IAX2/voipms-12305”, “Starting recording check against dontcare”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [recordcheck@sub-record-check:2] Goto(“IAX2/voipms-12305”, “dontcare”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [recordcheck@sub-record-check:3] Return(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [in@sub-record-check:5] Return(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:3] Set(“IAX2/voipms-12305”, “CHANNEL(tonezone)=us”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:4] ExecIf(“IAX2/voipms-12305”, “0?Set(__FROM_DID=s)”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:5] Set(“IAX2/voipms-12305”, “returnhere=1”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:6] Gosub(“IAX2/voipms-12305”, “app-blacklist-check,s,1()”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@app-blacklist-check:1] GotoIf(“IAX2/voipms-12305”, “0?blacklisted”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@app-blacklist-check:2] Set(“IAX2/voipms-12305”, “CALLED_BLACKLIST=1”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@app-blacklist-check:3] Return(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:7] Set(“IAX2/voipms-12305”, “CDR(did)=6475551212”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:8] GotoIf(“IAX2/voipms-12305”, “0?”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:9] ExecIf(“IAX2/voipms-12305”, “0 ?Set(CALLERID(name)=9055551212)”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:10] Set(“IAX2/voipms-12305”, “CHANNEL(musicclass)=Downie”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:11] Set(“IAX2/voipms-12305”, “__MOHCLASS=Downie”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:12] Set(“IAX2/voipms-12305”, “__REVERSAL_REJECT=FALSE”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:13] GotoIf(“IAX2/voipms-12305”, “1?post-reverse-charge”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (ext-did,s,15)
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:15] NoOp(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:16] Set(“IAX2/voipms-12305”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:17] Set(“IAX2/voipms-12305”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:18] Set(“IAX2/voipms-12305”, “CALLERID(name-pres)=allowed_not_screened”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:19] Set(“IAX2/voipms-12305”, “CALLERID(num-pres)=allowed_not_screened”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:20] NoOp(“IAX2/voipms-12305”, “CallerID Entry Point”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:21] Set(“IAX2/voipms-12305”, “__CRM_DIRECTION=INBOUND”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:22] Set(“IAX2/voipms-12305”, “__CRM_SOURCE=9055551212”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:23] Set(“IAX2/voipms-12305”, “__CRM_LINKEDID=1591982420.298”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:24] AGI(“IAX2/voipms-12305”, “agi://127.0.0.1/sangomacrm.agi,true”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] res_agi.c: <IAX2/voipms-12305>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:25] ExecIf(“IAX2/voipms-12305”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ext-did:26] Goto(“IAX2/voipms-12305”, “ivr-1,s,1”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (ivr-1,s,1)
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ivr-1:1] Set(“IAX2/voipms-12305”, “TIMEOUT_LOOPCOUNT=0”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ivr-1:2] Set(“IAX2/voipms-12305”, “INVALID_LOOPCOUNT=0”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ivr-1:3] Set(“IAX2/voipms-12305”, “_IVR_CONTEXT_ivr-1=”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ivr-1:4] Set(“IAX2/voipms-12305”, “_IVR_CONTEXT=ivr-1”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ivr-1:5] Set(“IAX2/voipms-12305”, “__IVR_RETVM=”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ivr-1:6] GotoIf(“IAX2/voipms-12305”, “0?skip”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ivr-1:7] Answer(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ivr-1:8] Set(“IAX2/voipms-12305”, “IVR_MSG=custom/DWF_Phone_Message_2020”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ivr-1:9] Set(“IAX2/voipms-12305”, “TIMEOUT(digit)=3”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] func_timeout.c: Digit timeout set to 3.000
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [s@ivr-1:10] ExecIf(“IAX2/voipms-12305”, “1?Background(custom/DWF_Phone_Message_2020)”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] file.c: <IAX2/voipms-12305> Playing ‘custom/DWF_Phone_Message_2020.slin’ (language ‘en’)
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [31@ivr-1:1] GotoIf(“IAX2/voipms-12305”, “0?i,1”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [31@ivr-1:2] Macro(“IAX2/voipms-12305”, “blkvm-clr,”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-blkvm-clr:1] Set(“IAX2/voipms-12305”, “SHARED(BLKVM,)=”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-blkvm-clr:2] Set(“IAX2/voipms-12305”, “GOSUB_RETVAL=”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-blkvm-clr:3] MacroExit(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [31@ivr-1:3] Set(“IAX2/voipms-12305”, “__NODEST=”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [31@ivr-1:4] Goto(“IAX2/voipms-12305”, “from-did-direct,31,1”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (from-did-direct,31,1)
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [31@from-did-direct:1] GotoIf(“IAX2/voipms-12305”, “1?ext-local,31,1:followme-check,31,1”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (ext-local,31,1)
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [31@ext-local:1] Set(“IAX2/voipms-12305”, “__RINGTIMER=15”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [31@ext-local:2] ExecIf(“IAX2/voipms-12305”, “0?Set(__CWIGNORE=)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [31@ext-local:3] Macro(“IAX2/voipms-12305”, “exten-vm,novm,31,0,0,0”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:1] Macro(“IAX2/voipms-12305”, “user-callerid,”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:1] Set(“IAX2/voipms-12305”, “TOUCH_MONITOR=1591982420.298”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:2] Set(“IAX2/voipms-12305”, “AMPUSER=9055551212”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:3] Set(“IAX2/voipms-12305”, “HOTDESCKCHAN=voipms-12305”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:4] Set(“IAX2/voipms-12305”, “HOTDESKEXTEN=voipms”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:5] Set(“IAX2/voipms-12305”, “HOTDESKCALL=0”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:6] ExecIf(“IAX2/voipms-12305”, “0?Set(HOTDESKCALL=1)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:7] ExecIf(“IAX2/voipms-12305”, “0?Set(CALLERID(name)=)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:8] GotoIf(“IAX2/voipms-12305”, “0?report”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:9] ExecIf(“IAX2/voipms-12305”, “1?Set(REALCALLERIDNUM=9055551212)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:10] Set(“IAX2/voipms-12305”, “AMPUSER=”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:11] GotoIf(“IAX2/voipms-12305”, “0?limit”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:12] Set(“IAX2/voipms-12305”, “AMPUSERCIDNAME=”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:13] ExecIf(“IAX2/voipms-12305”, “0?Set(__CIDMASQUERADING=TRUE)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:14] GotoIf(“IAX2/voipms-12305”, “1?report”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (macro-user-callerid,s,22)
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:22] NoOp(“IAX2/voipms-12305”, “Macro Depth is 2”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:23] GotoIf(“IAX2/voipms-12305”, “1?report2:macroerror”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (macro-user-callerid,s,24)
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:24] GotoIf(“IAX2/voipms-12305”, “0?continue”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:25] ExecIf(“IAX2/voipms-12305”, “1?Set(__CALLEE_ACCOUNCODE=)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:26] Set(“IAX2/voipms-12305”, “__TTL=64”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:27] GotoIf(“IAX2/voipms-12305”, “1?continue”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (macro-user-callerid,s,43)
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:43] Set(“IAX2/voipms-12305”, “CALLERID(number)=9055551212”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:44] Set(“IAX2/voipms-12305”, “CALLERID(name)=Adam S”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:45] GotoIf(“IAX2/voipms-12305”, “0?cnum”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:46] Set(“IAX2/voipms-12305”, “CDR(cnam)=Adam S”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:47] Set(“IAX2/voipms-12305”, “CDR(cnum)=9055551212”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-user-callerid:48] Set(“IAX2/voipms-12305”, “CHANNEL(language)=en”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:2] Set(“IAX2/voipms-12305”, “RingGroupMethod=none”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:3] Set(“IAX2/voipms-12305”, “__EXTTOCALL=31”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:4] Set(“IAX2/voipms-12305”, “__PICKUPMARK=31”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:5] Set(“IAX2/voipms-12305”, “RT=”) in new stack
[2020-06-12 17:20:27] WARNING[11406][C-00000124] chan_sip.c: This function can only be used on SIP channels.
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:6] ExecIf(“IAX2/voipms-12305”, “0?Macro(vm,novm,DIRECTDIAL,)”) in new stack
[2020-06-12 17:20:27] WARNING[11406][C-00000124] chan_sip.c: This function can only be used on SIP channels.
[2020-06-12 17:20:27] WARNING[11406][C-00000124] chan_sip.c: This function can only be used on SIP channels.
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:7] ExecIf(“IAX2/voipms-12305”, “0?MacroExit()”) in new stack
[2020-06-12 17:20:27] WARNING[11406][C-00000124] chan_sip.c: This function can only be used on SIP channels.
[2020-06-12 17:20:27] WARNING[11406][C-00000124] chan_sip.c: This function can only be used on SIP channels.
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:8] ExecIf(“IAX2/voipms-12305”, “0?Gosub(ext-intercom,*8031,1())”) in new stack
[2020-06-12 17:20:27] WARNING[11406][C-00000124] chan_sip.c: This function can only be used on SIP channels.
[2020-06-12 17:20:27] WARNING[11406][C-00000124] chan_sip.c: This function can only be used on SIP channels.
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:9] ExecIf(“IAX2/voipms-12305”, “0?MacroExit()”) in new stack
[2020-06-12 17:20:27] WARNING[11406][C-00000124] chan_sip.c: This function can only be used on SIP channels.
[2020-06-12 17:20:27] WARNING[11406][C-00000124] chan_sip.c: This function can only be used on SIP channels.
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:10] ExecIf(“IAX2/voipms-12305”, “0?ChanSpy(PJSIP/31,q)”) in new stack
[2020-06-12 17:20:27] WARNING[11406][C-00000124] chan_sip.c: This function can only be used on SIP channels.
[2020-06-12 17:20:27] WARNING[11406][C-00000124] chan_sip.c: This function can only be used on SIP channels.
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:11] ExecIf(“IAX2/voipms-12305”, “0?MacroExit()”) in new stack
[2020-06-12 17:20:27] WARNING[11406][C-00000124] chan_sip.c: This function can only be used on SIP channels.
[2020-06-12 17:20:27] ERROR[11406][C-00000124] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:12] ExecIf(“IAX2/voipms-12305”, “0?Macro(vm,novm,DIRECTDIAL,)”) in new stack
[2020-06-12 17:20:27] ERROR[11406][C-00000124] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2020-06-12 17:20:27] ERROR[11406][C-00000124] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:13] ExecIf(“IAX2/voipms-12305”, “0?MacroExit()”) in new stack
[2020-06-12 17:20:27] ERROR[11406][C-00000124] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2020-06-12 17:20:27] ERROR[11406][C-00000124] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:14] ExecIf(“IAX2/voipms-12305”, “0?Gosub(ext-intercom,*8031,1())”) in new stack
[2020-06-12 17:20:27] ERROR[11406][C-00000124] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2020-06-12 17:20:27] ERROR[11406][C-00000124] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:15] ExecIf(“IAX2/voipms-12305”, “0?MacroExit()”) in new stack
[2020-06-12 17:20:27] ERROR[11406][C-00000124] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2020-06-12 17:20:27] ERROR[11406][C-00000124] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:16] ExecIf(“IAX2/voipms-12305”, “0?ChanSpy(PJSIP/31,q)”) in new stack
[2020-06-12 17:20:27] ERROR[11406][C-00000124] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2020-06-12 17:20:27] ERROR[11406][C-00000124] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:17] ExecIf(“IAX2/voipms-12305”, “0?MacroExit()”) in new stack
[2020-06-12 17:20:27] ERROR[11406][C-00000124] res_pjsip_header_funcs.c: This function requires a PJSIP channel.
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:18] Gosub(“IAX2/voipms-12305”, “sub-record-check,s,1(exten,31,dontcare)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:1] GotoIf(“IAX2/voipms-12305”, “10?initialized”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (sub-record-check,s,10)
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:10] NoOp(“IAX2/voipms-12305”, “Recordings initialized”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:11] ExecIf(“IAX2/voipms-12305”, “0?Set(ARG3=dontcare)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:12] Set(“IAX2/voipms-12305”, “REC_POLICY_MODE_SAVE=”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:13] ExecIf(“IAX2/voipms-12305”, “0?Set(REC_STATUS=NO)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:14] GotoIf(“IAX2/voipms-12305”, “5?checkaction”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (sub-record-check,s,17)
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@sub-record-check:17] GotoIf(“IAX2/voipms-12305”, “1?sub-record-check,exten,1”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (sub-record-check,exten,1)
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [exten@sub-record-check:1] NoOp(“IAX2/voipms-12305”, “Exten Recording Check between 9055551212 and 31”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [exten@sub-record-check:2] Set(“IAX2/voipms-12305”, “CALLTYPE=external”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [exten@sub-record-check:3] ExecIf(“IAX2/voipms-12305”, “0?Set(CALLTYPE=)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [exten@sub-record-check:4] Set(“IAX2/voipms-12305”, “CALLEE=dontcare”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [exten@sub-record-check:5] ExecIf(“IAX2/voipms-12305”, “0?Set(CALLEE=dontcare)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [exten@sub-record-check:6] GotoIf(“IAX2/voipms-12305”, “1?callee”) in new stack

AsherN · June 12, 2020, 5:26pm

[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (sub-record-check,exten,11)
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [exten@sub-record-check:11] Gosub(“IAX2/voipms-12305”, “recordcheck,1(dontcare,external,31)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp(“IAX2/voipms-12305”, “Starting recording check against dontcare”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [recordcheck@sub-record-check:2] Goto(“IAX2/voipms-12305”, “dontcare”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [recordcheck@sub-record-check:3] Return(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [exten@sub-record-check:12] Return(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:19] GotoIf(“IAX2/voipms-12305”, “1?macrodial”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (macro-exten-vm,s,25)
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:25] GosubIf(“IAX2/voipms-12305”, “0?clrheader,1()”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-exten-vm:26] Macro(“IAX2/voipms-12305”, “dial-one,HhTtr,31”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:1] Set(“IAX2/voipms-12305”, “DEXTEN=31”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:2] Set(“IAX2/voipms-12305”, “__CRM_SOURCE=9055551212”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:3] ExecIf(“IAX2/voipms-12305”, “0?Set(__EXTTOCALL=31)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:4] Set(“IAX2/voipms-12305”, “DIALSTATUS_CW=”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:5] GosubIf(“IAX2/voipms-12305”, “0?screen,1()”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:6] GosubIf(“IAX2/voipms-12305”, “0?cf,1()”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:7] GotoIf(“IAX2/voipms-12305”, “1?skip1”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (macro-dial-one,s,10)
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:10] GotoIf(“IAX2/voipms-12305”, “0?nodial”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:11] GotoIf(“IAX2/voipms-12305”, “0?continue”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:12] Set(“IAX2/voipms-12305”, “EXTHASCW=ENABLED”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:13] GotoIf(“IAX2/voipms-12305”, “0?next1:cwinusebusy”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (macro-dial-one,s,25)
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:25] GotoIf(“IAX2/voipms-12305”, “0?next3:continue”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (macro-dial-one,s,27)
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:27] GotoIf(“IAX2/voipms-12305”, “0?nodial”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:28] GosubIf(“IAX2/voipms-12305”, “1?dstring,1():dlocal,1()”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [dstring@macro-dial-one:1] Set(“IAX2/voipms-12305”, “DSTRING=”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [dstring@macro-dial-one:2] Set(“IAX2/voipms-12305”, “DEVICES=31”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [dstring@macro-dial-one:3] ExecIf(“IAX2/voipms-12305”, “0?Return()”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [dstring@macro-dial-one:4] ExecIf(“IAX2/voipms-12305”, “0?Set(DEVICES=1)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [dstring@macro-dial-one:5] Set(“IAX2/voipms-12305”, “LOOPCNT=1”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [dstring@macro-dial-one:6] Set(“IAX2/voipms-12305”, “ITER=1”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [dstring@macro-dial-one:7] Set(“IAX2/voipms-12305”, “THISDIAL=PJSIP/31”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [dstring@macro-dial-one:8] GotoIf(“IAX2/voipms-12305”, “0?docheck”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [dstring@macro-dial-one:9] NoOp(“IAX2/voipms-12305”, “Debug: Found PJSIP Destination PJSIP/31”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [dstring@macro-dial-one:10] GotoIf(“IAX2/voipms-12305”, “0?doset”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [dstring@macro-dial-one:11] NoOp(“IAX2/voipms-12305”, “Debug: Updating PJSIP Destination with PJSIP_DIAL_CONTACTS”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [dstring@macro-dial-one:12] Set(“IAX2/voipms-12305”, “THISDIAL=PJSIP/31/sip:31@<my_public_IP>:51330;rinstance=704d51a758b29e8f”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [dstring@macro-dial-one:13] ExecIf(“IAX2/voipms-12305”, “0?Set(DIALSTATUS=CHANUNAVAIL)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [dstring@macro-dial-one:14] GotoIf(“IAX2/voipms-12305”, “0?skipset”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [dstring@macro-dial-one:15] Set(“IAX2/voipms-12305”, “DSTRING=PJSIP/31/sip:31@<my_public_IP>:51330;rinstance=704d51a758b29e8f&”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [dstring@macro-dial-one:16] Set(“IAX2/voipms-12305”, “ITER=2”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [dstring@macro-dial-one:17] GotoIf(“IAX2/voipms-12305”, “0?begin”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [dstring@macro-dial-one:18] ExecIf(“IAX2/voipms-12305”, “0?Return()”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [dstring@macro-dial-one:19] Set(“IAX2/voipms-12305”, “DSTRING=PJSIP/31/sip:31@<my_public_IP>:51330;rinstance=704d51a758b29e8f”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [dstring@macro-dial-one:20] Return(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:29] GotoIf(“IAX2/voipms-12305”, “0?nodial”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:30] GotoIf(“IAX2/voipms-12305”, “0?skiptrace”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:31] GosubIf(“IAX2/voipms-12305”, “1?ctset,1():ctclear,1()”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [ctset@macro-dial-one:1] Set(“IAX2/voipms-12305”, “DB(CALLTRACE/31)=9055551212”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [ctset@macro-dial-one:2] Return(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:32] Set(“IAX2/voipms-12305”, “D_OPTIONS=HhTtr”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:33] GosubIf(“IAX2/voipms-12305”, “0?func-set-sipheader,s,1(Alert-Info,)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:34] NoOp(“IAX2/voipms-12305”, "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:35] ExecIf(“IAX2/voipms-12305”, “0?Set(ALERT_INFO=)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:36] ExecIf(“IAX2/voipms-12305”, “0?Set(ALERT_INFO=)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:37] ExecIf(“IAX2/voipms-12305”, “0?Set(ALERT_INFO=)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:38] ExecIf(“IAX2/voipms-12305”, “0?Set(ALERT_INFO=Normal;volume=)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:39] ExecIf(“IAX2/voipms-12305”, “0?Set(ALERT_INFO=Normal;volume=)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:40] GosubIf(“IAX2/voipms-12305”, “0?func-set-sipheader,s,1(Alert-Info,)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:41] ExecIf(“IAX2/voipms-12305”, “1?Set(CHANNEL(musicclass)=Downie)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:42] GosubIf(“IAX2/voipms-12305”, “0?qwait,1()”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:43] Set(“IAX2/voipms-12305”, “__CWIGNORE=”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:44] Set(“IAX2/voipms-12305”, “__KEEPCID=TRUE”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:45] GotoIf(“IAX2/voipms-12305”, “0?usegoto,1”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:46] GotoIf(“IAX2/voipms-12305”, “1?godial”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (macro-dial-one,s,51)
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:51] Macro(“IAX2/voipms-12305”, “dialout-one-predial-hook,”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dialout-one-predial-hook:1] MacroExit(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:52] ExecIf(“IAX2/voipms-12305”, “1?Set(D_OPTIONS=HhtrI)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:53] ExecIf(“IAX2/voipms-12305”, “0?Set(CWRING=r(callwaiting)):Set(CWRING=)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:54] NoOp(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:55] ExecIf(“IAX2/voipms-12305”, “0?Set(D_OPTIONS=HhtrIg)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-dial-one:56] Dial(“IAX2/voipms-12305”, “PJSIP/31/sip:31@<my_public_IP>:51330;rinstance=704d51a758b29e8f,HhtrIb(func-apply-sipheaders^s^1)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] app_stack.c: PJSIP/31-00000120 Internal Gosub(func-apply-sipheaders,s,1) start
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf(“PJSIP/31-00000120”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp(“PJSIP/31-00000120”, “Applying SIP Headers to channel PJSIP/31-00000120”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@func-apply-sipheaders:3] Set(“PJSIP/31-00000120”, “TECH=PJSIP”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@func-apply-sipheaders:4] Set(“PJSIP/31-00000120”, “SIPHEADERKEYS=”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@func-apply-sipheaders:5] While(“PJSIP/31-00000120”, “0”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] app_while.c: Jumping to priority 13
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [s@func-apply-sipheaders:14] Return(“PJSIP/31-00000120”, “”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] app_stack.c: Spawn extension (from-internal, 31, 1) exited non-zero on ‘PJSIP/31-00000120’
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] app_stack.c: PJSIP/31-00000120 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] app_dial.c: Called PJSIP/31/sip:31@<my_public_IP>:51330;rinstance=704d51a758b29e8f
[2020-06-12 17:20:27] VERBOSE[10847] netsock2.c: Using SIP RTP Audio TOS bits 184
[2020-06-12 17:20:27] VERBOSE[10847] netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.
[2020-06-12 17:20:27] VERBOSE[10847] netsock2.c: Using SIP RTP Audio CoS mark 5
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] app_dial.c: Connected line update to IAX2/voipms-12305 prevented.
[2020-06-12 17:20:28] VERBOSE[11406][C-00000124] app_dial.c: PJSIP/31-00000120 is ringing
[2020-06-12 17:20:28] VERBOSE[11406][C-00000124] app_dial.c: PJSIP/31-00000120 is ringing
[2020-06-12 17:20:29] VERBOSE[11406][C-00000124] app_dial.c: PJSIP/31-00000120 answered IAX2/voipms-12305
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] bridge_channel.c: Channel PJSIP/31-00000120 joined ‘simple_bridge’ basic-bridge
[2020-06-12 17:20:29] VERBOSE[11406][C-00000124] bridge_channel.c: Channel IAX2/voipms-12305 joined ‘simple_bridge’ basic-bridge
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015478, ts 000160, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015479, ts 000320, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015480, ts 000480, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015481, ts 000640, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015482, ts 000800, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015483, ts 000960, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015484, ts 001120, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015485, ts 001280, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015486, ts 001440, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015487, ts 001600, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015488, ts 001760, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015489, ts 001920, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015490, ts 002080, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015491, ts 002240, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015492, ts 002400, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015493, ts 002560, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015494, ts 002720, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015495, ts 002880, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015496, ts 003040, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015497, ts 003200, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015498, ts 003360, len 000160)
[2020-06-12 17:20:29] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015499, ts 003520, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015500, ts 003680, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015501, ts 003840, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015502, ts 004000, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015503, ts 004160, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015504, ts 004320, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015505, ts 004480, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015506, ts 004640, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015507, ts 004800, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015508, ts 004960, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015509, ts 005120, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015510, ts 005280, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015511, ts 005440, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015512, ts 005600, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015513, ts 005760, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015514, ts 005920, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015515, ts 006080, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015516, ts 006240, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015517, ts 006400, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015518, ts 006560, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015519, ts 006720, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015520, ts 006880, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015521, ts 007040, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015522, ts 007200, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015523, ts 007360, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015524, ts 007520, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015525, ts 007680, len 000160)
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] bridge_channel.c: Channel IAX2/voipms-12305 left ‘simple_bridge’ basic-bridge
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] app_macro.c: Spawn extension (macro-dial-one, s, 56) exited non-zero on ‘IAX2/voipms-12305’ in macro ‘dial-one’
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] app_macro.c: Spawn extension (macro-exten-vm, s, 26) exited non-zero on ‘IAX2/voipms-12305’ in macro ‘exten-vm’
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx.c: Spawn extension (ext-local, 31, 3) exited non-zero on ‘IAX2/voipms-12305’
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx.c: Executing [h@ext-local:1] Macro(“IAX2/voipms-12305”, “hangupcall,”) in new stack
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-hangupcall:1] GotoIf(“IAX2/voipms-12305”, “1?theend”) in new stack
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-hangupcall:3] ExecIf(“IAX2/voipms-12305”, “0?Set(CDR(recordingfile)=)”) in new stack
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-hangupcall:4] NoOp(“IAX2/voipms-12305”, "PJSIP/31-00000120 montior file= ") in new stack
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-hangupcall:5] GotoIf(“IAX2/voipms-12305”, “1?skipagi”) in new stack
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx_builtins.c: Goto (macro-hangupcall,s,7)
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx.c: Executing [s@macro-hangupcall:7] Hangup(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] app_macro.c: Spawn extension (macro-hangupcall, s, 7) exited non-zero on ‘IAX2/voipms-12305’ in macro ‘hangupcall’
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx.c: Spawn extension (ext-local, h, 1) exited non-zero on ‘IAX2/voipms-12305’
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] app_stack.c: IAX2/voipms-12305 Internal Gosub(crm-hangup,s,1) start
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx.c: Executing [s@crm-hangup:1] NoOp(“IAX2/voipms-12305”, “Sending Hangup to CRM”) in new stack
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx.c: Executing [s@crm-hangup:2] NoOp(“IAX2/voipms-12305”, “HANGUP CAUSE: 16”) in new stack
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx.c: Executing [s@crm-hangup:3] ExecIf(“IAX2/voipms-12305”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx.c: Executing [s@crm-hangup:4] NoOp(“IAX2/voipms-12305”, “MASTER CHANNEL: 1591982420.298 = 1591982420.298”) in new stack
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx.c: Executing [s@crm-hangup:5] GotoIf(“IAX2/voipms-12305”, “0?return”) in new stack
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx.c: Executing [s@crm-hangup:6] Set(“IAX2/voipms-12305”, “__CRM_HANGUP=1”) in new stack
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx.c: Executing [s@crm-hangup:7] AGI(“IAX2/voipms-12305”, “agi://127.0.0.1/sangomacrm.agi”) in new stack
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] bridge_channel.c: Channel PJSIP/31-00000120 left ‘simple_bridge’ basic-bridge
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] app_stack.c: PJSIP/31-00000120 Internal Gosub(crm-hangup,s,1) start
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] pbx.c: Executing [s@crm-hangup:1] NoOp(“PJSIP/31-00000120”, “Sending Hangup to CRM”) in new stack
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] pbx.c: Executing [s@crm-hangup:2] NoOp(“PJSIP/31-00000120”, “HANGUP CAUSE: 16”) in new stack
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] pbx.c: Executing [s@crm-hangup:3] ExecIf(“PJSIP/31-00000120”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] pbx.c: Executing [s@crm-hangup:4] NoOp(“PJSIP/31-00000120”, “MASTER CHANNEL: 1591982427.299 = 1591982420.298”) in new stack
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] pbx.c: Executing [s@crm-hangup:5] GotoIf(“PJSIP/31-00000120”, “1?return”) in new stack
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] pbx_builtins.c: Goto (crm-hangup,s,8)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] pbx.c: Executing [s@crm-hangup:8] Return(“PJSIP/31-00000120”, “”) in new stack
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] app_stack.c: Spawn extension (from-internal, , 1) exited non-zero on ‘PJSIP/31-00000120’
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] app_stack.c: PJSIP/31-00000120 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] res_agi.c: <IAX2/voipms-12305>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx.c: Executing [s@crm-hangup:8] Return(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] app_stack.c: Spawn extension (ext-local, h, 1) exited non-zero on ‘IAX2/voipms-12305’
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] app_stack.c: IAX2/voipms-12305 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] chan_iax2.c: Hungup ‘IAX2/voipms-12305’

dicko · June 12, 2020, 5:54pm

Lots of

[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015513, ts 005760, len 000160)
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] res_rtp_asterisk.c: Sent RTP packet to <my_public_IP>:35654 (type 00, seq 015514, ts 005920, len 000160)

but no interstitial Received RTP packets, doesn’t seem to be getting through your firewall(s)

AsherN · June 12, 2020, 6:01pm

RTP filter on the FW is 10000 to 20000 to match the FreePBX settings. Local RTP ports on Zoiper is set to begin at 10000

dicko · June 12, 2020, 6:03pm

But IAX2 channels don’t do that 10000-20000 thing, it’s all in the protocol/port aforementioned

Maybe you need to switch to chan_sip or chan_pjsip.

AsherN · June 12, 2020, 6:05pm

Trunk to voip.ms is IAX2. Extensions are pjsip. Outbound from my softphone on WiFi works, so does both inbound and outbound on LTE

dicko · June 12, 2020, 10:03pm

I’m confused, you headed this thread with “never ending saga . . . .” , so exactly what is your “saga”

AsherN · June 13, 2020, 2:33am

From edge firewall to responsive firewall to soft phone. I’m finally at the last piece, and 3 out of 4 scenarios are working. It’s driving me crazy.

AsherN · June 16, 2020, 12:58pm

It has to be some NAT setting. but I can’t find anywhere to set NAT=Yes other than SIP nat in the device settings of Asterisk advanced setting. And that is set to yes.

arielgrin · June 16, 2020, 1:41pm

It needs to be set in the extension configuration