Asterisk in AWS - SIP w/ TLS and SRTP Odd Behavior

Asterisk Asterisk Support
1

Hi everyone!

So I’ve been banging my head against the wall for the past day or so and can’t seem to figure it out. I think it’s a NAT problem but I really really can’t pin it down. I’m definitely not a noob and have deployed Asterisk for larger call centers before but I feel like I’m missing something trivial (or not).

Here’s what I’ve got… I have two clients, 1) a Blink SoftPhone and 2) a Cisco SPA303. Both of the clients are in the same office behind the same firewall but on different network segments. I have an Asterisk box deployed in AWS and tied into two different SIP trunks (although I feel like they might be the same carrier [SIP.us & SIPTrunk.com] and calls in bound and out bound are successful… at times.

My Blink SoftPhone can call out all the time, every time. The SPA303 can only call out every once in a blue moon. The call will connect and then the SRTP stream kicks in and audio flows fine. I hang up, try again, SIP sets up the SRTP stream and when it cuts over to handle audio, the call drops. Again, it works once and then doesn’t work again for a long long long while.

Now, if I call from the SoftPhone to the SPA303, it works every time. SIP/TLS works and SRTP works. Audio stream is great in both directions. If I call from the SPA303 to the SoftPhone, I get a “No user responding” with a hangup code of 18.

Here’s the big picture of what the deployment will look like. I have several branch offices. I’d want to put the Asterisk box in AWS so I don’t have to worry about on premise infrastructure. I want to deploy deskphones to the branches and have them register to the Asterisk box in AWS. The desk phones need to be able to do extension to extension dialing, inside to outside dialing, and receive outside to inside calls. I need to have SIP/TLS and SRTP encryption running.

Here’s a quick diagram of what the current setup looks like:

Diagram.png970×687 29.7 KB

[Edit -- Had to remove sip traces. Will add in the reply below]

By the way, I do have Asterisk setup w/ the externip and localnets. Also, I’ve tried the firewall with and without doing SIP ALG but I’m thinking since there’s TLS involved, the ALG can’t inspect the packet to determine RTP ports and therefore can’t dynamically pinhole those ports to the clients?

Any help at all would be greatly appreciated!

Cheers!
QS

2

Here’s calling from 1001 -> 1003

Call 1001 -> 1003
sip set debug peer 1001

111.111.111.111 = Asterisk External IP4
222.222.222.222 = Office External IP
Ext 1001 = Calling Extension (Extension A)
Ext 1003 = Receiving Extension (Extension B)
192.168.1.193 = Private IP of Extension B (1003)
172.10.10.10 = Private IP of Extension A (1001)

<--- SIP read from TLS:222.222.222.222:31455 --->
PUBLISH sip:1001@pbx.mydomain.com SIP/2.0
Via: SIP/2.0/TLS 172.10.10.10:31455;rport;branch=z9hG4bKPj2fcb77c42bd5459488315f7810b01ece;alias
Max-Forwards: 70
From: "Extension A" <sip:1001@pbx.mydomain.com>;tag=703e00cfade34cb28ec1a685cb4bf776
To: "Extension A" <sip:1001@pbx.mydomain.com>
Call-ID: 65648b186b00433e9dcb0e270c30ec88
CSeq: 1 PUBLISH
Event: presence
Expires: 600
User-Agent: Blink 1.4.2 (Windows)
Content-Type: application/pidf+xml
Content-Length: 1847

<?xml version='1.0' encoding='UTF-8'?>
<presence xmlns:c="urn:ietf:params:xml:ns:pidf:cipid" xmlns:dm="urn:ietf:params:xml:ns:pidf:data-model" xmlns:agp-caps="urn:ag-projects:xml:ns:pidf:caps" xmlns:caps="urn:ietf:params:xml:ns:pidf:caps" xmlns:rpid="urn:ietf:params:xml:ns:pidf:rpid" xmlns:agp-pidf="urn:ag-projects:xml:ns:pidf" xmlns="urn:ietf:params:xml:ns:pidf" entity="sip%3A1001%40pbx.mydomain.com"><tuple id="SID-90542de7-a010-46ea-81ec-0685d2556092"><status><basic>open</basic><agp-pidf:extended>busy</agp-pidf:extended></status><caps:servcaps><caps:audio>true</caps:audio><caps:message>true</caps:message><caps:text>false</caps:text><agp-caps:file-transfer>true</agp-caps:file-transfer><agp-caps:screen-sharing-server>true</agp-caps:screen-sharing-server><agp-caps:screen-sharing-client>true</agp-caps:screen-sharing-client></caps:servcaps><c:display-name>Louis Carreiro</c:display-name><agp-pidf:device-info id="90542de7-a010-46ea-81ec-0685d2556092"><agp-pidf:description>E2-MT0570-LT</agp-pidf:description><agp-pidf:user-agent>Blink 1.4.2 (Windows)</agp-pidf:user-agent><agp-pidf:time-offset>1080</agp-pidf:time-offset></agp-pidf:device-info><rpid:user-input idle-threshold="600">active</rpid:user-input><dm:deviceID>90542de7-a010-46ea-81ec-0685d2556092</dm:deviceID><contact>sip%3A1001%40pbx.mydomain.com</contact><note>On the phone</note><timestamp>2016-10-19T16:10:52.528947-06:00</timestamp></tuple><dm:person id="PID-71b47415d7e04e86a307fb28640ba0fd"><rpid:activities><rpid:busy/></rpid:activities><dm:timestamp>2016-10-19T16:10:52.528947-06:00</dm:timestamp></dm:person><dm:device id="DID-90542de7-a010-46ea-81ec-0685d2556092"><dm:deviceID>90542de7-a010-46ea-81ec-0685d2556092</dm:deviceID><dm:note>Blink 1.4.2 (Windows) at E2-MT0570-LT</dm:note><dm:timestamp>2016-10-19T16:10:52.528947-06:00</dm:timestamp></dm:device></presence>
<------------->
--- (12 headers 2 lines) ---
Sending to 222.222.222.222:31455 (NAT)

<--- Transmitting (NAT) to 222.222.222.222:31455 --->
SIP/2.0 489 Bad Event
Via: SIP/2.0/TLS 172.10.10.10:31455;branch=z9hG4bKPj2fcb77c42bd5459488315f7810b01ece;alias;received=222.222.222.222;rport=31455
From: "Extension A" <sip:1001@pbx.mydomain.com>;tag=703e00cfade34cb28ec1a685cb4bf776
To: "Extension A" <sip:1001@pbx.mydomain.com>;tag=as3755f12a
Call-ID: 65648b186b00433e9dcb0e270c30ec88
CSeq: 1 PUBLISH
Server: FPBX-13.0.188.9(13.11.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


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

<--- SIP read from TLS:222.222.222.222:31455 --->
INVITE sip:1003@pbx.mydomain.com SIP/2.0
Via: SIP/2.0/TLS 172.10.10.10:31455;rport;branch=z9hG4bKPjfcd3dee84910476e91bf5ae194834dd1;alias
Max-Forwards: 70
From: "Extension A" <sip:1001@pbx.mydomain.com>;tag=b5c6b4f314a949e68c4160040434369f
To: <sip:1003@pbx.mydomain.com>
Contact: <sip:09653824@172.10.10.10:42969;transport=tls>
Call-ID: 6493ae8f065a44208aa4d2aef96d2ef8
CSeq: 19667 INVITE
Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER
Supported: 100rel, replaces, norefersub, gruu
User-Agent: Blink 1.4.2 (Windows)
Content-Type: application/sdp
Content-Length: 509

v=0
o=- 3685882252 3685882252 IN IP4 172.10.10.10
s=Blink 1.4.2 (Windows)
t=0 0
m=audio 50142 RTP/SAVP 113 9 0 8 101
c=IN IP4 172.10.10.10
a=rtcp:50143
a=rtpmap:113 opus/48000/2
a=fmtp:113 useinbandfec=1
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=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:mkLylZDFk3WMpw67r9+N3xlSoV2KXzQQub5tWToM
a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:M3McxbjE2Rmp2MC/OOm7+km2KdPCotnUTour1fBo
a=sendrecv
<------------->
--- (13 headers 17 lines) ---
Sending to 222.222.222.222:31455 (NAT)
Sending to 222.222.222.222:31455 (NAT)
Using INVITE request as basis request - 6493ae8f065a44208aa4d2aef96d2ef8
Found peer '1001' for '1001' from 222.222.222.222:31455

<--- Reliably Transmitting (NAT) to 222.222.222.222:31455 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/TLS 172.10.10.10:31455;branch=z9hG4bKPjfcd3dee84910476e91bf5ae194834dd1;alias;received=222.222.222.222;rport=31455
From: "Extension A" <sip:1001@pbx.mydomain.com>;tag=b5c6b4f314a949e68c4160040434369f
To: <sip:1003@pbx.mydomain.com>;tag=as2e9b441a
Call-ID: 6493ae8f065a44208aa4d2aef96d2ef8
CSeq: 19667 INVITE
Server: FPBX-13.0.188.9(13.11.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="507bf8d3"
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog '6493ae8f065a44208aa4d2aef96d2ef8' in 6400 ms (Method: INVITE)
Really destroying SIP dialog '65648b186b00433e9dcb0e270c30ec88' Method: PUBLISH

<--- SIP read from TLS:222.222.222.222:31455 --->
ACK sip:1003@pbx.mydomain.com SIP/2.0
Via: SIP/2.0/TLS 172.10.10.10:31455;rport;branch=z9hG4bKPjfcd3dee84910476e91bf5ae194834dd1;alias
Max-Forwards: 70
From: "Extension A" <sip:1001@pbx.mydomain.com>;tag=b5c6b4f314a949e68c4160040434369f
To: <sip:1003@pbx.mydomain.com>;tag=as2e9b441a
Call-ID: 6493ae8f065a44208aa4d2aef96d2ef8
CSeq: 19667 ACK
User-Agent: Blink 1.4.2 (Windows)
Content-Length: 0

<------------->
--- (9 headers 0 lines) ---

<--- SIP read from TLS:222.222.222.222:31455 --->
INVITE sip:1003@pbx.mydomain.com SIP/2.0
Via: SIP/2.0/TLS 172.10.10.10:31455;rport;branch=z9hG4bKPj6fdd4fc4e9d44153871e2db707ca524d;alias
Max-Forwards: 70
From: "Extension A" <sip:1001@pbx.mydomain.com>;tag=b5c6b4f314a949e68c4160040434369f
To: <sip:1003@pbx.mydomain.com>
Contact: <sip:09653824@172.10.10.10:42969;transport=tls>
Call-ID: 6493ae8f065a44208aa4d2aef96d2ef8
CSeq: 19668 INVITE
Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER
Supported: 100rel, replaces, norefersub, gruu
User-Agent: Blink 1.4.2 (Windows)
Authorization: Digest username="1001", realm="asterisk", nonce="507bf8d3", uri="sip:1003@pbx.mydomain.com", response="e29d1c35dfc476f444267904c2e0b043", algorithm=MD5
Content-Type: application/sdp
Content-Length: 509

v=0
o=- 3685882252 3685882252 IN IP4 172.10.10.10
s=Blink 1.4.2 (Windows)
t=0 0
m=audio 50142 RTP/SAVP 113 9 0 8 101
c=IN IP4 172.10.10.10
a=rtcp:50143
a=rtpmap:113 opus/48000/2
a=fmtp:113 useinbandfec=1
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=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:mkLylZDFk3WMpw67r9+N3xlSoV2KXzQQub5tWToM
a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:M3McxbjE2Rmp2MC/OOm7+km2KdPCotnUTour1fBo
a=sendrecv
<------------->
--- (14 headers 17 lines) ---
Sending to 222.222.222.222:31455 (NAT)
Using INVITE request as basis request - 6493ae8f065a44208aa4d2aef96d2ef8
Found peer '1001' for '1001' from 222.222.222.222:31455
Found RTP audio format 113
Found RTP audio format 9
Found RTP audio format 0
Found RTP audio format 8
Found RTP audio format 101
Found audio description format opus for ID 113
Found audio description format G722 for ID 9
Found audio description format PCMU for ID 0
Found audio description format PCMA for ID 8
Found audio description format telephone-event for ID 101
Capabilities: us - (g722|ulaw|alaw), peer - audio=(ulaw|alaw|g722|opus)/video=(nothing)/text=(nothing), combined - (g722|ulaw|alaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port 172.10.10.10:50142
Looking for 1003 in from-internal (domain pbx.mydomain.com)
sip_route_dump: route/path hop: <sip:09653824@172.10.10.10:42969;transport=tls>

<--- Transmitting (NAT) to 222.222.222.222:31455 --->
SIP/2.0 100 Trying
Via: SIP/2.0/TLS 172.10.10.10:31455;branch=z9hG4bKPj6fdd4fc4e9d44153871e2db707ca524d;alias;received=222.222.222.222;rport=31455
From: "Extension A" <sip:1001@pbx.mydomain.com>;tag=b5c6b4f314a949e68c4160040434369f
To: <sip:1003@pbx.mydomain.com>
Call-ID: 6493ae8f065a44208aa4d2aef96d2ef8
CSeq: 19668 INVITE
Server: FPBX-13.0.188.9(13.11.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:1003@111.111.111.111:5061;transport=TLS>
Content-Length: 0


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

<--- Transmitting (NAT) to 222.222.222.222:31455 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/TLS 172.10.10.10:31455;branch=z9hG4bKPj6fdd4fc4e9d44153871e2db707ca524d;alias;received=222.222.222.222;rport=31455
From: "Extension A" <sip:1001@pbx.mydomain.com>;tag=b5c6b4f314a949e68c4160040434369f
To: <sip:1003@pbx.mydomain.com>;tag=as69c7f34d
Call-ID: 6493ae8f065a44208aa4d2aef96d2ef8
CSeq: 19668 INVITE
Server: FPBX-13.0.188.9(13.11.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:1003@111.111.111.111:5061;transport=TLS>
P-Asserted-Identity: "Extension B" <sip:1003@pbx.mydomain.com>
Content-Length: 0


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

<--- Transmitting (NAT) to 222.222.222.222:31455 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/TLS 172.10.10.10:31455;branch=z9hG4bKPj6fdd4fc4e9d44153871e2db707ca524d;alias;received=222.222.222.222;rport=31455
From: "Extension A" <sip:1001@pbx.mydomain.com>;tag=b5c6b4f314a949e68c4160040434369f
To: <sip:1003@pbx.mydomain.com>;tag=as69c7f34d
Call-ID: 6493ae8f065a44208aa4d2aef96d2ef8
CSeq: 19668 INVITE
Server: FPBX-13.0.188.9(13.11.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:1003@111.111.111.111:5061;transport=TLS>
Content-Length: 0


<------------>
Audio is at 14018
Adding codec g722 to SDP
Adding codec ulaw to SDP
Adding codec alaw to SDP
Adding non-codec 0x1 (telephone-event) to SDP

<--- Reliably Transmitting (NAT) to 222.222.222.222:31455 --->
SIP/2.0 200 OK
Via: SIP/2.0/TLS 172.10.10.10:31455;branch=z9hG4bKPj6fdd4fc4e9d44153871e2db707ca524d;alias;received=222.222.222.222;rport=31455
From: "Extension A" <sip:1001@pbx.mydomain.com>;tag=b5c6b4f314a949e68c4160040434369f
To: <sip:1003@pbx.mydomain.com>;tag=as69c7f34d
Call-ID: 6493ae8f065a44208aa4d2aef96d2ef8
CSeq: 19668 INVITE
Server: FPBX-13.0.188.9(13.11.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:1003@111.111.111.111:5061;transport=TLS>
P-Asserted-Identity: "Extension B" <sip:1003@pbx.mydomain.com>
Content-Type: application/sdp
Content-Length: 389

v=0
o=root 1684673847 1684673847 IN IP4 111.111.111.111
s=Asterisk PBX 13.11.2
c=IN IP4 111.111.111.111
t=0 0
m=audio 14018 RTP/SAVP 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=maxptime:150
a=sendrecv
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:BvG8tsReNZizcutTJsT2GhTK+HUGe9xx/SIyylAH

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

<--- SIP read from TLS:222.222.222.222:31455 --->
ACK sip:1003@111.111.111.111:5061;transport=TLS SIP/2.0
Via: SIP/2.0/TLS 172.10.10.10:31455;rport;branch=z9hG4bKPjd341157e207d4c3390ae1ffabb5c1754;alias
Max-Forwards: 70
From: "Extension A" <sip:1001@pbx.mydomain.com>;tag=b5c6b4f314a949e68c4160040434369f
To: <sip:1003@pbx.mydomain.com>;tag=as69c7f34d
Call-ID: 6493ae8f065a44208aa4d2aef96d2ef8
CSeq: 19668 ACK
User-Agent: Blink 1.4.2 (Windows)
Content-Length: 0

<------------->
--- (9 headers 0 lines) ---
[2016-10-19 22:10:57] WARNING[3508][C-00000006]: translate.c:407 framein: no samples for g722tolin16
[2016-10-19 22:10:57] WARNING[3508][C-00000006]: translate.c:407 framein: no samples for g722tolin16
Scheduling destruction of SIP dialog '6493ae8f065a44208aa4d2aef96d2ef8' in 6400 ms (Method: ACK)
Reliably Transmitting (NAT) to 222.222.222.222:31455:
BYE sip:09653824@172.10.10.10:42969;transport=tls SIP/2.0
Via: SIP/2.0/TLS 111.111.111.111:5061;branch=z9hG4bK7a283541;rport
Max-Forwards: 70
From: <sip:1003@pbx.mydomain.com>;tag=as69c7f34d
To: "Extension A" <sip:1001@pbx.mydomain.com>;tag=b5c6b4f314a949e68c4160040434369f
Call-ID: 6493ae8f065a44208aa4d2aef96d2ef8
CSeq: 102 BYE
User-Agent: FPBX-13.0.188.9(13.11.2)
Proxy-Authorization: Digest username="09653824", realm="asterisk", algorithm=MD5, uri="sips:pbx.mydomain.com", nonce="507bf8d3", response="4a48ea6c23a8449e43e7b71e19c108dc"
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0


---

<--- SIP read from TLS:222.222.222.222:31455 --->
SIP/2.0 200 OK
Via: SIP/2.0/TLS 111.111.111.111:5061;rport=5061;received=111.111.111.111;branch=z9hG4bK7a283541
Call-ID: 6493ae8f065a44208aa4d2aef96d2ef8
From: <sip:1003@pbx.mydomain.com>;tag=as69c7f34d
To: "Extension A" <sip:1001@pbx.mydomain.com>;tag=b5c6b4f314a949e68c4160040434369f
CSeq: 102 BYE
Server: Blink 1.4.2 (Windows)
Content-Length: 0

<------------->
--- (8 headers 0 lines) ---
SIP Response message for INCOMING dialog BYE arrived

<--- SIP read from TLS:222.222.222.222:31455 --->
PUBLISH sip:1001@pbx.mydomain.com SIP/2.0
Via: SIP/2.0/TLS 172.10.10.10:31455;rport;branch=z9hG4bKPj30ea5df9066f4c2aae7acac32db8d591;alias
Max-Forwards: 70
From: "Extension A" <sip:1001@pbx.mydomain.com>;tag=f3c07d6850d046bab6bd3bbcebc070ad
To: "Extension A" <sip:1001@pbx.mydomain.com>
Call-ID: e49abcdaf458402ab622614de7b42328
CSeq: 1 PUBLISH
Event: presence
Expires: 600
User-Agent: Blink 1.4.2 (Windows)
Content-Type: application/pidf+xml
Content-Length: 1849

<?xml version='1.0' encoding='UTF-8'?>
<presence xmlns:c="urn:ietf:params:xml:ns:pidf:cipid" xmlns:dm="urn:ietf:params:xml:ns:pidf:data-model" xmlns:agp-caps="urn:ag-projects:xml:ns:pidf:caps" xmlns:caps="urn:ietf:params:xml:ns:pidf:caps" xmlns:rpid="urn:ietf:params:xml:ns:pidf:rpid" xmlns:agp-pidf="urn:ag-projects:xml:ns:pidf" xmlns="urn:ietf:params:xml:ns:pidf" entity="sip%3A1001%40pbx.mydomain.com"><tuple id="SID-90542de7-a010-46ea-81ec-0685d2556092"><status><basic>open</basic><agp-pidf:extended>available</agp-pidf:extended></status><caps:servcaps><caps:audio>true</caps:audio><caps:message>true</caps:message><caps:text>false</caps:text><agp-caps:file-transfer>true</agp-caps:file-transfer><agp-caps:screen-sharing-server>true</agp-caps:screen-sharing-server><agp-caps:screen-sharing-client>true</agp-caps:screen-sharing-client></caps:servcaps><c:display-name>Louis Carreiro</c:display-name><agp-pidf:device-info id="90542de7-a010-46ea-81ec-0685d2556092"><agp-pidf:description>E2-MT0570-LT</agp-pidf:description><agp-pidf:user-agent>Blink 1.4.2 (Windows)</agp-pidf:user-agent><agp-pidf:time-offset>1080</agp-pidf:time-offset></agp-pidf:device-info><rpid:user-input idle-threshold="600">active</rpid:user-input><dm:deviceID>90542de7-a010-46ea-81ec-0685d2556092</dm:deviceID><contact>sip%3A1001%40pbx.mydomain.com</contact><timestamp>2016-10-19T16:11:02.043327-06:00</timestamp></tuple><dm:person id="PID-71b47415d7e04e86a307fb28640ba0fd"><rpid:activities><rpid:other>available</rpid:other></rpid:activities><dm:timestamp>2016-10-19T16:11:02.043327-06:00</dm:timestamp></dm:person><dm:device id="DID-90542de7-a010-46ea-81ec-0685d2556092"><dm:deviceID>90542de7-a010-46ea-81ec-0685d2556092</dm:deviceID><dm:note>Blink 1.4.2 (Windows) at E2-MT0570-LT</dm:note><dm:timestamp>2016-10-19T16:11:02.043327-06:00</dm:timestamp></dm:device></presence>
<------------->
--- (12 headers 2 lines) ---
Sending to 222.222.222.222:31455 (NAT)

<--- Transmitting (NAT) to 222.222.222.222:31455 --->
SIP/2.0 489 Bad Event
Via: SIP/2.0/TLS 172.10.10.10:31455;branch=z9hG4bKPj30ea5df9066f4c2aae7acac32db8d591;alias;received=222.222.222.222;rport=31455
From: "Extension A" <sip:1001@pbx.mydomain.com>;tag=f3c07d6850d046bab6bd3bbcebc070ad
To: "Extension A" <sip:1001@pbx.mydomain.com>;tag=as4d0a3ebc
Call-ID: e49abcdaf458402ab622614de7b42328
CSeq: 1 PUBLISH
Server: FPBX-13.0.188.9(13.11.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


<------------>
Really destroying SIP dialog '6493ae8f065a44208aa4d2aef96d2ef8' Method: ACK
Really destroying SIP dialog 'e49abcdaf458402ab622614de7b42328' Method: PUBLISH
ip-172-31-42-212*CLI>
Disconnected from Asterisk server
Asterisk cleanly ending (0).
Executing last minute cleanups
3

Here’s calling from 1003 -> 1001

Call 1003 -> 1001
sip set debug peer 1003

111.111.111.111 = Asterisk External IP4
222.222.222.222 = Office External IP
Ext 1001 = Receiving Extension (Extension A)
Ext 1003 = Calling Extension (Extension B)
192.168.1.193 = Private IP of Extension B (1003)
172.10.10.10 = Private IP of Extension A (1001)




<--- SIP read from TLS:222.222.222.222:5069 --->
INVITE sip:1001@pbx.mydomain.com SIP/2.0
Via: SIP/2.0/TLS 192.168.1.193:5069;branch=z9hG4bK-a6c743bc
From: "Extension B" <sip:1003@pbx.mydomain.com>;tag=f367a0d7b35f7128o0
To: "Extension A" <sip:1001@pbx.mydomain.com>
Call-ID: ccb471c3-9828f52c@192.168.1.193
CSeq: 101 INVITE
Max-Forwards: 70
Contact: "Extension B" <sip:1003@192.168.1.193:5069;transport=tls>
Expires: 240
User-Agent: Cisco/SPA303-7.6.2
Content-Length: 566
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER, UPDATE
Supported: replaces
Content-Type: application/sdp

v=0
o=- 49556 49556 IN IP4 192.168.1.193
s=-
c=IN IP4 192.168.1.193
t=0 0
m=audio 19472 RTP/SAVP 0 2 8 9 18 96 97 98 101
a=rtpmap:0 PCMU/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:18 G729a/8000
a=rtpmap:96 G726-40/8000
a=rtpmap:97 G726-24/8000
a=rtpmap:98 G726-16/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv
a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:ajMjjG6MRffg7g6ITOf3KwE47uQPxTJ/FFLLoBgY
a=crypto:2 AES_CM_128_HMAC_SHA1_80 inline:ajMjjG6MRffg7g6ITOf3KwE47uQPxTJ/FFLLoBgY
<------------->
--- (14 headers 20 lines) ---
Sending to 222.222.222.222:5069 (NAT)
Sending to 222.222.222.222:5069 (NAT)
Using INVITE request as basis request - ccb471c3-9828f52c@192.168.1.193
Found peer '1003' for '1003' from 222.222.222.222:5069

<--- Reliably Transmitting (NAT) to 222.222.222.222:5069 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/TLS 192.168.1.193:5069;branch=z9hG4bK-a6c743bc;received=222.222.222.222;rport=5069
From: "Extension B" <sip:1003@pbx.mydomain.com>;tag=f367a0d7b35f7128o0
To: "Extension A" <sip:1001@pbx.mydomain.com>;tag=as18031082
Call-ID: ccb471c3-9828f52c@192.168.1.193
CSeq: 101 INVITE
Server: FPBX-13.0.188.9(13.11.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="5c583b09"
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog 'ccb471c3-9828f52c@192.168.1.193' in 6400 ms (Method: INVITE)

<--- SIP read from TLS:222.222.222.222:5069 --->
ACK sip:1001@pbx.mydomain.com SIP/2.0
Via: SIP/2.0/TLS 192.168.1.193:5069;branch=z9hG4bK-a6c743bc
From: "Extension B" <sip:1003@pbx.mydomain.com>;tag=f367a0d7b35f7128o0
To: "Extension A" <sip:1001@pbx.mydomain.com>;tag=as18031082
Call-ID: ccb471c3-9828f52c@192.168.1.193
CSeq: 101 ACK
Max-Forwards: 70
Contact: "Extension B" <sip:1003@192.168.1.193:5069;transport=tls>
User-Agent: Cisco/SPA303-7.6.2
Content-Length: 0

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

<--- SIP read from TLS:222.222.222.222:5069 --->
INVITE sip:1001@pbx.mydomain.com SIP/2.0
Via: SIP/2.0/TLS 192.168.1.193:5069;branch=z9hG4bK-958f0dd8
From: "Extension B" <sip:1003@pbx.mydomain.com>;tag=f367a0d7b35f7128o0
To: "Extension A" <sip:1001@pbx.mydomain.com>
Call-ID: ccb471c3-9828f52c@192.168.1.193
CSeq: 102 INVITE
Max-Forwards: 70
Authorization: Digest username="1003",realm="asterisk",nonce="5c583b09",uri="sip:1001@pbx.mydomain.com",algorithm=MD5,response="f42766499f97e250917a8da9ddfadf40"
Contact: "Extension B" <sip:1003@192.168.1.193:5069;transport=tls>
Expires: 240
User-Agent: Cisco/SPA303-7.6.2
Content-Length: 566
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER, UPDATE
Supported: replaces
Content-Type: application/sdp

v=0
o=- 49556 49556 IN IP4 192.168.1.193
s=-
c=IN IP4 192.168.1.193
t=0 0
m=audio 19472 RTP/SAVP 0 2 8 9 18 96 97 98 101
a=rtpmap:0 PCMU/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:18 G729a/8000
a=rtpmap:96 G726-40/8000
a=rtpmap:97 G726-24/8000
a=rtpmap:98 G726-16/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv
a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:ajMjjG6MRffg7g6ITOf3KwE47uQPxTJ/FFLLoBgY
a=crypto:2 AES_CM_128_HMAC_SHA1_80 inline:ajMjjG6MRffg7g6ITOf3KwE47uQPxTJ/FFLLoBgY
<------------->
--- (15 headers 20 lines) ---
Sending to 222.222.222.222:5069 (NAT)
Using INVITE request as basis request - ccb471c3-9828f52c@192.168.1.193
Found peer '1003' for '1003' from 222.222.222.222:5069
Found RTP audio format 0
Found RTP audio format 2
Found RTP audio format 8
Found RTP audio format 9
Found RTP audio format 18
Found RTP audio format 96
Found RTP audio format 97
Found RTP audio format 98
Found RTP audio format 101
Found audio description format PCMU for ID 0
Found audio description format G726-32 for ID 2
Found audio description format PCMA for ID 8
Found audio description format G722 for ID 9
Found audio description format G729a for ID 18
Found unknown media description format G726-40 for ID 96
Found unknown media description format G726-24 for ID 97
Found unknown media description format G726-16 for ID 98
Found audio description format telephone-event for ID 101
Capabilities: us - (g722|ulaw|alaw), peer - audio=(ulaw|g726|alaw|g722|g729)/video=(nothing)/text=(nothing), combined - (g722|ulaw|alaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port 192.168.1.193:19472
Looking for 1001 in from-internal (domain pbx.mydomain.com)
sip_route_dump: route/path hop: <sip:1003@192.168.1.193:5069;transport=tls>

<--- Transmitting (NAT) to 222.222.222.222:5069 --->
SIP/2.0 100 Trying
Via: SIP/2.0/TLS 192.168.1.193:5069;branch=z9hG4bK-958f0dd8;received=222.222.222.222;rport=5069
From: "Extension B" <sip:1003@pbx.mydomain.com>;tag=f367a0d7b35f7128o0
To: "Extension A" <sip:1001@pbx.mydomain.com>
Call-ID: ccb471c3-9828f52c@192.168.1.193
CSeq: 102 INVITE
Server: FPBX-13.0.188.9(13.11.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:1001@111.111.111.111:5061;transport=TLS>
Content-Length: 0


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

<--- Transmitting (NAT) to 222.222.222.222:5069 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/TLS 192.168.1.193:5069;branch=z9hG4bK-958f0dd8;received=222.222.222.222;rport=5069
From: "Extension B" <sip:1003@pbx.mydomain.com>;tag=f367a0d7b35f7128o0
To: "Extension A" <sip:1001@pbx.mydomain.com>;tag=as1606015f
Call-ID: ccb471c3-9828f52c@192.168.1.193
CSeq: 102 INVITE
Server: FPBX-13.0.188.9(13.11.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:1001@111.111.111.111:5061;transport=TLS>
P-Asserted-Identity: "Extension A" <sip:1001@pbx.mydomain.com>
Content-Length: 0


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

<--- Transmitting (NAT) to 222.222.222.222:5069 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/TLS 192.168.1.193:5069;branch=z9hG4bK-958f0dd8;received=222.222.222.222;rport=5069
From: "Extension B" <sip:1003@pbx.mydomain.com>;tag=f367a0d7b35f7128o0
To: "Extension A" <sip:1001@pbx.mydomain.com>;tag=as1606015f
Call-ID: ccb471c3-9828f52c@192.168.1.193
CSeq: 102 INVITE
Server: FPBX-13.0.188.9(13.11.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:1001@111.111.111.111:5061;transport=TLS>
Content-Length: 0


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

<--- SIP read from TLS:222.222.222.222:5069 --->
NOTIFY sip:pbx.mydomain.com SIP/2.0
Via: SIP/2.0/TLS 192.168.1.193:5069;branch=z9hG4bK-32c2814e
From: "Extension B" <sip:1003@pbx.mydomain.com>;tag=397016173c4ec7a1o0
To: <sip:pbx.mydomain.com>
Call-ID: bc24ba3f-f9523199@192.168.1.193
CSeq: 31 NOTIFY
Max-Forwards: 70
Contact: "Extension B" <sip:1003@192.168.1.193:5069;transport=tls>
Event: keep-alive
User-Agent: Cisco/SPA303-7.6.2
Content-Length: 0

<------------->
--- (11 headers 0 lines) ---

<--- Transmitting (NAT) to 222.222.222.222:5069 --->
SIP/2.0 200 OK
Via: SIP/2.0/TLS 192.168.1.193:5069;branch=z9hG4bK-32c2814e;received=222.222.222.222;rport=5069
From: "Extension B" <sip:1003@pbx.mydomain.com>;tag=397016173c4ec7a1o0
To: <sip:pbx.mydomain.com>;tag=as4622ee96
Call-ID: bc24ba3f-f9523199@192.168.1.193
CSeq: 31 NOTIFY
Server: FPBX-13.0.188.9(13.11.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog 'bc24ba3f-f9523199@192.168.1.193' in 32000 ms (Method: NOTIFY)
Audio is at 17136
Adding codec g722 to SDP
Adding codec ulaw to SDP
Adding codec alaw to SDP
Adding non-codec 0x1 (telephone-event) to SDP

<--- Reliably Transmitting (NAT) to 222.222.222.222:5069 --->
SIP/2.0 200 OK
Via: SIP/2.0/TLS 192.168.1.193:5069;branch=z9hG4bK-958f0dd8;received=222.222.222.222;rport=5069
From: "Extension B" <sip:1003@pbx.mydomain.com>;tag=f367a0d7b35f7128o0
To: "Extension A" <sip:1001@pbx.mydomain.com>;tag=as1606015f
Call-ID: ccb471c3-9828f52c@192.168.1.193
CSeq: 102 INVITE
Server: FPBX-13.0.188.9(13.11.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:1001@111.111.111.111:5061;transport=TLS>
P-Asserted-Identity: "Extension A" <sip:1001@pbx.mydomain.com>
Content-Type: application/sdp
Content-Length: 389

v=0
o=root 1827651168 1827651168 IN IP4 111.111.111.111
s=Asterisk PBX 13.11.2
c=IN IP4 111.111.111.111
t=0 0
m=audio 17136 RTP/SAVP 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=maxptime:150
a=sendrecv
a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:/QXD74U67Bn7ua7sSVCRquoNro5sxNvPbcdhi+kb

<------------>
[2016-10-19 22:12:15] WARNING[3416]: chan_sip.c:4059 retrans_pkt: Retransmission timeout reached on transmission ccb471c3-9828f52c@192.168.1.193 for seqno 102 (Critical Response) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 99ms with no response
[2016-10-19 22:12:15] WARNING[3416]: chan_sip.c:4083 retrans_pkt: Hanging up call ccb471c3-9828f52c@192.168.1.193 - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).
Scheduling destruction of SIP dialog 'ccb471c3-9828f52c@192.168.1.193' in 6400 ms (Method: INVITE)
Reliably Transmitting (NAT) to 222.222.222.222:5069:
BYE sip:1003@192.168.1.193:5069;transport=tls SIP/2.0
Via: SIP/2.0/TLS 111.111.111.111:5061;branch=z9hG4bK5484ed15;rport
Max-Forwards: 70
From: "Extension A" <sip:1001@pbx.mydomain.com>;tag=as1606015f
To: "Extension B" <sip:1003@pbx.mydomain.com>;tag=f367a0d7b35f7128o0
Call-ID: ccb471c3-9828f52c@192.168.1.193
CSeq: 102 BYE
User-Agent: FPBX-13.0.188.9(13.11.2)
Proxy-Authorization: Digest username="1003", realm="asterisk", algorithm=MD5, uri="sips:pbx.mydomain.com", nonce="5c583b09", response="0baab1610c1277e570ea4e8458989f80"
X-Asterisk-HangupCause: No user responding
X-Asterisk-HangupCauseCode: 18
Content-Length: 0


---
[2016-10-19 22:12:15] WARNING[3416]: chan_sip.c:4059 retrans_pkt: Retransmission timeout reached on transmission ccb471c3-9828f52c@192.168.1.193 for seqno 102 (Non-critical Request) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 99ms with no response
Really destroying SIP dialog 'ccb471c3-9828f52c@192.168.1.193' Method: INVITE

<--- SIP read from TLS:222.222.222.222:5069 --->
ACK sip:1001@111.111.111.111:5061;transport=TLS SIP/2.0
Via: SIP/2.0/TLS 192.168.1.193:5069;branch=z9hG4bK-4585b460
From: "Extension B" <sip:1003@pbx.mydomain.com>;tag=f367a0d7b35f7128o0
To: "Extension A" <sip:1001@pbx.mydomain.com>;tag=as1606015f
Call-ID: ccb471c3-9828f52c@192.168.1.193
CSeq: 102 ACK
Max-Forwards: 70
Authorization: Digest username="1003",realm="asterisk",nonce="5c583b09",uri="sip:1001@pbx.mydomain.com",algorithm=MD5,response="f42766499f97e250917a8da9ddfadf40"
Contact: "Extension B" <sip:1003@192.168.1.193:5069;transport=tls>
User-Agent: Cisco/SPA303-7.6.2
Content-Length: 0

<------------->
--- (11 headers 0 lines) ---

<--- SIP read from TLS:222.222.222.222:5069 --->
SIP/2.0 200 OK
To: "Extension B" <sip:1003@pbx.mydomain.com>;tag=f367a0d7b35f7128o0
From: "Extension A" <sip:1001@pbx.mydomain.com>;tag=as1606015f
Call-ID: ccb471c3-9828f52c@192.168.1.193
CSeq: 102 BYE
Via: SIP/2.0/TLS 111.111.111.111:5061;branch=z9hG4bK5484ed15
Server: Cisco/SPA303-7.6.2
Content-Length: 0

<------------->
--- (8 headers 0 lines) ---
ip-172-31-42-212*CLI>
Disconnected from Asterisk server
Asterisk cleanly ending (0).
Executing last minute cleanups

Hopefully the “sip set debug peer…” provided enough info. Just doing “sip set debug on” had too much garbage that might have confused the situation.

4

You seem to have rather long round trip delays on the ACK, but a rather short timeout (99ms). I’m wondering if the TCP handling applies the full timeout correctly (as it will not actually re-transmit at the application level. However, it seem unlikely that this would not have been discovered before, so I would check to see if you have overridden the timeout settings.

5

What version of Asterisk is this? A bug was introduced which was recently fixed[1] to resolve such a thing.

[1] https://gerrit.asterisk.org/#/c/3891/

6

Hey @jcolp! I don’t know why I didn’t think to include the version. Probably would have helped. I’m running 13.11.2. That bug description sounds about right. I’ll look at doing a rebuild here shortly to give it a shot.

7

Hey @david551! I haven’t touched any of the timeout settings but I’ll take a look to see what they’re at.

8

Ugh…trying to compile 13.12.0-rc1 breaks at compiling chan_sip… Might have to try a clean install…

[CC] chan_sip.c -> chan_sip.o
{standard input}: Assembler messages:
{standard input}:149694: Warning: end of file not at end of a line; newline inserted
{standard input}:150738: Error: unknown pseudo-op: `.lbe'
{standard input}: Error: open CFI at the end of file; missing .cfi_endproc directive
gcc: internal compiler error: Killed (program cc1)
Please submit a full bug report,
with preprocessed source if appropriate.
See <http://bugzilla.redhat.com/bugzilla> for instructions.
make[1]: *** [chan_sip.o] Error 4
make: *** [channels] Error 2
9

Weird… did a “make clean” and tried again…

[CC] chan_sip.c -> chan_sip.o
{standard input}: Assembler messages:
{standard input}:157670: Warning: end of file not at end of a line; newline inserted
{standard input}:159152: Error: no such instruction: `cal'
{standard input}: Error: open CFI at the end of file; missing .cfi_endproc directive
gcc: internal compiler error: Killed (program cc1)
Please submit a full bug report,
with preprocessed source if appropriate.
See <http://bugzilla.redhat.com/bugzilla> for instructions.
make[1]: *** [chan_sip.o] Error 4
make: *** [channels] Error 2
10

What version of gcc are you using?

11

Hey @creslin287! It’s:

gcc version 4.8.5 20150623 (Red Hat 4.8.5-4) (GCC)

12

Well! Looks like the patch fixed it… or something in 13.12.0-rc1 took care of it. I just did a new box and build from the 13.12.0-rc1 source, configured trunks, outbound routes, nat networks, enabled TLS, and configured an extension. Nothing special. So far, that SPA303 is able to send a SIP/TLS session and kick over to SRTP every time w/o out a headache. Very nice and thanks for that!

Now… quick question… when does 13.12.0-rc1 go mainstream?

13

Provided no critical blockers or regressions come up from people I’d expect it in a week or so, maybe a little longer.

14

Hi,
I am using Asterisk 13.11.2 and have the same problem. The fix jcolp mentions is already on 13.11.2 so is there another fix which can be applied?