Module: kamailio Branch: master Commit: 05577d19f21eeeaa416c17e4fd554dfd18fd9ce1 URL: https://github.com/kamailio/kamailio/commit/05577d19f21eeeaa416c17e4fd554df… Author: mrudenko &lt;m.rudenko(a)zaleos.net&gt; Committer: Daniel-Constantin Mierla &lt;miconda(a)gmail.com&gt; Date: 2021-08-11T19:35:42+02:00 tm: enhance fr/retr timers logging - Mention when FR timeout is reached, and which of FR timers expired - Log when starting FR/RETR timers - log when changing default timeouts to user set values - log when resetting fr/retr timers on provisional replies --- Modified: src/modules/tm/t_lookup.c Modified: src/modules/tm/t_reply.c Modified: src/modules/tm/t_suspend.c Modified: src/modules/tm/timer.c Modified: src/modules/tm/timer.h --- Diff: https://github.com/kamailio/kamailio/commit/05577d19f21eeeaa416c17e4fd554df… Patch: https://github.com/kamailio/kamailio/commit/05577d19f21eeeaa416c17e4fd554df… --- diff --git a/src/modules/tm/t_lookup.c b/src/modules/tm/t_lookup.c index 4ccdee7574..1ee57c995c 100644 --- a/src/modules/tm/t_lookup.c +++ b/src/modules/tm/t_lookup.c @@ -1818,6 +1818,9 @@ int t_set_fr(struct sip_msg* msg, unsigned int fr_inv_to, unsigned int fr_to) set_msgid_val(user_fr_inv_timeout, msg->id, int, (int)fr_inv); set_msgid_val(user_fr_timeout, msg->id, int, (int)fr); }else{ +#ifdef TIMER_DEBUG + LM_DBG("changing default FR timeout values: (\"fr_inv_timeout\": %d, \"fr_timeout\": %d)\n", fr_inv, fr); +#endif change_fr(t, fr_inv, fr); /* change running uac timers */ } return 1; @@ -1880,6 +1883,9 @@ int t_set_retr(struct sip_msg* msg, unsigned int t1_ms, unsigned int t2_ms) set_msgid_val(user_rt_t1_timeout_ms, msg->id, int, (int)t1_ms); set_msgid_val(user_rt_t2_timeout_ms, msg->id, int, (int)t2_ms); }else{ +#ifdef TIMER_DEBUG + LM_DBG("changing default RETR timeout values to: (\"retr_t1_interval\": %d, \"retr_t2_interval\": %d)\n", t1_ms, t2_ms); +#endif change_retr(t, 1, t1_ms, t2_ms); /* change running uac timers */ } return 1; diff --git a/src/modules/tm/t_reply.c b/src/modules/tm/t_reply.c index 306ed8f872..509cbcb950 100644 --- a/src/modules/tm/t_reply.c +++ b/src/modules/tm/t_reply.c @@ -2718,6 +2718,9 @@ int reply_received( struct sip_msg *p_msg ) ( (last_uac_status<msg_status) && ((msg_status>=180) || (last_uac_status==0)) ) ) ) { /* provisional now */ +#ifdef TIMER_DEBUG + LM_DBG("updating FR/RETR timers, \"fr_inv_timeout\": %d\n", t->fr_inv_timeout); +#endif restart_rb_fr(& uac->request, t->fr_inv_timeout); uac->request.flags|=F_RB_FR_INV; /* mark fr_inv */ } /* provisional replies */ diff --git a/src/modules/tm/t_suspend.c b/src/modules/tm/t_suspend.c index 826307d20a..bae9747282 100644 --- a/src/modules/tm/t_suspend.c +++ b/src/modules/tm/t_suspend.c @@ -486,6 +486,9 @@ int t_continue_helper(unsigned int hash_index, unsigned int label, ( (last_uac_status<msg_status) && ((msg_status>=180) || (last_uac_status==0)) ) ) ) { /* provisional now */ +#ifdef TIMER_DEBUG + LM_DBG("updating FR/RETR timers, \"fr_inv_timeout\": %d\n", t->fr_inv_timeout); +#endif restart_rb_fr(& t->uac[branch].request, t->fr_inv_timeout); t->uac[branch].request.flags|=F_RB_FR_INV; /* mark fr_inv */ } diff --git a/src/modules/tm/timer.c b/src/modules/tm/timer.c index 26734df2ee..a662920cab 100644 --- a/src/modules/tm/timer.c +++ b/src/modules/tm/timer.c @@ -510,6 +510,13 @@ ticks_t retr_buf_handler(ticks_t ticks, struct timer_ln *tl, void *p) a little race risk, but nothing bad would happen */ rbuf->flags |= F_RB_TIMEOUT; +#ifdef TIMER_DEBUG + if (rbuf->flags & F_RB_FR_INV) { + LM_DBG("reached the \"fr_inv_timeout\"\n"); + } else { + LM_DBG("reached the \"fr_timeout\"\n"); + } +#endif /* WARNING: the next line depends on taking care not to start the * wait timer before finishing with t (if this is not * guaranteed then comment the timer_allow_del() line) */ diff --git a/src/modules/tm/timer.h b/src/modules/tm/timer.h index 10a6e952a4..fa96beb90e 100644 --- a/src/modules/tm/timer.h +++ b/src/modules/tm/timer.h @@ -168,6 +168,10 @@ inline static int _set_fr_retr(struct retr_buf *rb, unsigned retr_ms) ticks_t retr_ticks; int ret; +#ifdef TIMER_DEBUG + LM_DBG("starting FR/RETR timers\n"); +#endif + ticks = get_ticks_raw(); timeout = rb->my_T->fr_timeout; eol = rb->my_T->end_of_life;