Sending BYE after ACK

kiim11 · July 3, 2014, 12:12pm

Asterisk sending BYE immediately after ACK for outgoing calls. I have no idea why that’s happening. Thanks in advance for help.

[code]INVITE sip:74852427787@10.226.20.130:5060 SIP/2.0
Via: SIP/2.0/UDP 172.16.120.5:5060;branch=z9hG4bK5901040c
Max-Forwards: 70
From: “666” sip:kis_97097@10.226.20.130;tag=as33683613
To: sip:74852427787@10.226.20.130:5060
Contact: sip:kis_97097@172.16.120.5:5060
Call-ID: 639064976734c25964559dd06d36cd5e@10.226.20.130
CSeq: 103 INVITE
User-Agent: Asterisk PBX 1.8.5.0
Proxy-Authorization: Digest username=“kis_97097”, realm=“Huawei”, algorithm=MD5, uri=“sip:74852427787@10.226.20.130:5060”, nonce=“15:53:58:41660”, response="6e8528661cd998ce9cc5c21a16e0a0f3"
Date: Thu, 03 Jul 2014 11:53:58 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 333

v=0
o=root 1043371746 1043371747 IN IP4 172.16.120.5
s=Asterisk PBX 1.8.5.0
c=IN IP4 172.16.120.5
t=0 0
m=audio 39580 RTP/AVP 8 18 3 101
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmt
<— SIP read from UDP:10.226.20.130:5060 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 172.16.120.5:5060;branch=z9hG4bK5901040c
Call-ID: 639064976734c25964559dd06d36cd5e@10.226.20.130
From: "666"sip:kis_97097@10.226.20.130;tag=as33683613
To: sip:74852427787@10.226.20.130:5060
CSeq: 103 INVITE
Content-Length: 0

<------------->
— (7 headers 0 lines) —

<— SIP read from UDP:10.226.20.130:5060 —>
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 172.16.120.5:5060;branch=z9hG4bK5901040c
Call-ID: 639064976734c25964559dd06d36cd5e@10.226.20.130
From: "666"sip:kis_97097@10.226.20.130;tag=as33683613
To: sip:74852427787@10.226.20.130:5060;tag=032d0960
CSeq: 103 INVITE
Contact: sip:74852427787@10.226.20.130:5061;user=phone
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,REGISTER,INFO,PRACK,SUBSCRIBE,NOTIFY,UPDATE,MESSAGE,REFER
Content-Length: 215
Content-Type: application/sdp

v=0
o=HuaweiSoftX3000 120673 120673 IN IP4 10.226.20.130
s=Sip Call
c=IN IP4 0.0.0.0
t=0 0
m=audio 0 RTP/AVP 8
a=rtpmap:8 PCMA/8000
a=ptime:20
a=silenceSupp:off - - - -
a=ecan:fb on -
a=X-fax
a=inactive
<------------->
— (10 headers 12 lines) —
– SIP/AsteriskSIPProvider1-00000013 is ringing
– SIP/AsteriskSIPProvider1-00000013 is making progress passing it to SIP/666-00000012
– Remote UNIX connection
– Remote UNIX connection disconnected

<— SIP read from UDP:10.226.20.130:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.16.120.5:5060;branch=z9hG4bK5901040c
Call-ID: 639064976734c25964559dd06d36cd5e@10.226.20.130
From: "666"sip:kis_97097@10.226.20.130;tag=as33683613
To: sip:74852427787@10.226.20.130:5060;tag=032d0960
CSeq: 103 INVITE
Contact: sip:74852427787@10.226.20.130:5061;user=phone
Content-Length: 215
Content-Type: application/sdp

v=0
o=HuaweiSoftX3000 120673 120674 IN IP4 10.226.20.130
s=Sip Call
c=IN IP4 0.0.0.0
t=0 0
m=audio 0 RTP/AVP 8
a=rtpmap:8 PCMA/8000
a=ptime:20
a=silenceSupp:off - - - -
a=ecan:fb on -
a=X-fax
a=inactive
<------------->
— (9 headers 12 lines) —
list_route: hop: sip:74852427787@10.226.20.130:5061;user=phone
set_destination: Parsing sip:74852427787@10.226.20.130:5061;user=phone for address/port to send to
set_destination: set destination to 10.226.20.130:5061
Transmitting (no NAT) to 10.226.20.130:5061:
ACK sip:74852427787@10.226.20.130:5061;user=phone SIP/2.0
Via: SIP/2.0/UDP 172.16.120.5:5060;branch=z9hG4bK4eb23c92
Max-Forwards: 70
From: “666” sip:kis_97097@10.226.20.130;tag=as33683613
To: sip:74852427787@10.226.20.130:5060;tag=032d0960
Contact: sip:kis_97097@172.16.120.5:5060
Call-ID: 639064976734c25964559dd06d36cd5e@10.226.20.130
CSeq: 103 ACK
User-Agent: Asterisk PBX 1.8.5.0
Content-Length: 0

set_destination: Parsing sip:74852427787@10.226.20.130:5061;user=phone for address/port to send to
set_destination: set destination to 10.226.20.130:5061
Reliably Transmitting (no NAT) to 10.226.20.130:5061:
BYE sip:74852427787@10.226.20.130:5061;user=phone SIP/2.0
Via: SIP/2.0/UDP 172.16.120.5:5060;branch=z9hG4bK6c446beb
Max-Forwards: 70
From: “666” sip:kis_97097@10.226.20.130;tag=as33683613
To: sip:74852427787@10.226.20.130:5060;tag=032d0960
Call-ID: 639064976734c25964559dd06d36cd5e@10.226.20.130
CSeq: 104 BYE
User-Agent: Asterisk PBX 1.8.5.0
Proxy-Authorization: Digest username=“kis_97097”, realm=“Huawei”, algorithm=MD5, uri=“sip:74852427787@10.226.20.130:5061”, nonce=“15:53:58:41660”, response="5f794d8a5426faff7085de25ab6361d0"
X-Asterisk-HangupCause: Unknown
X-Asterisk-HangupCauseCode: 0
Content-Length: 0

Scheduling destruction of SIP dialog ‘639064976734c25964559dd06d36cd5e@10.226.20.130’ in 32000 ms (Method: INVITE)
– SIP/AsteriskSIPProvider1-00000013 answered SIP/666-00000012
– Executing [s@macro-remember-the-transf:1] Set(“SIP/AsteriskSIPProvider1-00000013”, “__transf=AsteriskSIPProvider1”) in new stack
Scheduling destruction of SIP dialog ‘639064976734c25964559dd06d36cd5e@10.226.20.130’ in 32000 ms (Method: INVITE)
set_destination: Parsing sip:74852427787@10.226.20.130:5061;user=phone for address/port to send to
set_destination: set destination to 10.226.20.130:5061
Reliably Transmitting (no NAT) to 10.226.20.130:5061:
BYE sip:74852427787@10.226.20.130:5061;user=phone SIP/2.0
Via: SIP/2.0/UDP 172.16.120.5:5060;branch=z9hG4bK3bb3d478
Max-Forwards: 70
From: “666” sip:kis_97097@10.226.20.130;tag=as33683613
To: sip:74852427787@10.226.20.130:5060;tag=032d0960
Call-ID: 639064976734c25964559dd06d36cd5e@10.226.20.130
CSeq: 105 BYE
User-Agent: Asterisk PBX 1.8.5.0
Proxy-Authorization: Digest username=“kis_97097”, realm=“Huawei”, algorithm=MD5, uri=“sip:74852427787@10.226.20.130:5061”, nonce=“15:53:58:41660”, response="5f794d8a5426faff7085de25ab6361d0"
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0

-- Executing [s@macro-AsteriskSIPProvider1:3] Goto("SIP/666-00000012", "s-ANSWER,1") in new stack
-- Goto (macro-AsteriskSIPProvider1,s-ANSWER,1)
-- Executing [s-ANSWER@macro-AsteriskSIPProvider1:1] Hangup("SIP/666-00000012", "") in new stack

== Spawn extension (macro-AsteriskSIPProvider1, s-ANSWER, 1) exited non-zero on ‘SIP/666-00000012’ in macro ‘AsteriskSIPProvider1’
== Spawn extension (macro-Context2, s, 6) exited non-zero on ‘SIP/666-00000012’ in macro ‘Context2’
== Spawn extension (internal, 974852427787, 10) exited non-zero on ‘SIP/666-00000012’
– Executing [h@internal:1] NoOp(“SIP/666-00000012”, “”) in new stack
– Executing [h@internal:2] GotoIf(“SIP/666-00000012”, “0?:hang”) in new stack
– Goto (internal,h,6)
– Executing [h@internal:6] Hangup(“SIP/666-00000012”, “”) in new stack
== Spawn extension (internal, h, 6) exited non-zero on ‘SIP/666-00000012’

<— SIP read from UDP:10.226.20.130:5061 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.16.120.5:5060;branch=z9hG4bK6c446beb
Call-ID: 639064976734c25964559dd06d36cd5e@10.226.20.130
From: "666"sip:kis_97097@10.226.20.130;tag=as33683613
To: sip:74852427787@10.226.20.130:5060;tag=032d0960
CSeq: 104 BYE
Content-Length: 0

<------------->
— (7 headers 0 lines) —

<— SIP read from UDP:10.226.20.130:5061 —>
SIP/2.0 481 Call/Transaction Does Not Exist
Via: SIP/2.0/UDP 172.16.120.5:5060;branch=z9hG4bK3bb3d478
Call-ID: 639064976734c25964559dd06d36cd5e@10.226.20.130
From: "666"sip:kis_97097@10.226.20.130;tag=as33683613
To: sip:74852427787@10.226.20.130:5060;tag=032d0960
CSeq: 105 BYE
Warning: 399 10.226.20.130 "ToTag present"
Content-Length: 0

<------------->
— (8 headers 0 lines) —
Really destroying SIP dialog ‘639064976734c25964559dd06d36cd5e@10.226.20.130’ Method: INVITE[/code]

david55 · July 3, 2014, 12:31pm

The HuaWei has opened the call on full hold, which is not very friendly, although I didn’t think it was enough to justify aborting the call.

The normal reason for an immediate BYE is that the remote side has offered incompatible codecs. You haven’t got a high enough debugging level to see its analysis of the codecs.

However, looking further, it looks like it wasn’t dropped immediately, there has been an attempt to run a macro or a subroutine with a name that sounds like a macro. Unfortunately, you haven’t logged the part of the dialplan that specifies running that. Maybe that macro/subroutine didn’t return the right information to allow the call to proceed.

kiim11 · July 3, 2014, 12:55pm

This macro called from Dial application

[code]exten => s,n,Dial(SIP/${ARG1}@AsteriskSIPProvider1,90,${DIALOPT}M(remember-the-transf))

[macro-remember-the-transf]
exten => s,1,Set(__transf=${CHANNEL(peername)})
[/code]

I tested without Macro call - same result

Looks like codecs are OK, both sides negotiated for a=rtpmap:8 PCMA/8000 and plus incoming calls passes well

What kind of debug level do you need? i probably can provide it.

Timestamps of first ACK and BYE are 5.3549150 and 5.3563880

david55 · July 3, 2014, 1:39pm

Normally verbose 5, debug 5, debug log enabled (uncomment full in logger.conf).

kiim11 · July 3, 2014, 2:09pm

So i found

[Jul 3 17:59:32] WARNING[42992] chan_sip.c: Unsupported SDP media type in offer: audio 0 RTP/AVP 8 [Jul 3 17:59:32] WARNING[42992] chan_sip.c: Failing due to no acceptable offer found

I suppose issue is here.

Here’s full code

[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:  Header  0 [ 14]: SIP/2.0 200 OK
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:  Header  1 [ 57]: Via: SIP/2.0/UDP 172.16.120.5:5060;branch=z9hG4bK77693e83
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:  Header  2 [ 55]: Call-ID: 3e3d16554b1e94f23bdd3a85629ba294@10.226.20.130
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:  Header  3 [ 55]: From: "666"<sip:kis_97097@10.226.20.130>;tag=as684e70c0
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:  Header  4 [ 53]: To: <sip:74852427787@10.226.20.130:5060>;tag=98f26093
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:  Header  5 [ 16]: CSeq: 103 INVITE
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:  Header  6 [ 56]: Contact: <sip:74852427787@10.226.20.130:5062;user=phone>
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:  Header  7 [ 19]: Content-Length: 215
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:  Header  8 [ 29]: Content-Type: application/sdp
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:  Header  9 [  0]:
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:    Body  0 [  3]: v=0
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:    Body  1 [ 52]: o=HuaweiSoftX3000 120126 120127 IN IP4 10.226.20.130
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:    Body  2 [ 10]: s=Sip Call
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:    Body  3 [ 16]: c=IN IP4 0.0.0.0
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:    Body  4 [  5]: t=0 0
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:    Body  5 [ 19]: m=audio 0 RTP/AVP 8
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:    Body  6 [ 20]: a=rtpmap:8 PCMA/8000
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:    Body  7 [ 10]: a=ptime:20
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:    Body  8 [ 25]: a=silenceSupp:off - - - -
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:    Body  9 [ 14]: a=ecan:fb on -
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:    Body 10 [  7]: a=X-fax
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:    Body 11 [ 10]: a=inactive
[Jul  3 17:59:32] VERBOSE[42992] chan_sip.c: --- (9 headers 12 lines) ---
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c: = Looking for  Call ID: 3e3d16554b1e94f23bdd3a85629ba294@10.226.20.130 (Checking To) --From tag as684e70c0 --To-tag 98f26093
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c: Acked pending invite 103
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c: Stopping retransmission on '3e3d16554b1e94f23bdd3a85629ba294@10.226.20.130' of Request 103: Match Found
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c: SIP response 200 to standard invite
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED.
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c: Processing session-level SDP o=HuaweiSoftX3000 120126 120127 IN IP4 10.226.20.130... UNSUPPORTED.
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c: Processing session-level SDP s=Sip Call... UNSUPPORTED.
[Jul  3 17:59:32] DEBUG[42992] netsock2.c: Splitting '0.0.0.0' into...
[Jul  3 17:59:32] DEBUG[42992] netsock2.c: ...host '0.0.0.0' and port ''.
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c: Processing session-level SDP c=IN IP4 0.0.0.0... OK.
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED.
[Jul  3 17:59:32] WARNING[42992] chan_sip.c: Unsupported SDP media type in offer: audio 0 RTP/AVP 8
[Jul  3 17:59:32] WARNING[42992] chan_sip.c: Failing due to no acceptable offer found
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c: Updating call counter for outgoing call
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c: build_route: Contact hop: <sip:74852427787@10.226.20.130:5062;user=phone>
[Jul  3 17:59:32] VERBOSE[42992] chan_sip.c: list_route: hop: <sip:74852427787@10.226.20.130:5062;user=phone>
[Jul  3 17:59:32] DEBUG[42992] netsock2.c: Splitting '10.226.20.130:5062' into...
[Jul  3 17:59:32] DEBUG[42992] netsock2.c: ...host '10.226.20.130' and port '5062'.
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c: Strict routing enforced for session 3e3d16554b1e94f23bdd3a85629ba294@10.226.20.130
[Jul  3 17:59:32] VERBOSE[42992] chan_sip.c: set_destination: Parsing <sip:74852427787@10.226.20.130:5062;user=phone> for address/port to send to
[Jul  3 17:59:32] DEBUG[42992] netsock2.c: Splitting '10.226.20.130:5062' into...
[Jul  3 17:59:32] DEBUG[42992] netsock2.c: ...host '10.226.20.130' and port '5062'.
[Jul  3 17:59:32] VERBOSE[42992] chan_sip.c: set_destination: set destination to 10.226.20.130:5062
[Jul  3 17:59:32] VERBOSE[42992] chan_sip.c: Transmitting (no NAT) to 10.226.20.130:5062:
ACK sip:74852427787@10.226.20.130:5062;user=phone SIP/2.0^M
Via: SIP/2.0/UDP 172.16.120.5:5060;branch=z9hG4bK6df6ca1d^M
Max-Forwards: 70^M
From: "666" <sip:kis_97097@10.226.20.130>;tag=as684e70c0^M
To: <sip:74852427787@10.226.20.130:5060>;tag=98f26093^M
Contact: <sip:kis_97097@172.16.120.5:5060>^M
Call-ID: 3e3d16554b1e94f23bdd3a85629ba294@10.226.20.130^M

CSeq: 103 ACK^M
User-Agent: Asterisk PBX 1.8.5.0^M
Content-Length: 0^M
^M

---
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c: Trying to put 'ACK sip:748' onto UDP socket destined for 10.226.20.130:5062
[Jul  3 17:59:32] DEBUG[42992] channel.c: Soft-Hanging up channel 'SIP/AsteriskSIPProvider1-00000027'
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c: Strict routing enforced for session 3e3d16554b1e94f23bdd3a85629ba294@10.226.20.130
[Jul  3 17:59:32] VERBOSE[42992] chan_sip.c: set_destination: Parsing <sip:74852427787@10.226.20.130:5062;user=phone> for address/port to send to
[Jul  3 17:59:32] DEBUG[42992] netsock2.c: Splitting '10.226.20.130:5062' into...
[Jul  3 17:59:32] DEBUG[42992] netsock2.c: ...host '10.226.20.130' and port '5062'.
[Jul  3 17:59:32] VERBOSE[42992] chan_sip.c: set_destination: set destination to 10.226.20.130:5062
[Jul  3 17:59:32] VERBOSE[42992] chan_sip.c: Reliably Transmitting (no NAT) to 10.226.20.130:5062:
BYE sip:74852427787@10.226.20.130:5062;user=phone SIP/2.0^M
Via: SIP/2.0/UDP 172.16.120.5:5060;branch=z9hG4bK5f096940^M
Max-Forwards: 70^M
From: "666" <sip:kis_97097@10.226.20.130>;tag=as684e70c0^M
To: <sip:74852427787@10.226.20.130:5060>;tag=98f26093^M
Call-ID: 3e3d16554b1e94f23bdd3a85629ba294@10.226.20.130^M
CSeq: 104 BYE^M
User-Agent: Asterisk PBX 1.8.5.0^M
Proxy-Authorization: Digest username="kis_97097", realm="Huawei", algorithm=MD5, uri="sip:74852427787@10.226.20.130:5062", nonce="17:59:24:41693", response="7b7a8b5e5ea
X-Asterisk-HangupCause: Unknown^M
X-Asterisk-HangupCauseCode: 0^M
Content-Length: 0^M
^M

---
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id  #2226
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c: Trying to put 'BYE sip:748' onto UDP socket destined for 10.226.20.130:5062
[Jul  3 17:59:32] VERBOSE[42992] chan_sip.c: Scheduling destruction of SIP dialog '3e3d16554b1e94f23bdd3a85629ba294@10.226.20.130' in 32000 ms (Method: INVITE)
[Jul  3 17:59:32] DEBUG[42992] devicestate.c: No provider found, checking channel drivers for SIP - AsteriskSIPProvider1
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c: Checking device state for peer AsteriskSIPProvider1
[Jul  3 17:59:32] DEBUG[42992] devicestate.c: Changing state for SIP/AsteriskSIPProvider1 - state 2 (In use)
[Jul  3 17:59:32] DEBUG[42992] devicestate.c: device 'SIP/AsteriskSIPProvider1' state '2'
[Jul  3 17:59:32] DEBUG[42992] devicestate.c: Changing state for SIP/AsteriskSIPProvider1 - state 2 (In use)
[Jul  3 17:59:32] DEBUG[42992] devicestate.c: device 'SIP/AsteriskSIPProvider1' state '2'
[Jul  3 17:59:32] VERBOSE[42992] app_dial.c:     -- SIP/AsteriskSIPProvider1-00000027 answered SIP/666-00000026
[Jul  3 17:59:32] DEBUG[42992] pbx.c: Function result is 'AsteriskSIPProvider1'
[Jul  3 17:59:32] DEBUG[42992] pbx.c: Launching 'Set'
[Jul  3 17:59:32] VERBOSE[42992] pbx.c:     -- Executing [s@macro-remember-the-transf:1] Set("SIP/AsteriskSIPProvider1-00000027", "__transf=AsteriskSIPProvider1") in ne
[Jul  3 17:59:32] DEBUG[42992] app_macro.c: Executed application: Set
[Jul  3 17:59:32] DEBUG[42992] app_macro.c: Extension s, macroexten s, priority 1 returned normally even though call was hung up
[Jul  3 17:59:32] DEBUG[42992] app_dial.c: Macro exited with status 0
[Jul  3 17:59:32] DEBUG[42992] devicestate.c: No provider found, checking channel drivers for SIP - AsteriskSIPProvider1
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c: Checking device state for peer AsteriskSIPProvider1
[Jul  3 17:59:32] DEBUG[42992] devicestate.c: Changing state for SIP/AsteriskSIPProvider1 - state 2 (In use)
[Jul  3 17:59:32] DEBUG[42992] devicestate.c: device 'SIP/AsteriskSIPProvider1' state '2'
[Jul  3 17:59:32] DEBUG[42992] app_queue.c: Device 'SIP/AsteriskSIPProvider1' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Jul  3 17:59:32] DEBUG[42992] app_queue.c: Device 'SIP/AsteriskSIPProvider1' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Jul  3 17:59:32] VERBOSE[42992] chan_sip.c:
<--- SIP read from UDP:10.226.20.130:5062 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.16.120.5:5060;branch=z9hG4bK5f096940
Call-ID: 3e3d16554b1e94f23bdd3a85629ba294@10.226.20.130
From: "666"<sip:kis_97097@10.226.20.130>;tag=as684e70c0
To: <sip:74852427787@10.226.20.130:5060>;tag=98f26093
CSeq: 104 BYE
Content-Length: 0

<------------->
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:  Header  0 [ 14]: SIP/2.0 200 OK
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:  Header  1 [ 57]: Via: SIP/2.0/UDP 172.16.120.5:5060;branch=z9hG4bK5f096940
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:  Header  2 [ 55]: Call-ID: 3e3d16554b1e94f23bdd3a85629ba294@10.226.20.130
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:  Header  3 [ 55]: From: "666"<sip:kis_97097@10.226.20.130>;tag=as684e70c0
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:  Header  4 [ 53]: To: <sip:74852427787@10.226.20.130:5060>;tag=98f26093
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:  Header  5 [ 13]: CSeq: 104 BYE
[Jul  3 17:59:32] DEBUG[42992] chan_sip.c:  Header  6 [ 17]: Content-Length: 0

david55 · July 3, 2014, 2:23pm

It failed to match:

(sscanf(m, “audio %d RTP/AVP %n”, &x, &len) == 1 && len > 0))

I can’t see why, but maybe there are some characters there that aren’t what they look like. I suppose it could have been modified, recently, such that it fails to match 0 as the port number.

kiim11 · July 4, 2014, 8:55am

Thanks a lot for help.

I checked sources and discovered that there are additional condition

So it fails. I updated asterisk, now working fine.

Thanks again

david55 · July 4, 2014, 9:22am

That would probably justify a regression failure bug report. If they are going to check the port number, they should probably make an exception if the IP address is 0.0.0.0 (the old way of indicating a hold).

saleh50 · December 16, 2014, 12:05am

kim11- I have exactly the same problem. The call gets disconnected just after it is connected, sending a CSeq: 103 BYE. It was working okay for the last six months. I believe, something changed in the provider end, now I’m having this problem. I am running on asterisk 1.8.9.0.
What was your original asterisk release and which new one you switched to?

david55 · December 16, 2014, 11:01am

If you are having exactly the same problem, the provider has started using software which uses an obsolete SIP feature when they were previously using more current software. That sound unlikely. However, if that is the case, I imagine the situation hasn’t changed, as I don’t think the reporter raised a bug report.

If it is not really the same, or you haven’t gathered enough information to determine one way or the other, you should start a new question with all the relevant information.

Topic		Replies	Views
Why do I get an immediate BYE? Asterisk Support	0	260	August 4, 2010
Asterisk sending BYE just after call is connected Asterisk Support	8	2997	December 18, 2014
Strange asterisk behaviour? Asterisk Support	1	182	July 11, 2007
BYE request received immediately after outbound call is connected Asterisk Support	16	3624	May 22, 2017
Asterisk 13.7.2 pjsip 2.4.5 unexpected BYE with SIP cause 58 while answering Asterisk Support	1	2314	March 21, 2016

Sending BYE after ACK

Related topics