SIP call not hanging up after 2 minutes

Asterisk Asterisk SIP
1

Asterisk 13.12
Twilio Elastic SIP (secure)

I have setup an IVR and it works flawlessly when testing with a SIP phone connected to the Asterisk server. We are testing through the Twilio’s Elastic SIP (secure) service now and have a single weird issue before cloning to production:

If a call is up for more than two minutes, when the context includes hangup(), the call sends a BYE, throws an error, but never hangs up. If the call is less than two minutes, the call ends just fine.

[nm-goodbye]
exten => s,1,Playback(IVR/nm_goodbye)
exten => s,n,Hangup()

“sanitized” SIP message:
– Executing [s@nm-goodbye:2] Hangup(“SIP/twilio4-00000001”, “”) in new stack
== Spawn extension (nm-goodbye, s, 2) exited non-zero on 'SIP/twilio4-00000001’
Scheduling destruction of SIP dialog ‘72f540723a2258851d6653be8dc37501@0.0.0.0’ in 6400 ms (Method: ACK)
Reliably Transmitting (NAT) to [Twilio]:48335:
BYE sip:+[MyCell]@[NAT’dIPaddress]:5060;transport=udp SIP/2.0
Via: SIP/2.0/TLS [PubIP]:5061;branch=z9hG4bK00262e4c;rport
Route: sip:Twilio:5061;transport=tls;r2=on;lr;ftag=53351529_6772d868_9aa52420-650e-4be7-8a57-5337cb1ee3c2,sip:Twilio:5060;r2=on;lr;ftag=53351529_6772d868_9aa52420-650e-4be7-8a57-5337cb1ee3c2
Max-Forwards: 70
From: sip:+[IVR]@pbx.statement.services;user=phone;tag=as57f38389
To: sip:+[MyCell]@asterisk-server.pstn.twilio.com;isup-oli=62;tag=53351529_6772d868_9aa52420-650e-4be7-8a57-5337cb1ee3c2
Call-ID: 72f540723a2258851d6653be8dc37501@0.0.0.0
CSeq: 102 BYE
User-Agent: Asterisk PBX 13.12.0
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0

Error message received on console after two minutes:

[Oct 31 16:10:57] ERROR[6045][C-00000001]: chan_sip.c:4263 __sip_reliable_xmit: Serious Network Trouble; __sip_xmit returns error for pkt data

I have confirmed that firewall ports UDP/TCP 5060/5061 and UDP 10000-20000 are open.
I have debugged RTP, and it never breaks during the call.

The sip.conf trunk configuration is taken straight out of the Asterisk config document at https://www.twilio.com/docs/api/sip-trunking/sample-configuration#asterisk

twilio-trunk
type=peer
context=from-twilio ;Which dialplan to use for incoming calls
dtmfmode=rfc2833
canreinvite=no
insecure=port,invite
transport=tls
qualify=yes
encryption=yes
media_encryption=sdes

twilio0
host=asterisk-server.pstn.twilio.com

twilio1
host=54.172.60.2

twilio2
host=54.172.60.0

twilio3
host=54.172.60.1

twilio4
host=54.172.60.3

2

Looks like the peer dropped the TCP connection, rather than sending OK,

3

I put 5vs, i.e. -vvvvvr, on the console and I still cant find why I’m getting the non-zero spawn error:

Spawn extension (nm-goodbye, s, 2) exited non-zero on ‘SIP/twilio4-00000006’.

Any ideas on how to find the source?

4

You need to obtain protocol traces, but note that exited non-zero is not an error. It generally happens once in every call.

5

10-4.

Last question: I did another test and actually stayed on the phone because the call doesn’t actually drop. At 7:20, the call drops and here are the two messages:

<— SIP read from TLS:[Twilio]:37651 —>
BYE sip:+[IVR]@[PubIP]:5061;transport=TLS SIP/2.0
CSeq: 12817 BYE
From: sip:+[MyCell]@asterisk-server.pstn.twilio.com;isup-oli=62;tag=52168373_6772d868_f17b5c8a-6bdc-44d4-8ac8-f6525e0d3e0a
To: sip:+[IVR]@asterisk.server;user=phone;tag=as7e1bdc34
Call-ID: 5160958fe0d587093524e676772c5244@0.0.0.0
Max-Forwards: 69
User-Agent: Twilio
Via: SIP/2.0/TLS [Twilio]:5061;branch=z9hG4bK1252.47c50e22.0
Via: SIP/2.0/UDP NAT’dIPaddress:5060;rport=5060;received=[PubIP];branch=z9hG4bKf17b5c8a-6bdc-44d4-8ac8-f6525e0d3e0a_6772d868_364-8719048950985034200
X-Twilio-CallSid: CAc0cafd910d77e3872a4fef7ad6b3874a
Content-Length: 0

<------------->
— (11 headers 0 lines) —
Sending to 54.172.60.1:37651 (NAT)

<— Transmitting (NAT) to 54.172.60.1:37651 —>
SIP/2.0 481 Call leg/transaction does not exist
Via: SIP/2.0/TLS [Twilio]:5061;branch=z9hG4bK1252.47c50e22.0;received=[Twilio];rport=37651
Via: SIP/2.0/UDP [Nat’dIPAddress]:5060;rport=5060;received=[PubIP];branch=z9hG4bKf17b5c8a-6bdc-44d4-8ac8-f6525e0d3e0a_6772d868_364-8719048950985034200
From: sip:+[MyCell]@asterisk-server.pstn.twilio.com;isup-oli=62;tag=52168373_6772d868_f17b5c8a-6bdc-44d4-8ac8-f6525e0d3e0a
To: sip:+[IVR]@asterisk.server;user=phone;tag=as7e1bdc34
Call-ID: 5160958fe0d587093524e676772c5244@0.0.0.0
CSeq: 12817 BYE
Server: Asterisk PBX 13.12.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0

Any added clarity to the problem? I’m going to add this to the Twilio ticket.

6

Asterisk thinks the call has already ended, so look for timed out transactions earlier on.

7

swapped chan_sip for chan_pjsip resolved the hangup issue.