Never ending saga of a remote extension

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?

Without any logs, all thoughts will be guesses.

Which logs do you need?

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.

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

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

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 [[email protected]:1] NoOp(“IAX2/voipms-2589”, “Catch-All DID Match - Found 6475551212 - You probably want a DID for this.”) in new stack
– Executing [[email protected]:2] Set(“IAX2/voipms-2589”, “__FROM_DID=6475551212”) in new stack
– Executing [[email protected]:3] Goto(“IAX2/voipms-2589”, “ext-did,s,1”) in new stack
– Goto (ext-did,s,1)
– Executing [[email protected]:1] Set(“IAX2/voipms-2589”, “__DIRECTION=INBOUND”) in new stack
– Executing [[email protected]:2] Gosub(“IAX2/voipms-2589”, “sub-record-check,s,1(in,s,dontcare)”) in new stack
– Executing [[email protected]:1] GotoIf(“IAX2/voipms-2589”, “0?initialized”) in new stack
– Executing [[email protected]:2] Set(“IAX2/voipms-2589”, “__REC_STATUS=INITIALIZED”) in new stack
– Executing [[email protected]:3] Set(“IAX2/voipms-2589”, “NOW=1591977777”) in new stack
– Executing [[email protected]:4] Set(“IAX2/voipms-2589”, “__DAY=12”) in new stack
– Executing [[email protected]:5] Set(“IAX2/voipms-2589”, “__MONTH=06”) in new stack
– Executing [[email protected]:6] Set(“IAX2/voipms-2589”, “__YEAR=2020”) in new stack
– Executing [[email protected]:7] Set(“IAX2/voipms-2589”, “__TIMESTR=20200612-160257”) in new stack
– Executing [[email protected]:8] Set(“IAX2/voipms-2589”, “__FROMEXTEN=unknown”) in new stack
– Executing [[email protected]:9] Set(“IAX2/voipms-2589”, “__MON_FMT=wav”) in new stack
– Executing [[email protected]:10] NoOp(“IAX2/voipms-2589”, “Recordings initialized”) in new stack
– Executing [[email protected]:11] ExecIf(“IAX2/voipms-2589”, “0?Set(ARG3=dontcare)”) in new stack
– Executing [[email protected]:12] Set(“IAX2/voipms-2589”, “REC_POLICY_MODE_SAVE=”) in new stack
– Executing [[email protected]:13] ExecIf(“IAX2/voipms-2589”, “0?Set(REC_STATUS=NO)”) in new stack
– Executing [[email protected]:14] GotoIf(“IAX2/voipms-2589”, “2?checkaction”) in new stack
– Goto (sub-record-check,s,17)
– Executing [[email protected]:17] GotoIf(“IAX2/voipms-2589”, “1?sub-record-check,in,1”) in new stack
– Goto (sub-record-check,in,1)
– Executing [[email protected]:1] NoOp(“IAX2/voipms-2589”, “Inbound Recording Check to s”) in new stack
– Executing [[email protected]:2] Set(“IAX2/voipms-2589”, “FROMEXTEN=unknown”) in new stack
– Executing [[email protected]:3] ExecIf(“IAX2/voipms-2589”, “10?Set(FROMEXTEN=9055551212)”) in new stack
– Executing [[email protected]:4] Gosub(“IAX2/voipms-2589”, “recordcheck,1(dontcare,in,s)”) in new stack
– Executing [[email protected]:1] NoOp(“IAX2/voipms-2589”, “Starting recording check against dontcare”) in new stack
– Executing [[email protected]:2] Goto(“IAX2/voipms-2589”, “dontcare”) in new stack
– Goto (sub-record-check,recordcheck,3)
– Executing [[email protected]-check:3] Return(“IAX2/voipms-2589”, “”) in new stack
– Executing [[email protected]:5] Return(“IAX2/voipms-2589”, “”) in new stack
– Executing [[email protected]:3] Set(“IAX2/voipms-2589”, “CHANNEL(tonezone)=us”) in new stack
– Executing [[email protected]:4] ExecIf(“IAX2/voipms-2589”, “0?Set(__FROM_DID=s)”) in new stack
– Executing [[email protected]:5] Set(“IAX2/voipms-2589”, “returnhere=1”) in new stack
– Executing [[email protected]:6] Gosub(“IAX2/voipms-2589”, “app-blacklist-check,s,1()”) in new stack
– Executing [[email protected]:1] GotoIf(“IAX2/voipms-2589”, “0?blacklisted”) in new stack
– Executing [[email protected]:2] Set(“IAX2/voipms-2589”, “CALLED_BLACKLIST=1”) in new stack
– Executing [[email protected]:3] Return(“IAX2/voipms-2589”, “”) in new stack
– Executing [[email protected]:7] Set(“IAX2/voipms-2589”, “CDR(did)=6475551212”) in new stack
– Executing [[email protected]:8] GotoIf(“IAX2/voipms-2589”, “0?”) in new stack
– Executing [[email protected]:9] ExecIf(“IAX2/voipms-2589”, “0 ?Set(CALLERID(name)=9055551212)”) in new stack
– Executing [[email protected]:10] Set(“IAX2/voipms-2589”, “CHANNEL(musicclass)=Downie”) in new stack
– Executing [[email protected]:11] Set(“IAX2/voipms-2589”, “__MOHCLASS=Downie”) in new stack
– Executing [[email protected]:12] Set(“IAX2/voipms-2589”, “__REVERSAL_REJECT=FALSE”) in new stack
– Executing [[email protected]:13] GotoIf(“IAX2/voipms-2589”, “1?post-reverse-charge”) in new stack
– Goto (ext-did,s,15)
– Executing [[email protected]:15] NoOp(“IAX2/voipms-2589”, “”) in new stack
– Executing [[email protected]:16] Set(“IAX2/voipms-2589”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack
– Executing [[email protected]:17] Set(“IAX2/voipms-2589”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack
– Executing [[email protected]:18] Set(“IAX2/voipms-2589”, “CALLERID(name-pres)=allowed_not_screened”) in new stack
– Executing [[email protected]:19] Set(“IAX2/voipms-2589”, “CALLERID(num-pres)=allowed_not_screened”) in new stack
– Executing [[email protected]:20] NoOp(“IAX2/voipms-2589”, “CallerID Entry Point”) in new stack
– Executing [[email protected]:21] Set(“IAX2/voipms-2589”, “__CRM_DIRECTION=INBOUND”) in new stack
– Executing [[email protected]:22] Set(“IAX2/voipms-2589”, “__CRM_SOURCE=9055551212”) in new stack
– Executing [[email protected]:23] Set(“IAX2/voipms-2589”, “__CRM_LINKEDID=1591977777.291”) in new stack
– Executing [[email protected]: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 [[email protected]:25] ExecIf(“IAX2/voipms-2589”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
– Executing [[email protected]:26] Goto(“IAX2/voipms-2589”, “ivr-1,s,1”) in new stack
– Goto (ivr-1,s,1)
– Executing [[email protected]:1] Set(“IAX2/voipms-2589”, “TIMEOUT_LOOPCOUNT=0”) in new stack
– Executing [[email protected]:2] Set(“IAX2/voipms-2589”, “INVALID_LOOPCOUNT=0”) in new stack
– Executing [[email protected]:3] Set(“IAX2/voipms-2589”, “_IVR_CONTEXT_ivr-1=”) in new stack
– Executing [[email protected]:4] Set(“IAX2/voipms-2589”, “_IVR_CONTEXT=ivr-1”) in new stack
– Executing [[email protected]:5] Set(“IAX2/voipms-2589”, “__IVR_RETVM=”) in new stack
– Executing [[email protected]:6] GotoIf(“IAX2/voipms-2589”, “0?skip”) in new stack
– Executing [[email protected]:7] Answer(“IAX2/voipms-2589”, “”) in new stack
– Executing [[email protected]:8] Set(“IAX2/voipms-2589”, “IVR_MSG=custom/DWF_Phone_Message_2020”) in new stack
– Executing [[email protected]:9] Set(“IAX2/voipms-2589”, “TIMEOUT(digit)=3”) in new stack
– Digit timeout set to 3.000
– Executing [[email protected]: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 [[email protected]:1] GotoIf(“IAX2/voipms-2589”, “0?i,1”) in new stack
– Executing [[email protected]:2] Macro(“IAX2/voipms-2589”, “blkvm-clr,”) in new stack
– Executing [[email protected]:1] Set(“IAX2/voipms-2589”, “SHARED(BLKVM,)=”) in new stack
– Executing [[email protected]:2] Set(“IAX2/voipms-2589”, “GOSUB_RETVAL=”) in new stack
– Executing [[email protected]:3] MacroExit(“IAX2/voipms-2589”, “”) in new stack
– Executing [[email protected]:3] Set(“IAX2/voipms-2589”, “__NODEST=”) in new stack
– Executing [[email protected]:4] Goto(“IAX2/voipms-2589”, “from-did-direct,31,1”) in new stack
– Goto (from-did-direct,31,1)
– Executing [[email protected]:1] GotoIf(“IAX2/voipms-2589”, “1?ext-local,31,1:followme-check,31,1”) in new stack
– Goto (ext-local,31,1)
– Executing [[email protected]:1] Set(“IAX2/voipms-2589”, “__RINGTIMER=15”) in new stack
– Executing [[email protected]:2] ExecIf(“IAX2/voipms-2589”, “0?Set(__CWIGNORE=)”) in new stack
– Executing [[email protected]:3] Macro(“IAX2/voipms-2589”, “exten-vm,novm,31,0,0,0”) in new stack
– Executing [[email protected]:1] Macro(“IAX2/voipms-2589”, “user-callerid,”) in new stack
– Executing [[email protected]:1] Set(“IAX2/voipms-2589”, “TOUCH_MONITOR=1591977777.291”) in new stack
– Executing [[email protected]:2] Set(“IAX2/voipms-2589”, “AMPUSER=9055551212”) in new stack
– Executing [[email protected]:3] Set(“IAX2/voipms-2589”, “HOTDESCKCHAN=voipms-2589”) in new stack
– Executing [[email protected]:4] Set(“IAX2/voipms-2589”, “HOTDESKEXTEN=voipms”) in new stack
– Executing [[email protected]:5] Set(“IAX2/voipms-2589”, “HOTDESKCALL=0”) in new stack
– Executing [[email protected]:6] ExecIf(“IAX2/voipms-2589”, “0?Set(HOTDESKCALL=1)”) in new stack
– Executing [[email protected]:7] ExecIf(“IAX2/voipms-2589”, “0?Set(CALLERID(name)=)”) in new stack
– Executing [[email protected]:8] GotoIf(“IAX2/voipms-2589”, “0?report”) in new stack
– Executing [[email protected]:9] ExecIf(“IAX2/voipms-2589”, “1?Set(REALCALLERIDNUM=9055551212)”) in new stack
– Executing [[email protected]:10] Set(“IAX2/voipms-2589”, “AMPUSER=”) in new stack
– Executing [[email protected]:11] GotoIf(“IAX2/voipms-2589”, “0?limit”) in new stack
– Executing [[email protected]:12] Set(“IAX2/voipms-2589”, “AMPUSERCIDNAME=”) in new stack
– Executing [[email protected]:13] ExecIf(“IAX2/voipms-2589”, “0?Set(__CIDMASQUERADING=TRUE)”) in new stack
– Executing [[email protected]:14] GotoIf(“IAX2/voipms-2589”, “1?report”) in new stack
– Goto (macro-user-callerid,s,22)
– Executing [[email protected]:22] NoOp(“IAX2/voipms-2589”, “Macro Depth is 2”) in new stack
– Executing [[email protected]:23] GotoIf(“IAX2/voipms-2589”, “1?report2:macroerror”) in new stack
– Goto (macro-user-callerid,s,24)
– Executing [[email protected]:24] GotoIf(“IAX2/voipms-2589”, “0?continue”) in new stack
– Executing [[email protected]:25] ExecIf(“IAX2/voipms-2589”, “1?Set(__CALLEE_ACCOUNCODE=)”) in new stack
– Executing [[email protected]:26] Set(“IAX2/voipms-2589”, “__TTL=64”) in new stack
– Executing [[email protected]:27] GotoIf(“IAX2/voipms-2589”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,43)
– Executing [[email protected]:43] Set(“IAX2/voipms-2589”, “CALLERID(number)=9055551212”) in new stack
– Executing [[email protected]:44] Set(“IAX2/voipms-2589”, “CALLERID(name)=Adam S”) in new stack
– Executing [[email protected]:45] GotoIf(“IAX2/voipms-2589”, “0?cnum”) in new stack
– Executing [[email protected]:46] Set(“IAX2/voipms-2589”, “CDR(cnam)=Adam S”) in new stack
– Executing [[email protected]:47] Set(“IAX2/voipms-2589”, “CDR(cnum)=9055551212”) in new stack
– Executing [[email protected]:48] Set(“IAX2/voipms-2589”, “CHANNEL(language)=en”) in new stack
– Executing [[email protected]:2] Set(“IAX2/voipms-2589”, “RingGroupMethod=none”) in new stack
– Executing [[email protected]:3] Set(“IAX2/voipms-2589”, “__EXTTOCALL=31”) in new stack
– Executing [[email protected]:4] Set(“IAX2/voipms-2589”, “__PICKUPMARK=31”) in new stack
– Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:18] Gosub(“IAX2/voipms-2589”, “sub-record-check,s,1(exten,31,dontcare)”) in new stack
– Executing [[email protected]:1] GotoIf(“IAX2/voipms-2589”, “10?initialized”) in new stack
– Goto (sub-record-check,s,10)
– Executing [[email protected]:10] NoOp(“IAX2/voipms-2589”, “Recordings initialized”) in new stack
– Executing [[email protected]:11] ExecIf(“IAX2/voipms-2589”, “0?Set(ARG3=dontcare)”) in new stack
– Executing [[email protected]:12] Set(“IAX2/voipms-2589”, “REC_POLICY_MODE_SAVE=”) in new stack
– Executing [[email protected]:13] ExecIf(“IAX2/voipms-2589”, “0?Set(REC_STATUS=NO)”) in new stack
– Executing [[email protected]:14] GotoIf(“IAX2/voipms-2589”, “5?checkaction”) in new stack
– Goto (sub-record-check,s,17)
– Executing [[email protected]:17] GotoIf(“IAX2/voipms-2589”, “1?sub-record-check,exten,1”) in new stack
– Goto (sub-record-check,exten,1)
– Executing [[email protected]:1] NoOp(“IAX2/voipms-2589”, “Exten Recording Check between 9055551212 and 31”) in new stack
– Executing [[email protected]:2] Set(“IAX2/voipms-2589”, “CALLTYPE=external”) in new stack
– Executing [[email protected]:3] ExecIf(“IAX2/voipms-2589”, “0?Set(CALLTYPE=)”) in new stack
– Executing [[email protected]:4] Set(“IAX2/voipms-2589”, “CALLEE=dontcare”) in new stack
– Executing [[email protected]:5] ExecIf(“IAX2/voipms-2589”, “0?Set(CALLEE=dontcare)”) in new stack
– Executing [[email protected]:6] GotoIf(“IAX2/voipms-2589”, “1?callee”) in new stack
– Goto (sub-record-check,exten,11)
– Executing [[email protected]:11] Gosub(“IAX2/voipms-2589”, “recordcheck,1(dontcare,external,31)”) in new stack
– Executing [[email protected]:1] NoOp(“IAX2/voipms-2589”, “Starting recording check against dontcare”) in new stack
– Executing [[email protected]:2] Goto(“IAX2/voipms-2589”, “dontcare”) in new stack
– Goto (sub-record-check,recordcheck,3)
– Executing [[email protected]:3] Return(“IAX2/voipms-2589”, “”) in new stack
– Executing [[email protected]:12] Return(“IAX2/voipms-2589”, “”) in new stack
– Executing [[email protected]:19] GotoIf(“IAX2/voipms-2589”, “1?macrodial”) in new stack
– Goto (macro-exten-vm,s,25)
– Executing [[email protected]:25] GosubIf(“IAX2/voipms-2589”, “0?clrheader,1()”) in new stack
– Executing [[email protected]:26] Macro(“IAX2/voipms-2589”, “dial-one,HhTtr,31”) in new stack
– Executing [[email protected]:1] Set(“IAX2/voipms-2589”, “DEXTEN=31”) in new stack
– Executing [[email protected]:2] Set(“IAX2/voipms-2589”, “__CRM_SOURCE=9055551212”) in new stack
– Executing [[email protected]:3] ExecIf(“IAX2/voipms-2589”, “0?Set(__EXTTOCALL=31)”) in new stack
– Executing [[email protected]:4] Set(“IAX2/voipms-2589”, “DIALSTATUS_CW=”) in new stack
– Executing [[email protected]:5] GosubIf(“IAX2/voipms-2589”, “0?screen,1()”) in new stack
– Executing [[email protected]:6] GosubIf(“IAX2/voipms-2589”, “0?cf,1()”) in new stack
– Executing [[email protected]:7] GotoIf(“IAX2/voipms-2589”, “1?skip1”) in new stack
– Goto (macro-dial-one,s,10)
– Executing [[email protected]:10] GotoIf(“IAX2/voipms-2589”, “0?nodial”) in new stack
– Executing [[email protected]:11] GotoIf(“IAX2/voipms-2589”, “0?continue”) in new stack
– Executing [[email protected]:12] Set(“IAX2/voipms-2589”, “EXTHASCW=ENABLED”) in new stack
– Executing [[email protected]:13] GotoIf(“IAX2/voipms-2589”, “0?next1:cwinusebusy”) in new stack
– Goto (macro-dial-one,s,25)
– Executing [[email protected]:25] GotoIf(“IAX2/voipms-2589”, “0?next3:continue”) in new stack
– Goto (macro-dial-one,s,27)
– Executing [[email protected]:27] GotoIf(“IAX2/voipms-2589”, “0?nodial”) in new stack
– Executing [[email protected]:28] GosubIf(“IAX2/voipms-2589”, “1?dstring,1():dlocal,1()”) in new stack
– Executing [[email protected]:1] Set(“IAX2/voipms-2589”, “DSTRING=”) in new stack
– Executing [[email protected]:2] Set(“IAX2/voipms-2589”, “DEVICES=31”) in new stack
– Executing [[email protected]:3] ExecIf(“IAX2/voipms-2589”, “0?Return()”) in new stack
– Executing [[email protected]:4] ExecIf(“IAX2/voipms-2589”, “0?Set(DEVICES=1)”) in new stack
– Executing [[email protected]:5] Set(“IAX2/voipms-2589”, “LOOPCNT=1”) in new stack
– Executing [[email protected]:6] Set(“IAX2/voipms-2589”, “ITER=1”) in new stack
– Executing [[email protected]:7] Set(“IAX2/voipms-2589”, “THISDIAL=PJSIP/31”) in new stack
– Executing [[email protected]:8] GotoIf(“IAX2/voipms-2589”, “0?docheck”) in new stack
– Executing [[email protected]:9] NoOp(“IAX2/voipms-2589”, “Debug: Found PJSIP Destination PJSIP/31”) in new stack
– Executing [[email protected]:10] GotoIf(“IAX2/voipms-2589”, “0?doset”) in new stack
– Executing [[email protected]:11] NoOp(“IAX2/voipms-2589”, “Debug: Updating PJSIP Destination with PJSIP_DIAL_CONTACTS”) in new stack
– Executing [[email protected]:12] Set(“IAX2/voipms-2589”, “THISDIAL=PJSIP/31/sip:[email protected]<my_public_IP>:51330;rinstance=704d51a758b29e8f”) in new stack
– Executing [[email protected]:13] ExecIf(“IAX2/voipms-2589”, “0?Set(DIALSTATUS=CHANUNAVAIL)”) in new stack
– Executing [[email protected]:14] GotoIf(“IAX2/voipms-2589”, “0?skipset”) in new stack
– Executing [[email protected]:15] Set(“IAX2/voipms-2589”, “DSTRING=PJSIP/31/sip:[email protected]<my_public_IP>:51330;rinstance=704d51a758b29e8f&”) in new stack
– Executing [[email protected]:16] Set(“IAX2/voipms-2589”, “ITER=2”) in new stack
– Executing [[email protected]:17] GotoIf(“IAX2/voipms-2589”, “0?begin”) in new stack
– Executing [[email protected]:18] ExecIf(“IAX2/voipms-2589”, “0?Return()”) in new stack
– Executing [[email protected]:19] Set(“IAX2/voipms-2589”, “DSTRING=PJSIP/31/sip:[email protected]<my_public_IP>:51330;rinstance=704d51a758b29e8f”) in new stack
– Executing [[email protected]:20] Return(“IAX2/voipms-2589”, “”) in new stack
– Executing [[email protected]:29] GotoIf(“IAX2/voipms-2589”, “0?nodial”) in new stack
– Executing [[email protected]:30] GotoIf(“IAX2/voipms-2589”, “0?skiptrace”) in new stack
– Executing [[email protected]:31] GosubIf(“IAX2/voipms-2589”, “1?ctset,1():ctclear,1()”) in new stack
– Executing [[email protected]:1] Set(“IAX2/voipms-2589”, “DB(CALLTRACE/31)=9055551212”) in new stack
– Executing [[email protected]:2] Return(“IAX2/voipms-2589”, “”) in new stack
– Executing [[email protected]:32] Set(“IAX2/voipms-2589”, “D_OPTIONS=HhTtr”) in new stack
– Executing [[email protected]:33] GosubIf(“IAX2/voipms-2589”, “0?func-set-sipheader,s,1(Alert-Info,)”) in new stack
– Executing [[email protected]:34] NoOp(“IAX2/voipms-2589”, "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
– Executing [[email protected]:35] ExecIf(“IAX2/voipms-2589”, “0?Set(ALERT_INFO=)”) in new stack
– Executing [[email protected]:36] ExecIf(“IAX2/voipms-2589”, “0?Set(ALERT_INFO=)”) in new stack
– Executing [[email protected]:37] ExecIf(“IAX2/voipms-2589”, “0?Set(ALERT_INFO=)”) in new stack
– Executing [[email protected]:38] ExecIf(“IAX2/voipms-2589”, “0?Set(ALERT_INFO=Normal;volume=)”) in new stack
– Executing [[email protected]:39] ExecIf(“IAX2/voipms-2589”, “0?Set(ALERT_INFO=Normal;volume=)”) in new stack
– Executing [[email protected]:40] GosubIf(“IAX2/voipms-2589”, “0?func-set-sipheader,s,1(Alert-Info,)”) in new stack
– Executing [[email protected]:41] ExecIf(“IAX2/voipms-2589”, “1?Set(CHANNEL(musicclass)=Downie)”) in new stack
– Executing [[email protected]:42] GosubIf(“IAX2/voipms-2589”, “0?qwait,1()”) in new stack
– Executing [[email protected]:43] Set(“IAX2/voipms-2589”, “__CWIGNORE=”) in new stack
– Executing [[email protected]:44] Set(“IAX2/voipms-2589”, “__KEEPCID=TRUE”) in new stack
– Executing [[email protected]:45] GotoIf(“IAX2/voipms-2589”, “0?usegoto,1”) in new stack
– Executing [[email protected]:46] GotoIf(“IAX2/voipms-2589”, “1?godial”) in new stack
– Goto (macro-dial-one,s,51)
– Executing [[email protected]:51] Macro(“IAX2/voipms-2589”, “dialout-one-predial-hook,”) in new stack
– Executing [[email protected]:1] MacroExit(“IAX2/voipms-2589”, “”) in new stack
– Executing [[email protected]:52] ExecIf(“IAX2/voipms-2589”, “1?Set(D_OPTIONS=HhtrI)”) in new stack
– Executing [[email protected]:53] ExecIf(“IAX2/voipms-2589”, “0?Set(CWRING=r(callwaiting)):Set(CWRING=)”) in new stack
– Executing [[email protected]:54] NoOp(“IAX2/voipms-2589”, “”) in new stack
– Executing [[email protected]:55] ExecIf(“IAX2/voipms-2589”, “0?Set(D_OPTIONS=HhtrIg)”) in new stack
– Executing [[email protected]:56] Dial(“IAX2/voipms-2589”, “PJSIP/31/sip:[email protected]<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 [[email protected]:1] ExecIf(“PJSIP/31-0000011d”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
– Executing [[email protected]:2] NoOp(“PJSIP/31-0000011d”, “Applying SIP Headers to channel PJSIP/31-0000011d”) in new stack
– Executing [[email protected]:3] Set(“PJSIP/31-0000011d”, “TECH=PJSIP”) in new stack
– Executing [[email protected]:4] Set(“PJSIP/31-0000011d”, “SIPHEADERKEYS=”) in new stack
– Executing [[email protected]:5] While(“PJSIP/31-0000011d”, “0”) in new stack
– Jumping to priority 13
– Executing [[email protected]: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:[email protected]<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 [[email protected]:1] Macro(“IAX2/voipms-2589”, “hangupcall,”) in new stack
– Executing [[email protected]:1] GotoIf(“IAX2/voipms-2589”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,3)
– Executing [[email protected]: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 [[email protected]:1] NoOp(“PJSIP/31-0000011d”, “Sending Hangup to CRM”) in new stack
– Executing [[email protected]:2] NoOp(“PJSIP/31-0000011d”, “HANGUP CAUSE: 16”) in new stack
– Executing [[email protected]:3] ExecIf(“PJSIP/31-0000011d”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
– Executing [[email protected]:4] NoOp(“PJSIP/31-0000011d”, “MASTER CHANNEL: 1591977784.292 = 1591977777.291”) in new stack
– Executing [[email protected]:5] GotoIf(“PJSIP/31-0000011d”, “1?return”) in new stack
– Goto (crm-hangup,s,8)
– Executing [[email protected]: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 [[email protected]:4] NoOp(“IAX2/voipms-2589”, "PJSIP/31-0000011d montior file= ") in new stack
– Executing [[email protected]:5] GotoIf(“IAX2/voipms-2589”, “1?skipagi”) in new stack
– Goto (macro-hangupcall,s,7)
– Executing [[email protected]: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 [[email protected]:1] NoOp(“IAX2/voipms-2589”, “Sending Hangup to CRM”) in new stack
– Executing [[email protected]:2] NoOp(“IAX2/voipms-2589”, “HANGUP CAUSE: 16”) in new stack
– Executing [[email protected]:3] ExecIf(“IAX2/voipms-2589”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
– Executing [[email protected]:4] NoOp(“IAX2/voipms-2589”, “MASTER CHANNEL: 1591977777.291 = 1591977777.291”) in new stack
– Executing [[email protected]:5] GotoIf(“IAX2/voipms-2589”, “0?return”) in new stack
– Executing [[email protected]:6] Set(“IAX2/voipms-2589”, “__CRM_HANGUP=1”) in new stack
– Executing [[email protected]: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 [[email protected]: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’

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

It is

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

[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 [[email protected]: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 [[email protected]:2] Set(“IAX2/voipms-12305”, “__FROM_DID=6475551212”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:1] Set(“IAX2/voipms-12305”, “__DIRECTION=INBOUND”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:1] GotoIf(“IAX2/voipms-12305”, “0?initialized”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:2] Set(“IAX2/voipms-12305”, “__REC_STATUS=INITIALIZED”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:3] Set(“IAX2/voipms-12305”, “NOW=1591982420”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:4] Set(“IAX2/voipms-12305”, “__DAY=12”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:5] Set(“IAX2/voipms-12305”, “__MONTH=06”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:6] Set(“IAX2/voipms-12305”, “__YEAR=2020”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:7] Set(“IAX2/voipms-12305”, “__TIMESTR=20200612-172020”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:8] Set(“IAX2/voipms-12305”, “__FROMEXTEN=unknown”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:9] Set(“IAX2/voipms-12305”, “__MON_FMT=wav”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:10] NoOp(“IAX2/voipms-12305”, “Recordings initialized”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:2] Set(“IAX2/voipms-12305”, “FROMEXTEN=unknown”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:3] Return(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:5] Return(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:3] Set(“IAX2/voipms-12305”, “CHANNEL(tonezone)=us”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:5] Set(“IAX2/voipms-12305”, “returnhere=1”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:1] GotoIf(“IAX2/voipms-12305”, “0?blacklisted”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:2] Set(“IAX2/voipms-12305”, “CALLED_BLACKLIST=1”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:3] Return(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:7] Set(“IAX2/voipms-12305”, “CDR(did)=6475551212”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:8] GotoIf(“IAX2/voipms-12305”, “0?”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:10] Set(“IAX2/voipms-12305”, “CHANNEL(musicclass)=Downie”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:11] Set(“IAX2/voipms-12305”, “__MOHCLASS=Downie”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:12] Set(“IAX2/voipms-12305”, “__REVERSAL_REJECT=FALSE”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:15] NoOp(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:20] NoOp(“IAX2/voipms-12305”, “CallerID Entry Point”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:21] Set(“IAX2/voipms-12305”, “__CRM_DIRECTION=INBOUND”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:22] Set(“IAX2/voipms-12305”, “__CRM_SOURCE=9055551212”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:1] Set(“IAX2/voipms-12305”, “TIMEOUT_LOOPCOUNT=0”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:2] Set(“IAX2/voipms-12305”, “INVALID_LOOPCOUNT=0”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]:5] Set(“IAX2/voipms-12305”, “__IVR_RETVM=”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:6] GotoIf(“IAX2/voipms-12305”, “0?skip”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:7] Answer(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:20] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]-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 [[email protected]:2] Macro(“IAX2/voipms-12305”, “blkvm-clr,”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:1] Set(“IAX2/voipms-12305”, “SHARED(BLKVM,)=”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:2] Set(“IAX2/voipms-12305”, “GOSUB_RETVAL=”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:3] MacroExit(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:3] Set(“IAX2/voipms-12305”, “__NODEST=”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]:1] Set(“IAX2/voipms-12305”, “__RINGTIMER=15”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:2] ExecIf(“IAX2/voipms-12305”, “0?Set(__CWIGNORE=)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:1] Macro(“IAX2/voipms-12305”, “user-callerid,”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:2] Set(“IAX2/voipms-12305”, “AMPUSER=9055551212”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:3] Set(“IAX2/voipms-12305”, “HOTDESCKCHAN=voipms-12305”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:4] Set(“IAX2/voipms-12305”, “HOTDESKEXTEN=voipms”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:5] Set(“IAX2/voipms-12305”, “HOTDESKCALL=0”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]:8] GotoIf(“IAX2/voipms-12305”, “0?report”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:10] Set(“IAX2/voipms-12305”, “AMPUSER=”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:11] GotoIf(“IAX2/voipms-12305”, “0?limit”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:12] Set(“IAX2/voipms-12305”, “AMPUSERCIDNAME=”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:24] GotoIf(“IAX2/voipms-12305”, “0?continue”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:26] Set(“IAX2/voipms-12305”, “__TTL=64”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:43] Set(“IAX2/voipms-12305”, “CALLERID(number)=9055551212”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:45] GotoIf(“IAX2/voipms-12305”, “0?cnum”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:47] Set(“IAX2/voipms-12305”, “CDR(cnum)=9055551212”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:48] Set(“IAX2/voipms-12305”, “CHANNEL(language)=en”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:2] Set(“IAX2/voipms-12305”, “RingGroupMethod=none”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:3] Set(“IAX2/voipms-12305”, “__EXTTOCALL=31”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:4] Set(“IAX2/voipms-12305”, “__PICKUPMARK=31”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:10] NoOp(“IAX2/voipms-12305”, “Recordings initialized”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:2] Set(“IAX2/voipms-12305”, “CALLTYPE=external”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:3] ExecIf(“IAX2/voipms-12305”, “0?Set(CALLTYPE=)”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:4] Set(“IAX2/voipms-12305”, “CALLEE=dontcare”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:6] GotoIf(“IAX2/voipms-12305”, “1?callee”) in new stack

[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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:3] Return(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:12] Return(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:25] GosubIf(“IAX2/voipms-12305”, “0?clrheader,1()”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:1] Set(“IAX2/voipms-12305”, “DEXTEN=31”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:2] Set(“IAX2/voipms-12305”, “__CRM_SOURCE=9055551212”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:4] Set(“IAX2/voipms-12305”, “DIALSTATUS_CW=”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:5] GosubIf(“IAX2/voipms-12305”, “0?screen,1()”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:6] GosubIf(“IAX2/voipms-12305”, “0?cf,1()”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:10] GotoIf(“IAX2/voipms-12305”, “0?nodial”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:11] GotoIf(“IAX2/voipms-12305”, “0?continue”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:12] Set(“IAX2/voipms-12305”, “EXTHASCW=ENABLED”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]:27] GotoIf(“IAX2/voipms-12305”, “0?nodial”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:1] Set(“IAX2/voipms-12305”, “DSTRING=”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:2] Set(“IAX2/voipms-12305”, “DEVICES=31”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:3] ExecIf(“IAX2/voipms-12305”, “0?Return()”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:5] Set(“IAX2/voipms-12305”, “LOOPCNT=1”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:6] Set(“IAX2/voipms-12305”, “ITER=1”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:7] Set(“IAX2/voipms-12305”, “THISDIAL=PJSIP/31”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:8] GotoIf(“IAX2/voipms-12305”, “0?docheck”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:10] GotoIf(“IAX2/voipms-12305”, “0?doset”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:12] Set(“IAX2/voipms-12305”, “THISDIAL=PJSIP/31/sip:[email protected]<my_public_IP>:51330;rinstance=704d51a758b29e8f”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:14] GotoIf(“IAX2/voipms-12305”, “0?skipset”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:15] Set(“IAX2/voipms-12305”, “DSTRING=PJSIP/31/sip:[email protected]<my_public_IP>:51330;rinstance=704d51a758b29e8f&”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:16] Set(“IAX2/voipms-12305”, “ITER=2”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:17] GotoIf(“IAX2/voipms-12305”, “0?begin”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:18] ExecIf(“IAX2/voipms-12305”, “0?Return()”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:19] Set(“IAX2/voipms-12305”, “DSTRING=PJSIP/31/sip:[email protected]<my_public_IP>:51330;rinstance=704d51a758b29e8f”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:20] Return(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:29] GotoIf(“IAX2/voipms-12305”, “0?nodial”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:30] GotoIf(“IAX2/voipms-12305”, “0?skiptrace”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]:2] Return(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:32] Set(“IAX2/voipms-12305”, “D_OPTIONS=HhTtr”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:42] GosubIf(“IAX2/voipms-12305”, “0?qwait,1()”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:43] Set(“IAX2/voipms-12305”, “__CWIGNORE=”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:44] Set(“IAX2/voipms-12305”, “__KEEPCID=TRUE”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:45] GotoIf(“IAX2/voipms-12305”, “0?usegoto,1”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]:1] MacroExit(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]:54] NoOp(“IAX2/voipms-12305”, “”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]:56] Dial(“IAX2/voipms-12305”, “PJSIP/31/sip:[email protected]<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 [[email protected]: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 [[email protected]: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 [[email protected]:3] Set(“PJSIP/31-00000120”, “TECH=PJSIP”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:4] Set(“PJSIP/31-00000120”, “SIPHEADERKEYS=”) in new stack
[2020-06-12 17:20:27] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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:[email protected]<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 [[email protected]:1] Macro(“IAX2/voipms-12305”, “hangupcall,”) in new stack
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:2] NoOp(“IAX2/voipms-12305”, “HANGUP CAUSE: 16”) in new stack
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]:5] GotoIf(“IAX2/voipms-12305”, “0?return”) in new stack
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]:6] Set(“IAX2/voipms-12305”, “__CRM_HANGUP=1”) in new stack
[2020-06-12 17:20:30] VERBOSE[11406][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]:2] NoOp(“PJSIP/31-00000120”, “HANGUP CAUSE: 16”) in new stack
[2020-06-12 17:20:30] VERBOSE[11418][C-00000124] pbx.c: Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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’

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)

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

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.

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

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

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.

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.

It needs to be set in the extension configuration