BYE request received immediately after outbound call is connected

nasirjavaid · May 13, 2017, 7:57am

Hi,
We have 4 trunks with out provider for sending /receiving calls. What is happening is that when we dial, the call gets connected and immediately BYE is received from far end. When provider sends call using our trunks from his end then call goes fine but issue is happening only on our asterisk.

Can someone please guide. I am attaching configs and debug log.

root@Debian-81-64b:~# asterisk -V
Asterisk 11.13.1~dfsg-2+deb8u1

root@Debian-81-64b:~# cat /etc/debian_version
8.5

sip_debug1.txt (35.9 KB)
sip.conf.txt (2.6 KB)
sip_debug1.txt (35.9 KB)

david551 · May 13, 2017, 10:28am

Firstly, when submitting protocol logs, please use the log files and not a screen scrape. It is impossible to tell from your log that the BYE was immediate. Also delete irrelevant stuff, like the PUBLISH and SUBSCRIBE transactions. If possible include in-line, as pre-formatted text.

The normal reasons for an immediate BYE would be that that late offer SDP contained no acceptable codecs, or the response SDP contained no acceptable ones. Asterisk doesn’t initiate late offer, and there is nothing obviously wrong with the codecs, so you will need to solve the problem on the peer that is sending BYE.

However, it might still be worth trying straightforward codecs, like mu-law and A-law.

david551 · May 13, 2017, 10:37am

An other possibility is that the peer failed to receive any media, or less likely, they detected an error sending media.

I do note that, even with the partial obfuscation, you appear to have a mid of routable and non-routable IP addresses, but no configuration saying how to find the public address.

nasirjavaid · May 13, 2017, 3:26pm

Thanks for replying David.
Sorry about clutter in logs. I will capture through log files and try to remove SUBSCRIBE and PUBLISH transaction logs.

Asterisk sits on static public IP and I am connecting from behind NAT from remote IP and NAT is also enabled in extensions config.

Let me also try with simple codecs… hope provider supports them…

Thanks again.

david551 · May 13, 2017, 4:14pm

NAT is not enabled in extensions.conf. It’s enable by setting one or more of a number of parameters, including externip, in sip.conf. In some cases, particular when Asterisk is outside NAT, when nat= may need to be set to various values.

nasirjavaid · May 13, 2017, 4:52pm

Isn’t externip used when asterisk is behind nat? but here asterisk is on public ip. Sorry about some poor concepts about nat… But still it shouldn’t cause disconnection but only one way audio etc…

david551 · May 13, 2017, 5:22pm

Sorry. It is party A that is inside NAT, and has a broken NAT configuration. You may be able to work round that using nat=. However, it may be completely broken.

Ideally there should be no 192.168 addresses in your log if the Asterisk is outside of NAT.

nasirjavaid · May 13, 2017, 5:33pm

hmmm… its strange that same is happening from client’s extension and also inbound call to DID shows same behaviour… it rings, connects and aborts
I use same zoiper client to connect with dozens of other asterisk servers and they work fine with same config… look like I am out of options…

Any further steps to diagnose the issue?

Thanks.

nasirjavaid · May 13, 2017, 5:52pm

Here I upload latest debug using ulaw, alaw and gsm codecs. I have also removed SUBSCRIBE,OPTIONS and other useless clutter to make it as clean as possible.

Please note that IP and usernames have been changed.

Cheers!

full.txt (28.5 KB)

david551 · May 13, 2017, 5:53pm

I think the problem is clear. You have a peer that doesn’t understand how to work behind NAT.

If there is a delay before the BYE, the final straw might be that both are trying to use comedia and waiting for the other one to send first. Setting nat=yes is really setting comedia and force_rport. The comedia causes Asterisk to wait for incoming media in order to work out where to send outgoing media. If the peer is also doing the same, no medial will ever flow, and it might well time out and close the session.

If that is the case, you can’t remove comedia from Asterisk, as the peer is providing an unusable media address. You will have to address it on the device that is inside NAT.

nasirjavaid · May 13, 2017, 6:14pm

Thanks for providing lot of information… I have tried using nat=no and default nat value… with default nat value call is dropping same as before but the error message has change from “unknow error” to “normal clearing”

[May 14 02:09:11] — (10 headers 0 lines) —
[May 14 02:09:12] == Spawn extension (vtiger_inbound, 0060127822792, 1) exited non-zero on ‘SIP/5020-0000000e’
[May 14 02:09:12] Scheduling destruction of SIP dialog ‘NWJmMjUwZTExOTgwZTU3MmJkYTI0MWNiNDZmYTJiYTQ.’ in 21056 ms (Method: ACK)
[May 14 02:09:12] set_destination: Parsing sip:5020@192.168.8.100:52869;transport=UDP for address/port to send to
[May 14 02:09:12] set_destination: set destination to 192.168.8.100:52869
[May 14 02:09:12] Reliably Transmitting (NAT) to 103.255.4.85:5656:
[May 14 02:09:12] BYE sip:5020@192.168.8.100:52869;transport=UDP SIP/2.0
[May 14 02:09:12] Via: SIP/2.0/UDP 113.225.202.195:5261;branch=z9hG4bK02501038;rport
[May 14 02:09:12] Max-Forwards: 70
[May 14 02:09:12] From: sip:0060127822792@113.225.202.195:5261;transport=UDP;tag=as63c57f51
[May 14 02:09:12] To: "5020"sip:5020@113.225.202.195:5261;transport=UDP;tag=b95f4a4b
[May 14 02:09:12] Call-ID: NWJmMjUwZTExOTgwZTU3MmJkYTI0MWNiNDZmYTJiYTQ.
[May 14 02:09:12] CSeq: 102 BYE
[May 14 02:09:12] User-Agent: Asterisk PBX 11.13.1~dfsg-2+deb8u1
[May 14 02:09:12] X-Asterisk-HangupCause: Normal Clearing
[May 14 02:09:12] X-Asterisk-HangupCauseCode: 16
[May 14 02:09:12] Content-Length: 0
[May 14 02:09:12]

david551 · May 13, 2017, 8:38pm

No is not going to work as your peer is broken. You really need to work on the peer.

nasirjavaid · May 14, 2017, 5:47pm

From peer you mean the softphone side…right… Ok I will be checking and fixing it…
But the question is although I am facing one way audio with this peer when I connect to some other asterisk servers still call connection is fine but why call doesn’t even connect with this specific server?

Thanks.

david551 · May 14, 2017, 5:54pm

It does connect. One can only guess as to why the peer then disconnects, but my best guess is because it is seeing one way audio.

nasirjavaid · May 14, 2017, 6:14pm

Ok thanks for your prompt reply… let me try sending call through call file and land the called party to a voice prompt to see if my side is having issues…
I will report back once tested.

nasirjavaid · May 16, 2017, 1:01pm

Hi david,
I have tried sending call to the number using calls file and landing him in demo context. Call is sent and it seems its being answered immediately by the switch. Then dialplan executes and while demo-congrats plays for couple of seconds, BYE is received and call disconnect.

Please see the latest log below…

[May 16 20:53:42] – Attempting call on SIP/provider/0060127822792 for s@demo:1 (Retry 1)
[May 16 20:53:42] == Using SIP RTP CoS mark 5
[May 16 20:53:42] Audio is at 10648
[May 16 20:53:42] Adding codec 100003 (ulaw) to SDP
[May 16 20:53:42] Adding codec 100004 (alaw) to SDP
[May 16 20:53:42] Adding codec 100002 (gsm) to SDP
[May 16 20:53:42] Adding non-codec 0x1 (telephone-event) to SDP
[May 16 20:53:42] Reliably Transmitting (NAT) to 110.75.185.23:5060:
[May 16 20:53:42] INVITE sip:0060127822792@sip3.providervoip.com:5060 SIP/2.0
[May 16 20:53:42] Via: SIP/2.0/UDP 103.215.222.185:5261;branch=z9hG4bK637d4baf;rport
[May 16 20:53:42] Max-Forwards: 70
[May 16 20:53:42] From: “asterisk” sip:605605778@103.215.222.185:5261;tag=as773339b6
[May 16 20:53:42] To: sip:0060127822792@sip3.providervoip.com:5060
[May 16 20:53:42] Contact: sip:605605778@103.215.222.185:5261
[May 16 20:53:42] Call-ID: 041eb2785ecec39558c5600368368f24@103.215.222.185:5261
[May 16 20:53:42] CSeq: 102 INVITE
[May 16 20:53:42] User-Agent: Asterisk PBX 11.13.1~dfsg-2+deb8u1
[May 16 20:53:42] Date: Tue, 16 May 2017 12:53:42 GMT
[May 16 20:53:42] Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
[May 16 20:53:42] Supported: replaces, timer
[May 16 20:53:42] Content-Type: application/sdp
[May 16 20:53:42] Content-Length: 301
[May 16 20:53:42]
[May 16 20:53:42] v=0
[May 16 20:53:42] o=root 1791291458 1791291458 IN IP4 103.215.222.185
[May 16 20:53:42] s=Asterisk PBX 11.13.1~dfsg-2+deb8u1
[May 16 20:53:42] c=IN IP4 103.215.222.185
[May 16 20:53:42] t=0 0
[May 16 20:53:42] m=audio 10648 RTP/AVP 0 8 3 101
[May 16 20:53:42] a=rtpmap:0 PCMU/8000
[May 16 20:53:42] a=rtpmap:8 PCMA/8000
[May 16 20:53:42] a=rtpmap:3 GSM/8000
[May 16 20:53:42] a=rtpmap:101 telephone-event/8000
[May 16 20:53:42] a=fmtp:101 0-16
[May 16 20:53:42] a=ptime:20
[May 16 20:53:42] a=sendrecv
[May 16 20:53:42]
[May 16 20:53:42] —
[May 16 20:53:42]
[May 16 20:53:42] <— SIP read from UDP:110.75.185.23:5060 —>
[May 16 20:53:42] SIP/2.0 100 Giving a try
[May 16 20:53:42] Via: SIP/2.0/UDP 103.215.222.185:5261;received=103.215.222.185;branch=z9hG4bK637d4baf;rport=5261
[May 16 20:53:42] From: “asterisk” sip:605605778@103.215.222.185:5261;tag=as773339b6
[May 16 20:53:42] To: sip:0060127822792@sip3.providervoip.com:5060
[May 16 20:53:42] Call-ID: 041eb2785ecec39558c5600368368f24@103.215.222.185:5261
[May 16 20:53:42] CSeq: 102 INVITE
[May 16 20:53:42] Server: OpenSIPS (1.10.0beta-notls (x86_64/linux))
[May 16 20:53:42] Content-Length: 0
[May 16 20:53:42]
[May 16 20:53:42] <------------->
[May 16 20:53:42] — (8 headers 0 lines) —
[May 16 20:53:42]
[May 16 20:53:42] <— SIP read from UDP:110.75.185.23:5060 —>
[May 16 20:53:42] SIP/2.0 200 OK
[May 16 20:53:42] Via: SIP/2.0/UDP 103.215.222.185:5261;received=103.215.222.185;branch=z9hG4bK637d4baf;rport=5261
[May 16 20:53:42] Record-Route: sip:110.75.185.23;lr;ftag=as773339b6;did=dcc.29422d2
[May 16 20:53:42] From: “asterisk” sip:605605778@103.215.222.185:5261;tag=as773339b6
[May 16 20:53:42] To: sip:0060127822792@sip3.providervoip.com:5060;tag=as1643e4b0
[May 16 20:53:42] Call-ID: 041eb2785ecec39558c5600368368f24@103.215.222.185:5261
[May 16 20:53:42] CSeq: 102 INVITE
[May 16 20:53:42] User-Agent: SoftSwitch
[May 16 20:53:42] Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
[May 16 20:53:42] Supported: replaces
[May 16 20:53:42] Contact: sip:0060127822792@103.246.89.131
[May 16 20:53:42] Content-Type: application/sdp
[May 16 20:53:42] Content-Length: 267
[May 16 20:53:42]
[May 16 20:53:42] v=0
[May 16 20:53:42] o=root 31107 31107 IN IP4 103.246.89.131
[May 16 20:53:42] s=session
[May 16 20:53:42] c=IN IP4 103.246.89.131
[May 16 20:53:42] t=0 0
[May 16 20:53:42] m=audio 14886 RTP/AVP 0 3 101
[May 16 20:53:42] a=rtpmap:0 PCMU/8000
[May 16 20:53:42] a=rtpmap:3 GSM/8000
[May 16 20:53:42] a=rtpmap:101 telephone-event/8000
[May 16 20:53:42] a=fmtp:101 0-16
[May 16 20:53:42] a=silenceSupp:off - - - -
[May 16 20:53:42] a=ptime:20
[May 16 20:53:42] a=sendrecv
[May 16 20:53:42] <------------->
[May 16 20:53:42] — (13 headers 13 lines) —
[May 16 20:53:42] Found RTP audio format 0
[May 16 20:53:42] Found RTP audio format 3
[May 16 20:53:42] Found RTP audio format 101
[May 16 20:53:42] Found audio description format PCMU for ID 0
[May 16 20:53:42] Found audio description format GSM for ID 3
[May 16 20:53:42] Found audio description format telephone-event for ID 101
[May 16 20:53:42] Capabilities: us - (gsm|ulaw|alaw), peer - audio=(gsm|ulaw)/video=(nothing)/text=(nothing), combined - (gsm|ulaw)
[May 16 20:53:42] Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[May 16 20:53:42] Peer audio RTP is at port 103.246.89.131:14886
[May 16 20:53:42] list_route: hop: sip:110.75.185.23;lr;ftag=as773339b6;did=dcc.29422d2
[May 16 20:53:42] set_destination: Parsing sip:110.75.185.23;lr;ftag=as773339b6;did=dcc.29422d2 for address/port to send to
[May 16 20:53:42] set_destination: set destination to 110.75.185.23:5060
[May 16 20:53:42] Transmitting (NAT) to 110.75.185.23:5060:
[May 16 20:53:42] ACK sip:0060127822792@103.246.89.131 SIP/2.0
[May 16 20:53:42] Via: SIP/2.0/UDP 103.215.222.185:5261;branch=z9hG4bK1483bc5f;rport
[May 16 20:53:42] Route: sip:110.75.185.23;lr;ftag=as773339b6;did=dcc.29422d2
[May 16 20:53:42] Max-Forwards: 70
[May 16 20:53:42] From: “asterisk” sip:605605778@103.215.222.185:5261;tag=as773339b6
[May 16 20:53:42] To: sip:0060127822792@sip3.providervoip.com:5060;tag=as1643e4b0
[May 16 20:53:42] Contact: sip:605605778@103.215.222.185:5261
[May 16 20:53:42] Call-ID: 041eb2785ecec39558c5600368368f24@103.215.222.185:5261
[May 16 20:53:42] CSeq: 102 ACK
[May 16 20:53:42] User-Agent: Asterisk PBX 11.13.1~dfsg-2+deb8u1
[May 16 20:53:42] Content-Length: 0
[May 16 20:53:42]
[May 16 20:53:42]
[May 16 20:53:42] —
[May 16 20:53:42] – Executing [s@demo:1] Wait(“SIP/provider-00000021”, “1”) in new stack
[May 16 20:53:43] – Executing [s@demo:2] Answer(“SIP/provider-00000021”, “”) in new stack
[May 16 20:53:43] – Executing [s@demo:3] Set(“SIP/provider-00000021”, “TIMEOUT(digit)=5”) in new stack
[May 16 20:53:43] – Digit timeout set to 5.000
[May 16 20:53:43] – Executing [s@demo:4] Set(“SIP/provider-00000021”, “TIMEOUT(response)=10”) in new stack
[May 16 20:53:43] – Response timeout set to 10.000
[May 16 20:53:43] – Executing [s@demo:5] BackGround(“SIP/provider-00000021”, “demo-congrats”) in new stack
[May 16 20:53:43] – <SIP/provider-00000021> Playing ‘demo-congrats.gsm’ (language ‘en’)
[May 16 20:53:44]
[May 16 20:53:44] <— SIP read from UDP:175.140.228.39:56904 —>
[May 16 20:53:44]
[May 16 20:53:44]
[May 16 20:53:44] <------------->
[May 16 20:53:45]
[May 16 20:53:45] <— SIP read from UDP:110.75.185.23:5060 —>
[May 16 20:53:45] BYE sip:605605778@103.215.222.185:5261 SIP/2.0
[May 16 20:53:45] Via: SIP/2.0/UDP 110.75.185.23:5060;branch=z9hG4bKb9b.a4cd3f35.0
[May 16 20:53:45] Via: SIP/2.0/UDP 103.246.89.131:5060;received=103.246.89.131;branch=z9hG4bK6749e57f;rport=5060
[May 16 20:53:45] From: sip:0060127822792@sip3.providervoip.com:5060;tag=as1643e4b0
[May 16 20:53:45] To: “asterisk” sip:605605778@103.215.222.185:5261;tag=as773339b6
[May 16 20:53:45] Call-ID: 041eb2785ecec39558c5600368368f24@103.215.222.185:5261
[May 16 20:53:45] CSeq: 102 BYE
[May 16 20:53:45] User-Agent: SoftSwitch
[May 16 20:53:45] Max-Forwards: 69
[May 16 20:53:45] X-Asterisk-HangupCause: Unknown
[May 16 20:53:45] X-Asterisk-HangupCauseCode: 0
[May 16 20:53:45] Content-Length: 0
[May 16 20:53:45]
[May 16 20:53:45] <------------->
[May 16 20:53:45] — (12 headers 0 lines) —
[May 16 20:53:45] Sending to 110.75.185.23:5060 (NAT)
[May 16 20:53:45] Scheduling destruction of SIP dialog ‘041eb2785ecec39558c5600368368f24@103.215.222.185:5261’ in 6400 ms (Method: BYE)
[May 16 20:53:45]
[May 16 20:53:45] <— Transmitting (NAT) to 110.75.185.23:5060 —>
[May 16 20:53:45] SIP/2.0 200 OK
[May 16 20:53:45] Via: SIP/2.0/UDP 110.75.185.23:5060;branch=z9hG4bKb9b.a4cd3f35.0;received=110.75.185.23;rport=5060
[May 16 20:53:45] Via: SIP/2.0/UDP 103.246.89.131:5060;received=103.246.89.131;branch=z9hG4bK6749e57f;rport=5060
[May 16 20:53:45] From: sip:0060127822792@sip3.providervoip.com:5060;tag=as1643e4b0
[May 16 20:53:45] To: “asterisk” sip:605605778@103.215.222.185:5261;tag=as773339b6
[May 16 20:53:45] Call-ID: 041eb2785ecec39558c5600368368f24@103.215.222.185:5261
[May 16 20:53:45] CSeq: 102 BYE
[May 16 20:53:45] Server: Asterisk PBX 11.13.1~dfsg-2+deb8u1
[May 16 20:53:45] Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
[May 16 20:53:45] Supported: replaces, timer
[May 16 20:53:45] Content-Length: 0
[May 16 20:53:45]
[May 16 20:53:45]
[May 16 20:53:45] <------------>
[May 16 20:53:45] == Spawn extension (demo, s, 5) exited non-zero on ‘SIP/provider-00000021’
[May 16 20:53:45] NOTICE[21131]: pbx_spool.c:402 attempt_thread: Call completed to SIP/provider/0060127822792
Debian-81-64b*CLI>

Thanks.

jcolp · May 22, 2017, 12:47pm

From Asterisk there is nothing out of the ordinary, the call is fine. You’d need to investigate the other side.

Topic		Replies	Views
Asterisk terminating outbound call when picked up, sends 'BYE' message Asterisk SIP	6	1890	June 14, 2018
Asterisk sending BYE just after call is connected Asterisk Support	8	2997	December 18, 2014
Sending BYE after ACK Asterisk Support	9	1466	December 16, 2014
Outbound Calls - Remote End Inexplicably Hangs Up Asterisk Support	1	461	August 13, 2013
Why do I get an immediate BYE? Asterisk Support	0	260	August 4, 2010

BYE request received immediately after outbound call is connected

Related topics