…
From: Aron Rosenberg [mailto:arosenberg@xxxxxxxxxxxxxx]
Sent: Tuesday, July 15, 2008 12:07 PM
To: Scott Godin; resiprocate-devel
Subject: RE: [reSIProcate] NULL Pointer crash with resip 1.3.3 - [PATCH] forpart of issue
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.
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?
[[Aron]] Attached is the relevant portions of the resip logs showing the crash and the pcap showing what I think is the right subscription and the subsequent failure and new “empty user” field To/From. I believe I got all the relevant pieces, but this was reduced from a 100MB file. I can post the entire resip log (100MB) and the full pcap file if you need it.
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]] Yes, a successful registration occurs. Time passes (from 1 to 30 seconds). We “end” it and that end results in a local 408 which calls onRequestRetry which we then return 0 too. Upon returning 0, DUM creates a new transaction to replay our 408’ed “end”. NULL pointer crash then occurs. There is another slight variant of this where instead of calling “end” after time passes, reSUBSCRIBE occurs and results in a local 408. In this case we get the empty user To/From also.
-Aron
From: Scott Godin [mailto:slgodin@xxxxxxxxxxxx]
Sent: Tuesday, July 15, 2008 6:50 AM
To: Aron Rosenberg; resiprocate-devel
Subject: RE: [reSIProcate] NULL Pointer crash with resip 1.3.3 - [PATCH] forpart of issue
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
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
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
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
Resip ver: SVN rev 8128 on 1.3 branch
Call Stack:
resip::AppDialogSet::getHandle() Line 22 + 0x3 bytes C++
resip::DialogUsage::getAppDialogSet() Line 38 + 0x18 bytes C++
resip::ClientSubscription::processResponse(const resip::SipMessage & msg={...}) Line 198 + 0x12 bytes C++
resip::ClientSubscription::dispatch(const resip::SipMessage & msg={...}) Line 117 C++
resip::Dialog::dispatch(const resip::SipMessage & msg={...}) Line 651 + 0x1a bytes C++
resip::DialogSet::dispatchToAllDialogs(const resip::SipMessage & msg={...}) Line 1028 C++
resip::DialogSet::dispatch(const resip::SipMessage & msg={...}) Line 608 C++
resip::DialogUsageManager::processResponse(const resip::SipMessage & response={...}) Line 1810 C++
resip::DialogUsageManager::incomingProcess(std::auto_ptr<resip::Message> msg=auto_ptr {tu=??? }) Line 1363 C++
resip::DialogUsageManager::internalProcess(std::auto_ptr<resip::Message> msg=auto_ptr {tu=??? }) Line 1190 C++
resip::DialogUsageManager::process(resip::RWMutex * mutex=0x00000000) Line 1390 + 0x49 bytes C++
SipEP::run() Line 3408 + 0xa 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
918 Parker St, Suite A14
Berkeley, CA 94710
Phone: 510-665-2920
Cell: 510-847-7389
Fax: 510-649-9569
<crash-log.txt><badfrom.pcap>