[Home]

Summary:ASTERISK-06893: Asterisk sends CANCEL on INVITE before receiving any provisional response, thus not killing INVITE
Reporter:caspy (caspy)Labels:
Date Opened:2006-05-04 03:41:06Date Closed:2006-08-02 14:37:07
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Core/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) chan_sip.c.patch
Description:In some situations (when Asterisk works faster than ip-phone), Asterisk sends CANCEL request before receiving any provisional response on previously sended INVITE. Thus this INVITE stays uncancelled, and phone continues to ring.

According to RFC3261, section 9.1:
If no provisional response has been received, the CANCEL request MUST
NOT be sent; rather, the client MUST wait for the arrival of a
provisional response before sending the request.


****** ADDITIONAL INFORMATION ******

sip debug for this situation:

Reliably Transmitting (NAT) to 10.15.4.254:5060:
INVITE sip:1125@10.15.4.254:5060 SIP/2.0
Via: SIP/2.0/UDP 10.15.1.2:5060;branch=z9hG4bK0b1a5786;rport
From: "number" <sip:number@masterhost.ru>;tag=as37a4f9e6
To: <sip:1125@10.15.4.254:5060>
Contact: <sip:number@10.15.1.2>
Call-ID: 3b03abd97d2f4ced4e45353b2e9ae6e6@masterhost.ru
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Thu, 04 May 2006 07:17:10 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Type: application/sdp
Content-Length: 305

v=0
o=root 2580 2580 IN IP4 10.15.1.2
s=session
c=IN IP4 10.15.1.2
t=0 0
m=audio 11198 RTP/AVP 0 8 3 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
m=video 15364 RTP/AVP 34
a=rtpmap:34 H263/90000

---
Reliably Transmitting (NAT) to 10.15.4.254:5060:
CANCEL sip:1125@10.15.4.254:5060 SIP/2.0
Via: SIP/2.0/UDP 10.15.1.2:5060;branch=z9hG4bK0b1a5786;rport
From: "number" <sip:number@masterhost.ru>;tag=as37a4f9e6
To: <sip:1125@10.15.4.254:5060>
Contact: <sip:number@10.15.1.2>
Call-ID: 3b03abd97d2f4ced4e45353b2e9ae6e6@masterhost.ru
CSeq: 102 CANCEL
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0


---
Scheduling destruction of call '3b03abd97d2f4ced4e45353b2e9ae6e6@masterhost.ru' in 32000 ms

<-- SIP read from 10.15.4.254:5060:
SIP/2.0 100 Trying
Call-ID: 3b03abd97d2f4ced4e45353b2e9ae6e6@masterhost.ru
CSeq: 102 INVITE
From: "number" <sip:number@masterhost.ru>;tag=as37a4f9e6
To: <sip:1125@10.15.4.254:5060>;tag=a1f1f42becbcc5d
Via: SIP/2.0/UDP 10.15.1.2:5060;branch=z9hG4bK0b1a5786;rport
Content-Length: 0
User-Agent: Avaya SIP R2.2 Endpoint Brcm Callctrl/1.5.1.0 MxSF/v3.2.6.26


--- (8 headers 0 lines)---

<-- SIP read from 10.15.4.254:5060:
SIP/2.0 481 Call Does Not Exist
Call-ID: 3b03abd97d2f4ced4e45353b2e9ae6e6@masterhost.ru
CSeq: 102 CANCEL
From: "number" <sip:number@masterhost.ru>;tag=as37a4f9e6
To: <sip:1125@10.15.4.254:5060>;tag=87e4b12f6eaa301
Via: SIP/2.0/UDP 10.15.1.2:5060;branch=z9hG4bK0b1a5786;rport
Content-Length: 0
User-Agent: Avaya SIP R2.2 Endpoint Brcm Callctrl/1.5.1.0 MxSF/v3.2.6.26


--- (8 headers 0 lines)---
Destroying call '3b03abd97d2f4ced4e45353b2e9ae6e6@masterhost.ru'
<-- SIP read from 10.15.4.254:5060:
SIP/2.0 180 Ringing
Call-ID: 3b03abd97d2f4ced4e45353b2e9ae6e6@masterhost.ru
CSeq: 102 INVITE
From: "number" <sip:number@masterhost.ru>;tag=as37a4f9e6
To: <sip:1125@10.15.4.254:5060>;tag=a1f1f42becbcc5d
Via: SIP/2.0/UDP 10.15.1.2:5060;branch=z9hG4bK0b1a5786;rport
Content-Length: 0
Contact: <sip:1125@10.15.4.254:5060>
User-Agent: Avaya SIP R2.2 Endpoint Brcm Callctrl/1.5.1.0 MxSF/v3.2.6.26


--- (9 headers 0 lines)---
Comments:By: Serge Vecher (serge-v) 2006-05-04 08:31:20

caspy: do you have a way of reproducing this or does it happen due to a combination of certain factors?
By: caspy (caspy) 2006-05-04 08:36:30

vechers, it happens due to a combination of factors. i have no idea, how to reproduce it manually. but it happens several times a day, independently of current load.
By: Serge Vecher (serge-v) 2006-05-10 15:31:11

ok, well we need to narrow it down somehow. Can you please describe your network environment? Are the phones that exibit this behavior on a separate wan than Asterisk?
By: caspy (caspy) 2006-05-11 00:55:49

This all happens on plain L2 network with QoS.
Asterisk works on server, which connected with 100Mb trunk port to all needed vlans. Vlan with 10.15/16 network is one of them. All ip-phones in that vlan.
All signalling and voice packets from Asterisk marked down with corresponding DSCP values, and all ports on network use 'trust dscp' for queue processing.
There are no any lags or troubles on network.

Really, i don't know exactly, why Asterisk cancels call so early. But, may be it is because caller drops the line at the same time, for example?
By: Olle Johansson (oej) 2006-05-11 02:04:36

Regardless, we need to follow protocol. I think we have all information we need.
By: Kevin P. Fleming (kpfleming) 2006-05-24 15:37:51

Fixed in branch-1.2 revision 30069 and trunk revision 30070.
By: Jason Parker (jparker) 2006-06-15 23:21:34

Reopening, by request of marvy in #asterisk-bugs
By: marvy (marvy) 2006-06-15 23:33:39

I have 2 problems with the rev 30070 fix:

1. If the call is passing through a proxy server, the proxy will send back a "100 Trying". This patch takes this to be a response from the phone and will allow asterisk to send a CANCEL if required. This could still arrive at the phone before the actual phone had sent a response. Fix is obvious.

2. This patch breaks the use of canreinvite=yes. As reinvites are handled by the same check_pendings() call, if there is no CANCEL pending but a REINVITE is pending when a response is received then asterisk can and does send a new REINVITE before the old one is ACKed. This causes many phones to drop the call rather then send a "491 request pending". In the attached file is a patch which separates the check_pending for cancel's and reinvites so they are done correctly (IMHO).
By: mikma (mikma) 2006-06-18 10:17:02

1. I think it's a bug in your proxy server and not in Asterisk if the proxy sends a CANCEL request before it has received a provisional response for the call it's canceling. The SIP UAC (Asterisk in this case) can't know for sure if the SIP UAS has sent a 100 response, since it isn't forwarded by proxies.
By: Heiko Kopp (hkopp) 2006-06-20 09:35:26

While a call is hung up in canreinvite=yes mode, asterisk sends a re-INVITE to the client that did not hung up. This client sends an OK on this. Asterisk sends a cancel on this instead of a BYE, so the client responds with a "400 Bad Request" (You are not allowed to cancel an established dialog). The result is that the client which did not hung up does not know about ended dialog.

In chan_sip.c in method handle_response_invite() we found out, that this happens, as in the described process neither a TRYING (100) nor RINGING (180) is sent, but only these two set the SIP_CAN_BYE flag. By adding a

ast_set_flag(p, SIP_CAN_BYE)

at the and of the OK (200) case after line 9743 (check_pendings(p)) we achieved the old and IMHO correct behaviour. Please check wether this is the correct solution or something else has to be corrected.
By: Terry Wilson (twilson) 2006-08-01 22:20:29

Setting SIP_CAN_BYE just because we get a 100 response is very wrong.  If there is a SIP proxy involved you may always get a 100.  Then what happens if you get a 404 response from an upstream proxy?  Asterisk sends an ACK to the 404 that gets relayed... and then a BYE (I know this because it is happening to me right now).  You can't send a BYE until a dialog has been established (section 15.1 of RFC) which certainly doesn't happen because of a 100.  Shouldn't we check to see that there is a dialog established (i.e. a call-id, to-tag, and from-tag) before we send a BYE?
By: Kevin P. Fleming (kpfleming) 2006-08-02 14:37:05

OK, I believe this is fixed properly in branch 1.2 revision 38731 and trunk revision 38732.

Obviously, the logic I added before was faulty. Now, it behaves this way:

1) receipt of a 100 response changes nothing
2) receipt of a 1xx (but not 100) response sets the SIP_CAN_BYE flag, since all 1xx (but not 100) responses must include a To-tag, and therefore cause the establishment of a dialog; this flag is now set _before_ calling check_pendings, since there is no reason to do it later as the peer's dialog state has already changed
3) receipt of a 200 response sets the SIP_CAN_BYE flag, as it should have before

As far as the changes to check_pending splitting BYE and re-invite checks, that will have to be handled as a separate bug, since the original changes for this bug did not combine them together (they were already that way).

Thanks everyone for your input and for making me re-read the RFC and pay more attention :-)