Re: [OpenSIPStack] Double packets - opensbc
Brought to you by:
joegenbaclor
From: <jo...@op...> - 2007-11-18 13:39:46
|
Hi Jeremy, I think I found out whats causing this early firing of retransmission. The timer resolution set for SIPTimerManager is too low. IT's currently set to 500 ms which is as low as it could get. This would increase the chances of SIP Timer A to fire sooner. Try setting #define SIP_TIMER_RESOLUTION from 500 to 10 milliseconds in SIPTimerManager.cxx. Let me know if this solves it. Thanks for pointing it out. Joegen jo...@op... wrote: > Ouch! I guess you are right. For a second there, I thought I was > looking at milliseconds. Let me try to replicate this issue. For the > mean time would you be able to recompile using a higher value for > SIP_TIMER_T1. Just look for #define SIP_TIMER_T1 500 in SIPTimer.h. I > want to be sure it's actually Timer_A firing early instead of a rogue > code in OpenSIPStack. > > Joegen > > Jeremy A wrote: > >> Perhaps not? >> >> In your first example the time difference 0.030086 to 0.066302 / >> 0.073700 is of the order of 30-40 milliseconds >> >> In your second example the time difference 116.150431 to 116.159165 is >> 8734 microseconds or 8.734 milliseconds. >> >> I have looked carefully at the monitoring process to make sure it is not >> causing a false result. I can find no obvious problem. >> >> FYI The opensbc server is a VMWare virtual machine hosted on the >> monitoring server. The code running opensbc is the 1.1.4 linux release >> compiled natively and is the release version. >> >> >> jo...@op... wrote: >> >> >>> Here are the timestamps >>> >>> 0.030086 X.Y.Z.138 -> 1.2.3.4 SIP Request: REGISTER >>> 0.066302 1.2.3.4 -> X.Y.Z.138 SIP Status: 100 Trying (1 bindings) >>> 0.073700 1.2.3.4 -> X.Y.Z.138 SIP Status: 401 Unauthorized (1 bindings) >>> >>> If you will see, the first response from 1.2.3.4 comes after the SIP_TIMER_A value of 500 ms has expired. Thus a retransmission is required >>> >>> 116.150431 X.Y.Z.138 -> X.Y.Z.148 SIP/SDP Request: INVITE >>> 116.159165 X.Y.Z.148 -> X.Y.Z.138 SIP Status: 100 Trying >>> >>> Same with this sequence. As i said, this is normal retransmission you >>> are seeing. >>> >>> Joegen >>> >>> >>> >>> Jeremy A wrote: >>> >>> >>> >>>> Hello, >>>> >>>> Thanks for the suggested cause. However I think that DNS is not the >>>> issue. In the example there are no DNS requests by openSBC ( I assume it >>>> has cached these from earlier experiments) >>>> >>>> Every packet sent by openSBC is duplicated. This includes packets to the >>>> upstream provider and packets to the registering phone. >>>> >>>> The packets are duplicated long after any DNS caching should have >>>> happened - In the example below this occurs over a period of 130 >>>> seconds. It also occurs with the phone device where DNS resolution is >>>> not used. >>>> >>>> Joegen E. Baclor wrote: >>>> >>>> >>>> >>>> >>>>> This may just be timer synchronization issues where the first REGISTER >>>>> request took some time to be resolved via DNS long enough that the timer >>>>> for retransmission has already fired. OpenSBC is caching DNS records >>>>> so that the next need for DNS resoltuion would be faster. OpenSBC does >>>>> not support unsolicited NOTIFY. Your provider might be using NOTIFY to >>>>> maintain NAT pinholes, in which case the response is not really an issue >>>>> whether it's a 200 Ok or Method Not Allowed. >>>>> >>>>> >>>>> Jeremy A wrote: >>>>> >>>>> >>>>> >>>>> >>>>> >>>>>> Hello, >>>>>> >>>>>> I've just started to evaluate opensbc version 1.1.4 >>>>>> >>>>>> I put a wireshark trace on the traffic and it seems that every packet >>>>>> sent by opensbc is sent twice. Is this correct behaviour ? >>>>>> >>>>>> Here is a trace of a registration and an incoming call. The >>>>>> configuration is a linksys spa962 that normally registers direct with a >>>>>> VOIP provider and no outgoing proxy. I changed this to use the opensbc >>>>>> as outgoing proxy and logged the traffic. >>>>>> >>>>>> The linksys IP ends in .148. the opensbc instance ends in .138. Both >>>>>> addresses are routable and have equivalent firewall enabled access to >>>>>> the internet. The VOIP provider has a fake IP of 1.2.3.4 >>>>>> >>>>>> I also see a NOTIFY from the voip provider is being rejected - is this >>>>>> normal? >>>>>> >>>>>> >>>>>> 0.000817 X.Y.Z.148 -> X.Y.Z.138 SIP Request: REGISTER >>>>>> sip:gw4.fakesipprovider.com >>>>>> 0.018829 X.Y.Z.138 -> X.Y.Z.148 SIP Status: 100 Trying (0 bindings) >>>>>> 0.018837 X.Y.Z.138 -> X.Y.Z.148 SIP Status: 100 Trying (0 bindings) >>>>>> 0.030086 X.Y.Z.138 -> 1.2.3.4 SIP Request: REGISTER >>>>>> sip:gw4.fakesipprovider.com >>>>>> 0.030098 X.Y.Z.138 -> 1.2.3.4 SIP Request: REGISTER >>>>>> sip:gw4.fakesipprovider.com >>>>>> 0.066302 1.2.3.4 -> X.Y.Z.138 SIP Status: 100 Trying (1 bindings) >>>>>> 0.073700 1.2.3.4 -> X.Y.Z.138 SIP Status: 401 Unauthorized (1 bindings) >>>>>> 0.076972 X.Y.Z.138 -> X.Y.Z.148 SIP Status: 100 Trying (1 bindings) >>>>>> 0.076981 X.Y.Z.138 -> X.Y.Z.148 SIP Status: 100 Trying (1 bindings) >>>>>> 0.088366 X.Y.Z.138 -> X.Y.Z.148 SIP Status: 401 Unauthorized (1 >>>>>> bindings) >>>>>> 0.088377 X.Y.Z.138 -> X.Y.Z.148 SIP Status: 401 Unauthorized (1 >>>>>> bindings) >>>>>> 0.096668 X.Y.Z.148 -> X.Y.Z.138 SIP Request: REGISTER >>>>>> sip:gw4.fakesipprovider.com >>>>>> 0.116038 X.Y.Z.138 -> X.Y.Z.148 SIP Status: 100 Trying (0 bindings) >>>>>> 0.116055 X.Y.Z.138 -> X.Y.Z.148 SIP Status: 100 Trying (0 bindings) >>>>>> 0.119375 X.Y.Z.138 -> 1.2.3.4 SIP Request: REGISTER >>>>>> sip:gw4.fakesipprovider.com >>>>>> 0.119384 X.Y.Z.138 -> 1.2.3.4 SIP Request: REGISTER >>>>>> sip:gw4.fakesipprovider.com >>>>>> 0.160873 X.Y.Z.138 -> 1.2.3.4 SIP Request: REGISTER >>>>>> sip:gw4.fakesipprovider.com >>>>>> 0.160885 X.Y.Z.138 -> 1.2.3.4 SIP Request: REGISTER >>>>>> sip:gw4.fakesipprovider.com >>>>>> 0.163720 1.2.3.4 -> X.Y.Z.138 SIP Status: 100 Trying (1 bindings) >>>>>> 0.170387 1.2.3.4 -> X.Y.Z.138 SIP Status: 200 OK (1 bindings) >>>>>> 0.173012 X.Y.Z.138 -> X.Y.Z.148 SIP Status: 100 Trying (1 bindings) >>>>>> 0.173022 X.Y.Z.138 -> X.Y.Z.148 SIP Status: 100 Trying (1 bindings) >>>>>> 0.182666 X.Y.Z.138 -> X.Y.Z.148 SIP Status: 200 OK (1 bindings) >>>>>> 0.182677 X.Y.Z.138 -> X.Y.Z.148 SIP Status: 200 OK (1 bindings) >>>>>> 0.200877 1.2.3.4 -> X.Y.Z.138 SIP Status: 100 Trying (1 bindings) >>>>>> 0.208848 1.2.3.4 -> X.Y.Z.138 SIP Status: 200 OK (1 bindings) >>>>>> 10.019211 1.2.3.4 -> X.Y.Z.138 SIP Request: NOTIFY >>>>>> sip:55555555@X.Y.Z.138:65080 >>>>>> 10.027932 X.Y.Z.138 -> 1.2.3.4 SIP Status: 405 Method Not Allowed >>>>>> 10.027945 X.Y.Z.138 -> 1.2.3.4 SIP Status: 405 Method Not Allowed >>>>>> 10.693615 1.2.3.4 -> X.Y.Z.138 SIP Request: OPTIONS >>>>>> sip:55555555@X.Y.Z.138:65080 >>>>>> 10.707659 X.Y.Z.138 -> 1.2.3.4 SIP Status: 200 OK >>>>>> 10.707674 X.Y.Z.138 -> 1.2.3.4 SIP Status: 200 OK >>>>>> 70.737972 1.2.3.4 -> X.Y.Z.138 SIP Request: OPTIONS >>>>>> sip:55555555@X.Y.Z.138:65080 >>>>>> 70.746471 X.Y.Z.138 -> 1.2.3.4 SIP Status: 200 OK >>>>>> 70.746485 X.Y.Z.138 -> 1.2.3.4 SIP Status: 200 OK >>>>>> 116.129914 1.2.3.4 -> X.Y.Z.138 SIP/SDP Request: INVITE >>>>>> sip:55555555@X.Y.Z.138:65080, with session description >>>>>> 116.146387 X.Y.Z.138 -> 1.2.3.4 SIP Status: 100 Trying >>>>>> 116.146402 X.Y.Z.138 -> 1.2.3.4 SIP Status: 100 Trying >>>>>> 116.150431 X.Y.Z.138 -> X.Y.Z.148 SIP/SDP Request: INVITE >>>>>> sip:55555555@X.Y.Z.148:5060, with session description >>>>>> 116.150443 X.Y.Z.138 -> X.Y.Z.148 SIP/SDP Request: INVITE >>>>>> sip:55555555@X.Y.Z.148:5060, with session description >>>>>> 116.159165 X.Y.Z.148 -> X.Y.Z.138 SIP Status: 100 Trying >>>>>> 116.181582 X.Y.Z.148 -> X.Y.Z.138 SIP Status: 180 Ringing >>>>>> 116.192198 X.Y.Z.138 -> 1.2.3.4 SIP Status: 180 Ringing >>>>>> 116.192218 X.Y.Z.138 -> 1.2.3.4 SIP Status: 180 Ringing >>>>>> 118.894027 X.Y.Z.148 -> X.Y.Z.138 SIP/SDP Status: 200 OK, with session >>>>>> description >>>>>> 118.900656 X.Y.Z.138 -> X.Y.Z.148 SIP Request: ACK >>>>>> sip:55555555@X.Y.Z.148:5060 >>>>>> 118.900671 X.Y.Z.138 -> X.Y.Z.148 SIP Request: ACK >>>>>> sip:55555555@X.Y.Z.148:5060 >>>>>> 118.908267 X.Y.Z.138 -> 1.2.3.4 SIP/SDP Status: 200 OK, with session >>>>>> description >>>>>> 118.908279 X.Y.Z.138 -> 1.2.3.4 SIP/SDP Status: 200 OK, with session >>>>>> description >>>>>> 118.950770 1.2.3.4 -> X.Y.Z.138 SIP Request: ACK sip:X.Y.Z.138:5060 >>>>>> 122.220504 1.2.3.4 -> X.Y.Z.138 SIP Request: BYE sip:X.Y.Z.138:5060 >>>>>> 122.236390 X.Y.Z.138 -> 1.2.3.4 SIP Status: 200 OK >>>>>> 122.236401 X.Y.Z.138 -> 1.2.3.4 SIP Status: 200 OK >>>>>> 122.239402 X.Y.Z.138 -> X.Y.Z.148 SIP Request: BYE >>>>>> sip:55555555@X.Y.Z.148:5060 >>>>>> 122.239414 X.Y.Z.138 -> X.Y.Z.148 SIP Request: BYE >>>>>> sip:55555555@X.Y.Z.148:5060 >>>>>> 122.248420 X.Y.Z.148 -> X.Y.Z.138 SIP Status: 200 OK >>>>>> 130.767892 1.2.3.4 -> X.Y.Z.138 SIP Request: OPTIONS >>>>>> sip:55555555@X.Y.Z.138:65080 >>>>>> 130.776518 X.Y.Z.138 -> 1.2.3.4 SIP Status: 200 OK >>>>>> 130.776532 X.Y.Z.138 -> 1.2.3.4 SIP Status: 200 OK >>>>>> >>>>>> >>>>>> ------------------------------------------------------------------------- >>>>>> This SF.net email is sponsored by: Microsoft >>>>>> Defy all challenges. Microsoft(R) Visual Studio 2005. >>>>>> http://clk.atdmt.com/MRT/go/vse0120000070mrt/direct/01/ >>>>>> _______________________________________________ >>>>>> opensipstack-devel mailing list >>>>>> ope...@li... >>>>>> https://lists.sourceforge.net/lists/listinfo/opensipstack-devel >>>>>> >>>>>> >>>>>> >>>>>> >>>>>> >>>>>> >>>>>> >>>>>> >>>>> ------------------------------------------------------------------------- >>>>> This SF.net email is sponsored by: Microsoft >>>>> Defy all challenges. Microsoft(R) Visual Studio 2005. >>>>> http://clk.atdmt.com/MRT/go/vse0120000070mrt/direct/01/ >>>>> _______________________________________________ >>>>> opensipstack-devel mailing list >>>>> ope...@li... >>>>> https://lists.sourceforge.net/lists/listinfo/opensipstack-devel >>>>> >>>>> >>>>> >>>>> >>>>> >>>> ------------------------------------------------------------------------- >>>> This SF.net email is sponsored by: Microsoft >>>> Defy all challenges. Microsoft(R) Visual Studio 2005. >>>> http://clk.atdmt.com/MRT/go/vse0120000070mrt/direct/01/ >>>> _______________________________________________ >>>> opensipstack-devel mailing list >>>> ope...@li... >>>> https://lists.sourceforge.net/lists/listinfo/opensipstack-devel >>>> >>>> >>>> >>>> >>>> >>>> >>>> >>> ------------------------------------------------------------------------- >>> This SF.net email is sponsored by: Microsoft >>> Defy all challenges. Microsoft(R) Visual Studio 2005. >>> http://clk.atdmt.com/MRT/go/vse0120000070mrt/direct/01/ >>> _______________________________________________ >>> opensipstack-devel mailing list >>> ope...@li... >>> https://lists.sourceforge.net/lists/listinfo/opensipstack-devel >>> >>> >>> >> ------------------------------------------------------------------------- >> This SF.net email is sponsored by: Microsoft >> Defy all challenges. Microsoft(R) Visual Studio 2005. >> http://clk.atdmt.com/MRT/go/vse0120000070mrt/direct/01/ >> _______________________________________________ >> opensipstack-devel mailing list >> ope...@li... >> https://lists.sourceforge.net/lists/listinfo/opensipstack-devel >> >> >> >> >> > > > ------------------------------------------------------------------------- > This SF.net email is sponsored by: Microsoft > Defy all challenges. Microsoft(R) Visual Studio 2005. > http://clk.atdmt.com/MRT/go/vse0120000070mrt/direct/01/ > _______________________________________________ > opensipstack-devel mailing list > ope...@li... > https://lists.sourceforge.net/lists/listinfo/opensipstack-devel > > > > |