No subject

match a transaction. but it still performs the retrans.. I hope this
is the right segment to be useful...
...
Apr 13 13:16:55 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8177]:
DBG:tm:t_lookup_request: start searching: hash=3D18475, isACK=3D1
Apr 13 13:16:55 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8177]:
DBG:tm:matching_3261: RFC3261 transaction matched, tid=3D579b7283
Apr 13 13:16:55 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8177]:
DBG:tm:t_lookup_request: REF_UNSAFE: after is 2
Apr 13 13:16:55 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8177]:
DBG:tm:t_lookup_request: transaction found (T=3D0xb60be734)
Apr 13 13:16:55 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8177]:
DBG:tm:cleanup_uac_timers: RETR/FR timers reset
Apr 13 13:16:55 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8177]:
DBG:tm:insert_timer_unsafe: [2]: 0xb60be77c (31591)
Apr 13 13:16:55 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8177]:
DBG:tm:t_unref: UNREF_UNSAFE: after is 1
Apr 13 13:16:55 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8177]:
DBG:core:destroy_avp_list: destroying list (nil)
Apr 13 13:16:55 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8177]:
DBG:core:receive_msg: cleaning up
Apr 13 13:16:55 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8178]:
DBG:tm:_reply_light: finished
=85
Apr 13 13:16:56 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:utimer_routine: timer routine:4,tl=3D0xb60be880 next=3D0xb60be7fc,
timeout=3D31572400000
Apr 13 13:16:56 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:utimer_routine: timer routine:4,tl=3D0xb60be7fc next=3D(nil),
timeout=3D31572400000
Apr 13 13:16:56 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:retransmission_handler: retransmission_handler : reply
resending (t=3D0xb60be734, SIP/2.0 5 ... )
Apr 13 13:16:56 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:t_retransmit_reply: buf=3D0x78e040: SIP/2.0 5...,
shmem=3D0xb60bc67c: SIP/2.0 5
Apr 13 13:16:56 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:set_timer: relative timeout is 1000000
Apr 13 13:16:56 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:insert_timer_unsafe: [5]: 0xb60be7fc (31573400000)
Apr 13 13:16:56 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:retransmission_handler: retransmission_handler : done
Apr 13 13:16:57 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:utimer_routine: timer routine:5,tl=3D0xb60be7fc next=3D(nil),
timeout=3D31573400000
Apr 13 13:16:57 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:retransmission_handler: retransmission_handler : reply
resending (t=3D0xb60be734, SIP/2.0 5 ... )
Apr 13 13:16:57 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:t_retransmit_reply: buf=3D0x78e040: SIP/2.0 5...,
shmem=3D0xb60bc67c: SIP/2.0 5
Apr 13 13:16:57 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:set_timer: relative timeout is 2000000
Apr 13 13:16:57 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:insert_timer_unsafe: [6]: 0xb60be7fc (31575400000)
Apr 13 13:16:57 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:retransmission_handler: retransmission_handler : done
Apr 13 13:16:59 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:utimer_routine: timer routine:6,tl=3D0xb60be7fc next=3D(nil),
timeout=3D31575400000
Apr 13 13:16:59 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:retransmission_handler: retransmission_handler : reply
resending (t=3D0xb60be734, SIP/2.0 5 ... )
Apr 13 13:16:59 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:t_retransmit_reply: buf=3D0x78e040: SIP/2.0 5...,
shmem=3D0xb60bc67c: SIP/2.0 5
Apr 13 13:16:59 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:set_timer: relative timeout is 4000000
Apr 13 13:16:59 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:insert_timer_unsafe: [7]: 0xb60be7fc (31579400000)
Apr 13 13:16:59 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:retransmission_handler: retransmission_handler : done
Apr 13 13:17:00 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:timer_routine: timer routine:0,tl=3D0xb60be818 next=3D(nil),
timeout=3D31576
Apr 13 13:17:01 domU-XX-XX-XX-XX-XX-XX /usr/local/sbin/opensips[8182]:
DBG:tm:timer_routine: timer routine:1,tl=3D0xb60be89c next=3D(nil),
timeout=3D31577

Thanks for your help!
-Brett


On Tue, Apr 13, 2010 at 5:24 AM, Bogdan-Andrei Iancu
<bogdan at voice-system.ro> wrote:
> Hi Brett,
>
> in the failing case, maybe the received ACK does not match the
> transaction, so opensips keeps retransmitting - could you post the
> received INVITE, the sent 503 and the received ACK ?
>
> Regards,
> Bogdan
>
> Brett Nemeroff wrote:
>> Hello all,
>> I'm pretty sure I'm missing something obvious here..
>>
>> After hitting a failure route, I'm seeing retransmissions with a
>> t_reply. If I clear out the failure_route, opensips generates a 500,
>> which is sent out and it's happy with. Almost like the 500 (which is
>> internally generated) is sent statelessly, from a failure route?
>> Opensips sits on a server with a private IP and is NATed. I've set the
>> outside IP address in the advertised_address config param.
>>
>>
>> failure_route[1] {
>> =A0 =A0 =A0 =A0 xlog("L_INFO","In failure route");
>> }
>>
>>
>> (opensips at 10.249.126.19)
>> 0.052840 10.249.126.19 -> 1.2.3.4 SIP/SDP Request: INVITE
>> sip:74211234 at 1.2.3.4, with session description
>> =A0 0.061683 1.2.3.4 -> 10.249.126.19 SIP Status: 100 Trying
>> =A0 0.062550 1.2.3.4 -> 10.249.126.19 SIP Status: 503 Service Unavailabl=
e
>> =A0 0.062637 10.249.126.19 -> 1.2.3.4 SIP Request: ACK sip:74211234 at 1.2.=
3.4
>> =A0 0.062724 10.249.126.19 -> 5.6.7.8 =A0SIP Status: 500 Service Unavail=
able
>> =A0 0.100239 =A05.6.7.8 -> 10.249.126.19 SIP Request: ACK sip:1234 at sip.m=
ydomain.com
>> (No retransmissions.. everyone happy)
>>
>>
>> ---------------
>>
>> Now if I put a t_reply in there..
>> failure_route[1] {
>> =A0 =A0 =A0 =A0 xlog("L_INFO","In failure route");
>> =A0 =A0 =A0 =A0 t_reply("503","Cannot route");
>> =A0 =A0 =A0 =A0 exit;
>> }
>>
>>
>> =A0 0.042059 10.249.126.19 -> 1.2.3.4 SIP/SDP Request: INVITE
>> sip:74211234 at 1.2.3.4, with session description
>> =A0 0.051466 1.2.3.4 -> 10.249.126.19 SIP Status: 100 Trying
>> =A0 0.051919 1.2.3.4 -> 10.249.126.19 SIP Status: 503 Service Unavailabl=
e
>> =A0 0.052222 10.249.126.19 -> 1.2.3.4 SIP Request: ACK sip:742112324 at 1.2=
.3.4
>> =A0 0.052436 10.249.126.19 -> 5.6.7.8 =A0SIP Status: 503 Cannot route
>> =A0 0.089601 5.6.7.8 -> 10.249.126.19 SIP Request: ACK sip:1234 at sip.mydo=
main.com
>> =A0 1.030506 10.249.126.19 -> 5.6.7.8 =A0SIP Status: 503 Cannot route
>> =A0 2.030507 10.249.126.19 -> 5.6.7.8 =A0SIP Status: 503 Cannot route
>> =A0 4.030615 10.249.126.19 -> 5.6.7.8 =A0SIP Status: 503 Cannot route
>> (not happy)
>>
>>
>> Any ideas??
>> Thanks!
>> -Brett
>>
>> _______________________________________________
>> Users mailing list
>> Users at lists.opensips.org
>> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>>
>>
>
>
> --
> Bogdan-Andrei Iancu
> www.voice-system.ro
>
>
> _______________________________________________
> Users mailing list
> Users at lists.opensips.org
> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>