[reSIProcate] Route Set problem with Update in resip 1.1 RC1

Kovar, William (Bill) bkovar at avaya.com
Wed Mar 7 15:12:28 CST 2007


There seems to be another problem with Record Route processing.
 
After an established dialog, an Update is received that runs through
Helper::makeResponse() to build a 200 msg that does not contain the
correct Route Set.
 
I had found this error in a different scenario, i.e. a response, which
is fixed. Now I see this in an Update, i.e. a request.
 
I believe the problem is at Helper.cxx line 410
 
Here's a log snip, correct route set in ACK in blue, bad route set in
200 OK in red for same call-id:
 
 ![2007-03-07 20:14:53.258] <2952:RESIP:TRANSPORT>  DEBUG |
TransportSelector.cxx:869 | Transmitting to [ V4 135.8.52.181:5060 UDP
target domain=135.8.52.181 received on: Transport: [ V4 0.0.0.0:5060 UDP
target domain=unspecified connectionId=0 ] connectionId=0 ] tlsDomain=
via [ V4 135.8.116.33:5060 UDP target domain=135.8.52.181 connectionId=0
]
 
ACK sip:76800 at avaya.com:5061;transport=tls SIP/2.0
 
Via: SIP/2.0/UDP
135.8.116.33:5060;branch=z9hG4bK-d8754z-b20c1e5c1c57e971-1---d8754z-;rpo
rt
 
Max-Forwards: 70
 
Route: <sip:135.8.52.181:5060;lr>
 
Route: <sip:135.8.83.172:5061;lr;transport=tls>
 
Contact: <sip:56000 at 135.8.116.33:5060>
 
To: <sip:76800 at avaya.com>;tag=0945f2f40dddb181b46f94dc00
 
From: "IC 7.1 B2B"<sip:56000 at avaya.com>;tag=b855e212
 
Call-ID: ZDU4Yjg4M2UxYTE1MjRiNzJkZTU3ZWMzYmNlMjZlZjk.
 
CSeq: 2 ACK
 
Content-Type: application/sdp
 
Proxy-Authorization: Digest
username="56000",realm="avaya.com",nonce="MTE3MzMzMTA4NTpTREZTZXJ2ZXJTZW
NyZXRLZXk6NzQ1MTU0ODc4",uri="sip:76800 at avaya.com",response="e1bdfe0882c0
87d5334812ad288f7c60",algorithm=MD5
 
User-Agent: AvSIP 1.04.2
 
Content-Length: 202
 
 
 
v=0
 
o=- 1 2 IN IP4 135.8.83.172
 
s=-
 
c=IN IP4 135.8.83.133
 
t=0 0
 
m=audio 36456 RTP/AVP 0 18 127
 
a=fmtp:18 annexb=no
 
a=rtpmap:0 PCMU/8000
 
a=rtpmap:18 G729/8000
 
a=rtpmap:127 telephone-event/8000
 

 ![2007-03-07 20:14:53.258] <2952:RESIP:TRANSPORT>  DEBUG |
Transport.cxx:213 | Adding message to tx buffer to: [ V4
135.8.52.181:5060 UDP target domain=135.8.52.181 received on: Transport:
[ V4 0.0.0.0:5060 UDP target domain=unspecified connectionId=0 ]
connectionId=0 ]
 ![2007-03-07 20:14:53.305] <2952:RESIP:TRANSPORT>  DEBUG |
Transport.cxx:287 | incoming from: [ V4 135.8.52.181:32796 UDP target
domain=unspecified received on: Transport: [ V4 0.0.0.0:5060 UDP target
domain=unspecified connectionId=0 ] connectionId=0 ]
 ![2007-03-07 20:14:53.305] <2952:RESIP:TRANSACTION>  DEBUG |
TransactionUser.cxx:66 | Checking if SipReq:  UPDATE
56000 at 135.8.116.33:5060 <mailto:56000 at 135.8.116.33:5060>
tid=03950393A79343D4439ec3.0 cseq=UPDATE contact=76800 at avaya.com:5061
<mailto:contact=76800 at avaya.com:5061>  / 1 from(wire) is for me
 ![2007-03-07 20:14:53.305] <2952:RESIP:TRANSACTION>  DEBUG |
TransactionUser.cxx:71 | Checking rule...
 ![2007-03-07 20:14:53.305] <2952:RESIP:TRANSACTION>  DEBUG |
MessageFilterRule.cxx:70 | Matching rule for: 

 
UPDATE sip:56000 at 135.8.116.33:5060 SIP/2.0
 
Via: SIP/2.0/UDP
135.8.52.181:5060;branch=z9hG4bK83A503034493935543998a.0
 
Via: SIP/2.0/TLS
avaya.com;psrrposn=1;received=135.8.83.172;branch=z9hG4bK80945f2f40dddb1
c1b46f94dc00
 
Max-Forwards: 69
 
Record-Route: <sip:135.8.52.181:5060;lr>
 
Contact: "  CONFERENCE
2"<sip:76800 at avaya.com:5061;transport=tls>;isfocus
 
To: "IC 7.1 B2B" <sip:56000 at avaya.com>;tag=b855e212
 
From: sip:76800 at avaya.com;tag=0945f2f40dddb181b46f94dc00
 
Call-ID: ZDU4Yjg4M2UxYTE1MjRiNzJkZTU3ZWMzYmNlMjZlZjk.
 
CSeq: 1 UPDATE
 
Session-Expires: 240;refresher=uac
 
Min-SE: 240
 
Allow: INVITE, CANCEL, BYE, ACK, PRACK, SUBSCRIBE, NOTIFY, REFER,
OPTIONS
 
Supported: 100rel, timer, replaces, join, histinfo
 
User-Agent: Avaya CM/R013x.01.2.632.1
 
Content-Length: 0
 
 
 

 ![2007-03-07 20:14:53.383] <2952:RESIP:TRANSACTION>  DEBUG |
MessageFilterRule.cxx:241 | MSG User = 56000
 ![2007-03-07 20:14:53.383] <2952:RESIP:TRANSACTION>  DEBUG |
MessageFilterRule.cxx:252 | List USER = 56000
 ![2007-03-07 20:14:53.383] <2952:RESIP:TRANSACTION>  DEBUG |
TransactionUser.cxx:74 | Match!
 ![2007-03-07 20:14:53.383] <2952:RESIP>  DEBUG | Helper.cxx:372 |
Helper::makeResponse(SipReq:  UPDATE 56000 at 135.8.116.33:5060
<mailto:56000 at 135.8.116.33:5060>  tid=83A503034493935543998a.0
cseq=UPDATE contact=76800 at avaya.com:5061
<mailto:contact=76800 at avaya.com:5061>  / 1 from(wire) code=100 reason=
 ![2007-03-07 20:14:53.383] <2952:RESIP:TRANSACTION>  DEBUG |
TimerQueue.cxx:85 | Adding timer: Timer Trying
tid=83A503034493935543998a.0 ms=3500
 ![2007-03-07 20:14:53.383] <2952:RESIP:TRANSACTION>  DEBUG |
TransactionState.cxx:1852 | Send to TU: TU: DialogUsageManager size=0 
 
UPDATE sip:56000 at 135.8.116.33:5060 SIP/2.0
 
Via: SIP/2.0/UDP
135.8.52.181:5060;branch=z9hG4bK83A503034493935543998a.0
 
Via: SIP/2.0/TLS
avaya.com;psrrposn=1;received=135.8.83.172;branch=z9hG4bK80945f2f40dddb1
c1b46f94dc00
 
Max-Forwards: 69
 
Record-Route: <sip:135.8.52.181:5060;lr>
 
Contact: "  CONFERENCE
2"<sip:76800 at avaya.com:5061;transport=tls>;isfocus
 
To: "IC 7.1 B2B" <sip:56000 at avaya.com>;tag=b855e212
 
From: sip:76800 at avaya.com;tag=0945f2f40dddb181b46f94dc00
 
Call-ID: ZDU4Yjg4M2UxYTE1MjRiNzJkZTU3ZWMzYmNlMjZlZjk.
 
CSeq: 1 UPDATE
 
Session-Expires: 240;refresher=uac
 
Min-SE: 240
 
Allow: INVITE, CANCEL, BYE, ACK, PRACK, SUBSCRIBE, NOTIFY, REFER,
OPTIONS
 
Supported: 100rel, timer, replaces, join, histinfo
 
User-Agent: Avaya CM/R013x.01.2.632.1
 
Content-Length: 0
 
 
 

 ![2007-03-07 20:14:53.383] <2840:RESIP:DUM>  INFO |
DialogUsageManager.cxx:1190 | Got: SipReq:  UPDATE
56000 at 135.8.116.33:5060 <mailto:56000 at 135.8.116.33:5060>
tid=83A503034493935543998a.0 cseq=UPDATE contact=76800 at avaya.com:5061
<mailto:contact=76800 at avaya.com:5061>  / 1 from(wire)
 ![2007-03-07 20:14:53.399] <2840:RESIP:DUM>  DEBUG |
DialogUsageManager.cxx:1456 | DialogUsageManager::processRequest:
SipReq:  UPDATE 56000 at 135.8.116.33:5060 <mailto:56000 at 135.8.116.33:5060>
tid=83A503034493935543998a.0 cseq=UPDATE contact=76800 at avaya.com:5061
<mailto:contact=76800 at avaya.com:5061>  / 1 from(wire)
 ![2007-03-07 20:14:53.399] <2840:RESIP:DUM>  INFO |
DialogUsageManager.cxx:1516 | Handling in-dialog request: SipReq:
UPDATE 56000 at 135.8.116.33:5060 <mailto:56000 at 135.8.116.33:5060>
tid=83A503034493935543998a.0 cseq=UPDATE contact=76800 at avaya.com:5061
<mailto:contact=76800 at avaya.com:5061>  / 1 from(wire)
 ![2007-03-07 20:14:53.399] <2840:RESIP:DUM>  DEBUG | DialogId.cxx:50 |
DialogId::DialogId:
ZDU4Yjg4M2UxYTE1MjRiNzJkZTU3ZWMzYmNlMjZlZjk.-b855e212-0945f2f40dddb181b4
6f94dc00
 ![2007-03-07 20:14:53.399] <2840:RESIP:DUM>  DEBUG | DialogSet.cxx:428
| Found matching dialog mClientSubscriptions(0), mServerSubscriptions(0)
for 
 
UPDATE sip:56000 at 135.8.116.33:5060 SIP/2.0
 
Via: SIP/2.0/UDP
135.8.52.181:5060;branch=z9hG4bK83A503034493935543998a.0
 
Via: SIP/2.0/TLS
avaya.com;psrrposn=1;received=135.8.83.172;branch=z9hG4bK80945f2f40dddb1
c1b46f94dc00
 
Max-Forwards: 69
 
Record-Route: <sip:135.8.52.181:5060;lr>
 
Contact: "  CONFERENCE
2"<sip:76800 at avaya.com:5061;transport=tls>;isfocus
 
To: "IC 7.1 B2B"<sip:56000 at avaya.com>;tag=b855e212
 
From: <sip:76800 at avaya.com>;tag=0945f2f40dddb181b46f94dc00
 
Call-ID: ZDU4Yjg4M2UxYTE1MjRiNzJkZTU3ZWMzYmNlMjZlZjk.
 
CSeq: 1 UPDATE
 
Session-Expires: 240;refresher=uac
 
Min-SE: 240
 
Allow: INVITE, CANCEL, BYE, ACK, PRACK, SUBSCRIBE, NOTIFY, REFER,
OPTIONS
 
Supported: 100rel, timer, replaces, join, histinfo
 
User-Agent: Avaya CM/R013x.01.2.632.1
 
Content-Length: 0
 
 
 

 ![2007-03-07 20:14:53.399] <2840:RESIP:DUM>  DEBUG | Dialog.cxx:315 |
Dialog::dispatch: SipReq:  UPDATE 56000 at 135.8.116.33:5060
<mailto:56000 at 135.8.116.33:5060>  tid=83A503034493935543998a.0
cseq=UPDATE contact=76800 at avaya.com:5061
<mailto:contact=76800 at avaya.com:5061>  / 1 from(wire)
 ![2007-03-07 20:14:53.399] <2840:RESIP>  DEBUG | Helper.cxx:372 |
Helper::makeResponse(SipReq:  UPDATE 56000 at 135.8.116.33:5060
<mailto:56000 at 135.8.116.33:5060>  tid=83A503034493935543998a.0
cseq=UPDATE contact=76800 at avaya.com:5061
<mailto:contact=76800 at avaya.com:5061>  / 1 from(wire) code=200 reason=
 ![2007-03-07 20:14:53.399] <2840:RESIP:DUM>  DEBUG | Dialog.cxx:984 |
Dialog::makeResponse: 
 
SIP/2.0 200 OK
 
Via: SIP/2.0/UDP
135.8.52.181:5060;branch=z9hG4bK83A503034493935543998a.0
 
Via: SIP/2.0/TLS
avaya.com;psrrposn=1;received=135.8.83.172;branch=z9hG4bK80945f2f40dddb1
c1b46f94dc00
 
Record-Route: <sip:135.8.52.181:5060;lr>
 
Contact: <sip:56000>
 
To: "IC 7.1 B2B"<sip:56000 at avaya.com>;tag=b855e212
 
From: <sip:76800 at avaya.com>;tag=0945f2f40dddb181b46f94dc00
 
Call-ID: ZDU4Yjg4M2UxYTE1MjRiNzJkZTU3ZWMzYmNlMjZlZjk.
 
CSeq: 1 UPDATE
 
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, UPDATE, NOTIFY
 
Content-Length: 0
 
 
 

 ![2007-03-07 20:14:53.399] <2840:RESIP:APP>  INFO | UserAgent.cpp:2146
| sip:76800 at avaya.com CUserAgent::onReadyToSend(CISH) on session 23 -
SipResp: 200 tid=83A503034493935543998a.0 cseq=UPDATE contact=56000 / 1
from(tu)
 ![2007-03-07 20:14:53.399] <2840:RESIP:APP>  INFO | UserAgent.cpp:2147
| NO OP
 ![2007-03-07 20:14:53.399] <2840:RESIP:DUM>  DEBUG |
DialogUsageManager.cxx:800 | SEND: 
 
SIP/2.0 200 OK
 
Via: SIP/2.0/UDP
135.8.52.181:5060;branch=z9hG4bK83A503034493935543998a.0
 
Via: SIP/2.0/TLS
avaya.com;psrrposn=1;received=135.8.83.172;branch=z9hG4bK80945f2f40dddb1
c1b46f94dc00
 
Record-Route: <sip:135.8.52.181:5060;lr>
 
Contact: <sip:56000>
 
To: "IC 7.1 B2B"<sip:56000 at avaya.com>;tag=b855e212
 
From: <sip:76800 at avaya.com>;tag=0945f2f40dddb181b46f94dc00
 
Call-ID: ZDU4Yjg4M2UxYTE1MjRiNzJkZTU3ZWMzYmNlMjZlZjk.
 
CSeq: 1 UPDATE
 
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, UPDATE, NOTIFY
 
User-Agent: AvSIP 1.04.2
 
Content-Length: 0
 
 
 

 ![2007-03-07 20:14:53.399] <2840:RESIP>  DEBUG | SipStack.cxx:290 |
SEND: SipResp: 200 tid=83A503034493935543998a.0 cseq=UPDATE
contact=56000 / 1 from(tu)
 ![2007-03-07 20:14:53.414] <2952:RESIP:TRANSACTION>  DEBUG |
TimerQueue.cxx:85 | Adding timer: Timer J tid=83A503034493935543998a.0
ms=32000
 ![2007-03-07 20:14:53.414] <2952:RESIP:TRANSPORT>  DEBUG |
TransportSelector.cxx:521 | Looked up source for destination: [ V4
135.8.52.181:5060 UDP target domain=unspecified received on: Transport:
[ V4 0.0.0.0:5060 UDP target domain=unspecified connectionId=0 ]
connectionId=0 ] -> [ V4 135.8.116.33:0 UDP target domain=unspecified
received on: Transport: [ V4 0.0.0.0:5060 UDP target domain=unspecified
connectionId=0 ] connectionId=0 ] sent-by=135.8.52.181 sent-port=5060
 ![2007-03-07 20:14:53.414] <2952:RESIP:TRANSPORT>  DEBUG |
TransportSelector.cxx:869 | Transmitting to [ V4 135.8.52.181:5060 UDP
target domain=unspecified received on: Transport: [ V4 0.0.0.0:5060 UDP
target domain=unspecified connectionId=0 ] connectionId=0 ] tlsDomain=
via [ V4 135.8.116.33:5060 UDP target domain=unspecified received on:
Transport: [ V4 0.0.0.0:5060 UDP target domain=unspecified
connectionId=0 ] connectionId=0 ]
 
SIP/2.0 200 OK
 
Via: SIP/2.0/UDP
135.8.52.181:5060;branch=z9hG4bK83A503034493935543998a.0
 
Via: SIP/2.0/TLS
avaya.com;psrrposn=1;received=135.8.83.172;branch=z9hG4bK80945f2f40dddb1
c1b46f94dc00
 
Record-Route: <sip:135.8.52.181:5060;lr>
 
Contact: <sip:56000 at 135.8.116.33:5060>
 
To: "IC 7.1 B2B"<sip:56000 at avaya.com>;tag=b855e212
 
From: <sip:76800 at avaya.com>;tag=0945f2f40dddb181b46f94dc00
 
Call-ID: ZDU4Yjg4M2UxYTE1MjRiNzJkZTU3ZWMzYmNlMjZlZjk.
 
CSeq: 1 UPDATE
 
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, UPDATE, NOTIFY
 
User-Agent: AvSIP 1.04.2
 
Content-Length: 0
 
 
 

 ![2007-03-07 20:14:53.414] <2952:RESIP:TRANSPORT>  DEBUG |
Transport.cxx:213 | Adding message to tx buffer to: [ V4
135.8.52.181:5060 UDP target domain=unspecified received on: Transport:
[ V4 0.0.0.0:5060 UDP target domain=unspecified connectionId=0 ]
connectionId=0 ]

 
Bill Kovar
bkovar at avaya.com
Avaya, Inc.
(732) 852-2609
 
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://list.resiprocate.org/pipermail/resiprocate-devel/attachments/20070307/acc647a1/attachment.htm>


More information about the resiprocate-devel mailing list