| < Previous by Date | Date Index | Next by Date > |
| < Previous in Thread | Thread Index | Next in Thread > |
|
My full answer is stuck in the
moderator queue, but until then here is the snapshot of the resip logs up to
the crash point showing the empty username To/From and also the crash. I
removed the Dialog map dump since it was massive (where HUGE AMOUNTS OF DATA
REMOVED is replaced) SIP:
[.\DialogUsageManager.cxx:1299] Got: SipResp: 408 tid=151dd73cc5746622
cseq=SUBSCRIBE / 2 from(wire) SIP:
[.\DialogUsageManager.cxx:1923] Looking for dialogSet:
NmE5YTJmMWVjYTAzNmFkYmYyMzBjOWExNWI2OWQyZmQ.-fe55553a in map: SIP: [.\DialogUsageManager.cxx:1924]
HUGE AMOUNTS OF DATA REMOVED SIP:
[.\DialogUsageManager.cxx:1807] DialogUsageManager::processResponse: SipResp: 408
tid=151dd73cc5746622 cseq=SUBSCRIBE / 2 from(wire) SIP:
[.\ClientAuthManager.cxx:41] ClientAuthManager::handle: transitioning
NmE5YTJmMWVjYTAzNmFkYmYyMzBjOWExNWI2OWQyZmQ.-fe55553ato cached SIP:
[.\ClientAuthManager.cxx:198] ClientAuthManager::RealmState::transition from
current to cached SIP: [.\DialogId.cxx:50]
DialogId::DialogId: NmE5YTJmMWVjYTAzNmFkYmYyMzBjOWExNWI2OWQyZmQ.-fe55553a-4c3fe169 SIP: [.\DialogSet.cxx:472] No
matching dialog for SIP/2.0 408 Request Timeout Via: SIP/2.0/UDP
10.160.50.26:9001;branch=z9hG4bK-d8754z-151dd73cc5746622-1---d8754z-;rport To:
<sip:kristie.lomond@xxxxxxxxxxxxxxxxxx>;tag=4c3fe169 From: "Scott
Lomond"<sip:scott@xxxxxxxxxxxxxxxxxx>;tag=fe55553a Call-ID:
NmE5YTJmMWVjYTAzNmFkYmYyMzBjOWExNWI2OWQyZmQ. CSeq: 2 SUBSCRIBE Content-Length: 0 SIP: [.\Dialog.cxx:328]
Dialog::dispatch: SipResp: 408 tid=151dd73cc5746622 cseq=SUBSCRIBE / 2 from(wire) SIP: [.\Handled.cxx:16]
&&&&&& Handled::Handled 1457 this(0AD77060) 0349A028 SIP:
[.\ClientSubscription.cxx:33] ClientSubscription::ClientSubscription from
SipReq: SUBSCRIBE kristie.lomond@xxxxxxxxxxxxxxxxxx tid=151dd73cc5746622
cseq=SUBSCRIBE contact=scott / 2 from(tu) SIP: [.\Dialog.cxx:962]
Dialog::makeRequest: SUBSCRIBE
sip:sip.sightspeed.com:5062 SIP/2.0 Via: SIP/2.0/
;branch=z9hG4bK-d8754z-18390c0d726d3a09-1---d8754z-;rport Max-Forwards: 70 Contact:
<sip:scott@xxxxxxxxxxxxx:6968> To:
<sip:kristie.lomond@xxxxxxxxxxxxxxxxxx>;tag=10.11374.1216071735.678374 From:
<sip:scott@xxxxxxxxxxxxxxxxxx>;tag=fe55553a Call-ID:
NmE5YTJmMWVjYTAzNmFkYmYyMzBjOWExNWI2OWQyZmQ. CSeq: 4 SUBSCRIBE Event: presence Content-Length: 0 SIP: [.\ClientSubscription.cxx:59]
ClientSubscription::dispatch SipResp: 408 tid=151dd73cc5746622 cseq=SUBSCRIBE /
2 from(wire) SIP:
[.\ClientSubscription.cxx:114] processing client subscription response SIP:
[.\ClientSubscription.cxx:168] Received 408 to SUBSCRIBE <sip:kristie.lomond@xxxxxxxxxxxxxxxxxx>;tag=10.11374.1216071735.678374 SIP:
[c:\source\6.5-stable\qvixapp\appsrc\pstn\sipep.cxx:2149] SightSpeedClient v.
6541-End-Point: ClientSubscription-onRequestRetry: SipResp: 408
tid=151dd73cc5746622 cseq=SUBSCRIBE / 2 from(wire) SIP:
[.\ClientSubscription.cxx:188] Application requested immediate retry on
Retry-After SIP: [.\BaseCreator.cxx:140]
BaseCreator::makeInitialRequest: 0CEC00E8 SIP: [.\DialogSet.cxx:52]
************* Created DialogSet(UAC) -- NGM5YTI4Y2Q5ZWYwM2M5MGRjZDc5NzBiMDY0NDc3OTQ.-961e9d0e************* SIP:
[.\DialogUsageManager.cxx:471] ************* Adding DialogSet *************** SIP:
[.\DialogUsageManager.cxx:472] Before: HUGE AMOUNTS OF DATA REMOVED SIP:
[.\DialogUsageManager.cxx:474] After: HUGE AMOUNTS OF DATA REMOVED SIP:
[.\DialogUsageManager.cxx:1923] Looking for dialogSet:
NGM5YTI4Y2Q5ZWYwM2M5MGRjZDc5NzBiMDY0NDc3OTQ.-961e9d0e in map: SIP:
[.\DialogUsageManager.cxx:1924] HUGE AMOUNTS OF DATA REMOVED SIP:
[.\DialogUsageManager.cxx:832] SEND: SUBSCRIBE sip:sip.sightspeed.com:5062
SIP/2.0 Via: SIP/2.0/
;branch=z9hG4bK-d8754z-4214e518714fc165-1---d8754z-;rport Max-Forwards: 70 Contact: <sip:> To:
<sip:sip.sightspeed.com:5062> From: <sip:>;tag=961e9d0e Call-ID:
NGM5YTI4Y2Q5ZWYwM2M5MGRjZDc5NzBiMDY0NDc3OTQ. CSeq: 1 SUBSCRIBE Expires: 3600 User-Agent: SightSpeedClient v.
6541 Event: presence Content-Length: 0 SIP:
[.\DialogUsageManager.cxx:1923] Looking for dialogSet:
NGM5YTI4Y2Q5ZWYwM2M5MGRjZDc5NzBiMDY0NDc3OTQ.-961e9d0e in map: SIP: [.\DialogUsageManager.cxx:1924]
HUGE AMOUNTS OF DATA REMOVED SIP: [.\DialogId.cxx:50]
DialogId::DialogId: NGM5YTI4Y2Q5ZWYwM2M5MGRjZDc5NzBiMDY0NDc3OTQ.-961e9d0e- SIP:
[.\DialogUsageManager.cxx:965] Send: SipReq: SUBSCRIBE sip.sightspeed.com:5062
tid=4214e518714fc165 cseq=SUBSCRIBE contact= / 1 from(tu) SIP: [.\SipStack.cxx:307] SEND:
SipReq: SUBSCRIBE sip.sightspeed.com:5062 tid=4214e518714fc165 cseq=SUBSCRIBE
contact= / 1 from(tu) SIP: [.\Handled.cxx:23]
&&&&&& ~Handled 1457 this(0AD77060) 0349A028 SIP: [.\Dialog.cxx:328] Dialog::dispatch:
SipResp: 408 tid=151dd73cc5746622 cseq=SUBSCRIBE / 2 from(wire) SIP:
[.\ClientSubscription.cxx:59] ClientSubscription::dispatch SipResp: 408
tid=151dd73cc5746622 cseq=SUBSCRIBE / 2 from(wire) SIP:
[.\ClientSubscription.cxx:114] processing client subscription response SIP:
[.\ClientSubscription.cxx:168] Received 408 to SUBSCRIBE
<sip:kristie.lomond@xxxxxxxxxxxxxxxxxx>;tag=10.11385.1216071758.680732 SIP:
[c:\source\6.5-stable\qvixapp\appsrc\pstn\sipep.cxx:2149] SightSpeedClient v.
6541-End-Point: ClientSubscription-onRequestRetry: SipResp: 408
tid=151dd73cc5746622 cseq=SUBSCRIBE / 2 from(wire) SIP:
[.\ClientSubscription.cxx:188] Application requested immediate retry on
Retry-After <<<<<Crash Occurred
Now>>>>> -Aron From: Scott Godin
[mailto:slgodin@xxxxxxxxxxxx] … From: Aron Rosenberg
[mailto:arosenberg@xxxxxxxxxxxxxx] I get an empty To/From since the
presence server (OpenSER) puts only the ip:port or domain name as the
Contact header in the dialog. Contact:
<sip:sip.sightspeed.com> or <sip:123.123.123.123:5060> If the dialog/transaction then
times-out (408) the onRequestRetry callback is called. Our code returns 0
(please retry transaction). In this case the mRemoteTarget contained the
original contact header (just domain name or ip:port) and this value is then
used as the new “To” header when the ClientSubscription.cxx code calls
makeSubscription for us. We then have a To/From header which is missing the
“user” field of the original request. [Scott] – OK that makes sense –
the whole To/From header is not empty – just the username portion.
BTW: What message are you getting with the Contact header in it, if you
are receiving a 408? Can you attach the pcap trace and relevant portions
only (ie. Last few messages processed before the crash) of the resip logs? As for the “end”. We call end
off the subscription handle at some point in the future (i.e. when the user is
logging out) [Scott] – OK – so in step 1 you
actually successfully subscribing, then time passes, and the user “logs out”
then we move to step 2 from below? -Aron From: Scott Godin
[mailto:slgodin@xxxxxxxxxxxx] The NULL mAppDialogSet pointer
issues aside – I’m a little confused how you are getting the empty From/To
header. From the code it seems that if mRemoteTarget is set (ie. Host is
non-empty) then it will use that, otherwise it will use
mLastRequest->header(h_To). How does it end up being empty? Also – from your step 2 below,
you say: Ø
Client ends the
subscription by invoking end() on the handle What handle are you referring
to? I don’t think you should even have a client subscription handle until
the first notify arrives and you get your first callback
(onNewSubscription). Scott From:
resiprocate-devel-bounces@xxxxxxxxxxxxxxx
[mailto:resiprocate-devel-bounces@xxxxxxxxxxxxxxx] On Behalf Of Aron
Rosenberg Here is a simple patch which I
believe addresses part of the issue we are seeing. Index:
resip/dum/ClientSubscription.cxx =================================================================== ---
resip/dum/ClientSubscription.cxx (revision 8133) +++
resip/dum/ClientSubscription.cxx (working copy) @@ -78,10 +78,7 @@
if (!mOnNewSubscriptionCalled && !getAppDialogSet()->isReUsed())
{
InfoLog (<< "[ClientSubscription] " <<
mLastRequest->header(h_To)); -
if (msg.exists(h_Contacts)) -
{ -
mDialog.mRemoteTarget = msg.header(h_Contacts).front(); -
} +
mDialog.mRemoteTarget = msg.header(h_To);
handler->onNewSubscription(getHandle(), msg);
mOnNewSubscriptionCalled = true; -- The original symptom of an empty
From/To header was caused by the mRemoteTarget being set with the contact
address which is almost always (IP:Port) or just (DNS name:port). The mRemoteTarget
was then used to build the resubscribe if you requested it which resulted in
the empty to/from username. I believe that all the if…else
cases which tested mRemoteTarget for Uri / Host values aren’t needed if the
above is fixed properly. There is still the issue that
the getAppDialogSet() crashes since the pointer is NULL -Aron From:
resiprocate-devel-bounces@xxxxxxxxxxxxxxx
[mailto:resiprocate-devel-bounces@xxxxxxxxxxxxxxx] On Behalf Of Aron
Rosenberg I was finally able to get
a working pcap, resip log and debug crash at the same time. Here is what is
going on 1.
Client makes
subscription 2.
Client ends the
subscription by invoking end() on the handle 3.
This end results in
a local 408 error, which calls onRequestRetry 4.
Our code returns 0
to onRequestRetry(ClientSubscriptionHandle) to retry the request since we want
the server to know we ended the sub 5.
"Application requested immediate retry on Retry-After" is printed to log 6.
Crash happens in the
else statement in ClientSubscription.cxx:198 when trying to call getAppDialogSet()->reuse(). I have a full log (over 100MB of
resip data which I can send to a developer who wants to look at it along with
the matching pcap error file -Aron From:
resiprocate-devel-bounces@xxxxxxxxxxxxxxx
[mailto:resiprocate-devel-bounces@xxxxxxxxxxxxxxx] On Behalf Of Aron
Rosenberg Here is a little bit more
information gleaned from a pcap trace. The stack seems to be crashing
when dealing with a 400 error where the “From:” header looks like this “From: <sip:>;tag=5b461e50” I was able to find the outbound
SUBSCRIBE request and it also has an empty From address so something strange is
going on in the stack. Still working on getting the resip logs. -Aron From:
resiprocate-devel-bounces@xxxxxxxxxxxxxxx [mailto:resiprocate-devel-bounces@xxxxxxxxxxxxxxx]
On Behalf Of Aron Rosenberg Resip ver: SVN rev 8128 on 1.3 branch Call Stack: resip::AppDialogSet::getHandle() Line 22 + 0x3 bytes C++ The crash is because the appDialogSet returned in
DialogUsage::getAppDialogSet() is NULL. It came from our production client and is reasonable
repeatable, so I am working on getting the resip logs that would go with it. -Aron --------------------------------------------- Aron Rosenberg Founder and CTO SightSpeed - http://www.sightspeed.com/ 918 Parker St, Suite A14 Berkeley, CA 94710 Email: arosenberg@xxxxxxxxxxxxxx Phone: 510-665-2920 Cell: 510-847-7389 Fax: 510-649-9569 SightSpeed Video Link: http://aron.sightspeed.com |