On Mon, Aug 22, 2016 at 12:30:18PM +0200, Daniel Tryba wrote: > > OK. I will have to look at the source code? > > > > Btw, did you try with longer timeout? Still the same? If you change the > > modparam for the timeout, is it used? These will help to narrow down of > > t_set_fr() has no effect here, but only the modparam... > > 31s or 40s are indeed 31 or 40 seconds timeouts with the default > ft_timer of 30000. Setting fr_timer to 20000 and a t_set_fr<20000 over > tcp is maxed to 20000.
I have been trying to figure this out, but I'm not getting anywhere. Incoming INVITE. Do some lookup magic, t_set_fr(10000). Relay the INVITE, t_newtran is called. Debug output of first block below is al in the same second. DEBUG: tm [t_lookup.c:1312]: t_newtran(): DEBUG: t_newtran: msg id=32 , global msg id=32 , T on entrance=(nil) DEBUG: tm [t_lookup.c:466]: t_lookup_request(): t_lookup_request: start searching: hash=9972, isACK=0 DEBUG: tm [t_lookup.c:424]: matching_3261(): DEBUG: RFC3261 transaction matching failed DEBUG: tm [t_lookup.c:648]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found DEBUG: tm [t_hooks.c:358]: run_reqin_callbacks_internal(): DBG: trans=0x7f3288e078a0, callback type 1, id 0 entered DEBUG: tm [t_hooks.c:358]: run_reqin_callbacks_internal(): DBG: trans=0x7f3288e078a0, callback type 1, id 0 entered DEBUG: tm [t_funcs.c:321]: t_relay_to(): SER: new INVITE DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=32 global id=32 T start=0x7f3288e078a0 DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=32 global id=32 T start=0x7f3288e078a0 DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=32 global id=32 T start=0x7f3288e078a0 DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=32 global id=32 T start=0x7f3288e078a0 DEBUG: tm [t_lookup.c:943]: t_reply_matching(): DEBUG: t_reply_matching: reply matched (T=0x7f3288e078a0)! DEBUG: tm [t_hooks.c:266]: run_trans_callbacks_internal(): DBG: trans=0x7f3288e078a0, callback type 2, id 0 entered DEBUG: tm [t_hooks.c:266]: run_trans_callbacks_internal(): DBG: trans=0x7f3288e078a0, callback type 2, id 0 entered DEBUG: tm [t_hooks.c:266]: run_trans_callbacks_internal(): DBG: trans=0x7f3288e078a0, callback type 2, id 0 entered DEBUG: tm [t_lookup.c:1080]: t_check_msg(): DEBUG: t_check_msg: msg id=1 global id=1 T end=0x7f3288e078a0 DEBUG: tm [t_lookup.c:943]: t_reply_matching(): DEBUG: t_reply_matching: reply matched (T=0x7f3288e078a0)! DEBUG: tm [t_lookup.c:975]: t_reply_matching(): reply in callbacks already done (T=0x7f3288e078a0)! DEBUG: tm [t_lookup.c:1080]: t_check_msg(): DEBUG: t_check_msg: msg id=1 global id=1 T end=0x7f3288e078a0 DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=1 global id=1 T start=0x7f3288e078a0 DEBUG: tm [t_lookup.c:943]: t_reply_matching(): DEBUG: t_reply_matching: reply matched (T=0x7f3288e078a0)! DEBUG: tm [t_hooks.c:266]: run_trans_callbacks_internal(): DBG: trans=0x7f3288e078a0, callback type 2, id 0 entered DEBUG: tm [t_hooks.c:266]: run_trans_callbacks_internal(): DBG: trans=0x7f3288e078a0, callback type 2, id 0 entered DEBUG: tm [t_hooks.c:266]: run_trans_callbacks_internal(): DBG: trans=0x7f3288e078a0, callback type 2, id 0 entered DEBUG: tm [t_lookup.c:1080]: t_check_msg(): DEBUG: t_check_msg: msg id=2 global id=2 T end=0x7f3288e078a0 DEBUG: tm [t_lookup.c:943]: t_reply_matching(): DEBUG: t_reply_matching: reply matched (T=0x7f3288e078a0)! DEBUG: tm [t_lookup.c:975]: t_reply_matching(): reply in callbacks already done (T=0x7f3288e078a0)! DEBUG: tm [t_lookup.c:1080]: t_check_msg(): DEBUG: t_check_msg: msg id=2 global id=2 T end=0x7f3288e078a0 DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=2 global id=2 T start=0x7f3288e078a0 DEBUG: tm [t_hooks.c:266]: run_trans_callbacks_internal(): DBG: trans=0x7f3288e078a0, callback type 32, id 0 entered DEBUG: tm [t_hooks.c:266]: run_trans_callbacks_internal(): DBG: trans=0x7f3288e078a0, callback type 1048576, id 0 entered DEBUG: tm [t_hooks.c:266]: run_trans_callbacks_internal(): DBG: trans=0x7f3288e078a0, callback type 512, id 0 entered 20s later the interal 408 is triggered: DEBUG: tm [timer.c:534]: retr_buf_handler(): tm: timer retr_buf_handler @633715161 (0x7f3288e07b48 -> 0x7f3288e07b28 -> 0x7f3288e078a0) DEBUG: tm [t_reply.c:1233]: t_should_relay_response(): ->>>>>>>>> T_code=180, new_code=408 DEBUG: tm [t_hooks.c:266]: run_trans_callbacks_internal(): DBG: trans=0x7f3288e078a0, callback type 128, id 0 entered And callforward route is triggered from here. _______________________________________________ SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users