[reSIProcate] DNS performance tuning

Mon Jan 22 13:07:33 CST 2007

	I imagine you could be running into lazy-initialization delay. I  
know that at least the RRCache isn't initialized until the first  
access is attempted. I can look through the code when I get a free  
moment (unless someone else knows off the top of their head).

Best regards,
Byron Campen

> Answering my own question a bit, I put new logs at the beginning of
> DnsStub::query and the DnsStub::Query::Query constructor.  As you  
> would
> expect the constructor runs near instantaneously, but the delay occurs
> before DnsStub::query is called, 29 ms in this case.
>
> DEBUG | 20070122-122348.333 | dcmlaptop | SmSipMgr | RESIP:APP |  
> 2961 |
> 182419 | app.cpp:250 | ResipDns::lookup - waiting for results
> +++DnsStub::query: enter 1169490228.362918
> STACK | 20070122-122348.362 | dcmlaptop | SmSipMgr | RESIP:DNS |  
> 2961 |
> 158850 | dns/DnsStub.cxx:363 | Query ctor enter
> STACK | 20070122-122348.363 | dcmlaptop | SmSipMgr | RESIP:DNS |  
> 2961 |
> 158850 | dns/DnsStub.cxx:376 | DnsStub::Query::go:  
> _sip._udp.flammajobby.com
> type(enum): 33 proto: 1
>
>
> -----Original Message-----
> From: Dave Mason
> Sent: Monday, January 22, 2007 11:33 AM
> To: 'Byron Campen'
> Cc: resiprocate-devel at list.resiprocate.org
> Subject: RE: [reSIProcate] DNS performance tuning
>
> Oops, meant to point out in my last mail that the log in  
> DnsStub::Query::go
> is at the beginning of the method, so the delay has already  
> happened before
> that method starts.  My guess is there's some kind of overhead  
> involved,
> which hopefully I can move or deal with.
>
> Regards,
> Dave
>
> -----Original Message-----
> From: Byron Campen [mailto:bcampen at estacado.net]
> Sent: Monday, January 22, 2007 11:11 AM
> To: Dave Mason
> Cc: resiprocate-devel at list.resiprocate.org
> Subject: Re: [reSIProcate] DNS performance tuning
>
> 	Well, it looks like you don't have any SRV records in your DNS,
> which is what the resolver tries looking for first. When that  
> fails, it
> attempts an A query. So, you're having to wait for two DNS queries  
> to finish
> in sequence, which would explain some amount of delay. How much  
> delay are
> you seeing?
>
> Best regards,
> Byron Campen
>
>> Hi,
>> I picked up a development build from svn last week and the RRCache
>> code works great, thanks for the help on that one.  However, I'm  
>> still
>> seeing a big delay when DnsStub::Query::go: is first called.  Is this
>> because I'm specifying "transport=udp"?  Is there anything I can  
>> do to
>> reduce or eliminate this?  I keep a DnsInterface thread running
>> continuously for all my lookups so I don't need to restart it each
>> time.  I cant think of any problems with my mutex/condition that  
>> would
>> prevent Query::go from starting.
>>
>> Regards,
>> Dave
>>
>> Application code
>> ----------------
>> Constructor for singleton wrapper class:
>>    dns = new ResipDnsInterface(*stub);
>>    dns->run();
>>
>> Lookup code:
>>    Lock  lock(lookupCompleteMutex);
>>    Condition  dnsCond;
>>    DebugLog (<< "ResipDns::lookup - Looking up");
>>    dns->lookup(res, query.uri);
>>    DebugLog (<< "ResipDns::lookup - waiting for results");
>>    dnsCond.wait(lookupCompleteMutex); // signal sent from end of
>> DnsHandler::handle
>>    InfoLog (<< "ResipDns::lookup - DNS results for " << query.uri);
>>
>> Stack trace
>> -----------
>> DEBUG | 20070119-163503.126 | dcmlaptop | SmSipMgr | RESIP:APP |
>> 17423 |
>> 190616 | app.cpp:227 | ResipDns::lookup - Creating Uri:
>> sip:flammajobby.com;transport=udp
>> DEBUG | 20070119-163503.126 | dcmlaptop | SmSipMgr | RESIP:APP |
>> 17423 |
>> 190616 | app.cpp:233 | ResipDns::lookup - Creating DnsResult DEBUG |
>> 20070119-163503.126 | dcmlaptop | SmSipMgr | RESIP:APP |
>> 17423 |
>> 190616 | app.cpp:236 | ResipDns::lookup - Looking up DEBUG |
>> 20070119-163503.126 | dcmlaptop | SmSipMgr | RESIP:DNS |
>> 17423 |
>> 190616 | DnsResult.cxx:198 | DnsResult::lookup
>> sip:flammajobby.com;transport=udp STACK | 20070119-163503.126 |
>> dcmlaptop | SmSipMgr | RESIP:DNS |
>> 17423 |
>> 190616 | DnsResult.cxx:321 | Doing SRV lookup of
>> _sip._udp.flammajobby.com DEBUG | 20070119-163503.126 | dcmlaptop |
>> SmSipMgr | RESIP:APP |
>> 17423 |
>> 190616 | app.cpp:250 | ResipDns::lookup - waiting for results STACK |
>> 20070119-163503.154 | dcmlaptop | SmSipMgr | RESIP:DNS |
>> 17423 |
>> 162926 | dns/DnsStub.cxx:375 | DnsStub::Query::go:
>> _sip._udp.flammajobby.com
>> type(enum): 33 proto: 1
>> STACK | 20070119-163503.155 | dcmlaptop | SmSipMgr | RESIP:DNS |
>> 17423 |
>> 162926 | DnsResult.cxx:912 | Received SRV result for: flammajobby.com
>> STACK | 20070119-163503.155 | dcmlaptop | SmSipMgr | RESIP:DNS |
>> 17423 |
>> 162926 | DnsResult.cxx:915 | DnsResult::onDnsResult() 0 status=4  
>> STACK
>> | 20070119-163503.155 | dcmlaptop | SmSipMgr | RESIP:DNS |
>> 17423 |
>> 162926 | DnsResult.cxx:978 | SRV lookup failed:
>> _sip._udp.flammajobby.com 4
>> STACK | 20070119-163503.155 | dcmlaptop | SmSipMgr | RESIP:DNS |
>> 17423 |
>> 162926 | DnsResult.cxx:1024 | No SRV records for flammajobby.com.
>> Trying A
>> records
>> STACK | 20070119-163503.155 | dcmlaptop | SmSipMgr | RESIP:DNS |
>> 17423 |
>> 162926 | dns/DnsStub.cxx:375 | DnsStub::Query::go: flammajobby.com
>> type(enum): 1 proto: 1
>> STACK | 20070119-163503.155 | dcmlaptop | SmSipMgr | RESIP:DNS |
>> 17423 |
>> 162926 | DnsResult.cxx:749 | Received dns result for: flammajobby.com
>> STACK | 20070119-163503.155 | dcmlaptop | SmSipMgr | RESIP:DNS |
>> 17423 |
>> 162926 | DnsResult.cxx:750 | DnsResult::onDnsResult() 0 STACK |
>> 20070119-163503.155 | dcmlaptop | SmSipMgr | RESIP:DNS |
>> 17423 |
>> 162926 | DnsResult.cxx:771 | Adding [ V4 10.4.5.249:5060 UDP target
>> domain=flammajobby.com connectionId=0 ] to result set DEBUG |
>> 20070119-163503.155 | dcmlaptop | SmSipMgr | RESIP:APP |
>> 17423 |
>> 162926 | app.cpp:66 | ResipDnsHandler::handle - received
>> flammajobby.com STACK | 20070119-163503.155 | dcmlaptop | SmSipMgr |
>> RESIP:DNS |
>> 17423 |
>> 162926 | DnsResult.cxx:178 | Returning next dns entry: [ V4
>> 10.4.5.249:5060 UDP target domain=flammajobby.com connectionId=0 ]
>> DEBUG | 20070119-163503.155 | dcmlaptop | SmSipMgr | RESIP:APP |
>> 17423 |
>> 162926 | app.cpp:74 | flammajobby.com -> [ V4 10.4.5.249:5060 UDP
>> target domain=flammajobby.com connectionId=0 ] STACK |
>> 20070119-163503.155 | dcmlaptop | SmSipMgr | RESIP:DNS |
>> 17423 |
>> 162926 | DnsResult.cxx:485 | Priming [] DEBUG | 20070119-163503.155 |
>> dcmlaptop | SmSipMgr | RESIP:APP |
>> 17423 |
>> 162926 | app.cpp:78 | ResipDnsHandler::handle - complete INFO |
>> 20070119-163503.155 | dcmlaptop | SmSipMgr | RESIP:APP |
>> 17423 |
>> 190616 | app.cpp:253 | ResipDns::lookup - DNS results for
>> sip:flammajobby.com;transport=udp INFO | 20070119-163503.156 |
>> dcmlaptop | SmSipMgr | RESIP:APP |
>> 17423 |
>> 190616 | app.cpp:260 | [ V4 10.4.5.249:5060 UDP target
>> domain=flammajobby.com connectionId=0 ]
>>
>> _______________________________________________
>> resiprocate-devel mailing list
>> resiprocate-devel at list.resiprocate.org
>> https://list.resiprocate.org/mailman/listinfo/resiprocate-devel
>

-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 2423 bytes
Desc: not available
URL: <http://list.resiprocate.org/pipermail/resiprocate-devel/attachments/20070122/55d653fa/attachment.bin>