Issue Details (XML | Word | Printable)

Key: JSIP-373
Type: Bug Bug
Status: Open Open
Priority: Major Major
Assignee: Unassigned
Reporter: mturconi
Votes: 0
Watchers: 1
Operations

If you were logged in you would be able to see more operations.
jsip

ACK dropped when a previously wrong (CSeq:2) message is received.

Created: 29/Mar/11 07:10 AM   Updated: 26/Nov/12 05:27 PM
Component/s: None
Affects Version/s: current
Fix Version/s: None

Time Tracking:
Not Specified

File Attachments: 1. Java Archive File jain-sip-ri-1.2.X-SNAPSHOT.jar (837 kB) 08/Jul/11 08:35 PM - deruelle_jean
2. File shootme_logs.7z (7 kB) 26/Nov/12 05:27 PM - nickbaker


Tags:
Participants: deruelle_jean, mturconi and nickbaker


 Description  « Hide

We have the following problem.
We receive incoming calls, but before receiving the ACK, we sometimes receive a NOTIFY message with CSeq:2.
The NOTIFY is correctly replied by JSIP but then, the lastResponseCSeqNumber is set to 2.
After that, when the ACK is received, it is dropped.
The application then starts re-sending 200ok, and refuses all received ACK messages.

I know that the error is with the NOTIFY. But that is a received message, I think JSIP should take some protection upon such events.
I don't know what should the correct behaviour be, either refusing the NOTIFY with an error message or simply ignoring the received CSeq, as the call is not fully established.

I attach a piece of log (with XXXXX to hide private data).
The problem is here:

lastResponseCSeqNumber = 2 ackTxCSeq 1

dump:

2011-03-29 13:02:48.798 DEBUG [SIP-UDPMessageChannelThread-9]:
PROCESSING INCOMING REQUEST ACK sip:XXXXX@127.0.0.1:XXXXXXX SIP/2.0
CSeq: 1 ACK
Via: SIP/2.0/UDP
127.0.0.1:6040;branch=z9hG4bK50224fc0-6158-e011-8d6f-001e0b1f40c0;rport
=6040;received=127.0.0.1
User-Agent: XXXXXXXXXXXXXXX
From: "anonymous" <sip:anonymous@anonymous.invalid>;tag=txak0l8
Call-ID: 26442fc0-6158-e011-8d6f-001e0b1f40c0@XXXXXXXXXXXX
Supported: em,timer,replaces,path,early-session,resource-priority
To: <sip:XXXXXXXX@XXXXX;user=phone>;tag=tmynnj0
Allow:
REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIB
E,UPDATE
Max-Forwards: 70
Content-Length: 0

transactionChannel =
gov.nist.javax.sip.stack.SIPServerTransaction@9317a0ce listening point
= 127.0.0.1:26118
2011-03-29 13:02:48.798 DEBUG [SIP-UDPMessageChannelThread-9]:
transaction state = Trying Transaction
2011-03-29 13:02:48.798 DEBUG [SIP-UDPMessageChannelThread-9]:
getDialog(26442fc0-6158-e011-8d6f-001e0b1f40c0@XXXXXXXXX:tmynnj0:txak0l
8) : returning gov.nist.javax.s
ip.stack.SIPDialog@e1b3c
2011-03-29 13:02:48.798 DEBUG [SIP-UDPMessageChannelThread-9]:
dialogId =
26442fc0-6158-e011-8d6f-001e0b1f40c0@XXXXXXXXX:tmynnj0:txak0l8
2011-03-29 13:02:48.798 DEBUG [SIP-UDPMessageChannelThread-9]:
dialog = gov.nist.javax.sip.stack.SIPDialog@e1b3c
2011-03-29 13:02:48.798 DEBUG [SIP-UDPMessageChannelThread-9]:
Processing ACK for dialog gov.nist.javax.sip.stack.SIPDialog@e1b3c
2011-03-29 13:02:48.798 DEBUG [SIP-UDPMessageChannelThread-9]:
SIPDialog::isAckSeen:gov.nist.javax.sip.stack.SIPDialog@e1b3clastAckRec
eived is null – returning false
2011-03-29 13:02:48.798 DEBUG [SIP-UDPMessageChannelThread-9]:
SIPDialog::handleAck: lastResponseCSeqNumber = 2 ackTxCSeq 1
2011-03-29 13:02:48.798 DEBUG [SIP-UDPMessageChannelThread-9]:
INVITE transaction not found
2011-03-29 13:02:48.798 DEBUG [SIP-UDPMessageChannelThread-9]:
Dropping ACK - cannot find a transaction or dialog



mturconi added a comment - 29/Mar/11 07:23 AM

the jsip version used for the test is:

jain-sip-sdp-1.2.1897.jar


deruelle_jean added a comment - 08/Jul/11 03:12 PM

I'm trying a tentative patch to fix a race condition on setLastResponse, Can you retry with the attached jar to see if that fixes the issue ?

Thanks in advance
Jean


deruelle_jean added a comment - 08/Jul/11 08:33 PM

Attaching a new jar, the other one had a bug


deruelle_jean added a comment - 08/Jul/11 08:35 PM

Attaching a new jar, the other one had a bug


mturconi added a comment - 15/Jul/11 09:04 AM

I'm doing the test, about 80,000 calls so far.
I'm not having any problem (no "Dropping ACK"), but the situation that caused the problem was rare so I cannot be sure it is already happened.

I will repeat the test using some program of mine that sends the NOTIFY before the ACK, to be sure.


nickbaker added a comment - 26/Nov/12 05:27 PM

We are seeing some calls failing in this scenario (using Jitsi, which uses JSIP), both with and without the attached jar.

This happens fairly rarely in live use, but I can reliably repro the behaviour using a SIPp script pointed at our client, or at a modified 'Shootme' script. I have attached the shootme logs.

As far as I can see there is nothing in the SIP RFCs that say a NOTIFY should not be transmitted during a transaction, so I think JSIP should be able to handle this scenario.

This was seen on the following versions:
jain-sip-sdp-1.2.1111.jar
jain-sip-sdp-1.2.2185.jar