[Home]

Summary:ASTERISK-13025: problem handling race condition - reINVITE before ACK
Reporter:klaus3000 (klaus3000)Labels:
Date Opened:2008-11-06 11:35:05.000-0600Date Closed:2009-05-20 09:08:17
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Channels/chan_sip/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) 13849_v2.patch
( 1) 13849.patch
Description:Hi!

Asterisk has problems handling incoming reINVITE if the ACK of the incoming INVITE is still missing. Although this a pssobile scenario, e.g:

client   proxy     Asterisk
 --INV--->
          ----INV----->
          <---200 ok---
 <-200 ok-
 --ACK--->
 -reINV-->
           --reINV----->
           --ACK------->

This is a scearion which can really happen, e.g. as the processing of the ACK in the proxy may takes more time. It can also happen without proxy (an packet can overtake another packet).

The problem is:
1. Asterisk does not accept the reINVITE but sends 491 request pending
Sending 491 is only allowed if the request is in a pending state. But as the request is finished (200 is already sent) there can not be 491. The proper solution would be to accept the reINVITE - as this reINVITE is an implicit ACK to the previous INVITE. Receiving the reINVITE means, that the caller has received the 200 ok.

2. Asterisk does not accept the ACK to the 491, it goes on resending the 491.

3. My client then tries to reINVITE again, which is accepted by Asterisk. But then, if the call is hang up from the other side (in this case DHADI), Asterisk does not send BYE

It happends with pedantic= yes and no.

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

<--- SIP read from UDP:83.136.32.160:5060 --->
INVITE sip:fax936@83.136.32.165 SIP/2.0
Record-Route: <sip:83.136.32.160;ftag=603ced2b;lr=on>
Via: SIP/2.0/UDP 83.136.32.160;branch=z9hG4bK96c5.60670ed2.0
Via: SIP/2.0/UDP 83.136.33.3:5060;branch=z9hG4bK-d8754z-8e1b6a42665411d0-1---d8754z-;rport=1145
Max-Forwards: 69
Contact: <sip:klaus.darilion@83.136.33.3:5060>
To: <sip:078081120024@nic.at43.at>;transport=UDP
From: <sip:klaus.darilion@nic.at43.at>;transport=UDP;tag=603ced2b
Call-ID: NGZjODM5YjJhMWZiNGMzMDZiNzczYjJkM2Y1YWU0N2I.
CSeq: 2 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO
Content-Type: application/sdp
User-Agent: Zoiper for Windows rev.1811
Content-Length: 323

v=0
o=Zoiper_user 0 0 IN IP4 10.10.0.51
s=Zoiper_session
c=IN IP4 10.10.0.51
t=0 0
m=audio 8000 RTP/AVP 3 0 8 110 98 101
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:110 speex/8000
a=rtpmap:98 iLBC/8000
a=fmtp:98 mode=30
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
<------------->
--- (14 headers 15 lines) ---
 == Using SIP RTP CoS mark 5
 == Using SIP VRTP CoS mark 6
 == Using UDPTL CoS mark 5
Sending to 83.136.32.160 : 5060 (NAT)
Using INVITE request as basis request - NGZjODM5YjJhMWZiNGMzMDZiNzczYjJkM2Y1YWU0N2I.
No matching peer for 'klaus.darilion' from '83.136.32.160:5060'
Found RTP audio format 3
Found RTP audio format 0
Found RTP audio format 8
Found RTP audio format 110
Found RTP audio format 98
Found RTP audio format 101
Peer audio RTP is at port 10.10.0.51:8000
Found audio description format GSM for ID 3
Found audio description format PCMU for ID 0
Found audio description format PCMA for ID 8
Found audio description format speex for ID 110
Found audio description format iLBC for ID 98
Found audio description format telephone-event for ID 101
Capabilities: us - 0xc7f9ffe (gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|g726aal2|g722|slin16|jpeg|png|h261|h263|h263p|h264|mpeg4|red|t140), peer - audio=0x60e (gsm|ulaw|alaw|speex|ilbc)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x60e (gsm|ulaw|alaw|speex|ilbc)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
Peer audio RTP is at port 10.10.0.51:8000
Looking for fax936 in sipanon (domain 83.136.32.165)
list_route: hop: <sip:83.136.32.160;ftag=603ced2b;lr=on>

<--- Transmitting (NAT) to 83.136.32.160:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 83.136.32.160;branch=z9hG4bK96c5.60670ed2.0;received=83.136.32.160
Via: SIP/2.0/UDP 83.136.33.3:5060;branch=z9hG4bK-d8754z-8e1b6a42665411d0-1---d8754z-;rport=1145
Record-Route: <sip:83.136.32.160;ftag=603ced2b;lr=on>
From: <sip:klaus.darilion@nic.at43.at>;transport=UDP;tag=603ced2b
To: <sip:078081120024@nic.at43.at>;transport=UDP
Call-ID: NGZjODM5YjJhMWZiNGMzMDZiNzczYjJkM2Y1YWU0N2I.
CSeq: 2 INVITE
Server: Asterisk PBX SVN-trunk-r154926M
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
Contact: <sip:fax936@83.136.32.165>
Content-Length: 0


<------------>
   -- Executing [fax936@sipanon:1] FaxGateway("SIP/nic.at43.at-097e52d0", "Dahdi/g2/06624669936") in new stack
   -- Requested transfer capability: 0x00 - SPEECH

<------------->
--- (10 headers 0 lines) ---
Audio is at 83.136.32.165 port 10800
Adding codec 0x2 (gsm) to SDP
Adding codec 0x4 (ulaw) to SDP
Adding codec 0x8 (alaw) to SDP
Adding codec 0x200 (speex) to SDP
Adding codec 0x400 (ilbc) to SDP
Adding non-codec 0x1 (telephone-event) to SDP

<--- Reliably Transmitting (NAT) to 83.136.32.160:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 83.136.32.160;branch=z9hG4bK96c5.60670ed2.0;received=83.136.32.160
Via: SIP/2.0/UDP 83.136.33.3:5060;branch=z9hG4bK-d8754z-8e1b6a42665411d0-1---d8754z-;rport=1145
Record-Route: <sip:83.136.32.160;ftag=603ced2b;lr=on>
From: <sip:klaus.darilion@nic.at43.at>;transport=UDP;tag=603ced2b
To: <sip:078081120024@nic.at43.at>;transport=UDP;tag=as520b9659
Call-ID: NGZjODM5YjJhMWZiNGMzMDZiNzczYjJkM2Y1YWU0N2I.
CSeq: 2 INVITE
Server: Asterisk PBX SVN-trunk-r154926M
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
Contact: <sip:fax936@83.136.32.165>
Content-Type: application/sdp
Content-Length: 395

v=0
o=root 511991700 511991700 IN IP4 83.136.32.165
s=Asterisk PBX SVN-trunk-r154926M
c=IN IP4 83.136.32.165
t=0 0
m=audio 10800 RTP/AVP 3 0 8 110 98 101
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:110 speex/8000
a=rtpmap:98 iLBC/8000
a=fmtp:98 mode=30
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

<------------>

<--- SIP read from UDP:83.136.32.160:5060 --->
INVITE sip:fax936@83.136.32.165 SIP/2.0
Via: SIP/2.0/UDP 83.136.32.160;branch=z9hG4bKa6c5.8c7d2b02.0
Via: SIP/2.0/UDP 83.136.33.3:5060;branch=z9hG4bK-d8754z-53142fdb2cef96f0-1---d8754z-;rport=1145
Max-Forwards: 69
Contact: <sip:klaus.darilion@83.136.33.3:5060>
To: <sip:078081120024@nic.at43.at>;transport=UDP;tag=as520b9659
From: <sip:klaus.darilion@nic.at43.at>;transport=UDP;tag=603ced2b
Call-ID: NGZjODM5YjJhMWZiNGMzMDZiNzczYjJkM2Y1YWU0N2I.
CSeq: 3 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO
Content-Type: application/sdp
User-Agent: Zoiper for Windows rev.1811
Content-Length: 368

v=0
o=Zoiper_user 299622569 578367343 IN IP4 10.10.0.51
s=Zoiper_session
c=IN IP4 10.10.0.51
t=0 0
m=image 8000 udptl t38
a=T38FaxRateManagement:transferredTCF
a=T38FaxVersion:0
a=T38FaxMaxBuffer:400
a=T38FaxTranscodingMMR:0
a=T38FaxUdpEC:t38UDPRedundancy
a=T38FaxFillBitRemoval:0
a=T38MaxBitRate:14400
a=T38FaxMaxDatagram:400
a=T38FaxTranscodingJBIG:0
<------------->
--- (13 headers 15 lines) ---

<--- Reliably Transmitting (NAT) to 83.136.32.160:5060 --->
SIP/2.0 491 Request Pending
Via: SIP/2.0/UDP 83.136.32.160;branch=z9hG4bKa6c5.8c7d2b02.0;received=83.136.32.160
Via: SIP/2.0/UDP 83.136.33.3:5060;branch=z9hG4bK-d8754z-53142fdb2cef96f0-1---d8754z-;rport=1145
From: <sip:klaus.darilion@nic.at43.at>;transport=UDP;tag=603ced2b
To: <sip:078081120024@nic.at43.at>;transport=UDP;tag=as520b9659
Call-ID: NGZjODM5YjJhMWZiNGMzMDZiNzczYjJkM2Y1YWU0N2I.
CSeq: 3 INVITE
Server: Asterisk PBX SVN-trunk-r154926M
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
Content-Length: 0


<------------>

<--- SIP read from UDP:83.136.32.160:5060 --->
ACK sip:fax936@83.136.32.165 SIP/2.0
Via: SIP/2.0/UDP 83.136.32.160;branch=z9hG4bKa6c5.8c7d2b02.0
From: <sip:klaus.darilion@nic.at43.at>;transport=UDP;tag=603ced2b
Call-ID: NGZjODM5YjJhMWZiNGMzMDZiNzczYjJkM2Y1YWU0N2I.
To: <sip:078081120024@nic.at43.at>;transport=UDP;tag=as520b9659
CSeq: 3 ACK
Route: <sip:83.136.32.160;lr;ftag=603ced2b>
User-Agent: OpenSer (1.0.1-tls (i386/linux))
Content-Length: 0

<------------->
--- (9 headers 0 lines) ---

<--- SIP read from UDP:83.136.32.160:5060 --->
ACK sip:fax936@83.136.32.165 SIP/2.0
Via: SIP/2.0/UDP 83.136.32.160;branch=0
Via: SIP/2.0/UDP 83.136.33.3:5060;branch=z9hG4bK-d8754z-865af73e7d4e6095-1---d8754z-;rport=1145
Max-Forwards: 69
Contact: <sip:klaus.darilion@83.136.33.3:5060>
To: <sip:078081120024@nic.at43.at>;transport=UDP;tag=as520b9659
From: <sip:klaus.darilion@nic.at43.at>;transport=UDP;tag=603ced2b
Call-ID: NGZjODM5YjJhMWZiNGMzMDZiNzczYjJkM2Y1YWU0N2I.
CSeq: 2 ACK
User-Agent: Zoiper for Windows rev.1811
Content-Length: 0

<------------->
--- (11 headers 0 lines) ---
Retransmitting #1 (NAT) to 83.136.32.160:5060:
SIP/2.0 491 Request Pending
Via: SIP/2.0/UDP 83.136.32.160;branch=z9hG4bKa6c5.8c7d2b02.0;received=83.136.32.160
Via: SIP/2.0/UDP 83.136.33.3:5060;branch=z9hG4bK-d8754z-53142fdb2cef96f0-1---d8754z-;rport=1145
From: <sip:klaus.darilion@nic.at43.at>;transport=UDP;tag=603ced2b
To: <sip:078081120024@nic.at43.at>;transport=UDP;tag=as520b9659
Call-ID: NGZjODM5YjJhMWZiNGMzMDZiNzczYjJkM2Y1YWU0N2I.
CSeq: 3 INVITE
Server: Asterisk PBX SVN-trunk-r154926M
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
Content-Length: 0


---

<--- SIP read from UDP:83.136.32.160:5060 --->
ACK sip:fax936@83.136.32.165 SIP/2.0
Via: SIP/2.0/UDP 83.136.32.160;branch=z9hG4bKa6c5.8c7d2b02.0
From: <sip:klaus.darilion@nic.at43.at>;transport=UDP;tag=603ced2b
Call-ID: NGZjODM5YjJhMWZiNGMzMDZiNzczYjJkM2Y1YWU0N2I.
To: <sip:078081120024@nic.at43.at>;transport=UDP;tag=as520b9659
CSeq: 3 ACK
Route: <sip:83.136.32.160;lr;ftag=603ced2b>
User-Agent: OpenSer (1.0.1-tls (i386/linux))
Content-Length: 0



<------------->
--- (10 headers 0 lines) ---
Retransmitting #2 (NAT) to 83.136.32.160:5060:
SIP/2.0 491 Request Pending
Via: SIP/2.0/UDP 83.136.32.160;branch=z9hG4bKa6c5.8c7d2b02.0;received=83.136.32.160
Via: SIP/2.0/UDP 83.136.33.3:5060;branch=z9hG4bK-d8754z-53142fdb2cef96f0-1---d8754z-;rport=1145
From: <sip:klaus.darilion@nic.at43.at>;transport=UDP;tag=603ced2b
To: <sip:078081120024@nic.at43.at>;transport=UDP;tag=as520b9659
Call-ID: NGZjODM5YjJhMWZiNGMzMDZiNzczYjJkM2Y1YWU0N2I.
CSeq: 3 INVITE
Server: Asterisk PBX SVN-trunk-r154926M
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
Content-Length: 0


---

<--- SIP read from UDP:83.136.32.160:5060 --->
ACK sip:fax936@83.136.32.165 SIP/2.0
Via: SIP/2.0/UDP 83.136.32.160;branch=z9hG4bKa6c5.8c7d2b02.0
From: <sip:klaus.darilion@nic.at43.at>;transport=UDP;tag=603ced2b
Call-ID: NGZjODM5YjJhMWZiNGMzMDZiNzczYjJkM2Y1YWU0N2I.
To: <sip:078081120024@nic.at43.at>;transport=UDP;tag=as520b9659
CSeq: 3 ACK
Route: <sip:83.136.32.160;lr;ftag=603ced2b>
User-Agent: OpenSer (1.0.1-tls (i386/linux))
Content-Length: 0

<------------->
--- (9 headers 0 lines) ---
Comments:By: Mark Michelson (mmichelson) 2008-12-02 16:20:33.000-0600

I took a look at ftp://ftp.rfc-editor.org/in-notes/internet-drafts/draft-ietf-sipping-race-examples-06.txt

The scenario here seems to correspond to the scenario outlined in section 3.1.5 of that document. Sending a 491 in response to the reINVITE is the proper action to take. However, Asterisk's behavior of ignoring the ACK for the 491'd request is incorrect.

I suspect that this is due to the 'pendinginvite' field of the sip_pvt structure. More specifically, the problem is that we only keep track of one "pending" INVITE's CSeq number at any given time. By "pending," I mean that the three-way handshake associated with INVITEs has not completed. Based on looking at the code, I would be willing to bet that Asterisk misbehaves in this way any time it responds to an INVITE with a 491, because the CSeq number of the corresponding ACK will not match the 'pendinginvite' field of the sip_pvt structure.
By: klaus3000 (klaus3000) 2008-12-02 16:47:25.000-0600

Hi! Scenario in section 3.1.5 does have initial offer/answer in 200OK/ACK. Thus, 491 is used.

In my scenario the initial offer/answer is in INVITE/200ok which is handled in section 3.1.4
By: Mark Michelson (mmichelson) 2008-12-02 17:08:14.000-0600

Ah, you are quite right. I did not notice that difference. This makes things a bit more complicated.

Ok, Asterisk should send a 200 OK to the reINVITE. That part would probably be easy enough to handle. There are two tricky parts to handle for this situation. One is similar to what I stated in my previous message. Asterisk is not equipped to be able to recognize ACKs for multiple INVITEs in a single dialog. Change needs to be made with regards to how the 'pendinginvite' field is handled. The other tricky part is that I'm not sure of the proper way to tell if an SDP offer has been answered on the dialog at the time the reINVITE is handled. I'll do some searching and see what I can find.
By: klaus3000 (klaus3000) 2008-12-02 18:02:36.000-0600

I think a quick fix would be just to accept the reINVITE and also treat it as implicit ACK to the previous transaction. Of course in the long time it should be also capable of handling offer/answer in 200ok/ACK
By: Mark Michelson (mmichelson) 2009-03-31 13:50:37

I sat down to work on this and after an hour of analyzing everything and trying to make sense of it all, it seems like a simple 3-line change is all that may be necessary to handle this correctly. I've uploaded a patch (13849.patch) which I believe will handle this problem. Right now it has a bunch of comments so that if things don't work, I can follow what my previous logic was and potentially figure out what went wrong.

I'm optimistic that this patch will work; however, if it does not, please post a sip debug as well as core debug output from a failure so that I may see what went wrong.
By: Mark Michelson (mmichelson) 2009-04-07 11:30:02

I did some testing of the patch I originally uploaded using SIPp and found an oversight on my part. I made a small adjustment and got my scenario working correctly. I have uploaded the modified patch as 13849_v2.patch. I can now confirm that this patch works for me, and so my need for further testing is now more of a "peace of mind" thing. If I don't get any test results on this by the end of the week, I will commit this patch (with less verbose comments), pending a code review.
By: klaus3000 (klaus3000) 2009-04-09 06:40:15

Thanks for the patch. I tested it with eyebeam<-->openser<-->Asterisk where is manually delay the ACK packets --> works fine.

regarding comments: I really like them, it would be good if there would be more such comments in chan_sip :-)
By: Digium Subversion (svnbot) 2009-04-09 13:51:21

Repository: asterisk
Revision: 187484

U   branches/1.4/channels/chan_sip.c

------------------------------------------------------------------------
r187484 | mmichelson | 2009-04-09 13:51:21 -0500 (Thu, 09 Apr 2009) | 18 lines

Handle a SIP race condition (reinvite before an ACK) properly.

RFC 5047 explains the proper course of action to take if a
reINVITE is received before the ACK from a previous invite
transaction. What we are to do is to treat the reINVITE as
if it were both an ACK and a reINVITE and process it normally.

Later, when we receive the ACK we had been expecting, we will
ignore it since its CSeq is less than the current iseqno of
the sip_pvt representing this dialog.

(closes issue ASTERISK-13025)
Reported by: klaus3000
Patches:
     13849_v2.patch uploaded by mmichelson (license 60)
Tested by: mmichelson, klaus3000


------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=187484
By: Digium Subversion (svnbot) 2009-04-09 13:58:42

Repository: asterisk
Revision: 187488

_U  trunk/
U   trunk/channels/chan_sip.c

------------------------------------------------------------------------
r187488 | mmichelson | 2009-04-09 13:58:42 -0500 (Thu, 09 Apr 2009) | 24 lines

Merged revisions 187484 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.4

........
 r187484 | mmichelson | 2009-04-09 13:51:20 -0500 (Thu, 09 Apr 2009) | 18 lines
 
 Handle a SIP race condition (reinvite before an ACK) properly.
 
 RFC 5047 explains the proper course of action to take if a
 reINVITE is received before the ACK from a previous invite
 transaction. What we are to do is to treat the reINVITE as
 if it were both an ACK and a reINVITE and process it normally.
 
 Later, when we receive the ACK we had been expecting, we will
 ignore it since its CSeq is less than the current iseqno of
 the sip_pvt representing this dialog.
 
 (closes issue ASTERISK-13025)
 Reported by: klaus3000
 Patches:
       13849_v2.patch uploaded by mmichelson (license 60)
 Tested by: mmichelson, klaus3000
........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=187488
By: Digium Subversion (svnbot) 2009-04-09 14:14:39

Repository: asterisk
Revision: 187495

_U  branches/1.6.1/
U   branches/1.6.1/channels/chan_sip.c

------------------------------------------------------------------------
r187495 | mmichelson | 2009-04-09 14:14:39 -0500 (Thu, 09 Apr 2009) | 31 lines

Merged revisions 187488 via svnmerge from
https://origsvn.digium.com/svn/asterisk/trunk

................
 r187488 | mmichelson | 2009-04-09 13:58:41 -0500 (Thu, 09 Apr 2009) | 24 lines
 
 Merged revisions 187484 via svnmerge from
 https://origsvn.digium.com/svn/asterisk/branches/1.4
 
 ........
   r187484 | mmichelson | 2009-04-09 13:51:20 -0500 (Thu, 09 Apr 2009) | 18 lines
   
   Handle a SIP race condition (reinvite before an ACK) properly.
   
   RFC 5047 explains the proper course of action to take if a
   reINVITE is received before the ACK from a previous invite
   transaction. What we are to do is to treat the reINVITE as
   if it were both an ACK and a reINVITE and process it normally.
   
   Later, when we receive the ACK we had been expecting, we will
   ignore it since its CSeq is less than the current iseqno of
   the sip_pvt representing this dialog.
   
   (closes issue ASTERISK-13025)
   Reported by: klaus3000
   Patches:
         13849_v2.patch uploaded by mmichelson (license 60)
   Tested by: mmichelson, klaus3000
 ........
................

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=187495