Network setup with two SIP trunks

Hi,

I have a problem setting up two SIP trunks on FPBX,

FFPBX is 6.12.65-27
Asterisk is 11.17.1
Running on an HP NUC with a single NIC

The NUC connects to a Mikrotik switch which routes the existing SIP trunk traffic on VLan 10 to Telco 1’s private gateway and all other traffic on the native VLan is routed to the normal Internet gateway router.
The Private address range and the normal LAN address range are different and neither are able to be changed.

So far no problem.

It has been decided that we will provision an additional SIP trunk onto the system which will connect to Telco 2 via the Internet.

The system uses Chan_SIP and the normal Internet Public IP address is entered under SIP Settings with an address on the VLan 10 network in the CHAN_SIP “Over-ride External IP” box

After connecting Telco 2’s trunk, i can see correctly addressed SIP OPTIONS, INVITES and BYE’s being passed between FPBX and Telco 2, but the RTP packets are showing as originating from the address in the SIP Settings/Chan_SIP/Over-ride External IP field.

Is there a way to configure an additional “over-ride” address for the second {Telco 2} RTP packets ?

I see that Telco 2 does support IAX2 trunking as well as SIP Peering if that is helpful

Thanks

Jon

@jon_b Please provide call logs and/or SIP traces of the calls on the trunk with the issue and Telco 2. Also can you provide a screenshot of your network settings in the Advance Settings area?

No problem Blaze, but what is the normal protocol on this board regarding the showing of public ip addresses etc ?

A wireshark trace without these is going to be pretty meaningless :smile: but the client is not going to thank me for publishing his SIP details worldwide.

Jon

@jon_b You can use the sip debug tools for this and yes, you’ll have to edit the results if you don’t want to show the IPs. But you need to say something like XX.XX.XX.XX is the trunk and YY.YY.YY.YY is the telco.

OK, here goes (part 1)

Here is a normal incoming call to the Telco 1 Trunk. This is the working trunk on a private network.

As the call is established near the bottom of the trace, you will find the line
To: called_number <sip:[email protected]:5060 which is as expected.
The 10.13.154.xxx subnet is on VLan 25 of the NUC NIC and this traffic is routed to the private network gateway.


usnCLI> sip set debug peer CallPlus
SIP Debugging Enabled for IP: 10.20.60.1
– Attempting call on Local/s@tc-maint for application NoCDR() (Retry 1)
– Executing [s@tc-maint:1] NoCDR(“Local/s@tc-maint-0001444d;2”, “”) in new stack
– Executing [s@tc-maint:2] Set(“Local/s@tc-maint-0001444d;2”, “TCMAINT=RETURN”) in new stack
– Executing [s@tc-maint:3] Gosub(“Local/s@tc-maint-0001444d;2”, “timeconditions,1,1()”) in new stack
– Executing [1@timeconditions:1] Set(“Local/s@tc-maint-0001444d;2”, “DB(TC/1/INUSESTATE)=INUSE”) in new stack
– Executing [1@timeconditions:2] Set(“Local/s@tc-maint-0001444d;2”, “DB(TC/1/NOT_INUSESTATE)=NOT_INUSE”) in new stack
– Executing [1@timeconditions:3] GotoIfTime(“Local/s@tc-maint-0001444d;2”, "08:00-16:30,mon-fri,
,*?truestate") in new stack
– Executing [1@timeconditions:4] GotoIf(“Local/s@tc-maint-0001444d;2”, “0?truegoto”) in new stack
– Executing [1@timeconditions:5] ExecIf(“Local/s@tc-maint-0001444d;2”, “0?Set(DB(TC/1)=)”) in new stack
– Executing [1@timeconditions:6] Set(“Local/s@tc-maint-0001444d;2”, “DEVICE_STATE(Custom:TC1)=INUSE”) in new stack
– Executing [1@timeconditions:7] ExecIf(“Local/s@tc-maint-0001444d;2”, “0?Set(NOT_INUSE)”) in new stack
– Executing [1@timeconditions:8] GotoIf(“Local/s@tc-maint-0001444d;2”, “0?ext-queues,9100,1”) in new stack
– Executing [1@timeconditions:9] Set(“Local/s@tc-maint-0001444d;2”, “TCSTATE=false”) in new stack
– Executing [1@timeconditions:10] Set(“Local/s@tc-maint-0001444d;2”, “TCOVERRIDE=false”) in new stack
– Executing [1@timeconditions:11] Return(“Local/s@tc-maint-0001444d;2”, “”) in new stack
– Executing [s@tc-maint:4] System(“Local/s@tc-maint-0001444d;2”, “/var/lib/asterisk/bin/schedtc.php 60 /var/spool/asterisk/outgoing 1”) in new stack
– Executing [s@tc-maint:5] Answer(“Local/s@tc-maint-0001444d;2”, “”) in new stack
> Channel Local/s@tc-maint-0001444d;1 was answered.
> Launching NoCDR() on Local/s@tc-maint-0001444d;1
[2015-12-13 16:52:00] NOTICE[18313]: pbx_spool.c:402 attempt_thread: Call completed to Local/s@tc-maint
== Spawn extension (tc-maint, s, 5) exited non-zero on ‘Local/s@tc-maint-0001444d;2’

<— SIP read from UDP:10.20.60.1:5060 —>
INVITE sip:[email protected]:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 10.20.60.1:5060;branch=z9hG4bKd5f9hd301omgaokei491.1
From: my_phone _number <sip:my_phone [email protected]:5060;user=phone>;tag=1449979963
To: called_number sip:[email protected]:5060;user=phone
Call-ID: [email protected]
CSeq: 1 INVITE
Max-Forwards: 68
Supported: timer
Session-Expires: 1800
Min-SE: 1800
Contact: sip:10.20.60.1:5060;transport=udp
Allow: INVITE,ACK,PRACK,SUBSCRIBE,BYE,CANCEL,NOTIFY,INFO,REFER,UPDATE
P-Asserted-Identity: my_phone _number <sip:my_phone [email protected];user=phone>
Content-Type: application/sdp
Content-Length: 409
P-hint: outbound

v=0
o=- 3349705 0 IN IP4 10.20.60.1
s=Cisco SDP 0
c=IN IP4 10.20.60.1
t=0 0
m=audio 15194 RTP/AVP 8 18 0 101 100
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtpmap:100 X-NSE/8000
a=fmtp:100 192-194,200-202
a=X-sqn:0
a=X-cap: 1 audio RTP/AVP 100
a=X-cpar: a=rtpmap:100 X-NSE/8000
a=X-cpar: a=fmtp:100 192-194,200-202
a=X-cap: 2 image udptl t38
<------------->
— (16 headers 17 lines) —
Sending to 10.20.60.1:5060 (no NAT)
Sending to 10.20.60.1:5060 (no NAT)
Using INVITE request as basis request - [email protected]
Found peer ‘CallPlus’ for ‘my_phone _number’ from 10.20.60.1:5060
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
Found RTP audio format 8
Found RTP audio format 18
Found RTP audio format 0
Found RTP audio format 101
Found RTP audio format 100
Found audio description format G729 for ID 18
Found audio description format telephone-event for ID 101
Found unknown media description format X-NSE for ID 100
Capabilities: us - (ulaw|alaw|g722), peer - audio=(ulaw|alaw|g729)/video=(nothing)/text=(nothing), combined - (ulaw|alaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port 10.20.60.1:15194
Looking for called_number in from-trunk (domain 10.13.154.157)
list_route: hop: sip:10.20.60.1:5060;transport=udp

<— Transmitting (no NAT) to 10.20.60.1:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.20.60.1:5060;branch=z9hG4bKd5f9hd301omgaokei491.1;received=10.20.60.1
From: my_phone _number <sip:my_phone [email protected]:5060;user=phone>;tag=1449979963
To: called_number sip:[email protected]:5060;user=phone
Call-ID: [email protected]
CSeq: 1 INVITE
Server: FPBX-12.0.65(11.17.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Contact: sip:[email protected]:5060
Content-Length: 0

<------------>
– Executing [called_number@from-trunk:1] Set(“SIP/CallPlus-000090f5”, “__FROM_DID=called_number”) in new stack
– Executing [called_number@from-trunk:2] Set(“SIP/CallPlus-000090f5”, “CHANNEL(language)=en_NZ”) in new stack
– Executing [called_number@from-trunk:3] Gosub(“SIP/CallPlus-000090f5”, “app-blacklist-check,s,1()”) in new stack
– Executing [s@app-blacklist-check:1] GotoIf(“SIP/CallPlus-000090f5”, “0?blacklisted”) in new stack
– Executing [s@app-blacklist-check:2] Set(“SIP/CallPlus-000090f5”, “CALLED_BLACKLIST=1”) in new stack
– Executing [s@app-blacklist-check:3] Return(“SIP/CallPlus-000090f5”, “”) in new stack
– Executing [called_number@from-trunk:4] Set(“SIP/CallPlus-000090f5”, “CDR(did)=called_number”) in new stack
– Executing [called_number@from-trunk:5] ExecIf(“SIP/CallPlus-000090f5”, “0 ?Set(CALLERID(name)=my_phone _number)”) in new stack
– Executing [called_number@from-trunk:6] Set(“SIP/CallPlus-000090f5”, “CHANNEL(musicclass)=Maxicom”) in new stack
– Executing [called_number@from-trunk:7] Set(“SIP/CallPlus-000090f5”, “__MOHCLASS=Maxicom”) in new stack
[2015-12-13 16:52:20] WARNING[18327][C-00012ac4]: func_channel.c:538 func_channel_read: Unknown or unavailable item requested: ‘reversecharge’
– Executing [called_number@from-trunk:8] GotoIf(“SIP/CallPlus-000090f5”, “0?macro-hangupcall”) in new stack
– Executing [called_number@from-trunk:9] Set(“SIP/CallPlus-000090f5”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
– Executing [called_number@from-trunk:10] Set(“SIP/CallPlus-000090f5”, “CALLERPRES()=allowed_not_screened”) in new stack
– Executing [called_number@from-trunk:11] Goto(“SIP/CallPlus-000090f5”, “app-setcid,96,1”) in new stack
– Goto (app-setcid,96,1)
– Executing [96@app-setcid:1] NoOp(“SIP/CallPlus-000090f5”, “(*DDI 95) Changing cid to called_number <my_phone _number>”) in new stack
– Executing [96@app-setcid:2] Set(“SIP/CallPlus-000090f5”, “CALLERID(name)=called_number”) in new stack
– Executing [96@app-setcid:3] Set(“SIP/CallPlus-000090f5”, “CALLERID(num)=my_phone _number”) in new stack
– Executing [96@app-setcid:4] Goto(“SIP/CallPlus-000090f5”, “ext-local,vmu395,1”) in new stack
– Goto (ext-local,vmu395,1)
– Executing [vmu395@ext-local:1] Macro(“SIP/CallPlus-000090f5”, “vm,395,NOANSWER,”) in new stack
– Executing [s@macro-vm:1] Macro(“SIP/CallPlus-000090f5”, “user-callerid,SKIPTTL”) in new stack
– Executing [s@macro-user-callerid:1] Set(“SIP/CallPlus-000090f5”, “TOUCH_MONITOR=1449978740.203163”) in new stack
– Executing [s@macro-user-callerid:2] Set(“SIP/CallPlus-000090f5”, “AMPUSER=my_phone _number”) in new stack
– Executing [s@macro-user-callerid:3] GotoIf(“SIP/CallPlus-000090f5”, “0?report”) in new stack
– Executing [s@macro-user-callerid:4] ExecIf(“SIP/CallPlus-000090f5”, “1?Set(REALCALLERIDNUM=my_phone _number)”) in new stack
– Executing [s@macro-user-callerid:5] Set(“SIP/CallPlus-000090f5”, “AMPUSER=”) in new stack
– Executing [s@macro-user-callerid:6] GotoIf(“SIP/CallPlus-000090f5”, “0?limit”) in new stack
– Executing [s@macro-user-callerid:7] Set(“SIP/CallPlus-000090f5”, “AMPUSERCIDNAME=”) in new stack
– Executing [s@macro-user-callerid:8] GotoIf(“SIP/CallPlus-000090f5”, “1?report”) in new stack
– Goto (macro-user-callerid,s,16)
– Executing [s@macro-user-callerid:16] GotoIf(“SIP/CallPlus-000090f5”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,30)
– Executing [s@macro-user-callerid:30] Set(“SIP/CallPlus-000090f5”, “CALLERID(number)=my_phone _number”) in new stack
– Executing [s@macro-user-callerid:31] Set(“SIP/CallPlus-000090f5”, “CALLERID(name)=called_number”) in new stack
– Executing [s@macro-user-callerid:32] Set(“SIP/CallPlus-000090f5”, “CDR(cnum)=my_phone _number”) in new stack
– Executing [s@macro-user-callerid:33] Set(“SIP/CallPlus-000090f5”, “CDR(cnam)=called_number”) in new stack
– Executing [s@macro-user-callerid:34] Set(“SIP/CallPlus-000090f5”, “CHANNEL(language)=en_NZ”) in new stack
– Executing [s@macro-vm:2] Set(“SIP/CallPlus-000090f5”, “VMGAIN=g(12)”) in new stack
– Executing [s@macro-vm:3] Macro(“SIP/CallPlus-000090f5”, “blkvm-check,”) in new stack
– Executing [s@macro-blkvm-check:1] Set(“SIP/CallPlus-000090f5”, “GOSUB_RETVAL=”) in new stack
– Executing [s@macro-blkvm-check:2] ExecIf(“SIP/CallPlus-000090f5”, “0?Set(GOSUB_RETVAL=TRUE)”) in new stack
– Executing [s@macro-blkvm-check:3] MacroExit(“SIP/CallPlus-000090f5”, “”) in new stack
– Executing [s@macro-vm:4] GotoIf(“SIP/CallPlus-000090f5”, “1?vmx,1”) in new stack
– Goto (macro-vm,vmx,1)
– Executing [vmx@macro-vm:1] Set(“SIP/CallPlus-000090f5”, “MEXTEN=395”) in new stack
– Executing [vmx@macro-vm:2] Set(“SIP/CallPlus-000090f5”, “MMODE=NOANSWER”) in new stack
– Executing [vmx@macro-vm:3] Set(“SIP/CallPlus-000090f5”, “RETVM=”) in new stack
– Executing [vmx@macro-vm:4] Set(“SIP/CallPlus-000090f5”, “MODE=unavail”) in new stack
– Executing [vmx@macro-vm:5] Macro(“SIP/CallPlus-000090f5”, “get-vmcontext,395”) in new stack
– Executing [s@macro-get-vmcontext:1] Set(“SIP/CallPlus-000090f5”, “VMCONTEXT=default”) in new stack
– Executing [s@macro-get-vmcontext:2] GotoIf(“SIP/CallPlus-000090f5”, “0?200:300”) in new stack
– Goto (macro-get-vmcontext,s,300)
– Executing [s@macro-get-vmcontext:300] NoOp(“SIP/CallPlus-000090f5”, “”) in new stack
– Executing [vmx@macro-vm:6] Set(“SIP/CallPlus-000090f5”, “MODE=unavail”) in new stack
– Executing [vmx@macro-vm:7] NoOp(“SIP/CallPlus-000090f5”, “MODE IS: unavail”) in new stack
– Executing [vmx@macro-vm:8] GotoIf(“SIP/CallPlus-000090f5”, “0?chknomsg”) in new stack
– Executing [vmx@macro-vm:9] Set(“SIP/CallPlus-000090f5”, “VM_OPTS=”) in new stack
– Executing [vmx@macro-vm:10] GotoIf(“SIP/CallPlus-000090f5”, “0?s-NOANSWER,1”) in new stack
– Executing [vmx@macro-vm:11] GotoIf(“SIP/CallPlus-000090f5”, “1?notdirect”) in new stack
– Goto (macro-vm,vmx,13)
– Executing [vmx@macro-vm:13] NoOp(“SIP/CallPlus-000090f5”, “Checking if ext 395 is enabled: enabled”) in new stack
– Executing [vmx@macro-vm:14] GotoIf(“SIP/CallPlus-000090f5”, “0?s-NOANSWER,1”) in new stack
– Executing [vmx@macro-vm:15] GotoIf(“SIP/CallPlus-000090f5”, “1?nofile”) in new stack
– Goto (macro-vm,vmx,56)
– Executing [vmx@macro-vm:56] NoOp(“SIP/CallPlus-000090f5”, “File for mode: unavail does not exist, SYSTEMSTATUS: , going to normal voicemail”) in new stack
– Executing [vmx@macro-vm:57] Goto(“SIP/CallPlus-000090f5”, “s-NOANSWER,1”) in new stack
– Goto (macro-vm,s-NOANSWER,1)
– Executing [s-NOANSWER@macro-vm:1] Macro(“SIP/CallPlus-000090f5”, “get-vmcontext,395”) in new stack
– Executing [s@macro-get-vmcontext:1] Set(“SIP/CallPlus-000090f5”, “VMCONTEXT=default”) in new stack
– Executing [s@macro-get-vmcontext:2] GotoIf(“SIP/CallPlus-000090f5”, “0?200:300”) in new stack
– Goto (macro-get-vmcontext,s,300)
– Executing [s@macro-get-vmcontext:300] NoOp(“SIP/CallPlus-000090f5”, “”) in new stack
– Executing [s-NOANSWER@macro-vm:2] VoiceMail(“SIP/CallPlus-000090f5”, “395@default,ug(12)”) in new stack
Audio is at 36030
Adding codec 100003 (ulaw) to SDP
Adding codec 100004 (alaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP

<— Reliably Transmitting (no NAT) to 10.20.60.1:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.20.60.1:5060;branch=z9hG4bKd5f9hd301omgaokei491.1;received=10.20.60.1
From: my_phone _number <sip:my_phone [email protected]:5060;user=phone>;tag=1449979963
To: called_number sip:[email protected]:5060;user=phone;tag=as065b84ca
Call-ID: [email protected]
CSeq: 1 INVITE
Server: FPBX-12.0.65(11.17.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Session-Expires: 1800;refresher=uas
Contact: sip:[email protected]:5060
Content-Type: application/sdp
Require: timer
Content-Length: 260

v=0
o=root 901962426 901962426 IN IP4 10.13.154.157
s=Asterisk PBX 11.17.1
c=IN IP4 10.13.154.157
t=0 0
m=audio 36030 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

<------------>

<— SIP read from UDP:10.20.60.1:5060 —>
ACK sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 10.20.60.1:5060;branch=z9hG4bKfl2hn800380g8rs2m2s1.1
From: my_phone _number <sip:my_phone [email protected]:5060;user=phone>;tag=1449979963
To: called_number sip:[email protected]:5060;user=phone;tag=as065b84ca
Call-ID: [email protected]
CSeq: 1 ACK
Max-Forwards: 68
Content-Length: 0

<------------->
— (8 headers 0 lines) —
> 0xb2b47708 – Probation passed - setting RTP source address to 10.20.60.1:15194
– <SIP/CallPlus-000090f5> Playing ‘vm-theperson.gsm’ (language ‘en_NZ’)
[2015-12-13 16:52:20] NOTICE[18327][C-00012ac4]: channel.c:4301 __ast_read: Dropping incompatible voice frame on SIP/CallPlus-000090f5 of format ulaw since our native format has changed to (alaw)
– <SIP/CallPlus-000090f5> Playing ‘digits/3.gsm’ (language ‘en_NZ’)
– <SIP/CallPlus-000090f5> Playing ‘digits/9.gsm’ (language ‘en_NZ’)
– <SIP/CallPlus-000090f5> Playing ‘digits/5.gsm’ (language ‘en_NZ’)
[2015-12-13 16:52:23] NOTICE[2507]: chan_sip.c:29710 sip_poke_peer: Still have a QUALIFY dialog active, deleting
– <SIP/CallPlus-000090f5> Playing ‘vm-isunavail.gsm’ (language ‘en_NZ’)
[2015-12-13 16:52:24] NOTICE[2507]: chan_sip.c:29710 sip_poke_peer: Still have a QUALIFY dialog active, deleting
– <SIP/CallPlus-000090f5> Playing ‘vm-intro.gsm’ (language ‘en_NZ’)

<— SIP read from UDP:10.20.60.1:5060 —>
BYE sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 10.20.60.1:5060;branch=z9hG4bKfl2hn800380g8rs2m2s1cd0000010.1
From: my_phone _number <sip:my_phone [email protected]:5060;user=phone>;tag=1449979963
To: called_number sip:[email protected]:5060;user=phone;tag=as065b84ca
Call-ID: [email protected]
CSeq: 2 BYE
Max-Forwards: 68
Supported: timer
Content-Length: 0

<------------->
— (9 headers 0 lines) —
Sending to 10.20.60.1:5060 (no NAT)
Scheduling destruction of SIP dialog ‘[email protected]’ in 6400 ms (Method: BYE)

<— Transmitting (no NAT) to 10.20.60.1:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.20.60.1:5060;branch=z9hG4bKfl2hn800380g8rs2m2s1cd0000010.1;received=10.20.60.1
From: my_phone _number <sip:my_phone [email protected]:5060;user=phone>;tag=1449979963
To: called_number sip:[email protected]:5060;user=phone;tag=as065b84ca
Call-ID: [email protected]
CSeq: 2 BYE
Server: FPBX-12.0.65(11.17.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0

<------------>
== Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on ‘SIP/CallPlus-000090f5’ in macro ‘vm’
== Spawn extension (ext-local, vmu395, 1) exited non-zero on ‘SIP/CallPlus-000090f5’
– Executing [h@ext-local:1] Macro(“SIP/CallPlus-000090f5”, “hangupcall,”) in new stack
– Executing [s@macro-hangupcall:1] ExecIf(“SIP/CallPlus-000090f5”, “0?Set(CDR(recordingfile)=.)”) in new stack
– Executing [s@macro-hangupcall:2] GotoIf(“SIP/CallPlus-000090f5”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,4)
– Executing [s@macro-hangupcall:4] Hangup(“SIP/CallPlus-000090f5”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/CallPlus-000090f5’ in macro ‘hangupcall’
== Spawn extension (ext-local, h, 1) exited non-zero on 'SIP/CallPlus-000090f5’
usnCLI> sip set debug off
SIP Debugging Disabled
usn
CLI>


Part 2…

Next up is an incoming call to the Telco 2 trunk which is via the Internet.

This call sets up correctly, rings the target extension and can be answered, but there is no audio.

I’ve just noticed that the “Contact” line changes from
Contact: <sip:my_phone_number@“Telco 2”:5060> (line 32)
to Contact: sip:[email protected]:5060 (line 94)

Thats not what we want. It needs to stay as @Telco 2


usnCLI> sip set debug peer Maxicom
SIP Debugging Enabled for IP: “Telco 2”
– Attempting call on Local/s@tc-maint for application NoCDR() (Retry 1)
– Executing [s@tc-maint:1] NoCDR(“Local/s@tc-maint-00014428;2”, “”) in new stack
– Executing [s@tc-maint:2] Set(“Local/s@tc-maint-00014428;2”, “TCMAINT=RETURN”) in new stack
– Executing [s@tc-maint:3] Gosub(“Local/s@tc-maint-00014428;2”, “timeconditions,1,1()”) in new stack
– Executing [1@timeconditions:1] Set(“Local/s@tc-maint-00014428;2”, “DB(TC/1/INUSESTATE)=INUSE”) in new stack
– Executing [1@timeconditions:2] Set(“Local/s@tc-maint-00014428;2”, “DB(TC/1/NOT_INUSESTATE)=NOT_INUSE”) in new stack
– Executing [1@timeconditions:3] GotoIfTime(“Local/s@tc-maint-00014428;2”, "08:00-16:30,mon-fri,
,*?truestate") in new stack
– Executing [1@timeconditions:4] GotoIf(“Local/s@tc-maint-00014428;2”, “0?truegoto”) in new stack
– Executing [1@timeconditions:5] ExecIf(“Local/s@tc-maint-00014428;2”, “0?Set(DB(TC/1)=)”) in new stack
– Executing [1@timeconditions:6] Set(“Local/s@tc-maint-00014428;2”, “DEVICE_STATE(Custom:TC1)=INUSE”) in new stack
– Executing [1@timeconditions:7] ExecIf(“Local/s@tc-maint-00014428;2”, “0?Set(NOT_INUSE)”) in new stack
– Executing [1@timeconditions:8] GotoIf(“Local/s@tc-maint-00014428;2”, “0?ext-queues,9100,1”) in new stack
– Executing [1@timeconditions:9] Set(“Local/s@tc-maint-00014428;2”, “TCSTATE=false”) in new stack
– Executing [1@timeconditions:10] Set(“Local/s@tc-maint-00014428;2”, “TCOVERRIDE=false”) in new stack
– Executing [1@timeconditions:11] Return(“Local/s@tc-maint-00014428;2”, “”) in new stack
– Executing [s@tc-maint:4] System(“Local/s@tc-maint-00014428;2”, “/var/lib/asterisk/bin/schedtc.php 60 /var/spool/asterisk/outgoing 0”) in new stack
– Executing [s@tc-maint:5] Answer(“Local/s@tc-maint-00014428;2”, “”) in new stack
> Channel Local/s@tc-maint-00014428;1 was answered.
> Launching NoCDR() on Local/s@tc-maint-00014428;1
== Spawn extension (tc-maint, s, 5) exited non-zero on ‘Local/s@tc-maint-00014428;2’
[2015-12-13 16:31:00] NOTICE[17408]: pbx_spool.c:402 attempt_thread: Call completed to Local/s@tc-maint

<— SIP read from UDP:“Telco 2”:5060 —>
INVITE sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP “Telco 2”:5060;branch=z9hG4bK5031b6bf;rport
Max-Forwards: 70
From: “my name” <sip:my_phone_number@“Telco 2”>;tag=as28316508
To: sip:[email protected]:5060
Contact: <sip:my_phone_number@“Telco 2”:5060>
Call-ID: 1a43471c385b51f1131a679465e4a4b4@"Telco 2"
CSeq: 102 INVITE
User-Agent: NZ PBX
Date: Sun, 13 Dec 2015 03:31:01 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces
Content-Type: application/sdp
Content-Length: 340

v=0
o=root 1873276086 1873276086 IN IP4 "Telco 2"
s=NZ PBX
c=IN IP4 "Telco 2"
t=0 0
m=audio 33722 RTP/AVP 8 9 0 18 3 101
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
<------------->
— (14 headers 16 lines) —
Sending to “Telco 2”:5060 (no NAT)
Sending to “Telco 2”:5060 (no NAT)
Using INVITE request as basis request - 1a43471c385b51f1131a679465e4a4b4@"Telco 2"
Found peer ‘Maxicom’ for ‘my_phone_number’ from “Telco 2”:5060
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
Found RTP audio format 8
Found RTP audio format 9
Found RTP audio format 0
Found RTP audio format 18
Found RTP audio format 3
Found RTP audio format 101
Found audio description format PCMA for ID 8
Found audio description format G722 for ID 9
Found audio description format PCMU for ID 0
Found audio description format G729 for ID 18
Found audio description format GSM for ID 3
Found audio description format telephone-event for ID 101
Capabilities: us - (ulaw|alaw|g722), peer - audio=(gsm|ulaw|alaw|g729|g722)/video=(nothing)/text=(nothing), combined - (ulaw|alaw|g722)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port “Telco 2”:33722
Looking for Test_DDI in from-trunk (domain 192.168.13.13)
list_route: hop: <sip:my_phone_number@“Telco 2”:5060>

<— Transmitting (no NAT) to “Telco 2”:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP “Telco 2”:5060;branch=z9hG4bK5031b6bf;received=“Telco 2”;rport=5060
From: “my name” <sip:my_phone_number@“Telco 2”>;tag=as28316508
To: sip:[email protected]:5060
Call-ID: 1a43471c385b51f1131a679465e4a4b4@"Telco 2"
CSeq: 102 INVITE
Server: FPBX-12.0.65(11.17.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: sip:[email protected]:5060
Content-Length: 0

<------------>
– Executing [Test_DDI@from-trunk:1] Set(“SIP/Maxicom-000090e4”, “__FROM_DID=Test_DDI”) in new stack
– Executing [Test_DDI@from-trunk:2] Set(“SIP/Maxicom-000090e4”, “CHANNEL(language)=en_NZ”) in new stack
– Executing [Test_DDI@from-trunk:3] Gosub(“SIP/Maxicom-000090e4”, “sub-record-check,s,1(in,Test_DDI,dontcare)”) in new stack
– Executing [s@sub-record-check:1] GotoIf(“SIP/Maxicom-000090e4”, “0?initialized”) in new stack
– Executing [s@sub-record-check:2] Set(“SIP/Maxicom-000090e4”, “__REC_STATUS=INITIALIZED”) in new stack
– Executing [s@sub-record-check:3] Set(“SIP/Maxicom-000090e4”, “NOW=1449977462”) in new stack
– Executing [s@sub-record-check:4] Set(“SIP/Maxicom-000090e4”, “__DAY=13”) in new stack
– Executing [s@sub-record-check:5] Set(“SIP/Maxicom-000090e4”, “__MONTH=12”) in new stack
– Executing [s@sub-record-check:6] Set(“SIP/Maxicom-000090e4”, “__YEAR=2015”) in new stack
– Executing [s@sub-record-check:7] Set(“SIP/Maxicom-000090e4”, “__TIMESTR=20151213-163102”) in new stack
– Executing [s@sub-record-check:8] Set(“SIP/Maxicom-000090e4”, “__FROMEXTEN=unknown”) in new stack
– Executing [s@sub-record-check:9] Set(“SIP/Maxicom-000090e4”, “__MON_FMT=gsm”) in new stack
– Executing [s@sub-record-check:10] NoOp(“SIP/Maxicom-000090e4”, “Recordings initialized”) in new stack
– Executing [s@sub-record-check:11] ExecIf(“SIP/Maxicom-000090e4”, “0?Set(ARG3=dontcare)”) in new stack
– Executing [s@sub-record-check:12] Set(“SIP/Maxicom-000090e4”, “REC_POLICY_MODE_SAVE=”) in new stack
– Executing [s@sub-record-check:13] ExecIf(“SIP/Maxicom-000090e4”, “0?Set(REC_STATUS=NO)”) in new stack
– Executing [s@sub-record-check:14] GotoIf(“SIP/Maxicom-000090e4”, “2?checkaction”) in new stack
– Goto (sub-record-check,s,17)
– Executing [s@sub-record-check:17] GotoIf(“SIP/Maxicom-000090e4”, “1?sub-record-check,in,1”) in new stack
– Goto (sub-record-check,in,1)
– Executing [in@sub-record-check:1] NoOp(“SIP/Maxicom-000090e4”, “Inbound Recording Check to Test_DDI”) in new stack
– Executing [in@sub-record-check:2] Set(“SIP/Maxicom-000090e4”, “FROMEXTEN=unknown”) in new stack
– Executing [in@sub-record-check:3] ExecIf(“SIP/Maxicom-000090e4”, “9?Set(FROMEXTEN=my_phone_number)”) in new stack
– Executing [in@sub-record-check:4] Gosub(“SIP/Maxicom-000090e4”, “recordcheck,1(dontcare,in,Test_DDI)”) in new stack
– Executing [recordcheck@sub-record-check:1] NoOp(“SIP/Maxicom-000090e4”, “Starting recording check against dontcare”) in new stack
– Executing [recordcheck@sub-record-check:2] Goto(“SIP/Maxicom-000090e4”, “dontcare”) in new stack
– Goto (sub-record-check,recordcheck,3)
– Executing [recordcheck@sub-record-check:3] Return(“SIP/Maxicom-000090e4”, “”) in new stack
– Executing [in@sub-record-check:5] Return(“SIP/Maxicom-000090e4”, “”) in new stack
– Executing [Test_DDI@from-trunk:4] Gosub(“SIP/Maxicom-000090e4”, “app-blacklist-check,s,1()”) in new stack
– Executing [s@app-blacklist-check:1] GotoIf(“SIP/Maxicom-000090e4”, “0?blacklisted”) in new stack
– Executing [s@app-blacklist-check:2] Set(“SIP/Maxicom-000090e4”, “CALLED_BLACKLIST=1”) in new stack
– Executing [s@app-blacklist-check:3] Return(“SIP/Maxicom-000090e4”, “”) in new stack
– Executing [Test_DDI@from-trunk:5] Set(“SIP/Maxicom-000090e4”, “CDR(did)=Test_DDI”) in new stack
– Executing [Test_DDI@from-trunk:6] ExecIf(“SIP/Maxicom-000090e4”, “0 ?Set(CALLERID(name)=my_phone_number)”) in new stack
– Executing [Test_DDI@from-trunk:7] Set(“SIP/Maxicom-000090e4”, “CHANNEL(musicclass)=Maxicom”) in new stack
– Executing [Test_DDI@from-trunk:8] Set(“SIP/Maxicom-000090e4”, “__MOHCLASS=Maxicom”) in new stack
[2015-12-13 16:31:02] WARNING[17417][C-00012aa4]: func_channel.c:538 func_channel_read: Unknown or unavailable item requested: ‘reversecharge’
– Executing [Test_DDI@from-trunk:9] GotoIf(“SIP/Maxicom-000090e4”, “0?macro-hangupcall”) in new stack
– Executing [Test_DDI@from-trunk:10] Set(“SIP/Maxicom-000090e4”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
– Executing [Test_DDI@from-trunk:11] Set(“SIP/Maxicom-000090e4”, “CALLERPRES()=allowed_not_screened”) in new stack
– Executing [Test_DDI@from-trunk:12] Goto(“SIP/Maxicom-000090e4”, “from-did-direct,220,1”) in new stack
– Goto (from-did-direct,220,1)
– Executing [220@from-did-direct:1] GotoIf(“SIP/Maxicom-000090e4”, “1?ext-local,220,1”) in new stack
– Goto (ext-local,220,1)
– Executing [220@ext-local:1] Set(“SIP/Maxicom-000090e4”, “__RINGTIMER=15”) in new stack
– Executing [220@ext-local:2] Macro(“SIP/Maxicom-000090e4”, “exten-vm,novm,220,0,0,0”) in new stack
– Executing [s@macro-exten-vm:1] Macro(“SIP/Maxicom-000090e4”, “user-callerid,”) in new stack
– Executing [s@macro-user-callerid:1] Set(“SIP/Maxicom-000090e4”, “TOUCH_MONITOR=1449977462.203072”) in new stack
– Executing [s@macro-user-callerid:2] Set(“SIP/Maxicom-000090e4”, “AMPUSER=my_phone_number”) in new stack
– Executing [s@macro-user-callerid:3] GotoIf(“SIP/Maxicom-000090e4”, “0?report”) in new stack
– Executing [s@macro-user-callerid:4] ExecIf(“SIP/Maxicom-000090e4”, “1?Set(REALCALLERIDNUM=my_phone_number)”) in new stack
– Executing [s@macro-user-callerid:5] Set(“SIP/Maxicom-000090e4”, “AMPUSER=”) in new stack
– Executing [s@macro-user-callerid:6] GotoIf(“SIP/Maxicom-000090e4”, “0?limit”) in new stack
– Executing [s@macro-user-callerid:7] Set(“SIP/Maxicom-000090e4”, “AMPUSERCIDNAME=”) in new stack
– Executing [s@macro-user-callerid:8] GotoIf(“SIP/Maxicom-000090e4”, “1?report”) in new stack
– Goto (macro-user-callerid,s,16)
– Executing [s@macro-user-callerid:16] GotoIf(“SIP/Maxicom-000090e4”, “0?continue”) in new stack
– Executing [s@macro-user-callerid:17] ExecIf(“SIP/Maxicom-000090e4”, “1?Set(__CALLEE_ACCOUNCODE=Monitor)”) in new stack
– Executing [s@macro-user-callerid:18] Set(“SIP/Maxicom-000090e4”, “__TTL=64”) in new stack
– Executing [s@macro-user-callerid:19] GotoIf(“SIP/Maxicom-000090e4”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,30)
– Executing [s@macro-user-callerid:30] Set(“SIP/Maxicom-000090e4”, “CALLERID(number)=my_phone_number”) in new stack
– Executing [s@macro-user-callerid:31] Set(“SIP/Maxicom-000090e4”, “CALLERID(name)=Bond J & C”) in new stack
– Executing [s@macro-user-callerid:32] Set(“SIP/Maxicom-000090e4”, “CDR(cnum)=my_phone_number”) in new stack
– Executing [s@macro-user-callerid:33] Set(“SIP/Maxicom-000090e4”, “CDR(cnam)=Bond J & C”) in new stack
– Executing [s@macro-user-callerid:34] Set(“SIP/Maxicom-000090e4”, “CHANNEL(language)=en_NZ”) in new stack
– Executing [s@macro-exten-vm:2] Set(“SIP/Maxicom-000090e4”, “RingGroupMethod=none”) in new stack
– Executing [s@macro-exten-vm:3] Set(“SIP/Maxicom-000090e4”, “__EXTTOCALL=220”) in new stack
– Executing [s@macro-exten-vm:4] Set(“SIP/Maxicom-000090e4”, “__PICKUPMARK=220”) in new stack
– Executing [s@macro-exten-vm:5] Set(“SIP/Maxicom-000090e4”, “RT=”) in new stack
– Executing [s@macro-exten-vm:6] ExecIf(“SIP/Maxicom-000090e4”, “0?Macro(vm,novm,DIRECTDIAL,)”) in new stack
– Executing [s@macro-exten-vm:7] ExecIf(“SIP/Maxicom-000090e4”, “0?MacroExit()”) in new stack
– Executing [s@macro-exten-vm:8] Gosub(“SIP/Maxicom-000090e4”, “sub-record-check,s,1(exten,220,dontcare)”) in new stack
– Executing [s@sub-record-check:1] GotoIf(“SIP/Maxicom-000090e4”, “9?initialized”) in new stack
– Goto (sub-record-check,s,10)
– Executing [s@sub-record-check:10] NoOp(“SIP/Maxicom-000090e4”, “Recordings initialized”) in new stack
– Executing [s@sub-record-check:11] ExecIf(“SIP/Maxicom-000090e4”, “0?Set(ARG3=dontcare)”) in new stack
– Executing [s@sub-record-check:12] Set(“SIP/Maxicom-000090e4”, “REC_POLICY_MODE_SAVE=”) in new stack
– Executing [s@sub-record-check:13] ExecIf(“SIP/Maxicom-000090e4”, “0?Set(REC_STATUS=NO)”) in new stack
– Executing [s@sub-record-check:14] GotoIf(“SIP/Maxicom-000090e4”, “5?checkaction”) in new stack
– Goto (sub-record-check,s,17)
– Executing [s@sub-record-check:17] GotoIf(“SIP/Maxicom-000090e4”, “1?sub-record-check,exten,1”) in new stack
– Goto (sub-record-check,exten,1)
– Executing [exten@sub-record-check:1] NoOp(“SIP/Maxicom-000090e4”, “Exten Recording Check between my_phone_number and 220”) in new stack
– Executing [exten@sub-record-check:2] Set(“SIP/Maxicom-000090e4”, “CALLTYPE=external”) in new stack
– Executing [exten@sub-record-check:3] ExecIf(“SIP/Maxicom-000090e4”, “0?Set(CALLTYPE=)”) in new stack
– Executing [exten@sub-record-check:4] Set(“SIP/Maxicom-000090e4”, “CALLEE=force”) in new stack
– Executing [exten@sub-record-check:5] ExecIf(“SIP/Maxicom-000090e4”, “0?Set(CALLEE=dontcare)”) in new stack
– Executing [exten@sub-record-check:6] GotoIf(“SIP/Maxicom-000090e4”, “1?callee”) in new stack
– Goto (sub-record-check,exten,11)
– Executing [exten@sub-record-check:11] Gosub(“SIP/Maxicom-000090e4”, “recordcheck,1(force,external,220)”) in new stack
– Executing [recordcheck@sub-record-check:1] NoOp(“SIP/Maxicom-000090e4”, “Starting recording check against force”) in new stack
– Executing [recordcheck@sub-record-check:2] Goto(“SIP/Maxicom-000090e4”, “force”) in new stack
– Goto (sub-record-check,recordcheck,5)
– Executing [recordcheck@sub-record-check:5] Set(“SIP/Maxicom-000090e4”, “__REC_POLICY_MODE=FORCE”) in new stack
– Executing [recordcheck@sub-record-check:6] GotoIf(“SIP/Maxicom-000090e4”, “1?startrec”) in new stack
– Goto (sub-record-check,recordcheck,16)
– Executing [recordcheck@sub-record-check:16] NoOp(“SIP/Maxicom-000090e4”, “Starting recording: external, 220”) in new stack
– Executing [recordcheck@sub-record-check:17] Set(“SIP/Maxicom-000090e4”, “AUDIOHOOK_INHERIT(MixMonitor)=yes”) in new stack
– Executing [recordcheck@sub-record-check:18] Set(“SIP/Maxicom-000090e4”, “__CALLFILENAME=external-220-my_phone_number-20151213-163102-1449977462.203072”) in new stack
– Executing [recordcheck@sub-record-check:19] MixMonitor(“SIP/Maxicom-000090e4”, “2015/12/13/external-220-my_phone_number-20151213-163102-1449977462.203072.gsm,ai(LOCAL_MIXMON_ID),”) in new stack
– Executing [recordcheck@sub-record-check:20] Set(“SIP/Maxicom-000090e4”, “__MIXMON_ID=0xb2ac9068”) in new stack
– Executing [recordcheck@sub-record-check:21] Set(“SIP/Maxicom-000090e4”, “__RECORD_ID=SIP/Maxicom-000090e4”) in new stack
– Executing [recordcheck@sub-record-check:22] Set(“SIP/Maxicom-000090e4”, “__REC_STATUS=RECORDING”) in new stack
– Executing [recordcheck@sub-record-check:23] Set(“SIP/Maxicom-000090e4”, “CDR(recordingfile)=external-220-my_phone_number-20151213-163102-1449977462.203072.gsm”) in new stack
– Executing [recordcheck@sub-record-check:24] Return(“SIP/Maxicom-000090e4”, “”) in new stack
– Executing [exten@sub-record-check:12] Return(“SIP/Maxicom-000090e4”, “”) in new stack
– Executing [s@macro-exten-vm:9] GotoIf(“SIP/Maxicom-000090e4”, “1?macrodial”) in new stack
– Goto (macro-exten-vm,s,15)
– Executing [s@macro-exten-vm:15] GosubIf(“SIP/Maxicom-000090e4”, “0?clrheader,1()”) in new stack
– Executing [s@macro-exten-vm:16] Macro(“SIP/Maxicom-000090e4”, “dial-one,Ttr,220”) in new stack
– Executing [s@macro-dial-one:1] Set(“SIP/Maxicom-000090e4”, “DEXTEN=220”) in new stack
– Executing [s@macro-dial-one:2] Set(“SIP/Maxicom-000090e4”, “DIALSTATUS_CW=”) in new stack
– Executing [s@macro-dial-one:3] GosubIf(“SIP/Maxicom-000090e4”, “0?screen,1()”) in new stack
– Executing [s@macro-dial-one:4] GosubIf(“SIP/Maxicom-000090e4”, “0?cf,1()”) in new stack
– Executing [s@macro-dial-one:5] GotoIf(“SIP/Maxicom-000090e4”, “1?skip1”) in new stack
– Goto (macro-dial-one,s,8)
– Executing [s@macro-dial-one:8] GotoIf(“SIP/Maxicom-000090e4”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:9] GotoIf(“SIP/Maxicom-000090e4”, “0?continue”) in new stack
– Executing [s@macro-dial-one:10] Set(“SIP/Maxicom-000090e4”, “EXTHASCW=”) in new stack
– Executing [s@macro-dial-one:11] GotoIf(“SIP/Maxicom-000090e4”, “1?next1:cwinusebusy”) in new stack
– Goto (macro-dial-one,s,12)
– Executing [s@macro-dial-one:12] GotoIf(“SIP/Maxicom-000090e4”, “0?docfu:skip3”) in new stack
– Goto (macro-dial-one,s,16)
– Executing [s@macro-dial-one:16] GotoIf(“SIP/Maxicom-000090e4”, “1?next2:continue”) in new stack
– Goto (macro-dial-one,s,17)
== Begin MixMonitor Recording SIP/Maxicom-000090e4
– Executing [s@macro-dial-one:17] GotoIf(“SIP/Maxicom-000090e4”, “1?continue”) in new stack
– Goto (macro-dial-one,s,25)
– Executing [s@macro-dial-one:25] GotoIf(“SIP/Maxicom-000090e4”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:26] GosubIf(“SIP/Maxicom-000090e4”, “1?dstring,1():dlocal,1()”) in new stack
– Executing [dstring@macro-dial-one:1] Set(“SIP/Maxicom-000090e4”, “DSTRING=”) in new stack
– Executing [dstring@macro-dial-one:2] Set(“SIP/Maxicom-000090e4”, “DEVICES=220”) in new stack
– Executing [dstring@macro-dial-one:3] ExecIf(“SIP/Maxicom-000090e4”, “0?Return()”) in new stack
– Executing [dstring@macro-dial-one:4] ExecIf(“SIP/Maxicom-000090e4”, “0?Set(DEVICES=20)”) in new stack
– Executing [dstring@macro-dial-one:5] Set(“SIP/Maxicom-000090e4”, “LOOPCNT=1”) in new stack
– Executing [dstring@macro-dial-one:6] Set(“SIP/Maxicom-000090e4”, “ITER=1”) in new stack
– Executing [dstring@macro-dial-one:7] Set(“SIP/Maxicom-000090e4”, “THISDIAL=SIP/220”) in new stack
– Executing [dstring@macro-dial-one:8] GosubIf(“SIP/Maxicom-000090e4”, “1?zap2dahdi,1()”) in new stack
– Executing [zap2dahdi@macro-dial-one:1] ExecIf(“SIP/Maxicom-000090e4”, “0?Return()”) in new stack
– Executing [zap2dahdi@macro-dial-one:2] Set(“SIP/Maxicom-000090e4”, “NEWDIAL=”) in new stack
– Executing [zap2dahdi@macro-dial-one:3] Set(“SIP/Maxicom-000090e4”, “LOOPCNT2=1”) in new stack
– Executing [zap2dahdi@macro-dial-one:4] Set(“SIP/Maxicom-000090e4”, “ITER2=1”) in new stack
– Executing [zap2dahdi@macro-dial-one:5] Set(“SIP/Maxicom-000090e4”, “THISPART2=SIP/220”) in new stack
– Executing [zap2dahdi@macro-dial-one:6] ExecIf(“SIP/Maxicom-000090e4”, “0?Set(THISPART2=DAHDI/220)”) in new stack
– Executing [zap2dahdi@macro-dial-one:7] Set(“SIP/Maxicom-000090e4”, “NEWDIAL=SIP/220&”) in new stack
– Executing [zap2dahdi@macro-dial-one:8] Set(“SIP/Maxicom-000090e4”, “ITER2=2”) in new stack
– Executing [zap2dahdi@macro-dial-one:9] GotoIf(“SIP/Maxicom-000090e4”, “0?begin2”) in new stack
– Executing [zap2dahdi@macro-dial-one:10] Set(“SIP/Maxicom-000090e4”, “THISDIAL=SIP/220”) in new stack
– Executing [zap2dahdi@macro-dial-one:11] Return(“SIP/Maxicom-000090e4”, “”) in new stack
– Executing [dstring@macro-dial-one:9] GotoIf(“SIP/Maxicom-000090e4”, “1?doset”) in new stack
– Goto (macro-dial-one,dstring,12)
– Executing [dstring@macro-dial-one:12] Set(“SIP/Maxicom-000090e4”, “DSTRING=SIP/220&”) in new stack
– Executing [dstring@macro-dial-one:13] Set(“SIP/Maxicom-000090e4”, “ITER=2”) in new stack
– Executing [dstring@macro-dial-one:14] GotoIf(“SIP/Maxicom-000090e4”, “0?begin”) in new stack
– Executing [dstring@macro-dial-one:15] Set(“SIP/Maxicom-000090e4”, “DSTRING=SIP/220”) in new stack
– Executing [dstring@macro-dial-one:16] Return(“SIP/Maxicom-000090e4”, “”) in new stack
– Executing [s@macro-dial-one:27] GotoIf(“SIP/Maxicom-000090e4”, “0?nodial”) in new stack
– Executing [s@macro-dial-one:28] GotoIf(“SIP/Maxicom-000090e4”, “0?skiptrace”) in new stack
– Executing [s@macro-dial-one:29] GosubIf(“SIP/Maxicom-000090e4”, “1?ctset,1():ctclear,1()”) in new stack
– Executing [ctset@macro-dial-one:1] Set(“SIP/Maxicom-000090e4”, “DB(CALLTRACE/220)=my_phone_number”) in new stack
– Executing [ctset@macro-dial-one:2] Return(“SIP/Maxicom-000090e4”, “”) in new stack
– Executing [s@macro-dial-one:30] Set(“SIP/Maxicom-000090e4”, “D_OPTIONS=Ttr”) in new stack
– Executing [s@macro-dial-one:31] ExecIf(“SIP/Maxicom-000090e4”, “0?SIPAddHeader(Alert-Info: )”) in new stack
– Executing [s@macro-dial-one:32] ExecIf(“SIP/Maxicom-000090e4”, “0?SIPAddHeader()”) in new stack
– Executing [s@macro-dial-one:33] ExecIf(“SIP/Maxicom-000090e4”, “1?Set(CHANNEL(musicclass)=Maxicom)”) in new stack
– Executing [s@macro-dial-one:34] GosubIf(“SIP/Maxicom-000090e4”, “0?qwait,1()”) in new stack
– Executing [s@macro-dial-one:35] Set(“SIP/Maxicom-000090e4”, “__CWIGNORE=”) in new stack
– Executing [s@macro-dial-one:36] Set(“SIP/Maxicom-000090e4”, “__KEEPCID=TRUE”) in new stack
– Executing [s@macro-dial-one:37] GotoIf(“SIP/Maxicom-000090e4”, “0?usegoto,1”) in new stack
– Executing [s@macro-dial-one:38] GotoIf(“SIP/Maxicom-000090e4”, “1?godial”) in new stack
– Goto (macro-dial-one,s,42)
– Executing [s@macro-dial-one:42] Macro(“SIP/Maxicom-000090e4”, “dialout-one-predial-hook,”) in new stack
– Executing [s@macro-dialout-one-predial-hook:1] MacroExit(“SIP/Maxicom-000090e4”, “”) in new stack
– Executing [s@macro-dial-one:43] Dial(“SIP/Maxicom-000090e4”, “SIP/220,Ttr”) in new stack
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
– Called SIP/220

<— Transmitting (no NAT) to “Telco 2”:5060 —>
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP “Telco 2”:5060;branch=z9hG4bK5031b6bf;received=“Telco 2”;rport=5060
From: “my name” <sip:my_phone_number@“Telco 2”>;tag=as28316508
To: sip:[email protected]:5060;tag=as58ae8261
Call-ID: 1a43471c385b51f1131a679465e4a4b4@"Telco 2"
CSeq: 102 INVITE
Server: FPBX-12.0.65(11.17.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: sip:[email protected]:5060
Content-Length: 0

<------------>
– SIP/220-000090e5 is ringing

<— Transmitting (no NAT) to “Telco 2”:5060 —>
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP “Telco 2”:5060;branch=z9hG4bK5031b6bf;received=“Telco 2”;rport=5060
From: “my name” <sip:my_phone_number@“Telco 2”>;tag=as28316508
To: sip:[email protected]:5060;tag=as58ae8261
Call-ID: 1a43471c385b51f1131a679465e4a4b4@"Telco 2"
CSeq: 102 INVITE
Server: FPBX-12.0.65(11.17.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: sip:[email protected]:5060
Content-Length: 0

<------------>
– SIP/220-000090e5 answered SIP/Maxicom-000090e4
Audio is at 17704
Adding codec 100012 (g722) to SDP
Adding codec 100003 (ulaw) to SDP
Adding codec 100004 (alaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP

<— Reliably Transmitting (no NAT) to “Telco 2”:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP “Telco 2”:5060;branch=z9hG4bK5031b6bf;received=“Telco 2”;rport=5060
From: “my name” <sip:my_phone_number@“Telco 2”>;tag=as28316508
To: sip:[email protected]:5060;tag=as58ae8261
Call-ID: 1a43471c385b51f1131a679465e4a4b4@"Telco 2"
CSeq: 102 INVITE
Server: FPBX-12.0.65(11.17.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: sip:[email protected]:5060
Content-Type: application/sdp
Content-Length: 284

v=0
o=root 284436111 284436111 IN IP4 10.13.154.157
s=Asterisk PBX 11.17.1
c=IN IP4 10.13.154.157
t=0 0
m=audio 17704 RTP/AVP 9 0 8 101
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

<------------>

<— SIP read from UDP:“Telco 2”:5060 —>
ACK sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP “Telco 2”:5060;branch=z9hG4bK522e9682;rport
Max-Forwards: 70
From: “my name” <sip:my_phone_number@“Telco 2”>;tag=as28316508
To: sip:[email protected]:5060;tag=as58ae8261
Contact: <sip:my_phone_number@“Telco 2”:5060>
Call-ID: 1a43471c385b51f1131a679465e4a4b4@"Telco 2"
CSeq: 102 ACK
User-Agent: NZ PBX
Content-Length: 0

<------------->
— (10 headers 0 lines) —

<— SIP read from UDP:“Telco 2”:5060 —>
BYE sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP “Telco 2”:5060;branch=z9hG4bK1c4c26cc;rport
Max-Forwards: 70
From: “my name” <sip:my_phone_number@“Telco 2”>;tag=as28316508
To: sip:[email protected]:5060;tag=as58ae8261
Call-ID: 1a43471c385b51f1131a679465e4a4b4@"Telco 2"
CSeq: 103 BYE
User-Agent: NZ PBX
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0

<------------->
— (11 headers 0 lines) —
Sending to “Telco 2”:5060 (no NAT)
Scheduling destruction of SIP dialog ‘1a43471c385b51f1131a679465e4a4b4@“Telco 2”’ in 6400 ms (Method: BYE)

<— Transmitting (no NAT) to “Telco 2”:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP “Telco 2”:5060;branch=z9hG4bK1c4c26cc;received=“Telco 2”;rport=5060
From: “my name” <sip:my_phone_number@“Telco 2”>;tag=as28316508
To: sip:[email protected]:5060;tag=as58ae8261
Call-ID: 1a43471c385b51f1131a679465e4a4b4@"Telco 2"
CSeq: 103 BYE
Server: FPBX-12.0.65(11.17.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0

<------------>
– Executing [h@macro-dial-one:1] Macro(“SIP/Maxicom-000090e4”, “hangupcall,”) in new stack
– Executing [s@macro-hangupcall:1] ExecIf(“SIP/Maxicom-000090e4”, “0?Set(CDR(recordingfile)=external-220-my_phone_number-20151213-163102-1449977462.203072.gsm)”) in new stack
– Executing [s@macro-hangupcall:2] GotoIf(“SIP/Maxicom-000090e4”, “1?theend”) in new stack
– Goto (macro-hangupcall,s,4)
– Executing [s@macro-hangupcall:4] Hangup(“SIP/Maxicom-000090e4”, “”) in new stack
== Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/Maxicom-000090e4’ in macro ‘hangupcall’
== Spawn extension (macro-dial-one, h, 1) exited non-zero on ‘SIP/Maxicom-000090e4’
== Spawn extension (macro-dial-one, s, 43) exited non-zero on ‘SIP/Maxicom-000090e4’ in macro ‘dial-one’
== Spawn extension (macro-exten-vm, s, 16) exited non-zero on ‘SIP/Maxicom-000090e4’ in macro ‘exten-vm’
== Spawn extension (ext-local, 220, 2) exited non-zero on ‘SIP/Maxicom-000090e4’
== MixMonitor close filestream (mixed)
== End MixMonitor Recording SIP/Maxicom-000090e4
Reliably Transmitting (no NAT) to “Telco 2”:5060:
OPTIONS sip:“Telco 2” SIP/2.0
Via: SIP/2.0/UDP 10.13.154.157:5060;branch=z9hG4bK65947c33
Max-Forwards: 70
From: “Unknown” sip:[email protected];tag=as2d55264f
To: <sip:“Telco 2”>
Contact: sip:[email protected]:5060
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-12.0.65(11.17.1)
Date: Sun, 13 Dec 2015 03:31:19 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


<— SIP read from UDP:“Telco 2”:5060 —>
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 10.13.154.157:5060;branch=z9hG4bK65947c33;received=yyy.yyy.yyy.yyy;rport=5060
From: “Unknown” sip:[email protected];tag=as2d55264f
To: <sip:“Telco 2”>;tag=as29972313
Call-ID: [email protected]:5060
CSeq: 102 OPTIONS
Server: NZ PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces
Accept: application/sdp
Content-Length: 0

<------------->
— (11 headers 0 lines) —
Really destroying SIP dialog ‘[email protected]:5060’ Method: OPTIONS
Really destroying SIP dialog ‘1a43471c385b51f1131a679465e4a4b4@“Telco 2”’ Method: BYE
[2015-12-13 16:31:23] NOTICE[2507]: chan_sip.c:29710 sip_poke_peer: Still have a QUALIFY dialog active, deleting
[2015-12-13 16:31:24] NOTICE[2507]: chan_sip.c:29710 sip_poke_peer: Still have a QUALIFY dialog active, deleting
usnCLI> sip set debug off
SIP Debugging Disabled
usn
CLI>


Network settings as requested form Settings/Asterisk SIP Settings/General SIP Settings

External Address yyy.yyy.yyy.yyy
Local networks 10.8.0.0/24 (VPN)
192.168.13.0/24 (Native VLan)
10.13.154.144/28 (VLan 25)

From Settings/Asterisk SIP Settings/Chan SIP

NAT No
IP Configuration Static
Override External IP 10.13.154.157

VLan 25 (eth0.25) is defined in System Admin/Network Settings

Static IP 10.13.154.157
Netmask 225.225.225.240
Gateway 10.13.154.158

Let me know if there is anything else you need.

Appreciate the support

Jon

So you are having one way or two way audio issues? And do you have the PBX setup to do NAT? Because this is completely a networking configuration issue. With all the private LANs I’m seeing and the fact that all the debugs show “No NAT” this isn’t going to work until you resolve your networking issues.

You do realize that the “Override External IP” is for an IP or FQDN that’s on the WAN side of your router, not the LAN so having a private LAN IP will not work. You also cannot have two override IPs on the Chan_SIP trunk.

It’s no speech at all, so lets call that 2 way.

I don’t think it is a NAT problem although i wouldn’t rule out some other networking issue.

From what i can see, from the unsuccessful “Telco 2” trace, in the packet immediately after the Invite,(100, Trying) the PBX sets it’s Contact URI to [email protected].
I would have expected [email protected]

The next packet (Status 200 OK from the PBX) repeats the [email protected] Contact URI

The packet after, (Request ACK… from Telco 2) is addressed correctly, [email protected]

Bu from here on, its all one way RTP traffic from the PBX.
There is no reply from Telco 2 as although the packet Destination address is correct (Telco 2’s SIP Peering server), the Source address is 10.13.154.157

10.13.154.157 belongs on Vlan 25, not the native VLan, so why is FPBX issuing this as the Source address for SIP traffic on the Native VLan ?

10.13.154.157 only appears in the config in two places that i can see
It’s the defined Static IP for Eth 0.25 and the Override External IP as previously mentioned.

I’ll take a closer look on Monday and see what i can find.
In the meantime i’ll take any suggestions.

Jon

Yeah, I’m not sure it’s a NAT issue either but there’s something going on within the network. How is the audio on endpoint to endpoint calls? So if you have ext 100 and ext 200 do you have audio between the two?

Endpoint/endpoint audio and endpoint/private trunk audio are all fine.

This is a working system running a 24/7 call centre.
The SIP peering trunk via the internet is an add-on for diversity and call-cost reduction.

Jon