No final ACK recieved on inbound SIP call

I am hoping that somebody out there can help me with a problem I have configuring a SIP peer to a VoIP service provider.

I have recently set up an Asterisk server with FreePBX and gone through the basic configuration to add a few extensions and a SIP trunk to a service provider. Everything looks fine and I can make calls between extensions and can make a call inbound from the SIP trunk. The extension I am pointing the call to from the trunk rings and I can answer but I do not get any audio in the external to internal direction. I ran a test making a call and capturing the logfiles. What I can see is an Invite being recieved, the request is forwarded to the extension, and SIP 180 Ringing returned to the external trunk. When the extension is answered a SIP 200 OK is sent to the trunk but no ACK is recieved in response to this. Therefore, Asterisk sends re-transmittions of the 200 OK until the max number of retransissions is reached and drops the call. Obviously there is no audio inbound during this time because the call is not yet established.

If I set up a softphone client such as X-Lite and register that with the service provider SIP trunk from the same LAN instead of the Asterisk server and make the same inbound test call, I do get the ACK and the call is successful so it looks like the broadband router is not blocking ports etc.

For background information the service provider is Plusnet in the UK and this is the account details they sent me …

Your phone number: xxxxxxxxxxxxxx
Your SIP ID: nnnnnnnn
Your SIP password: password
Your username: nnnnnnnn
Your voicemail pin code: pppp

Basic server settings

Your SIP domain: sip.plus.net
Your SIP proxy: nat.plus.net:5082

I have checked the registration status and the trunk is registered OK and the SIP Peer shows as OK too.

This is a log of a call that I made as a test …

<— SIP read from UDP:79.135.125.154:5060 —>
INVITE sip:[email protected]:5060 SIP/2.0
Record-Route: sip:79.135.125.154;lr=on;ftag=as79ddaf3b;did=29d.7d309816
Via: SIP/2.0/UDP 79.135.125.154:5060;branch=z9hG4bK26c5.8a8400f5.0
Via: SIP/2.0/UDP 212.11.91.119:5060;received=212.11.91.119;branch=z9hG4bK13873a52;rport=5060
From: “External_CID” sip:[email protected];tag=as79ddaf3b
To: sip:[email protected]
Contact: sip:[email protected]
Call-ID: [email protected]
CSeq: 102 INVITE
Max-Forwards: 69
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Type: application/sdp
Content-Length: 492

v=0
o=root 19061 19061 IN IP4 212.11.91.119
s=session
c=IN IP4 212.11.91.119
t=0 0
m=audio 11748 RTP/AVP 8 0 18 4 3 111 112 97 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:4 G723/8000
a=fmtp:4 annexa=no
a=rtpmap:3 GSM/8000
a=rtpmap:111 G726-32/8000
a=rtpmap:112 AAL2-G726-32/8000
a=rtpmap:97 iLBC/8000
a=fmtp:97 mode=30
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

<------------->
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: — (14 headers 22 lines) —
[Jan 7 23:23:13] VERBOSE[2948] netsock.c: == Using SIP RTP TOS bits 184
[Jan 7 23:23:13] VERBOSE[2948] netsock.c: == Using SIP RTP CoS mark 5
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Sending to 79.135.125.154 : 5060 (NAT)
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Using INVITE request as basis request - [email protected]
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Found peer ‘Plusnet SIP’ for ‘External_CID’ from 79.135.125.154:5060
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Found RTP audio format 8
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Found RTP audio format 0
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Found RTP audio format 18
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Found RTP audio format 4
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Found RTP audio format 3
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Found RTP audio format 111
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Found RTP audio format 112
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Found RTP audio format 97
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Found RTP audio format 101
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Found audio description format PCMA for ID 8
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Found audio description format PCMU for ID 0
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Found audio description format G729 for ID 18
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Found audio description format G723 for ID 4
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Found audio description format GSM for ID 3
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Found audio description format G726-32 for ID 111
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Found audio description format AAL2-G726-32 for ID 112
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Found audio description format iLBC for ID 97
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Found audio description format telephone-event for ID 101
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Capabilities: us - 0x8 (alaw), peer - audio=0xd1f (g723|gsm|ulaw|alaw|g726|g729|ilbc|g726aal2)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x8 (alaw)
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Peer audio RTP is at port 212.11.91.119:11748
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: Looking for Plusnet_in in from-pstn (domain 192.168.1.132)
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c: list_route: hop: sip:79.135.125.154;lr=on;ftag=as79ddaf3b;did=29d.7d309816
[Jan 7 23:23:13] VERBOSE[2948] chan_sip.c:
<— Transmitting (NAT) to 79.135.125.154:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 79.135.125.154:5060;branch=z9hG4bK26c5.8a8400f5.0;received=79.135.125.154
Via: SIP/2.0/UDP 212.11.91.119:5060;received=212.11.91.119;branch=z9hG4bK13873a52;rport=5060
Record-Route: sip:79.135.125.154;lr=on;ftag=as79ddaf3b;did=29d.7d309816
From: “External_CID” sip:[email protected];tag=as79ddaf3b
To: sip:[email protected]
Call-ID: [email protected]
CSeq: 102 INVITE
Server: FPBX-2.7.0(1.6.2.11)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: sip:[email protected]
Content-Length: 0

<------------>
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:1] NoOp(“SIP/Plusnet SIP-00000018”, “Catch-All DID Match - Found Plusnet_in - You probably want a DID for this.”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:2] Goto(“SIP/Plusnet SIP-00000018”, “ext-did,s,1”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Goto (ext-did,s,1)
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:1] Set(“SIP/Plusnet SIP-00000018”, “__FROM_DID=s”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:2] ExecIf(“SIP/Plusnet SIP-00000018”, “0 ?Set(CALLERID(name)=External_CID)”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:3] Set(“SIP/Plusnet SIP-00000018”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:4] Set(“SIP/Plusnet SIP-00000018”, “CALLERPRES()=allowed_not_screened”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:5] Goto(“SIP/Plusnet SIP-00000018”, “from-did-direct,241,1”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Goto (from-did-direct,241,1)
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:1] Macro(“SIP/Plusnet SIP-00000018”, “exten-vm,novm,241”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:1] Macro(“SIP/Plusnet SIP-00000018”, “user-callerid,”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:1] Set(“SIP/Plusnet SIP-00000018”, “AMPUSER=External_CID”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:2] GotoIf(“SIP/Plusnet SIP-00000018”, “0?report”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:3] ExecIf(“SIP/Plusnet SIP-00000018”, “1?Set(REALCALLERIDNUM=External_CID)”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:4] Set(“SIP/Plusnet SIP-00000018”, “AMPUSER=”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:5] Set(“SIP/Plusnet SIP-00000018”, “AMPUSERCIDNAME=”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:6] GotoIf(“SIP/Plusnet SIP-00000018”, “1?report”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Goto (macro-user-callerid,s,9)
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:9] GotoIf(“SIP/Plusnet SIP-00000018”, “0?continue”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:10] Set(“SIP/Plusnet SIP-00000018”, “__TTL=64”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:11] GotoIf(“SIP/Plusnet SIP-00000018”, “1?continue”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Goto (macro-user-callerid,s,18)
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:18] Set(“SIP/Plusnet SIP-00000018”, “CALLERID(number)=External_CID”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:19] Set(“SIP/Plusnet SIP-00000018”, “CALLERID(name)=External_CID”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:20] NoOp(“SIP/Plusnet SIP-00000018”, “Using CallerID “External_CID” <External_CID>”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:2] Set(“SIP/Plusnet SIP-00000018”, “RingGroupMethod=none”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:3] Set(“SIP/Plusnet SIP-00000018”, “VMBOX=novm”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:4] Set(“SIP/Plusnet SIP-00000018”, “EXTTOCALL=241”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:5] Set(“SIP/Plusnet SIP-00000018”, “CFUEXT=”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:6] Set(“SIP/Plusnet SIP-00000018”, “CFBEXT=”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:7] Set(“SIP/Plusnet SIP-00000018”, “RT=”"") in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:8] Macro(“SIP/Plusnet SIP-00000018”, “record-enable,241,IN”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:1] GotoIf(“SIP/Plusnet SIP-00000018”, “1?check”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Goto (macro-record-enable,s,4)
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:4] ExecIf(“SIP/Plusnet SIP-00000018”, “0?MacroExit()”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:5] GotoIf(“SIP/Plusnet SIP-00000018”, “0?Group:OUT”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Goto (macro-record-enable,s,15)
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:15] GotoIf(“SIP/Plusnet SIP-00000018”, “1?IN”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Goto (macro-record-enable,s,20)
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:20] ExecIf(“SIP/Plusnet SIP-00000018”, “1?MacroExit()”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:9] Macro(“SIP/Plusnet SIP-00000018”, “dial,tr,241”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:1] GotoIf(“SIP/Plusnet SIP-00000018”, “1?dial”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Goto (macro-dial,s,3)
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:3] AGI(“SIP/Plusnet SIP-00000018”, “dialparties.agi”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] res_agi.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[Jan 7 23:23:13] VERBOSE[4171] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[Jan 7 23:23:13] VERBOSE[4171] res_agi.c: dialparties.agi: Caller ID name is ‘External_CID’ number is ‘External_CID’
[Jan 7 23:23:13] VERBOSE[4171] res_agi.c: dialparties.agi: Methodology of ring is ‘none’
[Jan 7 23:23:13] VERBOSE[4171] res_agi.c: – dialparties.agi: Added extension 241 to extension map
[Jan 7 23:23:13] VERBOSE[4171] res_agi.c: – dialparties.agi: Extension 241 cf is disabled
[Jan 7 23:23:13] VERBOSE[4171] res_agi.c: – dialparties.agi: Extension 241 do not disturb is disabled
[Jan 7 23:23:13] VERBOSE[4171] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[Jan 7 23:23:13] VERBOSE[4171] res_agi.c: – dialparties.agi: dbset CALLTRACE/241 to External_CID
[Jan 7 23:23:13] VERBOSE[4171] res_agi.c: – dialparties.agi: Filtered ARG3: 241
[Jan 7 23:23:13] VERBOSE[4171] res_agi.c: – <SIP/Plusnet SIP-00000018>AGI Script dialparties.agi completed, returning 0
[Jan 7 23:23:13] VERBOSE[4171] pbx.c: – Executing [[email protected]:7] Dial(“SIP/Plusnet SIP-00000018”, “SIP/241,tr”) in new stack
[Jan 7 23:23:13] VERBOSE[4171] netsock.c: == Using SIP RTP TOS bits 184
[Jan 7 23:23:13] VERBOSE[4171] netsock.c: == Using SIP RTP CoS mark 5
[Jan 7 23:23:13] VERBOSE[4171] chan_sip.c: Audio is at 192.168.1.132 port 11272
[Jan 7 23:23:13] VERBOSE[4171] chan_sip.c: Adding codec 0x8 (alaw) to SDP
[Jan 7 23:23:13] VERBOSE[4171] chan_sip.c: Adding codec 0x4 (ulaw) to SDP
[Jan 7 23:23:13] VERBOSE[4171] chan_sip.c: Adding codec 0x2 (gsm) to SDP
[Jan 7 23:23:13] VERBOSE[4171] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[Jan 7 23:23:13] VERBOSE[4171] chan_sip.c: Reliably Transmitting (NAT) to 192.168.1.158:5060:
INVITE sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.132:5060;branch=z9hG4bK002f8bdc;rport
Max-Forwards: 70
From: “External_CID” sip:[email protected];tag=as654adac6
To: sip:[email protected]:5060
Contact: sip:[email protected]
Call-ID: [email protected]
CSeq: 102 INVITE
User-Agent: FPBX-2.7.0(1.6.2.11)
Date: Fri, 07 Jan 2005 23:23:13 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 284

v=0
o=root 951391704 951391704 IN IP4 192.168.1.132
s=Asterisk PBX 1.6.2.11
c=IN IP4 192.168.1.132
t=0 0
m=audio 11272 RTP/AVP 8 0 3 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv


[Jan 7 23:23:13] VERBOSE[4171] app_dial.c: – Called 241
[Jan 7 23:23:13] VERBOSE[4171] chan_sip.c:
<— Transmitting (NAT) to 79.135.125.154:5060 —>
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 79.135.125.154:5060;branch=z9hG4bK26c5.8a8400f5.0;received=79.135.125.154
Via: SIP/2.0/UDP 212.11.91.119:5060;received=212.11.91.119;branch=z9hG4bK13873a52;rport=5060
Record-Route: sip:79.135.125.154;lr=on;ftag=as79ddaf3b;did=29d.7d309816
From: “External_CID” sip:[email protected];tag=as79ddaf3b
To: sip:[email protected];tag=as6b5dfa80
Call-ID: [email protected]
CSeq: 102 INVITE
Server: FPBX-2.7.0(1.6.2.11)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: sip:[email protected]
Content-Length: 0

<------------>
[Jan 7 23:23:14] VERBOSE[2948] chan_sip.c:
<— SIP read from UDP:192.168.1.158:5060 —>
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.1.132:5060;branch=z9hG4bK002f8bdc;rport
Call-ID: [email protected]
CSeq: 102 INVITE
From: “External_CID” sip:[email protected];tag=as654adac6
To: sip:[email protected]:5060;tag=JmrUGs3kzbh3xLJO
Contact: sip:[email protected]:5060
Content-Length: 0

<------------->
[Jan 7 23:23:14] VERBOSE[2948] chan_sip.c: — (8 headers 0 lines) —
[Jan 7 23:23:14] VERBOSE[4171] app_dial.c: – SIP/241-00000019 is ringing
[Jan 7 23:23:14] VERBOSE[4171] chan_sip.c:
<— Transmitting (NAT) to 79.135.125.154:5060 —>
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 79.135.125.154:5060;branch=z9hG4bK26c5.8a8400f5.0;received=79.135.125.154
Via: SIP/2.0/UDP 212.11.91.119:5060;received=212.11.91.119;branch=z9hG4bK13873a52;rport=5060
Record-Route: sip:79.135.125.154;lr=on;ftag=as79ddaf3b;did=29d.7d309816
From: “External_CID” sip:[email protected];tag=as79ddaf3b
To: sip:[email protected];tag=as6b5dfa80
Call-ID: [email protected]
CSeq: 102 INVITE
Server: FPBX-2.7.0(1.6.2.11)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: sip:[email protected]
Content-Length: 0

<------------>
<— SIP read from UDP:192.168.1.158:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.132:5060;branch=z9hG4bK002f8bdc;rport
Call-ID: [email protected]
CSeq: 102 INVITE
From: “External_CID” sip:[email protected];tag=as654adac6
To: sip:[email protected]:5060;tag=JmrUGs3kzbh3xLJO
Contact: sip:[email protected]:5060
Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REFER, NOTIFY, INFO, PRACK, UPDATE, MESSAGE
Supported: replaces
Content-Type: application/sdp
Content-Length: 138

v=0
o=- 90002947 07009832 IN IP4 192.168.1.158
s=SIP CALL
c=IN IP4 192.168.1.158
t=0 0
m=audio 1722 RTP/AVP 8
a=rtpmap:8 PCMA/8000

<------------->
[Jan 7 23:23:18] VERBOSE[2948] chan_sip.c: — (11 headers 7 lines) —
[Jan 7 23:23:18] VERBOSE[2948] chan_sip.c: Found RTP audio format 8
[Jan 7 23:23:18] VERBOSE[2948] chan_sip.c: Found audio description format PCMA for ID 8
[Jan 7 23:23:18] VERBOSE[2948] chan_sip.c: Capabilities: us - 0x50e (gsm|ulaw|alaw|g729|ilbc), peer - audio=0x8 (alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x8 (alaw)
[Jan 7 23:23:18] VERBOSE[2948] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing)
[Jan 7 23:23:18] VERBOSE[2948] chan_sip.c: Peer audio RTP is at port 192.168.1.158:1722
[Jan 7 23:23:18] VERBOSE[2948] chan_sip.c: list_route: hop: sip:[email protected]:5060
[Jan 7 23:23:18] VERBOSE[2948] chan_sip.c: set_destination: Parsing sip:[email protected]:5060 for address/port to send to
[Jan 7 23:23:18] VERBOSE[2948] chan_sip.c: set_destination: set destination to 192.168.1.158, port 5060
[Jan 7 23:23:18] VERBOSE[2948] chan_sip.c: Transmitting (NAT) to 192.168.1.158:5060:
ACK sip:[email protected]:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.132:5060;branch=z9hG4bK6257c6c4;rport
Max-Forwards: 70
From: “External_CID” sip:[email protected];tag=as654adac6
To: sip:[email protected]:5060;tag=JmrUGs3kzbh3xLJO
Contact: sip:[email protected]
Call-ID: [email protected]
CSeq: 102 ACK
User-Agent: FPBX-2.7.0(1.6.2.11)
Content-Length: 0


[Jan 7 23:23:18] VERBOSE[4171] app_dial.c: – SIP/241-00000019 answered SIP/Plusnet SIP-00000018
[Jan 7 23:23:18] VERBOSE[4171] chan_sip.c: Audio is at 212.159.66.21 port 19660
[Jan 7 23:23:18] VERBOSE[4171] chan_sip.c: Adding codec 0x8 (alaw) to SDP
[Jan 7 23:23:18] VERBOSE[4171] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[Jan 7 23:23:18] VERBOSE[4171] chan_sip.c:
<— Reliably Transmitting (NAT) to 79.135.125.154:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 79.135.125.154:5060;branch=z9hG4bK26c5.8a8400f5.0;received=79.135.125.154
Via: SIP/2.0/UDP 212.11.91.119:5060;received=212.11.91.119;branch=z9hG4bK13873a52;rport=5060
Record-Route: sip:79.135.125.154;lr=on;ftag=as79ddaf3b;did=29d.7d309816
From: “External_CID” sip:[email protected];tag=as79ddaf3b
To: sip:[email protected];tag=as6b5dfa80
Call-ID: [email protected]
CSeq: 102 INVITE
Server: FPBX-2.7.0(1.6.2.11)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: sip:[email protected]
Content-Type: application/sdp
Content-Length: 239

v=0
o=root 1130305464 1130305464 IN IP4 212.159.66.21
s=Asterisk PBX 1.6.2.11
c=IN IP4 212.159.66.21
t=0 0
m=audio 19660 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

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

<------------>
[Jan 7 23:23:19] VERBOSE[2948] chan_sip.c: Scheduling destruction of SIP dialog ‘[email protected]’ in 32000 ms (Method: REGISTER)
[Jan 7 23:23:19] VERBOSE[2948] chan_sip.c: Retransmitting #1 (NAT) to 79.135.125.154:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 79.135.125.154:5060;branch=z9hG4bK26c5.8a8400f5.0;received=79.135.125.154
Via: SIP/2.0/UDP 212.11.91.119:5060;received=212.11.91.119;branch=z9hG4bK13873a52;rport=5060
Record-Route: sip:79.135.125.154;lr=on;ftag=as79ddaf3b;did=29d.7d309816
From: “External_CID” sip:[email protected];tag=as79ddaf3b
To: sip:[email protected];tag=as6b5dfa80
Call-ID: [email protected]
CSeq: 102 INVITE
Server: FPBX-2.7.0(1.6.2.11)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: sip:[email protected]
Content-Type: application/sdp
Content-Length: 239

v=0
o=root 1130305464 1130305464 IN IP4 212.159.66.21
s=Asterisk PBX 1.6.2.11
c=IN IP4 212.159.66.21
t=0 0
m=audio 19660 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv


[Jan 7 23:23:19] VERBOSE[2948] chan_sip.c: Retransmitting #2 (NAT) to 79.135.125.154:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 79.135.125.154:5060;branch=z9hG4bK26c5.8a8400f5.0;received=79.135.125.154
Via: SIP/2.0/UDP 212.11.91.119:5060;received=212.11.91.119;branch=z9hG4bK13873a52;rport=5060
Record-Route: sip:79.135.125.154;lr=on;ftag=as79ddaf3b;did=29d.7d309816
From: “External_CID” sip:[email protected];tag=as79ddaf3b
To: sip:[email protected];tag=as6b5dfa80
Call-ID: [email protected]
CSeq: 102 INVITE
Server: FPBX-2.7.0(1.6.2.11)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: sip:[email protected]
Content-Type: application/sdp
Content-Length: 239

v=0
o=root 1130305464 1130305464 IN IP4 212.159.66.21
s=Asterisk PBX 1.6.2.11
c=IN IP4 212.159.66.21
t=0 0
m=audio 19660 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv


<------------->
[Jan 7 23:23:19] VERBOSE[2948] chan_sip.c: — (12 headers 0 lines) —
[Jan 7 23:23:19] VERBOSE[2948] chan_sip.c: Retransmitting #3 (NAT) to 79.135.125.154:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 79.135.125.154:5060;branch=z9hG4bK26c5.8a8400f5.0;received=79.135.125.154
Via: SIP/2.0/UDP 212.11.91.119:5060;received=212.11.91.119;branch=z9hG4bK13873a52;rport=5060
Record-Route: sip:79.135.125.154;lr=on;ftag=as79ddaf3b;did=29d.7d309816
From: “External_CID” sip:[email protected];tag=as79ddaf3b
To: sip:[email protected];tag=as6b5dfa80
Call-ID: [email protected]
CSeq: 102 INVITE
Server: FPBX-2.7.0(1.6.2.11)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: sip:[email protected]
Content-Type: application/sdp
Content-Length: 239

v=0
o=root 1130305464 1130305464 IN IP4 212.159.66.21
s=Asterisk PBX 1.6.2.11
c=IN IP4 212.159.66.21
t=0 0
m=audio 19660 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

<------------->
[Jan 7 23:23:20] VERBOSE[2948] chan_sip.c: — (13 headers 0 lines) —
[Jan 7 23:23:20] VERBOSE[2948] chan_sip.c: Really destroying SIP dialog ‘[email protected]’ Method: OPTIONS
[Jan 7 23:23:20] VERBOSE[2948] chan_sip.c: Retransmitting #4 (NAT) to 79.135.125.154:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 79.135.125.154:5060;branch=z9hG4bK26c5.8a8400f5.0;received=79.135.125.154
Via: SIP/2.0/UDP 212.11.91.119:5060;received=212.11.91.119;branch=z9hG4bK13873a52;rport=5060
Record-Route: sip:79.135.125.154;lr=on;ftag=as79ddaf3b;did=29d.7d309816
From: “External_CID” sip:[email protected];tag=as79ddaf3b
To: sip:[email protected];tag=as6b5dfa80
Call-ID: [email protected]
CSeq: 102 INVITE
Server: FPBX-2.7.0(1.6.2.11)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: sip:[email protected]
Content-Type: application/sdp
Content-Length: 239

v=0
o=root 1130305464 1130305464 IN IP4 212.159.66.21
s=Asterisk PBX 1.6.2.11
c=IN IP4 212.159.66.21
t=0 0
m=audio 19660 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

<------------->
[Jan 7 23:23:21] VERBOSE[2948] chan_sip.c: — (13 headers 0 lines) —
[Jan 7 23:23:21] VERBOSE[2948] chan_sip.c: Really destroying SIP dialog ‘[email protected]’ Method: OPTIONS
[Jan 7 23:23:22] VERBOSE[2948] chan_sip.c: Retransmitting #5 (NAT) to 79.135.125.154:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 79.135.125.154:5060;branch=z9hG4bK26c5.8a8400f5.0;received=79.135.125.154
Via: SIP/2.0/UDP 212.11.91.119:5060;received=212.11.91.119;branch=z9hG4bK13873a52;rport=5060
Record-Route: sip:79.135.125.154;lr=on;ftag=as79ddaf3b;did=29d.7d309816
From: “External_CID” sip:[email protected];tag=as79ddaf3b
To: sip:[email protected];tag=as6b5dfa80
Call-ID: [email protected]
CSeq: 102 INVITE
Server: FPBX-2.7.0(1.6.2.11)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: sip:[email protected]
Content-Type: application/sdp
Content-Length: 239

v=0
o=root 1130305464 1130305464 IN IP4 212.159.66.21
s=Asterisk PBX 1.6.2.11
c=IN IP4 212.159.66.21
t=0 0
m=audio 19660 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

<------------>
[Jan 7 23:23:25] VERBOSE[2948] chan_sip.c: Scheduling destruction of SIP dialog ‘[email protected]’ in 32000 ms (Method: REGISTER)
[Jan 7 23:23:25] VERBOSE[2948] chan_sip.c: Retransmitting #6 (NAT) to 79.135.125.154:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 79.135.125.154:5060;branch=z9hG4bK26c5.8a8400f5.0;received=79.135.125.154
Via: SIP/2.0/UDP 212.11.91.119:5060;received=212.11.91.119;branch=z9hG4bK13873a52;rport=5060
Record-Route: sip:79.135.125.154;lr=on;ftag=as79ddaf3b;did=29d.7d309816
From: “External_CID” sip:[email protected];tag=as79ddaf3b
To: sip:[email protected];tag=as6b5dfa80
Call-ID: [email protected]
CSeq: 102 INVITE
Server: FPBX-2.7.0(1.6.2.11)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: sip:[email protected]
Content-Type: application/sdp
Content-Length: 239

v=0
o=root 1130305464 1130305464 IN IP4 212.159.66.21
s=Asterisk PBX 1.6.2.11
c=IN IP4 212.159.66.21
t=0 0
m=audio 19660 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

<------------>
[Jan 7 23:23:28] VERBOSE[2948] chan_sip.c: Scheduling destruction of SIP dialog ‘[email protected]’ in 32000 ms (Method: REGISTER)
[Jan 7 23:23:28] VERBOSE[2948] chan_sip.c:
<— SIP read from UDP:192.168.1.158:5060 —>
BYE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.168.1.158:5060;branch=z9hG4bKtFjK6gW3CHODS9MX
Max-Forwards: 70
User-Agent: ATL Telecom V1.51.011 CFG0
From: sip:[email protected]:5060;tag=JmrUGs3kzbh3xLJO
To: “External_CID” sip:[email protected];tag=as654adac6
Call-ID: [email protected]
Contact: sip:[email protected]:5060
CSeq: 1 BYE
Content-Length: 0

<------------->
[Jan 7 23:23:28] VERBOSE[2948] chan_sip.c: — (10 headers 0 lines) —
[Jan 7 23:23:28] VERBOSE[2948] chan_sip.c: Sending to 192.168.1.158 : 5060 (NAT)
[Jan 7 23:23:28] VERBOSE[2948] chan_sip.c:
<— Transmitting (NAT) to 192.168.1.158:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.158:5060;branch=z9hG4bKtFjK6gW3CHODS9MX;received=192.168.1.158
From: sip:[email protected]:5060;tag=JmrUGs3kzbh3xLJO
To: “External_CID” sip:[email protected];tag=as654adac6
Call-ID: [email protected]
CSeq: 1 BYE
Server: FPBX-2.7.0(1.6.2.11)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0

<------------>
[Jan 7 23:23:28] VERBOSE[4171] pbx.c: – Executing [[email protected]:1] Macro(“SIP/Plusnet SIP-00000018”, “hangupcall”) in new stack
[Jan 7 23:23:28] VERBOSE[4171] pbx.c: – Executing [[email protected]:1] GotoIf(“SIP/Plusnet SIP-00000018”, “1?skiprg”) in new stack
[Jan 7 23:23:28] VERBOSE[4171] pbx.c: – Goto (macro-hangupcall,s,4)
[Jan 7 23:23:28] VERBOSE[4171] pbx.c: – Executing [[email protected]:4] GotoIf(“SIP/Plusnet SIP-00000018”, “1?skipblkvm”) in new stack
[Jan 7 23:23:28] VERBOSE[4171] pbx.c: – Goto (macro-hangupcall,s,7)
[Jan 7 23:23:28] VERBOSE[4171] pbx.c: – Executing [[email protected]:7] GotoIf(“SIP/Plusnet SIP-00000018”, “1?theend”) in new stack
[Jan 7 23:23:28] VERBOSE[4171] pbx.c: – Goto (macro-hangupcall,s,9)
[Jan 7 23:23:28] VERBOSE[4171] pbx.c: – Executing [[email protected]:9] Hangup(“SIP/Plusnet SIP-00000018”, “”) in new stack
[Jan 7 23:23:28] VERBOSE[4171] app_macro.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/Plusnet SIP-00000018’ in macro ‘hangupcall’
[Jan 7 23:23:28] VERBOSE[4171] features.c: == Spawn extension (macro-dial, h, 1) exited non-zero on ‘SIP/Plusnet SIP-00000018’
[Jan 7 23:23:28] VERBOSE[4171] app_macro.c: == Spawn extension (macro-dial, s, 7) exited non-zero on ‘SIP/Plusnet SIP-00000018’ in macro ‘dial’
[Jan 7 23:23:28] VERBOSE[4171] app_macro.c: == Spawn extension (macro-exten-vm, s, 9) exited non-zero on ‘SIP/Plusnet SIP-00000018’ in macro ‘exten-vm’
[Jan 7 23:23:28] VERBOSE[4171] pbx.c: == Spawn extension (from-did-direct, 241, 1) exited non-zero on ‘SIP/Plusnet SIP-00000018’
[Jan 7 23:23:28] VERBOSE[4171] chan_sip.c: Scheduling destruction of SIP dialog ‘[email protected]’ in 6400 ms (Method: INVITE)
[Jan 7 23:23:28] VERBOSE[2948] chan_sip.c:

<------------>
[Jan 7 23:23:29] VERBOSE[2948] chan_sip.c: Scheduling destruction of SIP dialog ‘[email protected]’ in 32000 ms (Method: REGISTER)
[Jan 7 23:23:29] WARNING[2948] chan_sip.c: Maximum retries exceeded on transmission [email protected] for seqno 102 (Critical Response) – See doc/sip-retransmit.txt.
[Jan 7 23:23:29] VERBOSE[2948] chan_sip.c: Really destroying SIP dialog ‘[email protected]’ Method: INVITE
[Jan 7 23:23:29] VERBOSE[2948] chan_sip.c:

This looks like a firewall problem. Do you have RTP ports forwarded to your server?

Alan,

I’d agree with you if this was only a one way audio issue but I believe the one way audio is being caused by the missing ACK which is a signalling item rather than RTP. I am confident that if I can get the SIP transactions flowing correctly then the audio will follow.

I have not used Asterisk (or for that matter Linux) before so I am learning as I go along and I am not sure how I would set up RTP port forwarding on the server. I am fairly familiar with SIP though. I have checked the broadband router and turned off the firewall there as a temporary check but that made no difference. Besides that, the fact that I can use a softphone client from within the LAN and that is successful would kind of suggest that SIP routing and RTP routing on the router are not the issue.