< Previous by Date Date Index Next by Date >
  Thread Index Next in Thread >

[reSIProcate] Issues with ClientSubscription issuing local 408 timeouts


So our implementation with ClientSubscription works most of the time, however every now and then when we create a new ClientSubscription about half of the requests will generate a local 408 even though the subscription was already created and ACK’ed and NOTIFY’ied.

 

Attached is the resip log without DNS or STATS catagories (we don’t log those in our application) for a single SUBSCRIBE request from aron@xxxxxxxxxxxxxxxxxx to roger@xxxxxxxxxxxxxxxxxx .

Also attached is a pcap file showing the full transaction with our OpenSER presence server.

 

The pcap and log file shows all the behavior:

 

SUBSCRIBE -> 202 OK -> NOTIFY -> 200 OK behavior. However, you will keep seeing the client issuing retransmissions on the initial SUBSCRIBE request even though the 202OK and NOTIFY came in.

 

Any help would be appreciated. It seems like a second AppDialog set is getting created if you look at the resip log, but I can’t figure out why it wasn’t matching the first one, or why this is a transient issue that doesn’t happen all the time (or if it is an OpenSER issue)

 

Resiprocate version is 1.0 with most of the patches that made it into 1.1. Will try a fully up2date head version too see if this exists in the latest version

 

-Aron

 

 

 

 

 

Attachment: resip_subscribe.pcap
Description: resip_subscribe.pcap

SIP: [c:\source\6.0\qvixapp\appsrc\pstn\sipep.cxx:402] 
SS-SUBS-presence-sip:aron@xxxxxxxxxxxxxxxxxxxxxx:roger@xxxxxxxxxxxxxxxxxx: 
creating AppDialogSet 28
SIP: [.\BaseCreator.cxx:127] BaseCreator::makeInitialRequest: 02BBC468
SIP: [.\DialogSet.cxx:52]  ************* Created DialogSet(UAC)  -- 
MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.-0d484236*************
SIP: [.\DialogUsageManager.cxx:800] SEND: SUBSCRIBE 
sip:roger@xxxxxxxxxxxxxxxxxx SIP/2.0

Via: SIP/2.0/ ;branch=z9hG4bK-d87543-b37be75f232aa925-1--d87543-;rport

Max-Forwards: 70

Contact: <sip:aron>

To: <sip:roger@xxxxxxxxxxxxxxxxxx>

From: "Aron Rosenberg"<sip:aron@xxxxxxxxxxxxxxxxxx>;tag=0d484236

Call-ID: MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.

CSeq: 1 SUBSCRIBE

Expires: 1180

User-Agent: SightSpeedClient v. 6086

Event: presence

Content-Length: 0




SIP: [.\DialogId.cxx:50] DialogId::DialogId: 
MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.-0d484236-
SIP: [.\DialogUsageManager.cxx:912] Using outbound proxy: 
sip:67.133.32.41:5062;lr -> SipReq:  SUBSCRIBE roger@xxxxxxxxxxxxxxxxxx 
tid=b37be75f232aa925 cseq=SUBSCRIBE contact=aron / 1 from(tu)
SIP: [.\TimerQueue.cxx:85] Adding timer: Timer F tid=b37be75f232aa925 ms=32000
SIP: [.\TimerQueue.cxx:85] Adding timer: Timer E1 tid=b37be75f232aa925 ms=500
SIP: [.\TransportSelector.cxx:525] Looked up source for destination: [ V4 
67.133.32.41:5062 UDP target domain=67.133.32.41 connectionId=0 ] -> [ V4 
10.160.50.26:0 UDP target domain=67.133.32.41 connectionId=0 ] sent-by= 
sent-port=0
SIP: [.\TransportSelector.cxx:971] findTransportBySource([ V4 10.160.50.26:0 
UDP target domain=67.133.32.41 connectionId=0 ])
SIP: [.\TransportSelector.cxx:1083] findTransport (any port, any interface) => 
Transport: [ V4 0.0.0.0:9027 UDP target domain=unspecified connectionId=0 ]
SIP: [.\TransportSelector.cxx:766] Transmitting to [ V4 67.133.32.41:5062 UDP 
target domain=67.133.32.41 received on: Transport: [ V4 0.0.0.0:9027 UDP target 
domain=unspecified connectionId=0 ] connectionId=0 ] tlsDomain= via [ V4 
10.160.50.26:9027 UDP target domain=67.133.32.41 connectionId=0 ]SUBSCRIBE 
sip:roger@xxxxxxxxxxxxxxxxxx SIP/2.0

Via: SIP/2.0/UDP 
10.160.50.26:9027;branch=z9hG4bK-d87543-b37be75f232aa925-1--d87543-;rport

Max-Forwards: 70

Contact: <sip:aron@xxxxxxxxxxxx:9027>

To: <sip:roger@xxxxxxxxxxxxxxxxxx>

From: "Aron Rosenberg"<sip:aron@xxxxxxxxxxxxxxxxxx>;tag=0d484236

Call-ID: MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.

CSeq: 1 SUBSCRIBE

Expires: 1180

User-Agent: SightSpeedClient v. 6086

Event: presence

Content-Length: 0




SIP: [.\Transport.cxx:209] Adding message to tx buffer to: [ V4 
67.133.32.41:5062 UDP target domain=67.133.32.41 received on: Transport: [ V4 
0.0.0.0:9027 UDP target domain=unspecified connectionId=0 ] connectionId=0 ]
SIP: [.\TransactionState.cxx:1721] Send to TU: TU: DialogUsageManager size=0 
SIP/2.0 401 Unauthorized

Via: SIP/2.0/UDP 
10.160.50.26:9027;branch=z9hG4bK-d87543-b37be75f232aa925-1--d87543-;rport=38110;received=65.241.182.51

To: <sip:roger@xxxxxxxxxxxxxxxxxx>;tag=ff2fecb8e293e16df3bfb4bc73d9ff07.c3bc

From: "Aron Rosenberg"<sip:aron@xxxxxxxxxxxxxxxxxx>;tag=0d484236

Call-ID: MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.

CSeq: 1 SUBSCRIBE

Server: SightSpeed (prod) v. 6052

WWW-Authenticate: Digest realm="sip.sightspeed.com", 
nonce="469bcaf0b631f35459cea1ce68598e39e4ce6ebd"

Content-Length: 0




SIP: [.\TimerQueue.cxx:85] Adding timer: Timer K tid=b37be75f232aa925 ms=5000
SIP: [.\DialogUsageManager.cxx:1190] Got: SipResp: 401 tid=b37be75f232aa925 
cseq=SUBSCRIBE / 1 from(wire)
SIP: [.\DialogUsageManager.cxx:1646] DialogUsageManager::processResponse: 
SipResp: 401 tid=b37be75f232aa925 cseq=SUBSCRIBE / 1 from(wire)
SIP: [.\ClientAuthManager.cxx:219] ClientAuthManager::RealmState::handleAuth: 
08E30D30 Digest 
realm="sip.sightspeed.com",nonce="469bcaf0b631f35459cea1ce68598e39e4ce6ebd" is 
proxy: 0
SIP: [.\ClientAuthManager.cxx:193] ClientAuthManager::RealmState::transition 
from invalid to current
SIP: [.\UserProfile.cxx:158] Found credential for realm: 
realm=sip.sightspeed.com user=aronsip.sightspeed.com
SIP: [.\ClientAuthManager.cxx:58] Produced response to digest challenge for 
UserProfile: "Aron 
Rosenberg"<sip:aron@xxxxxxxxxxxxxxxxxx>[realm=sip.sightspeed.com user=aron]
SIP: [.\DialogSet.cxx:244] about to re-send request with digest credentials
SIP: [.\ClientAuthManager.cxx:313]  Add auth, 08E30D30 in response to: Digest 
realm="sip.sightspeed.com",nonce="469bcaf0b631f35459cea1ce68598e39e4ce6ebd"
SIP: [.\ClientAuthManager.cxx:321] 
ClientAuthManager::RealmState::addAuthentication, proxy: 0 Digest 
username="aron",realm="sip.sightspeed.com",nonce="469bcaf0b631f35459cea1ce68598e39e4ce6ebd",uri="sip:roger@xxxxxxxxxxxxxxxxxx",response="8efc1326e84a0002c99208ca844aacd6",algorithm=MD5
SIP: [.\DialogUsageManager.cxx:800] SEND: SUBSCRIBE 
sip:roger@xxxxxxxxxxxxxxxxxx SIP/2.0

Via: SIP/2.0/ ;branch=z9hG4bK-d87543-fb1fd858af057b6e-1--d87543-;rport

Max-Forwards: 70

Contact: <sip:aron>

To: <sip:roger@xxxxxxxxxxxxxxxxxx>

From: "Aron Rosenberg"<sip:aron@xxxxxxxxxxxxxxxxxx>;tag=0d484236

Call-ID: MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.

CSeq: 2 SUBSCRIBE

Expires: 1180

User-Agent: SightSpeedClient v. 6086

Authorization: Digest 
username="aron",realm="sip.sightspeed.com",nonce="469bcaf0b631f35459cea1ce68598e39e4ce6ebd",uri="sip:roger@xxxxxxxxxxxxxxxxxx",response="8efc1326e84a0002c99208ca844aacd6",algorithm=MD5

Event: presence

Content-Length: 0




SIP: [.\DialogId.cxx:50] DialogId::DialogId: 
MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.-0d484236-
SIP: [.\DialogUsageManager.cxx:912] Using outbound proxy: 
sip:67.133.32.41:5062;lr -> SipReq:  SUBSCRIBE roger@xxxxxxxxxxxxxxxxxx 
tid=fb1fd858af057b6e cseq=SUBSCRIBE contact=aron / 2 from(tu)
SIP: [.\Transport.cxx:258] incoming from: [ V4 67.133.32.41:5062 UDP target 
domain=unspecified received on: Transport: [ V4 0.0.0.0:9027 UDP target 
domain=unspecified connectionId=0 ] connectionId=0 ]
SIP: [.\TimerQueue.cxx:85] Adding timer: Timer F tid=fb1fd858af057b6e ms=32000
SIP: [.\TimerQueue.cxx:85] Adding timer: Timer E1 tid=fb1fd858af057b6e ms=500
SIP: [.\TransportSelector.cxx:525] Looked up source for destination: [ V4 
67.133.32.41:5062 UDP target domain=67.133.32.41 connectionId=0 ] -> [ V4 
10.160.50.26:0 UDP target domain=67.133.32.41 connectionId=0 ] sent-by= 
sent-port=0
SIP: [.\TransportSelector.cxx:971] findTransportBySource([ V4 10.160.50.26:0 
UDP target domain=67.133.32.41 connectionId=0 ])
SIP: [.\TransportSelector.cxx:1083] findTransport (any port, any interface) => 
Transport: [ V4 0.0.0.0:9027 UDP target domain=unspecified connectionId=0 ]
SIP: [.\TransportSelector.cxx:766] Transmitting to [ V4 67.133.32.41:5062 UDP 
target domain=67.133.32.41 received on: Transport: [ V4 0.0.0.0:9027 UDP target 
domain=unspecified connectionId=0 ] connectionId=0 ] tlsDomain= via [ V4 
10.160.50.26:9027 UDP target domain=67.133.32.41 connectionId=0 ]SUBSCRIBE 
sip:roger@xxxxxxxxxxxxxxxxxx SIP/2.0

Via: SIP/2.0/UDP 
10.160.50.26:9027;branch=z9hG4bK-d87543-fb1fd858af057b6e-1--d87543-;rport

Max-Forwards: 70

Contact: <sip:aron@xxxxxxxxxxxx:9027>

To: <sip:roger@xxxxxxxxxxxxxxxxxx>

From: "Aron Rosenberg"<sip:aron@xxxxxxxxxxxxxxxxxx>;tag=0d484236

Call-ID: MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.

CSeq: 2 SUBSCRIBE

Expires: 1180

User-Agent: SightSpeedClient v. 6086

Authorization: Digest 
username="aron",realm="sip.sightspeed.com",nonce="469bcaf0b631f35459cea1ce68598e39e4ce6ebd",uri="sip:roger@xxxxxxxxxxxxxxxxxx",response="8efc1326e84a0002c99208ca844aacd6",algorithm=MD5

Event: presence

Content-Length: 0



SIP: [.\Transport.cxx:209] Adding message to tx buffer to: [ V4 
67.133.32.41:5062 UDP target domain=unspecified received on: Transport: [ V4 
0.0.0.0:9027 UDP target domain=unspecified connectionId=0 ] connectionId=0 ]
SIP: [.\TransactionUser.cxx:66] Checking if SipReq:  NOTIFY 
aron@xxxxxxxxxxxxx:38110 tid=9e8d.5e13ba04.0 cseq=NOTIFY 
contact=sip.sightspeed.com:5062 / 4 from(wire) is for me
SIP: [.\TransactionUser.cxx:71] Checking rule...
SIP: [.\MessageFilterRule.cxx:42] Matching rule for NOTIFY 
sip:aron@xxxxxxxxxxxxx:38110 SIP/2.0

Via: SIP/2.0/UDP 67.133.32.41:5062;branch=z9hG4bK9e8d.5e13ba04.0

Contact: <sip:sip.sightspeed.com:5062>

To: sip:aron@xxxxxxxxxxxxxxxxxx;tag=0d484236

From: sip:roger@xxxxxxxxxxxxxxxxxx;tag=10.6702.1184614852.18824075

Call-ID: MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.

CSeq: 4 NOTIFY

Content-Type: application/pidf+xml

User-Agent: SightSpeed (prod) v. 6052

Subscription-State: active;expires=1180

Event: presence

Content-Length: 0




SIP: [.\TransactionUser.cxx:74] Match!
SIP: [.\TransactionState.cxx:1721] Send to TU: TU: DialogUsageManager size=0 
NOTIFY sip:aron@xxxxxxxxxxxxx:38110 SIP/2.0

Via: SIP/2.0/UDP 67.133.32.41:5062;branch=z9hG4bK9e8d.5e13ba04.0

Contact: <sip:sip.sightspeed.com:5062>

To: sip:aron@xxxxxxxxxxxxxxxxxx;tag=0d484236

From: sip:roger@xxxxxxxxxxxxxxxxxx;tag=10.6702.1184614852.18824075

Call-ID: MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.

CSeq: 4 NOTIFY

Content-Type: application/pidf+xml

User-Agent: SightSpeed (prod) v. 6052

Subscription-State: active;expires=1180

Event: presence

Content-Length: 0




SIP: [.\DialogUsageManager.cxx:1190] Got: SipReq:  NOTIFY 
aron@xxxxxxxxxxxxx:38110 tid=9e8d.5e13ba04.0 cseq=NOTIFY 
contact=sip.sightspeed.com:5062 / 4 from(wire)
SIP: [.\DialogUsageManager.cxx:1456] DialogUsageManager::processRequest: 
SipReq:  NOTIFY aron@xxxxxxxxxxxxx:38110 tid=9e8d.5e13ba04.0 cseq=NOTIFY 
contact=sip.sightspeed.com:5062 / 4 from(wire)
SIP: [.\DialogUsageManager.cxx:1516] Handling in-dialog request: SipReq:  
NOTIFY aron@xxxxxxxxxxxxx:38110 tid=9e8d.5e13ba04.0 cseq=NOTIFY 
contact=sip.sightspeed.com:5062 / 4 from(wire)
SIP: [.\DialogId.cxx:50] DialogId::DialogId: 
MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.-0d484236-10.6702.1184614852.18824075
SIP: [.\DialogSet.cxx:719] Creating a new Dialog from msg: NOTIFY 
sip:aron@xxxxxxxxxxxxx:38110 SIP/2.0

Via: SIP/2.0/UDP 67.133.32.41:5062;branch=z9hG4bK9e8d.5e13ba04.0

Contact: <sip:sip.sightspeed.com:5062>

To: <sip:aron@xxxxxxxxxxxxxxxxxx>;tag=0d484236

From: <sip:roger@xxxxxxxxxxxxxxxxxx>;tag=10.6702.1184614852.18824075

Call-ID: MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.

CSeq: 4 NOTIFY

Content-Type: application/pidf+xml

User-Agent: SightSpeed (prod) v. 6052

Subscription-State: active;expires=1180

Event: presence

Content-Length: 0




SIP: [.\Dialog.cxx:87] UAS dialog ID creation, DS: 
MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.-0d484236
SIP: [.\DialogId.cxx:63] DialogId::DialogId: 
MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.-0d484236-10.6702.1184614852.18824075
SIP: [.\Dialog.cxx:129] ************** Created Dialog as UAS **************
SIP: [.\Dialog.cxx:130] mRemoteNameAddr: 
<sip:roger@xxxxxxxxxxxxxxxxxx>;tag=10.6702.1184614852.18824075
SIP: [.\Dialog.cxx:131] mLocalNameAddr: 
<sip:aron@xxxxxxxxxxxxxxxxxx>;tag=0d484236
SIP: [.\Dialog.cxx:132] mLocalContact: <sip:aron@xxxxxxxxxxxxx:38110>
SIP: [.\Dialog.cxx:133] mRemoteTarget: <sip:sip.sightspeed.com:5062>
SIP: [.\Dialog.cxx:214] Dialog::Dialog 
MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.-0d484236-10.6702.1184614852.18824075
SIP: [.\DialogSet.cxx:757] ### Calling CreateAppDialog ### NOTIFY 
sip:aron@xxxxxxxxxxxxx:38110 SIP/2.0

Via: SIP/2.0/UDP 67.133.32.41:5062;branch=z9hG4bK9e8d.5e13ba04.0

Contact: <sip:sip.sightspeed.com:5062>

To: <sip:aron@xxxxxxxxxxxxxxxxxx>;tag=0d484236

From: <sip:roger@xxxxxxxxxxxxxxxxxx>;tag=10.6702.1184614852.18824075

Call-ID: MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.

CSeq: 4 NOTIFY

Content-Type: application/pidf+xml

User-Agent: SightSpeed (prod) v. 6052

Subscription-State: active;expires=1180

Event: presence

Content-Length: 0




SIP: [c:\source\6.0\qvixapp\appsrc\pstn\sipep.cxx:385] 
SS-SUBS-presence-sip:aron@xxxxxxxxxxxxxxxxxxxxxx:roger@xxxxxxxxxxxxxxxxxx: 
ssAppDialog: created.
SIP: [c:\source\6.0\qvixapp\appsrc\pstn\sipep.cxx:415] 
SS-SUBS-presence-sip:aron@xxxxxxxxxxxxxxxxxxxxxx:roger@xxxxxxxxxxxxxxxxxx: 
createAppDialog.
SIP: [.\Dialog.cxx:300] Dialog::dispatch: SipReq:  NOTIFY 
aron@xxxxxxxxxxxxx:38110 tid=9e8d.5e13ba04.0 cseq=NOTIFY 
contact=sip.sightspeed.com:5062 / 4 from(wire)
SIP: [.\KeepAliveManager.cxx:40] Association added for [ V4 67.133.32.41:5062 
UDP target domain=unspecified received on: Transport: [ V4 0.0.0.0:9027 UDP 
target domain=unspecified connectionId=0 ] connectionId=0 ]
SIP: [.\Dialog.cxx:489] Making subscription (from creator) request: SUBSCRIBE 
sip:roger@xxxxxxxxxxxxxxxxxx SIP/2.0

Via: SIP/2.0/ ;branch=z9hG4bK-d87543-fb1fd858af057b6e-1--d87543-;rport

Max-Forwards: 70

Contact: <sip:aron>

To: <sip:roger@xxxxxxxxxxxxxxxxxx>

From: "Aron Rosenberg"<sip:aron@xxxxxxxxxxxxxxxxxx>;tag=0d484236

Call-ID: MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.

CSeq: 2 SUBSCRIBE

Expires: 1180

User-Agent: SightSpeedClient v. 6086

Authorization: Digest 
username="aron",realm="sip.sightspeed.com",nonce="469bcaf0b631f35459cea1ce68598e39e4ce6ebd",uri="sip:roger@xxxxxxxxxxxxxxxxxx",response="8efc1326e84a0002c99208ca844aacd6",algorithm=MD5

Event: presence

Content-Length: 0




SIP: [.\ClientSubscription.cxx:33] ClientSubscription::ClientSubscription from 
SipReq:  SUBSCRIBE roger@xxxxxxxxxxxxxxxxxx tid=fb1fd858af057b6e cseq=SUBSCRIBE 
contact=aron / 2 from(tu)
SIP: [.\Dialog.cxx:922] Dialog::makeRequest: SUBSCRIBE 
sip:sip.sightspeed.com:5062 SIP/2.0

Via: SIP/2.0/ ;branch=z9hG4bK-d87543-776bb34dd37ce74a-1--d87543-;rport

Max-Forwards: 70

Contact: <sip:aron@xxxxxxxxxxxxx:38110>

To: <sip:roger@xxxxxxxxxxxxxxxxxx>;tag=10.6702.1184614852.18824075

From: <sip:aron@xxxxxxxxxxxxxxxxxx>;tag=0d484236

Call-ID: MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.

CSeq: 2 SUBSCRIBE

Event: presence

Content-Length: 0




SIP: [.\ClientSubscription.cxx:59] ClientSubscription::dispatch SipReq:  NOTIFY 
aron@xxxxxxxxxxxxx:38110 tid=9e8d.5e13ba04.0 cseq=NOTIFY 
contact=sip.sightspeed.com:5062 / 4 from(wire)
SIP: [.\ClientSubscription.cxx:80] [ClientSubscription] 
<sip:roger@xxxxxxxxxxxxxxxxxx>;tag=10.6702.1184614852.18824075
SIP: [c:\source\6.0\qvixapp\appsrc\pstn\sipep.cxx:1729] SightSpeedClient v. 
6086-End-Point: ClientSubscription-onNewSubscription: SipReq:  NOTIFY 
aron@xxxxxxxxxxxxx:38110 tid=9e8d.5e13ba04.0 cseq=NOTIFY 
contact=sip.sightspeed.com:5062 / 4 from(wire)
SIP: [.\ClientSubscription.cxx:103] no queued notify
SIP: [.\ClientSubscription.cxx:282] No expires header in last request, set to 
1180
SIP: [.\TimerQueue.cxx:105] Adding application timer: DumTimeout::Subscription 
ClientSubscription sip:aron@xxxxxxxxxxxxxxxxxx: duration=1062 seq=1
SIP: [.\ClientSubscription.cxx:343] [ClientSubscription] reSUBSCRIBE in 1062
SIP: [c:\source\6.0\qvixapp\appsrc\pstn\sipep.cxx:1676] SightSpeedClient v. 
6086-End-Point: ClientSubscription-onUpdateActive: SipReq:  NOTIFY 
aron@xxxxxxxxxxxxx:38110 tid=9e8d.5e13ba04.0 cseq=NOTIFY 
contact=sip.sightspeed.com:5062 / 4 from(wire)
SIP: [c:\source\6.0\qvixapp\appsrc\pstn\sipep.cxx:986] Filtering for: 
sip:aron@xxxxxxxxxxxxxxxxxx

SIP: [c:\source\6.0\qvixapp\appsrc\pstn\sipep.cxx:990] Matching contact: 
sip:aron;rinstance=64635458464d3073

SIP: [.\Helper.cxx:302] Helper::makeResponse(SipReq:  NOTIFY 
aron@xxxxxxxxxxxxx:38110 tid=9e8d.5e13ba04.0 cseq=NOTIFY 
contact=sip.sightspeed.com:5062 / 4 from(wire) code=200 reason=
SIP: [.\Dialog.cxx:970] Dialog::makeResponse: SIP/2.0 200 OK

Via: SIP/2.0/UDP 67.133.32.41:5062;branch=z9hG4bK9e8d.5e13ba04.0

Contact: <sip:aron@xxxxxxxxxxxxx:38110>

To: <sip:aron@xxxxxxxxxxxxxxxxxx>;tag=0d484236

From: <sip:roger@xxxxxxxxxxxxxxxxxx>;tag=10.6702.1184614852.18824075

Call-ID: MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.

CSeq: 4 NOTIFY

Content-Length: 0




SIP: [.\DialogUsageManager.cxx:800] SEND: SIP/2.0 200 OK

Via: SIP/2.0/UDP 67.133.32.41:5062;branch=z9hG4bK9e8d.5e13ba04.0

Contact: <sip:aron@xxxxxxxxxxxxx:38110>

To: <sip:aron@xxxxxxxxxxxxxxxxxx>;tag=0d484236

From: <sip:roger@xxxxxxxxxxxxxxxxxx>;tag=10.6702.1184614852.18824075

Call-ID: MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.

CSeq: 4 NOTIFY

User-Agent: SightSpeedClient v. 6086

Content-Length: 0




SIP: [.\SipStack.cxx:278] SEND: SipResp: 200 tid=9e8d.5e13ba04.0 cseq=NOTIFY 
contact=aron@xxxxxxxxxxxxx:38110 / 4 from(tu)
SIP: [.\Transport.cxx:258] incoming from: [ V4 67.133.32.41:5062 UDP target 
domain=unspecified received on: Transport: [ V4 0.0.0.0:9027 UDP target 
domain=unspecified connectionId=0 ] connectionId=0 ]
SIP: [.\TimerQueue.cxx:85] Adding timer: Timer J tid=9e8d.5e13ba04.0 ms=32000
SIP: [.\TransportSelector.cxx:525] Looked up source for destination: [ V4 
67.133.32.41:5062 UDP target domain=unspecified received on: Transport: [ V4 
0.0.0.0:9027 UDP target domain=unspecified connectionId=0 ] connectionId=0 ] -> 
[ V4 10.160.50.26:0 UDP target domain=unspecified received on: Transport: [ V4 
0.0.0.0:9027 UDP target domain=unspecified connectionId=0 ] connectionId=0 ] 
sent-by=67.133.32.41 sent-port=5062
SIP: [.\TransportSelector.cxx:766] Transmitting to [ V4 67.133.32.41:5062 UDP 
target domain=unspecified received on: Transport: [ V4 0.0.0.0:9027 UDP target 
domain=unspecified connectionId=0 ] connectionId=0 ] tlsDomain= via [ V4 
10.160.50.26:9027 UDP target domain=unspecified received on: Transport: [ V4 
0.0.0.0:9027 UDP target domain=unspecified connectionId=0 ] connectionId=0 
]SIP/2.0 200 OK

Via: SIP/2.0/UDP 67.133.32.41:5062;branch=z9hG4bK9e8d.5e13ba04.0

Contact: <sip:aron@xxxxxxxxxxxxx:38110>

To: <sip:aron@xxxxxxxxxxxxxxxxxx>;tag=0d484236

From: <sip:roger@xxxxxxxxxxxxxxxxxx>;tag=10.6702.1184614852.18824075

Call-ID: MDIyNjI5ZWY4M2QxYmM1MGJjOTJkYzIwOGQwMGUzZjU.

CSeq: 4 NOTIFY

User-Agent: SightSpeedClient v. 6086

Content-Length: 0




SIP: [.\Transport.cxx:209] Adding message to tx buffer to: [ V4 
67.133.32.41:5062 UDP target domain=unspecified received on: Transport: [ V4 
0.0.0.0:9027 UDP target domain=unspecified connectionId=0 ] connectionId=0 ]
SIP: [.\TransactionUser.cxx:66] Checking if SipReq:  NOTIFY 
aron@xxxxxxxxxxxxx:38110 tid=0e51.8db7ed22.0 cseq=NOTIFY 
contact=sip.sightspeed.com:5062 / 4 from(wire) is for me
SIP: [.\TransactionUser.cxx:71] Checking rule...
SIP: [.\MessageFilterRule.cxx:42] Matching rule for NOTIFY 
sip:aron@xxxxxxxxxxxxx:38110 SIP/2.0