[Users] 1.2.0 and retransmissions
Bogdan-Andrei Iancu
bogdan at voice-system.ro
Fri Feb 16 19:00:33 CET 2007
Hi Helge,
thanks for the log - what is very strange is the timeout values -
identical for all retransmission; I applied on CVS more debug logs and
also made a small fix in timers (small, but relevant ;) ). Could you
please update and give it another try ? again, log are most helpful...
thanks and regards,
bogdan
Helge Waastad wrote:
> Hi Bogdan,
> this is what I see:
>
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> Dispatcher-02: [LB]:5060 <= 10.46.11.104:5060 REGISTER from:
> sip:[id]@[domain]
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> parse_headers: flags=200
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]: found end
> of header
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> find_first_route: No Route headers found
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> loose_route: There is no Route HF
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> Dispatcher-02: Request from UAC...
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> parse_headers: flags=80
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> Dispatcher-02: UAC behind NAT...
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> parse_headers: flags=800
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> DISPATCHER:ds_select_dst: set index [1->0]
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> DISPATCHER:ds_select_dst: alg hash [4169264799]
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> DISPATCHER:ds_select_dst: selected [0-1/0/0] <sip:[SP]:5080>
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> Dispatcher-02: [LB]:5060 => sip:[SP]:5080 REGISTER
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> parse_headers: flags=ffffffffffffffff
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]: DEBUG:
> t_newtran: msg id=1018 , global msg id=1017 , T on entrance=0xffffffff
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> parse_headers: flags=ffffffffffffffff
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> parse_headers: flags=78
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> t_lookup_request: start searching: hash=51317, isACK=0
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]: DEBUG:
> RFC3261 transaction matching failed
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]: DEBUG:
> t_lookup_request: no transaction found
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]: DBG:
> trans=0xb60d8368, callback type 1, id 0 entered
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]: DEBUG:
> mk_proxy: doing DNS lookup...
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> check_via_address(10.46.11.104, 10.46.11.104, 0)
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]: DEBUG:
> add_to_tail_of_timer[4]: 0xb60d84b4
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> DEBUG:tm:_set_fr_retr: FR_TIMER = 3
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]: DEBUG:
> add_to_tail_of_timer[0]: 0xb60d84d0
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> DEBUG:tm:t_relay_to: new transaction fwd'ed
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> DEBUG:tm:UNREF_UNSAFE: after is 0
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> DEBUG:destroy_avp_list: destroying list (nil)
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28921]:
> receive_msg: cleaning up
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28926]: DEBUG:
> timer routine:4,tl=0xb60d84b4 next=(nil), timeout=785159744
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28926]: DEBUG:
> retransmission_handler : request resending (t=0xb60d8368,
> REGISTER ... )
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28926]: DEBUG:
> add_to_tail_of_timer[5]: 0xb60d84b4
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28926]: DEBUG:
> retransmission_handler : done
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28926]: DEBUG:
> timer routine:5,tl=0xb60d84b4 next=(nil), timeout=785759744
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28926]: DEBUG:
> retransmission_handler : request resending (t=0xb60d8368,
> REGISTER ... )
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28926]: DEBUG:
> add_to_tail_of_timer[6]: 0xb60d84b4
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28926]: DEBUG:
> retransmission_handler : done
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28926]: DEBUG:
> timer routine:6,tl=0xb60d84b4 next=(nil), timeout=786759744
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28926]: DEBUG:
> retransmission_handler : request resending (t=0xb60d8368,
> REGISTER ... )
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28926]: DEBUG:
> add_to_tail_of_timer[7]: 0xb60d84b4
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28926]: DEBUG:
> retransmission_handler : done
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28926]: DEBUG:
> timer routine:7,tl=0xb60da30c next=0xb60de19c, timeout=788659744
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28926]: DEBUG:
> timer routine:7,tl=0xb60de19c next=0xb60d84b4, timeout=788659744
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28926]: DEBUG:
> timer routine:7,tl=0xb60d84b4 next=(nil), timeout=788759744
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28926]: DEBUG:
> retransmission_handler : request resending (t=0xb60d8368,
> REGISTER ... )
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28926]: DEBUG:
> add_to_tail_of_timer[7]: 0xb60d84b4
> Feb 16 08:22:31 proxy-02 /usr/sbin/openser-dispatcher[28926]: DEBUG:
> retransmission_handler : done
>
> br hw
>
>
>
> On tor, 2007-02-15 at 19:05 +0200, Bogdan-Andrei Iancu wrote:
>
>> debug 9 :) ...of the whole transaction...
>>
>> thanks,
>> bogdan
>>
>> Helge Waastad wrote:
>>
>>> Hi,
>>> no there are no retransmissions from the UAC.
>>>
>>> What level do you want the debug on?
>>>
>>> br hw
>>>
>>>
>>>
>>> On tor, 2007-02-15 at 18:29 +0200, Bogdan-Andrei Iancu wrote:
>>>
>>>
>>>> Hi Helge,
>>>>
>>>> is it a way to reproduce this? is there any retransmission from UAC to
>>>> LB? do you have a debug log for this?
>>>>
>>>> regards,
>>>> bogdan
>>>>
>>>> Helge Waastad wrote:
>>>>
>>>>
>>>>> Hi,
>>>>> I've started to notice a lot of retransmissions in my 1.2.0 test lab.
>>>>>
>>>>> I'm running two LB(dispatcher) and two SP's on two servers, using
>>>>> separate ports.
>>>>>
>>>>> What I se is this:
>>>>>
>>>>> SP:5080 LB:5060 UAC:5060
>>>>> | | | <Call><PFrame><Time>
>>>>> | | |
>>>>> | |<-- REGISTER F1<| 1 PF:1 08:09:21.1442
>>>>> | | |
>>>>> |<--- REGISTER F2<| | 1 PF:2 08:09:21.1446
>>>>> | | |
>>>>> |<--- REGISTER F3<| | 1 PF:3 08:09:21.1469
>>>>> | | |
>>>>> |<--- REGISTER F4<| | 1 PF:4 08:09:21.1469
>>>>> | | |
>>>>> |<--- REGISTER F5<| | 1 PF:5 08:09:21.1469
>>>>> | | |
>>>>> |<--- REGISTER F6<| | 1 PF:6 08:09:21.1470
>>>>> | | |
>>>>> |>F7 100 Trying ->| | 1 PF:7 08:09:21.1615
>>>>> | | |
>>>>> |>F8 100 Trying ->| | 1 PF:8 08:09:21.1673
>>>>> | | |
>>>>> |>F9 100 Trying ->| | 1 PF:9 08:09:21.1714
>>>>>
>>>>>
>>>>> dns_failover and blacklists are disabled
>>>>>
>>>>> Using the same tm timer configurations that I've been using on 1.1.1
>>>>> (basically default values)
>>>>>
>>>>> Can anyone tell me what triggers retransmission here?
>>>>>
>>>>> (after register, the UAC sends SUBSCRIBE and the same rtx happens)
>>>>>
>>>>> br hw
>>>>>
>>>>>
>>>>> _______________________________________________
>>>>> Users mailing list
>>>>> Users at openser.org
>>>>> http://openser.org/cgi-bin/mailman/listinfo/users
>>>>>
>>>>>
>>>>>
>>>>>
>>>
>>>
>
>
More information about the sr-users
mailing list