Outbound Calls - Remote End Inexplicably Hangs Up

I am trying to track down why certain outgoing calls terminate after only a minute or so. This has happened consistently with at least two separate phone numbers that I regularly dial. In each case, the called party answers, we speak for about a minute, and then the call terminates. A sip debug shows that the remote end has sent a BYE response, even though the called party assures me that they did not hang up the call.

The fact that two-way audio works fine makes me believe that it’s not a NAT problem, and the fact that it only seems to happen with respect to certain dialed numbers makes me think that possibly there may be a problem on the remote end. Nonetheless, I’m trying to figure out if there is any problem with my configuration that might be causing the problem.

Asterisk Version: 1.8.20.0, installed from yum, Centos 6

Network Environment:

handset (192.168.200.10) --> asterisk (192.168.200.1) --> public (static) IP --> VOIP provider

Sip Debug:

(I’ve stripped out all the SDP data.)

<--- SIP read from UDP:192.168.200.10:5060 --->
INVITE sip:720xxxxxxx@192.168.200.1 SIP/2.0
Via: SIP/2.0/UDP 192.168.200.10:5060;branch=z9hG4bK-90b4ad96
From: "12345" <sip:12345@192.168.200.1>;tag=51defdb77016929co0
To: <sip:720xxxxxxx@192.168.200.1>
Call-ID: 1c649413-fc088ff0@192.168.200.10
CSeq: 101 INVITE
Max-Forwards: 70
Contact: "12345" <sip:12345@192.168.200.10:5060>
Expires: 240
User-Agent: Linksys/SPA962-6.1.5(a)
Content-Length: 399
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces
Content-Type: application/sdp


<--- Reliably Transmitting (NAT) to 192.168.200.10:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.200.10:5060;branch=z9hG4bK-90b4ad96;received=192.168.200.10;rport=5060
From: "12345" <sip:12345@192.168.200.1>;tag=51defdb77016929co0
To: <sip:720xxxxxxx@192.168.200.1>;tag=as1544cffe
Call-ID: 1c649413-fc088ff0@192.168.200.10
CSeq: 101 INVITE
Server: Asterisk PBX 1.8.20.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="090a8ffc"
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog '1c649413-fc088ff0@192.168.200.10' in 128000 ms (Method: INVITE)

<--- SIP read from UDP:192.168.200.10:5060 --->
ACK sip:720xxxxxxx@192.168.200.1 SIP/2.0
Via: SIP/2.0/UDP 192.168.200.10:5060;branch=z9hG4bK-90b4ad96
From: "12345" <sip:12345@192.168.200.1>;tag=51defdb77016929co0
To: <sip:720xxxxxxx@192.168.200.1>;tag=as1544cffe
Call-ID: 1c649413-fc088ff0@192.168.200.10
CSeq: 101 ACK
Max-Forwards: 70
Contact: "12345" <sip:12345@192.168.200.10:5060>
User-Agent: Linksys/SPA962-6.1.5(a)
Content-Length: 0


<--- SIP read from UDP:192.168.200.10:5060 --->
INVITE sip:720xxxxxxx@192.168.200.1 SIP/2.0
Via: SIP/2.0/UDP 192.168.200.10:5060;branch=z9hG4bK-433de502
From: "12345" <sip:12345@192.168.200.1>;tag=51defdb77016929co0
To: <sip:720xxxxxxx@192.168.200.1>
Call-ID: 1c649413-fc088ff0@192.168.200.10
CSeq: 102 INVITE
Max-Forwards: 70
Authorization: Digest username="12345",realm="asterisk",nonce="090a8ffc",uri="sip:720xxxxxxx@192.168.200.1",algorithm=MD5,response="71324aa8ec2789645389bc0e15084d9d"
Contact: "12345" <sip:12345@192.168.200.10:5060>
Expires: 240
User-Agent: Linksys/SPA962-6.1.5(a)
Content-Length: 399
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces
Content-Type: application/sdp


<--- Transmitting (NAT) to 192.168.200.10:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.200.10:5060;branch=z9hG4bK-433de502;received=192.168.200.10;rport=5060
From: "12345" <sip:12345@192.168.200.1>;tag=51defdb77016929co0
To: <sip:720xxxxxxx@192.168.200.1>
Call-ID: 1c649413-fc088ff0@192.168.200.10
CSeq: 102 INVITE
Server: Asterisk PBX 1.8.20.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: <sip:720xxxxxxx@192.168.200.1:5060>
Content-Length: 0


<------------>
    -- Executing [720xxxxxxx@dialed-from-handset:1] Set("SIP/12345-00000166", "CALLERID(all)="VOIP User" <303xxxxxxx>") in new stack
    -- Executing [720xxxxxxx@dialed-from-handset:2] NoOp("SIP/12345-00000166", "SIPCALLID: 1c649413-fc088ff0@192.168.200.10") in new stack
    -- Executing [720xxxxxxx@dialed-from-handset:3] Dial("SIP/12345-00000166", "SIP/+1720xxxxxxx@voicepulse-primary") in new stack
  == Using SIP RTP CoS mark 5


Reliably Transmitting (NAT) to 209.31.18.12:5060:
INVITE sip:+1720xxxxxxx@sjc-primary.voicepulse.com SIP/2.0
Via: SIP/2.0/UDP xxx.xxx.xxx.17:5060;branch=z9hG4bK202f94d5;rport
Max-Forwards: 70
From: "VOIP User" <sip:303xxxxxxx@xxx.xxx.xxx.17>;tag=as1076426a
To: <sip:+1720xxxxxxx@sjc-primary.voicepulse.com>
Contact: <sip:303xxxxxxx@xxx.xxx.xxx.17:5060>
Call-ID: 71a58afc0694df072a88854e494ded33@xxx.xxx.xxx.17:5060
CSeq: 102 INVITE
User-Agent: Asterisk PBX 1.8.20.0
Date: Fri, 02 Aug 2013 18:20:05 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 309

    -- Called SIP/+1720xxxxxxx@voicepulse-primary

<--- SIP read from UDP:209.31.18.12:5060 --->
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP xxx.xxx.xxx.17:5060;branch=z9hG4bK202f94d5;rport=5060
From: "VOIP User" <sip:303xxxxxxx@xxx.xxx.xxx.17>;tag=as1076426a
To: <sip:+1720xxxxxxx@sjc-primary.voicepulse.com>;tag=bf91ba8e754533baedb51a458caf3219.c21a
Call-ID: 71a58afc0694df072a88854e494ded33@xxx.xxx.xxx.17:5060
CSeq: 102 INVITE
Proxy-Authenticate: Digest realm="xxx.xxx.xxx.17", nonce="51fbf873000067b70e20adb145657d0e2f7d57be6e8a65fe", qop="auth"
Server: OpenSIPS (1.6.2-notls (x86_64/linux))
Content-Length: 0


Transmitting (NAT) to 209.31.18.12:5060:
ACK sip:+1720xxxxxxx@sjc-primary.voicepulse.com SIP/2.0
Via: SIP/2.0/UDP xxx.xxx.xxx.17:5060;branch=z9hG4bK202f94d5;rport
Max-Forwards: 70
From: "VOIP User" <sip:303xxxxxxx@xxx.xxx.xxx.17>;tag=as1076426a
To: <sip:+1720xxxxxxx@sjc-primary.voicepulse.com>;tag=bf91ba8e754533baedb51a458caf3219.c21a
Contact: <sip:303xxxxxxx@xxx.xxx.xxx.17:5060>
Call-ID: 71a58afc0694df072a88854e494ded33@xxx.xxx.xxx.17:5060
CSeq: 102 ACK
User-Agent: Asterisk PBX 1.8.20.0
Content-Length: 0


Reliably Transmitting (NAT) to 209.31.18.12:5060:
INVITE sip:+1720xxxxxxx@sjc-primary.voicepulse.com SIP/2.0
Via: SIP/2.0/UDP xxx.xxx.xxx.17:5060;branch=z9hG4bK3c15ce92;rport
Max-Forwards: 70
From: "VOIP User" <sip:303xxxxxxx@xxx.xxx.xxx.17>;tag=as1076426a
To: <sip:+1720xxxxxxx@sjc-primary.voicepulse.com>
Contact: <sip:303xxxxxxx@xxx.xxx.xxx.17:5060>
Call-ID: 71a58afc0694df072a88854e494ded33@xxx.xxx.xxx.17:5060
CSeq: 103 INVITE
User-Agent: Asterisk PBX 1.8.20.0
Proxy-Authorization: Digest username="abc123DEF", realm="xxx.xxx.xxx.17", algorithm=MD5, uri="sip:+1720xxxxxxx@sjc-primary.voicepulse.com", nonce="51fbf873000067b70e20adb145657d0e2f7d57be6e8a65fe", response="e1416a5e293ed322465aa64dc7c309aa", qop=auth, cnonce="7b92ec36", nc=00000001
Date: Fri, 02 Aug 2013 18:20:05 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 309


<--- SIP read from UDP:209.31.18.12:5060 --->
SIP/2.0 100 Giving a try
Via: SIP/2.0/UDP xxx.xxx.xxx.17:5060;branch=z9hG4bK3c15ce92;rport=5060
From: "VOIP User" <sip:303xxxxxxx@xxx.xxx.xxx.17>;tag=as1076426a
To: <sip:+1720xxxxxxx@sjc-primary.voicepulse.com>
Call-ID: 71a58afc0694df072a88854e494ded33@xxx.xxx.xxx.17:5060
CSeq: 103 INVITE
Server: OpenSIPS (1.6.2-notls (x86_64/linux))
Content-Length: 0


<--- SIP read from UDP:209.31.18.12:5060 --->
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP xxx.xxx.xxx.17:5060;received=xxx.xxx.xxx.17;branch=z9hG4bK3c15ce92;rport=5060
Record-Route: <sip:209.31.18.12;lr=on;ftag=as1076426a>
From: "VOIP User" <sip:303xxxxxxx@xxx.xxx.xxx.17>;tag=as1076426a
To: <sip:+1720xxxxxxx@sjc-primary.voicepulse.com>;tag=as08614f5e
Call-ID: 71a58afc0694df072a88854e494ded33@xxx.xxx.xxx.17:5060
CSeq: 103 INVITE
User-Agent: VoicePulse PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:+1720xxxxxxx@209.31.18.13>
Content-Type: application/sdp
Content-Length: 283

    -- SIP/voicepulse-primary-00000167 is making progress passing it to SIP/12345-00000166

<--- Transmitting (NAT) to 192.168.200.10:5060 --->
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 192.168.200.10:5060;branch=z9hG4bK-433de502;received=192.168.200.10;rport=5060
From: "12345" <sip:12345@192.168.200.1>;tag=51defdb77016929co0
To: <sip:720xxxxxxx@192.168.200.1>;tag=as0c12a3ea
Call-ID: 1c649413-fc088ff0@192.168.200.10
CSeq: 102 INVITE
Server: Asterisk PBX 1.8.20.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: <sip:720xxxxxxx@192.168.200.1:5060>
Content-Type: application/sdp
Content-Length: 335


<--- SIP read from UDP:209.31.18.12:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP xxx.xxx.xxx.17:5060;received=xxx.xxx.xxx.17;branch=z9hG4bK3c15ce92;rport=5060
Record-Route: <sip:209.31.18.12;lr=on;ftag=as1076426a>
From: "VOIP User" <sip:303xxxxxxx@xxx.xxx.xxx.17>;tag=as1076426a
To: <sip:+1720xxxxxxx@sjc-primary.voicepulse.com>;tag=as08614f5e
Call-ID: 71a58afc0694df072a88854e494ded33@xxx.xxx.xxx.17:5060
CSeq: 103 INVITE
User-Agent: VoicePulse PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:+1720xxxxxxx@209.31.18.13>
Content-Type: application/sdp
Content-Length: 283


Transmitting (NAT) to 209.31.18.12:5060:
ACK sip:+1720xxxxxxx@209.31.18.13 SIP/2.0
Via: SIP/2.0/UDP xxx.xxx.xxx.17:5060;branch=z9hG4bK71b246ce;rport
Route: <sip:209.31.18.12;lr=on;ftag=as1076426a>
Max-Forwards: 70
From: "VOIP User" <sip:303xxxxxxx@xxx.xxx.xxx.17>;tag=as1076426a
To: <sip:+1720xxxxxxx@sjc-primary.voicepulse.com>;tag=as08614f5e
Contact: <sip:303xxxxxxx@xxx.xxx.xxx.17:5060>
Call-ID: 71a58afc0694df072a88854e494ded33@xxx.xxx.xxx.17:5060
CSeq: 103 ACK
User-Agent: Asterisk PBX 1.8.20.0
Content-Length: 0

    -- SIP/voicepulse-primary-00000167 answered SIP/12345-00000166


<--- Reliably Transmitting (NAT) to 192.168.200.10:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.200.10:5060;branch=z9hG4bK-433de502;received=192.168.200.10;rport=5060
From: "12345" <sip:12345@192.168.200.1>;tag=51defdb77016929co0
To: <sip:720xxxxxxx@192.168.200.1>;tag=as0c12a3ea
Call-ID: 1c649413-fc088ff0@192.168.200.10
CSeq: 102 INVITE
Server: Asterisk PBX 1.8.20.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: <sip:720xxxxxxx@192.168.200.1:5060>
Content-Type: application/sdp
Content-Length: 335

    -- Locally bridging SIP/12345-00000166 and SIP/voicepulse-primary-00000167

<--- SIP read from UDP:192.168.200.10:5060 --->
ACK sip:720xxxxxxx@192.168.200.1:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.200.10:5060;branch=z9hG4bK-67b25f0b
From: "12345" <sip:12345@192.168.200.1>;tag=51defdb77016929co0
To: <sip:720xxxxxxx@192.168.200.1>;tag=as0c12a3ea
Call-ID: 1c649413-fc088ff0@192.168.200.10
CSeq: 102 ACK
Max-Forwards: 70
Authorization: Digest username="12345",realm="asterisk",nonce="090a8ffc",uri="sip:720xxxxxxx@192.168.200.1",algorithm=MD5,response="71324aa8ec2789645389bc0e15084d9d"
Contact: "12345" <sip:12345@192.168.200.10:5060>
User-Agent: Linksys/SPA962-6.1.5(a)
Content-Length: 0


<--- SIP read from UDP:209.31.18.12:5060 --->
BYE sip:303xxxxxxx@xxx.xxx.xxx.17:5060 SIP/2.0
Via: SIP/2.0/UDP 209.31.18.12;branch=z9hG4bK34301001
Via: SIP/2.0/UDP 209.31.18.13:5060;received=209.31.18.13;branch=z9hG4bK34301001;rport=5060
From: <sip:+1720xxxxxxx@sjc-primary.voicepulse.com>;tag=as08614f5e
To: "VOIP User" <sip:303xxxxxxx@xxx.xxx.xxx.17>;tag=as1076426a
Call-ID: 71a58afc0694df072a88854e494ded33@xxx.xxx.xxx.17:5060
CSeq: 102 BYE
User-Agent: VoicePulse PBX
Max-Forwards: 69
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0
VP-hint: loose-routed
VP-hint: forwarded


<--- Transmitting (NAT) to 209.31.18.12:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 209.31.18.12;branch=z9hG4bK34301001;received=209.31.18.12;rport=5060
Via: SIP/2.0/UDP 209.31.18.13:5060;received=209.31.18.13;branch=z9hG4bK34301001;rport=5060
From: <sip:+1720xxxxxxx@sjc-primary.voicepulse.com>;tag=as08614f5e
To: "VOIP User" <sip:303xxxxxxx@xxx.xxx.xxx.17>;tag=as1076426a
Call-ID: 71a58afc0694df072a88854e494ded33@xxx.xxx.xxx.17:5060
CSeq: 102 BYE
Server: Asterisk PBX 1.8.20.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0


  == Spawn extension (dialed-from-handset, 720xxxxxxx, 3) exited non-zero on 'SIP/12345-00000166'

Reliably Transmitting (NAT) to 192.168.200.10:5060:
BYE sip:12345@192.168.200.10:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.200.1:5060;branch=z9hG4bK21a4cc09;rport
Max-Forwards: 70
From: <sip:720xxxxxxx@192.168.200.1>;tag=as0c12a3ea
To: "12345" <sip:12345@192.168.200.1>;tag=51defdb77016929co0
Call-ID: 1c649413-fc088ff0@192.168.200.10
CSeq: 102 BYE
User-Agent: Asterisk PBX 1.8.20.0
Proxy-Authorization: Digest username="12345", realm="asterisk", algorithm=MD5, uri="sip:192.168.200.1", nonce="", response="b8e9f69b80618b6001835096fe404caa"
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0


<--- SIP read from UDP:192.168.200.10:5060 --->
SIP/2.0 200 OK
To: "12345" <sip:12345@192.168.200.1>;tag=51defdb77016929co0
From: <sip:720xxxxxxx@192.168.200.1>;tag=as0c12a3ea
Call-ID: 1c649413-fc088ff0@192.168.200.10
CSeq: 102 BYE
Via: SIP/2.0/UDP 192.168.200.1:5060;branch=z9hG4bK21a4cc09
Server: Linksys/SPA962-6.1.5(a)
Content-Length: 0

SIP Response message for INCOMING dialog BYE arrived
Really destroying SIP dialog '1c649413-fc088ff0@192.168.200.10' Method: ACK

If it helps, I created a diagram of the SIP dialog here – http://pastebin.com/khNAck8s.

About six months ago, I increased the T1 timer to 2000 ms. I’ve forgotten the exact specifics why I did that, but it had something to do with the fact that, when an INVITE wasn’t responded to within 500 ms, asterisk would send a second INVITE and would end up placing two calls to the same callee. I wonder if that might not be causing my current problems.

I would be very grateful for any help or hints with this.

Thanks!

The called party cleared normally.

It didn’t retransmit its OK’s, so this isn’t a case of a lost ACK.

I assume there was media for the first minute, so I assume it is not timing out a lack of RTP.

You are going to have to address this from the other end.