Asterisk or VoIP gateway hung up on its own!

Setup

Since Asterisk and the VoIP gateway sit in one private network behind a NAT router, and the remote IP phone sits in another network behind its own NAT router, all RTP packets go through Asterisk (canreinvite=no).

Asterisk = 192.168.0.5 on the inside and 82.224.x.y on the outside, Linksys 3102 VoIP gateway is 192.168.0.253, and the remote IP phone is 82.237.x.y:

1. Called from the PSTN into the Linksys 3102 VoIP gateway

2. The 3102 notifies Asterisk of the incoming call

3. Asterisk rings extension "group", which includes extension 204 (remote, NATted IP phone)

4. Extension 204 answers, and communication is established between this remote IP phone and the remote PSTN caller

5. After a few seconds, the call is unvoluntarily hung up! At first sight, nothing suspicious in the SIP debug output below :-/

SIP debug session

<-- SIP read from 192.168.0.253:5061:
INVITE sip:group@192.168.0.5 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.253:5061;branch=z9hG4bK-bee56f08
From: (From 3102 VoIP Gateway) ;tag=7dbf7c3b908c8190o1
To:
Remote-Party-ID: (From 3102 VoIP Gateway) ;screen=yes;party=calling
Call-ID: 27dcb5d7-967934a4@192.168.0.253
CSeq: 101 INVITE
Max-Forwards: 70
Contact: (From 3102 VoIP Gateway)
Expires: 240
User-Agent: Linksys/SPA3102-5.1.7(GW)
Content-Length: 448
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura, replaces
Content-Type: application/sdp

v=0
o=- 26514960 26514960 IN IP4 192.168.0.253
s=-
c=IN IP4 192.168.0.253
t=0 0
m=audio 16386 RTP/AVP 0 2 4 8 18 96 97 98 100 101
a=rtpmap:0 PCMU/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:4 G723/8000
a=rtpmap:8 PCMA/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:100 NSE/8000
a=fmtp:100 192-193
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30
a=sendrecv

--- (15 headers 20 lines) ---
Using INVITE request as basis request - 27dcb5d7-967934a4@192.168.0.253
Sending to 192.168.0.253 : 5061 (NAT)
Reliably Transmitting (no NAT) to 192.168.0.253:5061:
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.0.253:5061;branch=z9hG4bK-bee56f08;received=192.168.0.253
From: (From 3102 VoIP Gateway) ;tag=7dbf7c3b908c8190o1
To: ;tag=as0ec378f8
Call-ID: 27dcb5d7-967934a4@192.168.0.253
CSeq: 101 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="7b838b69"
Content-Length: 0


---
Scheduling destruction of call '27dcb5d7-967934a4@192.168.0.253' in 15000 ms
Found user 'fxo'
<-- SIP read from 192.168.0.253:5061:
ACK sip:group@192.168.0.5 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.253:5061;branch=z9hG4bK-bee56f08
From: (From 3102 VoIP Gateway) ;tag=7dbf7c3b908c8190o1
To: ;tag=as0ec378f8
Call-ID: 27dcb5d7-967934a4@192.168.0.253
CSeq: 101 ACK
Max-Forwards: 70
Contact: (From 3102 VoIP Gateway)
User-Agent: Linksys/SPA3102-5.1.7(GW)
Content-Length: 0


--- (10 headers 0 lines) ---
<-- SIP read from 192.168.0.253:5061:
INVITE sip:group@192.168.0.5 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.253:5061;branch=z9hG4bK-728ae588
From: (From 3102 VoIP Gateway) ;tag=7dbf7c3b908c8190o1
To:
Remote-Party-ID: (From 3102 VoIP Gateway) ;screen=yes;party=calling
Call-ID: 27dcb5d7-967934a4@192.168.0.253
CSeq: 102 INVITE
Max-Forwards: 70
Proxy-Authorization: Digest username="fxo",realm="asterisk",nonce="7b838b69",uri="sip:group@192.168.0.5",algorithm=MD5,response="a3254ef413b2807179e2526e7a58fece"
Contact: (From 3102 VoIP Gateway)
Expires: 240
User-Agent: Linksys/SPA3102-5.1.7(GW)
Content-Length: 448
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: x-sipura, replaces
Content-Type: application/sdp

v=0
o=- 26514960 26514960 IN IP4 192.168.0.253
s=-
c=IN IP4 192.168.0.253
t=0 0
m=audio 16386 RTP/AVP 0 2 4 8 18 96 97 98 100 101
a=rtpmap:0 PCMU/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:4 G723/8000
a=rtpmap:8 PCMA/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:100 NSE/8000
a=fmtp:100 192-193
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30
a=sendrecv

--- (16 headers 20 lines) ---
Using INVITE request as basis request - 27dcb5d7-967934a4@192.168.0.253
Sending to 192.168.0.253 : 5061 (non-NAT)
Found user 'fxo'
Found RTP audio format 0
Found RTP audio format 2
Found RTP audio format 4
Found RTP audio format 8
Found RTP audio format 18
Found RTP audio format 96
Found RTP audio format 97
Found RTP audio format 98
Found RTP audio format 100
Found RTP audio format 101
Peer audio RTP is at port 192.168.0.253:16386
Found description format PCMU
Found description format G726-32
Found description format G723
Found description format PCMA
Found description format G729a
Found description format G726-40
Found description format G726-24
Found description format G726-16
Found description format NSE
Found description format telephone-event
Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x51d (g723|ulaw|alaw|g726|g729|ilbc)/video=0x0 (nothing), combined - 0xc (ulaw|alaw)
Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
Looking for group in myinternal (domain 192.168.0.5)
list_route: hop:
Transmitting (no NAT) to 192.168.0.253:5061:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.0.253:5061;branch=z9hG4bK-728ae588;received=192.168.0.253
From: (From 3102 VoIP Gateway) ;tag=7dbf7c3b908c8190o1
To:
Call-ID: 27dcb5d7-967934a4@192.168.0.253
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact:
Content-Length: 0


---
-- Executing LookupCIDName("SIP/fxo-095d4868", "") in new stack
-- Executing Dial("SIP/fxo-095d4868", "SIP/204") in new stack
We're at 82.224.x.y port 10062
Adding codec 0x4 (ulaw) to SDP
Adding codec 0x8 (alaw) to SDP
Adding codec 0x2 (gsm) to SDP
Adding non-codec 0x1 (telephone-event) to SDP
13 headers, 12 lines
Reliably Transmitting (NAT) to 82.237.x.y:5060:
INVITE sip:204@82.237.x.y SIP/2.0
Via: SIP/2.0/UDP 82.224.x.y:5060;branch=z9hG4bK60b492ba;rport
From: "(From 3102 VoIP Gateway)" ;tag=as4cc59efa
To:
Contact:
Call-ID: 17f827464576a52079c3ca921c65cbd9@82.224.x.y
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Sat, 26 May 2007 22:34:47 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Type: application/sdp
Content-Length: 267

v=0
o=root 11908 11908 IN IP4 82.224.x.y
s=session
c=IN IP4 82.224.x.y
t=0 0
m=audio 10062 RTP/AVP 0 8 3 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -

---
-- Called 204
<-- SIP read from 82.237.x.y:5060:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 82.224.x.y:5060;branch=z9hG4bK60b492ba;rport
From: "(From 3102 VoIP Gateway)" ;tag=as4cc59efa
To:
Call-ID: 17f827464576a52079c3ca921c65cbd9@82.224.x.y
CSeq: 102 INVITE
User-Agent: Grandstream BT120 1.0.8.33
Warning: 399 82.237.x.y "detected NAT type is port restricted cone"
Content-Length: 0


--- (9 headers 0 lines) ---
<-- SIP read from 82.237.x.y:5060:
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 82.224.x.y:5060;branch=z9hG4bK60b492ba;rport
From: "(From 3102 VoIP Gateway)" ;tag=as4cc59efa
To: ;tag=c43aef8a9cd8d2fc
Call-ID: 17f827464576a52079c3ca921c65cbd9@82.224.x.y
CSeq: 102 INVITE
User-Agent: Grandstream BT120 1.0.8.33
Warning: 399 82.237.x.y "detected NAT type is port restricted cone"
Content-Length: 0


--- (9 headers 0 lines) ---
-- SIP/204-095c6940 is ringing
Transmitting (no NAT) to 192.168.0.253:5061:
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.0.253:5061;branch=z9hG4bK-728ae588;received=192.168.0.253
From: (From 3102 VoIP Gateway) ;tag=7dbf7c3b908c8190o1
To: ;tag=as6862eeea
Call-ID: 27dcb5d7-967934a4@192.168.0.253
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact:
Content-Length: 0


---
<-- SIP read from 82.237.x.y:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 82.224.x.y:5060;branch=z9hG4bK60b492ba;rport
From: "(From 3102 VoIP Gateway)" ;tag=as4cc59efa
To: ;tag=c43aef8a9cd8d2fc
Call-ID: 17f827464576a52079c3ca921c65cbd9@82.224.x.y
CSeq: 102 INVITE
User-Agent: Grandstream BT120 1.0.8.33
Warning: 399 82.237.x.y "detected NAT type is port restricted cone"
Contact:
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE
Content-Type: application/sdp
Supported: replaces
Content-Length: 210

v=0
o=204 8000 8000 IN IP4 82.237.x.y
s=SIP Call
c=IN IP4 82.237.x.y
t=0 0
m=audio 5004 RTP/AVP 0 101
a=sendrecv
a=rtpmap:0 PCMU/8000
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11

--- (13 headers 11 lines) ---
Found RTP audio format 0
Found RTP audio format 101
Peer audio RTP is at port 82.237.x.y:5004
Found description format PCMU
Found description format telephone-event
Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw)
Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
list_route: hop:
set_destination: Parsing for address/port to send to
set_destination: set destination to 82.237.x.y, port 5060
Transmitting (NAT) to 82.237.x.y:5060:
ACK sip:204@82.237.x.y SIP/2.0
Via: SIP/2.0/UDP 82.224.x.y:5060;branch=z9hG4bK2f63b66b;rport
From: "(From 3102 VoIP Gateway)" ;tag=as4cc59efa
To: ;tag=c43aef8a9cd8d2fc
Contact:
Call-ID: 17f827464576a52079c3ca921c65cbd9@82.224.x.y
CSeq: 102 ACK
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0


---
-- SIP/204-095c6940 answered SIP/fxo-095d4868
We're at 192.168.0.5 port 10070
Adding codec 0x4 (ulaw) to SDP
Adding codec 0x8 (alaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP
Reliably Transmitting (no NAT) to 192.168.0.253:5061:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.0.253:5061;branch=z9hG4bK-728ae588;received=192.168.0.253
From: (From 3102 VoIP Gateway) ;tag=7dbf7c3b908c8190o1
To: ;tag=as6862eeea
Call-ID: 27dcb5d7-967934a4@192.168.0.253
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact:
Content-Type: application/sdp
ontent-Length: 238

v=0
o=root 11908 11908 IN IP4 192.168.0.5
s=session
c=IN IP4 192.168.0.5
t=0 0
m=audio 10070 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=silenceSupp:off - - - -

---
-- Attempting native bridge of SIP/fxo-095d4868 and SIP/204-095c6940
<-- SIP read from 192.168.0.253:5061:
ACK sip:group@192.168.0.5 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.253:5061;branch=z9hG4bK-a62ce160
From: (From 3102 VoIP Gateway) ;tag=7dbf7c3b908c8190o1
To: ;tag=as6862eeea
Call-ID: 27dcb5d7-967934a4@192.168.0.253
CSeq: 102 ACK
Max-Forwards: 70
Proxy-Authorization: Digest username="fxo",realm="asterisk",nonce="7b838b69",uri="sip:group@192.168.0.5",algorithm=MD5,response="a3254ef413b2807179e2526e7a58fece"
Contact: (From 3102 VoIP Gateway)
User-Agent: Linksys/SPA3102-5.1.7(GW)
Content-Length: 0


Hung up on here!


--- (11 headers 0 lines) ---
<-- SIP read from 192.168.0.253:5061:
BYE sip:group@192.168.0.5 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.253:5061;branch=z9hG4bK-f5c358c2
From: (From 3102 VoIP Gateway) ;tag=7dbf7c3b908c8190o1
To: ;tag=as6862eeea
Call-ID: 27dcb5d7-967934a4@192.168.0.253
CSeq: 103 BYE
Max-Forwards: 70
Proxy-Authorization: Digest username="fxo",realm="asterisk",nonce="7b838b69",uri="sip:group@192.168.0.5",algorithm=MD5,response="bcea663bb207a64c08346eb1b81f2230"
User-Agent: Linksys/SPA3102-5.1.7(GW)
Content-Length: 0


--- (10 headers 0 lines) ---
Sending to 192.168.0.253 : 5061 (non-NAT)
Transmitting (no NAT) to 192.168.0.253:5061:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.0.253:5061;branch=z9hG4bK-f5c358c2;received=192.168.0.253
From: (From 3102 VoIP Gateway) ;tag=7dbf7c3b908c8190o1
To: ;tag=as6862eeea
Call-ID: 27dcb5d7-967934a4@192.168.0.253
CSeq: 103 BYE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact:
Content-Length: 0
X-Asterisk-HangupCause: Normal Clearing


---
Scheduling destruction of call '17f827464576a52079c3ca921c65cbd9@82.224.x.y' in 32000 ms
set_destination: Parsing for address/port to send to
set_destination: set destination to 82.237.x.y, port 5060
Reliably Transmitting (NAT) to 82.237.x.y:5060:
BYE sip:204@82.237.x.y SIP/2.0
Via: SIP/2.0/UDP 82.224.x.y:5060;branch=z9hG4bK6a99ae9e;rport
From: "(From 3102 VoIP Gateway)" ;tag=as4cc59efa
To: ;tag=c43aef8a9cd8d2fc
Call-ID: 17f827464576a52079c3ca921c65cbd9@82.224.x.y
CSeq: 103 BYE
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0


---
== Spawn extension (myinternal, group, 2) exited non-zero on 'SIP/fxo-095d4868'
<-- SIP read from 82.237.x.y:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 82.224.x.y:5060;branch=z9hG4bK6a99ae9e;rport
From: "(From 3102 VoIP Gateway)" ;tag=as4cc59efa
To: ;tag=c43aef8a9cd8d2fc
Call-ID: 17f827464576a52079c3ca921c65cbd9@82.224.x.y
CSeq: 103 BYE
User-Agent: Grandstream BT120 1.0.8.33
Warning: 399 82.237.x.y "detected NAT type is port restricted cone"
Contact:
Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE
Supported: replaces
Content-Length: 0


--- (12 headers 0 lines) ---
Destroying call '17f827464576a52079c3ca921c65cbd9@82.224.x.y'
Destroying call '27dcb5d7-967934a4@192.168.0.253'