[reSIProcate] Missing non-INVITE request before BYE

Tue May 3 07:12:29 CDT 2005

Hello.

In case when remote UA sends BYE just after INFO not waiting for 
termination of INFO transaction, reSIProcate misses the INFO 
sometimes. The log is attached.

"Terminating a Session with a BYE Request" / "UAS Behavior" (15.1.2 
section of SIP RFC) states:

  The UAS MUST still respond to any pending requests received for 
  that dialog.  It is RECOMMENDED that a 487 (Request Terminated) 
  response be generated to those pending requests."

Therefore, although remote UAs must not use overlapping transactions, 
reSIProcate in turn must not miss them.

-- 
...Bye..Dmitry.
-------------- next part --------------
DEBUG | 20050429-193535.779 | SipMgr | RESIP:TRANSPORT | 2216 | Transport.cxx:209 | incoming from: [ V4 1.2.3.4:5070 UDP received on: Transport: [ V4 0.0.0.0:5070 UDP connectionId=0 ] connectionId=0 ]

STACK | 20050429-193535.779 | SipMgr | RESIP:TRANSPORT | 2216 | Transport.cxx:210 | 

INFO sip:5.6.7.8:5070 SIP/2.0

To: <sip:SE>;tag=081eec19

From: <sip:1.2.3.4:5070>;tag=13597

Via: SIP/2.0/UDP 1.2.3.4:5070;branch=z9hG4bK4313

Call-ID: 5443cf4db969a868 at U0U.

CSeq: 5 INFO

Max-Forwards: 5

[...]

STACK | 20050429-193535.779 | SipMgr | RESIP:TRANSACTION | 2216 | TransactionState.cxx:155 | Found matching transaction for SipReq:  INFO 5.6.7.8:5070 tid=4313 cseq=INFO / 5 from(wire) -> tid=4313 [ ServerNonInvite/Completed unreliable target=[ V4 1.2.3.4:5070 UDP received on: Transport: [ V4 0.0.0.0:5070 UDP connectionId=0 ] connectionId=0 ]]

STACK | 20050429-193535.779 | SipMgr | RESIP:TRANSACTION | 2216 | TransactionState.cxx:781 | TransactionState::processServerNonInvite: SipReq:  INFO 5.6.7.8:5070 tid=4313 cseq=INFO / 5 from(wire)

STACK | 20050429-193535.779 | SipMgr | RESIP:TRANSACTION | 2216 | TransactionState.cxx:1472 | tid=4313 sending to : [ V4 1.2.3.4:5070 UDP received on: Transport: [ V4 0.0.0.0:5070 UDP connectionId=0 ] connectionId=0 ]

DEBUG | 20050429-193535.779 | SipMgr | RESIP:TRANSPORT | 2216 | Transport.cxx:160 | Adding message to tx buffer to: [ V4 1.2.3.4:5070 UDP received on: Transport: [ V4 0.0.0.0:5070 UDP connectionId=0 ] connectionId=0 ]

DEBUG | 20050429-193535.795 | SipMgr | RESIP:TRANSPORT | 2216 | Transport.cxx:209 | incoming from: [ V4 1.2.3.4:5070 UDP received on: Transport: [ V4 0.0.0.0:5070 UDP connectionId=0 ] connectionId=0 ]

STACK | 20050429-193535.795 | SipMgr | RESIP:TRANSPORT | 2216 | Transport.cxx:210 | 

BYE sip:5.6.7.8:5070 SIP/2.0

To: <sip:SE>;tag=081eec19

From: <sip:1.2.3.4:5070>;tag=13597

Via: SIP/2.0/UDP 1.2.3.4:5070;branch=z9hG4bK11840

Call-ID: 5443cf4db969a868 at U0U.

CSeq: 6 BYE

Max-Forwards: 5

Content-Length: 0

STACK | 20050429-193535.795 | SipMgr | RESIP:TRANSACTION | 2216 | TransactionState.cxx:190 | No matching transaction for SipReq:  BYE 5.6.7.8:5070 tid=11840 cseq=BYE / 6 from(wire)

DEBUG | 20050429-193535.795 | SipMgr | RESIP:TRANSACTION | 2216 | TransactionUser.cxx:56 | Checking if SipReq:  BYE 5.6.7.8:5070 tid=11840 cseq=BYE / 6 from(wire) is for me

DEBUG | 20050429-193535.795 | SipMgr | RESIP:TRANSACTION | 2216 | TransactionUser.cxx:61 | Checking rule...

DEBUG | 20050429-193535.795 | SipMgr | RESIP:TRANSACTION | 2216 | MessageFilterRule.cxx:42 | Matching rule for BYE sip:5.6.7.8:5070 SIP/2.0

To: <sip:SE>;tag=081eec19

From: <sip:1.2.3.4:5070>;tag=13597

Via: SIP/2.0/UDP 1.2.3.4:5070;branch=z9hG4bK11840

Call-ID: 5443cf4db969a868 at U0U.

CSeq: 6 BYE

Max-Forwards: 5

Content-Length: 0

DEBUG | 20050429-193535.795 | SipMgr | RESIP:TRANSACTION | 2216 | TransactionUser.cxx:64 | Match!

STACK | 20050429-193535.795 | SipMgr | RESIP:TRANSACTION | 2216 | TransactionState.cxx:45 | Creating new TransactionState: tid=11840 [ ServerNonInvite/Trying reliable target=[ V4 0.0.0.0:0 UNKNOWN_TRANSPORT connectionId=0 ]]

DEBUG | 20050429-193535.795 | SipMgr | RESIP:TRANSACTION | 2216 | TransactionState.cxx:1535 | Send to TU: TU: DialogUsageManager size=0 BYE sip:5.6.7.8:5070 SIP/2.0

To: <sip:SE>;tag=081eec19

From: <sip:1.2.3.4:5070>;tag=13597

Via: SIP/2.0/UDP 1.2.3.4:5070;branch=z9hG4bK11840

Call-ID: 5443cf4db969a868 at U0U.

CSeq: 6 BYE

Max-Forwards: 5

Content-Length: 0

INFO | 20050429-193535.795 | SipMgr | RESIP:DUM | 2216 | DialogUsageManager.cxx:820 | Got: SipReq:  BYE 5.6.7.8:5070 tid=11840 cseq=BYE / 6 from(wire)

DEBUG | 20050429-193535.795 | SipMgr | RESIP:DUM | 2216 | DialogUsageManager.cxx:1205 | DialogUsageManager::processRequest: SipReq:  BYE 5.6.7.8:5070 tid=11840 cseq=BYE / 6 from(wire)

DEBUG | 20050429-193535.795 | SipMgr | RESIP:DUM | 2216 | DialogUsageManager.cxx:1486 | Looking for dialogSet: 5443cf4db969a868 at U0U.-081eec19 in map:

DEBUG | 20050429-193535.795 | SipMgr | RESIP:DUM | 2216 | DialogUsageManager.cxx:1487 | [1645876e3c206309 at U0U.-c6763536 -> 0ED1C840, 5443cf4db969a868 at U0U.-081eec19 -> 099F2EF8, 791d2071fa54af39 at U0U.-8e121008 -> 09A1B8B8, a2190f60f612f80d at U0U.-99000154 -> 09ABA668, af3c9b1acd04db3d at U0U.-845e7402 -> 09A0B608]

INFO | 20050429-193535.795 | SipMgr | RESIP:DUM | 2216 | DialogUsageManager.cxx:1259 | Handling in-dialog request: SipReq:  BYE 5.6.7.8:5070 tid=11840 cseq=BYE / 6 from(wire)

DEBUG | 20050429-193535.795 | SipMgr | RESIP:DUM | 2216 | DialogId.cxx:50 | DialogId::DialogId: 5443cf4db969a868 at U0U.-081eec19-13597

DEBUG | 20050429-193535.795 | SipMgr | RESIP:DUM | 2216 | DialogSet.cxx:669 | findDialog: 5443cf4db969a868 at U0U.-081eec19-13597 in [5443cf4db969a868 at U0U.-081eec19-13597 -> 0ECFAEC0]

DEBUG | 20050429-193535.795 | SipMgr | RESIP:DUM | 2216 | DialogSet.cxx:365 | Found matching dialog mClientSubscriptions(0), mServerSubscriptions(0) for 

BYE sip:5.6.7.8:5070 SIP/2.0

To: <sip:SE>;tag=081eec19

From: <sip:1.2.3.4:5070>;tag=13597

Via: SIP/2.0/UDP 1.2.3.4:5070;branch=z9hG4bK11840

Call-ID: 5443cf4db969a868 at U0U.

CSeq: 6 BYE

Max-Forwards: 5

Content-Length: 0

DEBUG | 20050429-193535.795 | SipMgr | RESIP:DUM | 2216 | Dialog.cxx:289 | Dialog::dispatch: SipReq:  BYE 5.6.7.8:5070 tid=11840 cseq=BYE / 6 from(wire)

INFO | 20050429-193535.795 | SipMgr | RESIP:DUM | 2216 | InviteSession.cxx:1050 | Received SipReq:  BYE 5.6.7.8:5070 tid=11840 cseq=BYE / 6 from(wire)

DEBUG | 20050429-193535.795 | SipMgr | RESIP | 2216 | Helper.cxx:282 | Helper::makeResponse(SipReq:  BYE 5.6.7.8:5070 tid=11840 cseq=BYE / 6 from(wire) code=200 reason=

DEBUG | 20050429-193535.795 | SipMgr | RESIP:DUM | 2216 | Dialog.cxx:914 | Dialog::makeResponse: SIP/2.0 200 OK

To: <sip:SE>;tag=081eec19

From: <sip:1.2.3.4:5070>;tag=13597

Via: SIP/2.0/UDP 1.2.3.4:5070;branch=z9hG4bK11840

Call-ID: 5443cf4db969a868 at U0U.

CSeq: 6 BYE

Contact: <sip:5.6.7.8:5070>

Content-Length: 0

DEBUG | 20050429-193535.795 | SipMgr | RESIP:DUM | 2216 | DialogUsageManager.cxx:1486 | Looking for dialogSet: 5443cf4db969a868 at U0U.-081eec19 in map:

DEBUG | 20050429-193535.795 | SipMgr | RESIP:DUM | 2216 | DialogUsageManager.cxx:1487 | [1645876e3c206309 at U0U.-c6763536 -> 0ED1C840, 5443cf4db969a868 at U0U.-081eec19 -> 099F2EF8, 791d2071fa54af39 at U0U.-8e121008 -> 09A1B8B8, a2190f60f612f80d at U0U.-99000154 -> 09ABA668, af3c9b1acd04db3d at U0U.-845e7402 -> 09A0B608]

DEBUG | 20050429-193535.795 | SipMgr | RESIP:DUM | 2216 | DialogUsageManager.cxx:605 | SEND: SIP/2.0 200 OK

To: <sip:SE>;tag=081eec19

From: <sip:1.2.3.4:5070>;tag=13597

Via: SIP/2.0/UDP 1.2.3.4:5070;branch=z9hG4bK11840

Call-ID: 5443cf4db969a868 at U0U.

CSeq: 6 BYE

Contact: <sip:5.6.7.8:5070>

Content-Length: 0

DEBUG | 20050429-193535.795 | SipMgr | RESIP | 2216 | SipStack.cxx:269 | SEND: SipResp: 200 tid=11840 cseq=BYE contact=5.6.7.8:5070 / 6 from(tu)

INFO | 20050429-193535.795 | SipMgr | RESIP:DUM | 2216 | InviteSession.cxx:1435 | Transition InviteSession::Connected -> InviteSession::Terminated