SIP BYE "Normal Clearing" not sent

Asterisk Asterisk Support
1

Hello,

I have an IVR where key1 simply hangup the session:

exten => 1,1,NoOp(Digit 1)
same => n,Wait(1)
same => n,Playback(MIC_ivr_hangup_in_5secs)
same => n,Hangup()

however as you can see from the below logs, after asterisk prepare the BYE it seems it detect a Broken pipe and the BYE “Normal Clearing” never leave the Asterisk machine.
The session get then dropped down but due to RTP Timeout.

How can I figure out to have a clean BYE leaving Asterisk ?

Thank you,
Andrea

    -- Executing [1@ivr-1:1] NoOp("SIP/mnc90.mcc222.3gppnetwork.org-00000003", "Digit 1") in new stack
    -- Executing [1@ivr-1:2] Wait("SIP/mnc90.mcc222.3gppnetwork.org-00000003", "1") in new stack
    -- Executing [1@ivr-1:3] Playback("SIP/mnc90.mcc222.3gppnetwork.org-00000003", "MIC_ivr_hangup_in_5secs") in new stack
    -- <SIP/mnc90.mcc222.3gppnetwork.org-00000003> Playing 'MIC_ivr_hangup_in_5secs.slin' (language 'en')
    -- Executing [1@ivr-1:4] Hangup("SIP/mnc90.mcc222.3gppnetwork.org-00000003", "") in new stack
  == Spawn extension (ivr-1, 1, 4) exited non-zero on 'SIP/mnc90.mcc222.3gppnetwork.org-00000003'
Scheduling destruction of SIP dialog '23FCF94F-1@s' in 32000 ms (Method: INVITE)
Reliably Transmitting (no NAT) to 192.168.92.100:5060:
BYE sip:172.16.99.103:5060 SIP/2.0
Via: SIP/2.0/TCP 192.168.92.99:5060;branch=z9hG4bK67089950
Route: <sip:1555124610@192.168.92.100:5060;lr>,<sip:1555124610@192.168.92.100:20606;lr>,<sip:2.228.173.141:20606;lr>
Max-Forwards: 70
From: <sip:3995555599;phone-context=mnc90.mcc222.3gppnetwork.org@mnc90.mcc222.3gppnetwork.org;user=phone>;tag=as304667f1
To: <sip:3995555554@mnc90.mcc222.3gppnetwork.org>;tag=s+1+41a50000+17d00641
Call-ID: 23FCF94F-1@s
CSeq: 102 BYE
User-Agent: Asterisk PBX 13.9.1
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0


---
[Jun 20 10:20:59] WARNING[3274][C-00000003]: chan_sip.c:3775 __sip_xmit: sip_xmit of 0x7f58d8006520 (len 596) to 192.168.92.100:5060 returned -2: Broken pipe
asterisk-99*CLI> 
asterisk-99*CLI> 
asterisk-99*CLI> 

<--- SIP read from TCP:192.168.92.100:5060 --->
BYE sip:s@192.168.92.99:5060;transport=TCP SIP/2.0
Via: SIP/2.0/TCP 192.168.92.100:5060;branch=z9hG4bK+0edb7ce2e3bbdc0e71882a005cbb4e9a2+s+1;X-CID-1=20020590;X-CID-2=20020434
Via: SIP/2.0/UDP 2.228.173.141:20606;branch=z9hG4bK+eb02d513c26be149b619ef80f0b6b15a1+s+1;X-CID-1=20020589;X-CID-2=20020436
P-Asserted-Identity: <sip:3995555554@mnc90.mcc222.3gppnetwork.org>
Call-ID: 23FCF94F-1@s
From: <sip:3995555554@mnc90.mcc222.3gppnetwork.org>;tag=s+1+41a50000+17d00641
To: <sip:3995555599;phone-context=mnc90.mcc222.3gppnetwork.org@mnc90.mcc222.3gppnetwork.org;user=phone>;tag=as304667f1
CSeq: 253746458 BYE
Content-Length: 0
Supported: 100rel
Supported: Path
Supported: Replaces
User-Agent: iOS/9.0.1 (13A404) iPhone
Reason: sip;text="RTP Timeout"
Allow: ACK,BYE,CANCEL,INVITE,MESSAGE,NOTIFY,OPTIONS,PRACK,REFER,UPDATE
Session-ID: bcbf800efa832008bbbbd4db4d4da3e3
Max-Forwards: 66

----Follow up----

Hello,

I tried to get some more log about the error:
[Jun 20 10:20:59] WARNING[3274][C-00000003]: chan_sip.c:3775 __sip_xmit: sip_xmit of 0x7f58d8006520 (len 596) to 192.168.92.100:5060 returned -2: Broken pipe

So I started following log:
asterisk-99*CLI> logger add channel debug_log_123456 notice,warning,error,debug,verbose,dtmf

but the extract from “/var/log/asterisk/debug_log_123456” does not seems to be much helpful:

[Jun 21 03:50:56] DEBUG[8526][C-00000000] pbx.c: Launching 'Hangup'
[Jun 21 03:50:56] DEBUG[8526][C-00000000] channel.c: Soft-Hanging (0x20) up channel 'SIP/mnc90.mcc222.3gppnetwork.org-00000000'
[Jun 21 03:50:56] DEBUG[8526][C-00000000] pbx.c: Spawn extension (ivr-1,1,4) exited non-zero on 'SIP/mnc90.mcc222.3gppnetwork.org
-00000000'
[Jun 21 03:50:56] DEBUG[8526][C-00000000] channel.c: Soft-Hanging (0x10) up channel 'SIP/mnc90.mcc222.3gppnetwork.org-00000000'
[Jun 21 03:50:56] DEBUG[8526][C-00000000] channel.c: Hanging up channel 'SIP/mnc90.mcc222.3gppnetwork.org-00000000'
[Jun 21 03:50:56] DEBUG[8526][C-00000000] chan_sip.c: Hangup call SIP/mnc90.mcc222.3gppnetwork.org-00000000, SIP callid 1A5F7651-
1@s
[Jun 21 03:50:56] DEBUG[8526][C-00000000] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fdea0007f08'
[Jun 21 03:50:56] DEBUG[8526][C-00000000] chan_sip.c: Trying to put 'BYE sip:172' onto TCP socket destined for 192.168.92.100:506
0
[Jun 21 03:50:56] WARNING[8526][C-00000000] chan_sip.c: sip_xmit of 0x7fdea80099e0 (len 593) to 192.168.92.100:5060 returned -2:
Broken pipe

So does anybody has an idea why Asterisk 13.9.1 refuse to send this BYE message over the network:

Scheduling destruction of SIP dialog '1094FBB2-1@s' in 32000 ms (Method: INVITE)
Reliably Transmitting (no NAT) to 192.168.92.100:5060:
BYE sip:172.16.99.108:5060 SIP/2.0
Via: SIP/2.0/TCP 192.168.92.99:5060;branch=z9hG4bK2ab0931e
Route: <sip:1131144731@192.168.92.100:5060;lr>,<sip:1131144731@192.168.92.100:20606;lr>,<sip:2.228.173.141:20606;lr>
Max-Forwards: 70
From: <sip:3995555599;phone-context=mnc90.mcc222.3gppnetwork.org@mnc90.mcc222.3gppnetwork.org;user=phone>;tag=as197819db
To: <sip:3995555554@mnc90.mcc222.3gppnetwork.org>;tag=s+1+411e0007+42bcdf82
Call-ID: 1094FBB2-1@s
CSeq: 102 BYE
User-Agent: Asterisk PBX 13.9.1
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0


---
[Jun 21 04:11:20] WARNING[8829][C-0000000b]: chan_sip.c:3775 __sip_xmit: sip_xmit of 0x7fde58006cf0 (len 596) to 192.168.92.100:5060 returned -2: Broken pipe
3

Hi,
No specific idea so far, but some things to check.

  1. You are running SIP over TCP. Maybe TCP connection is closed / broken by the moment of sending BYE? Did you launch tcpdump and look at the packet trace at L3-L4 - is everything OK with TCP/IP stack?
  2. Continuing #1: is it possible to change transport protocol to UDP and check this again?
  3. Is this issue specific for Playback application only (i.e. to IVR)? Does everything work correctly for other dialplan apps (e.g. Dial) or not?