Daniel,

After applying the patch the 'fr_inv_timer' is working.

Thanks Hans

----- Original Message ----- From: "Daniel-Constantin Mierla" miconda@gmail.com To: hans@onsmail.nl Cc: users@lists.kamailio.org Sent: Tuesday, June 30, 2009 11:28 Subject: Re: [Kamailio-Users] strange fr_inv_timer behaviour

please take this patch and try. The other one I just sent included some work done for nathelper module.

Thanks, Daniel

On 06/30/2009 11:26 AM, Daniel-Constantin Mierla wrote:

...

Hello,

On 06/30/2009 09:26 AM, hans@onsmail.nl wrote:

...

I'm still trying to find out why the fr_inv_timer isn't working properly.

I tried version 1.5 with a very basic configuration and then the timeout is sent to early (about half the 'fr_inv_timer' value) but when running version 1.4 (on the same machine) everything is working fine and the timeout occures after the amount of seconds defined by 'fr_inv_timer'.

Anyone any idea what can cause this behavior in 1.5 (and not in 1.4) ?

can you try attached patch?

Thanks, Daniel

...

----- Original Message ----- From: hans@onsmail.nl To: "Daniel-Constantin Mierla" miconda@gmail.com Cc: users@lists.kamailio.org Sent: Wednesday, June 10, 2009 20:10 Subject: Re: [Kamailio-Users] strange fr_inv_timer behaviour

...

Daniel,

loadmodule "tm.so" modparam("tm", "fr_inv_timer_avp", "$avp(s:callee_fr_inv_timer)") modparam("tm", "fr_timer", 3)

$avp(s:callee_fr_inv_timer) = 90;

This setting causes a 408 to be generated after 30 seconds.

If i don't use the avp but set fr_inv_timer directly i have the same problem.

Kind regards Hans

...

Hello,

can you send me all tm module parameters you set?

I tried to reproduce, but all was fine:

• 40 sec t/o

INVITE: U 2009/06/10 12:52:54.457315 213.133.111.169:5062 -> 86.121.130.133:6536 408: U 2009/06/10 12:53:35.084385 213.133.111.169:5062 -> 86.121.130.133:5060

• 60 sec t/o

INVITE: U 2009/06/10 12:58:05.806196 213.133.111.169:5062 -> 86.121.130.133:6536 408: U 2009/06/10 12:59:05.644824 213.133.111.169:5062 -> 86.121.130.133:5060

Thanks, Daniel

On 06/03/2009 05:00 PM, hans@onsmail.nl wrote:

...

Hi,

When setting ?fr_inv_timer? to 60s and the phone is not answered kamailio generates a timeout after 20s ? If ?fr_inv_timer? is set to 90s the timeout is generated after 30s ?

Doing a level 7 debug I received the following tm timer related output

Jun 3 15:07:12 sip-proxy-01 /usr/local/sbin/kamailio[1755]: DBG:tm:set_timer: relative timeout is 500000 Jun 3 15:07:12 sip-proxy-01 /usr/local/sbin/kamailio[1755]: DBG:tm:insert_timer_unsafe: [4]: 0xafa6abc4 (16900000) Jun 3 15:07:12 sip-proxy-01 /usr/local/sbin/kamailio[1755]: DBG:tm:set_timer: relative timeout is 3 Jun 3 15:07:12 sip-proxy-01 /usr/local/sbin/kamailio[1755]: DBG:tm:insert_timer_unsafe: [0]: 0xafa6abe0 (51) Jun 3 15:07:12 sip-proxy-01 /usr/local/sbin/kamailio[1754]: DBG:tm:set_timer: relative timeout is 60 Jun 3 15:07:12 sip-proxy-01 /usr/local/sbin/kamailio[1754]: DBG:tm:insert_timer_unsafe: [1]: 0xafa6abe0 (108) Jun 3 15:07:12 sip-proxy-01 /usr/local/sbin/kamailio[1751]: DBG:tm:set_timer: relative timeout is 60 Jun 3 15:07:12 sip-proxy-01 /usr/local/sbin/kamailio[1751]: DBG:tm:insert_timer_unsafe: [1]: 0xafa6abe0 (108) Jun 3 15:07:12 sip-proxy-01 /usr/local/sbin/kamailio[1758]: DBG:tm:utimer_routine: timer routine:4,tl=0xafa6abc4 next=(nil), timeout=16900000

<phone is ringing ....>

Jun 3 15:07:32 sip-proxy-01 /usr/local/sbin/kamailio[1758]: DBG:tm:timer_routine: timer routine:1,tl=0xafa6abe0 next=(nil), timeout=108 Jun 3 15:07:32 sip-proxy-01 /usr/local/sbin/kamailio[1758]: DBG:tm:final_response_handler: stop retr. and send CANCEL (0xafa6aa78) Jun 3 15:07:32 sip-proxy-01 /usr/local/sbin/kamailio[1758]: DBG:tm:t_should_relay_response: T_code=180, new_code=408 Jun 3 15:07:32 sip-proxy-01 /usr/local/sbin/kamailio[1758]: DBG:tm:t_pick_branch: picked branch 0, code 408 Jun 3 15:07:32 sip-proxy-01 /usr/local/sbin/kamailio[1758]: DBG:tm:t_check: start=0xafa6aa78 Jun 3 15:07:32 sip-proxy-01 /usr/local/sbin/kamailio[1758]: DBG:tm:t_check: transaction already found! Jun 3 15:07:32 sip-proxy-01 /usr/local/sbin/kamailio[1758]: DBG:tm:pv_get_tm_reply_code: reply code is <408>

version: kamailio 1.5.1-notls (i386/linux) flags: STATISTICS, USE_IPV6, USE_TCP, DISABLE_NAGLE, USE_MCAST, SHM_MMAP, PKG_MALLOC, F_MALLOC, FAST_LOCK-ADAPTIVE_WAIT ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, PKG_SIZE 4194304 poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. svnrevision: 2:5868M @(#) $Id: main.c 5608 2009-02-13 16:48:17Z henningw $ main.c compiled on 14:40:00 Jun 3 2009 with gcc 4.1.2

Kind regards Hans

---

Kamailio (OpenSER) - Users mailing list Users@lists.kamailio.org http://lists.kamailio.org/cgi-bin/mailman/listinfo/users http://lists.openser-project.org/cgi-bin/mailman/listinfo/users

-- Daniel-Constantin Mierla http://www.asipto.com/

---

Kamailio (OpenSER) - Users mailing list Users@lists.kamailio.org http://lists.kamailio.org/cgi-bin/mailman/listinfo/users http://lists.openser-project.org/cgi-bin/mailman/listinfo/users

---

Kamailio (OpenSER) - Users mailing list Users@lists.kamailio.org http://lists.kamailio.org/cgi-bin/mailman/listinfo/users http://lists.openser-project.org/cgi-bin/mailman/listinfo/users

-- Daniel-Constantin Mierla http://www.asipto.com/

--------------------------------------------------------------------------------

Index: timer.c

--- timer.c (revision 5883) +++ timer.c (working copy) @@ -16,8 +16,8 @@

• MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
• GNU General Public License for more details.

• • You should have received a copy of the GNU General Public License
• • along with this program; if not, write to the Free Software

• • You should have received a copy of the GNU General Public License
• • along with this program; if not, write to the Free Software

• Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307

USA

• History:

@@ -145,7 +145,7 @@

• \brief Create a new timer, allocated in private memory
• \return NULL on error, a pointer to the new timer on success

*/ -static inline struct sr_timer* new_sr_timer(timer_function f, +static inline struct sr_timer* new_sr_timer(timer_function f, void* param, unsigned int interval) { struct sr_timer* t; @@ -258,19 +258,16 @@ /*!

• \brief Process all timer on the list

*/ -static inline void timer_ticker(struct sr_timer *timer_list, int do_jiffies) +static inline void timer_ticker(struct sr_timer *timer_list) { struct sr_timer* t; unsigned int prev_jiffies;

prev_jiffies=*jiffies; *jiffies+=TIMER_TICK;

• if (do_jiffies) {
• *jiffies+=TIMER_TICK;
• }

/* test for overflow (if tick= 1s =>overflow in 136 years)*/

• if (*jiffies<prev_jiffies){
• /*force expire & update every timer, a little buggy but it

• if (*jiffies<prev_jiffies){
• /*force expire & update every timer, a little buggy but it

• happens once in 136 years :) */

for(t=timer_list;t;t=t->next){ t->expires=*jiffies+t->interval; @@ -278,7 +275,7 @@ } return; }

for (t=timer_list;t; t=t->next){ if (*jiffies>=t->expires){ t->expires=*jiffies+t->interval; @@ -291,13 +288,11 @@ /*!

• \brief Process all utimer on the list

*/ -static inline void utimer_ticker(struct sr_timer *utimer_list, int do_jiffies) +static inline void utimer_ticker(struct sr_timer *utimer_list) { struct sr_timer* t;

• if (do_jiffies) {
• *ujiffies+=UTIMER_TICK;
• }

• *ujiffies+=UTIMER_TICK;

/* no overflow test as even if we go for 1 microsecond tick, this will

• happen in 14038618 years :P */

@@ -315,6 +310,8 @@ */ static void run_timer_process(struct sr_timer_process *tpl, int do_jiffies) {

• unsigned int local_jiffies=0;
• utime_t local_ujiffies=0;

unsigned int multiple; unsigned int cnt; struct timeval o_tv; @@ -333,11 +330,16 @@ LM_DBG("tv = %ld, %ld , m=%d\n", o_tv.tv_sec,o_tv.tv_usec,multiple);

• if (!do_jiffies) {
• jiffies = &local_jiffies;
• ujiffies = &local_ujiffies;
• }

if (tpl->utimer_list==NULL) { for( ; ; ) { tv = o_tv; select( 0, 0, 0, 0, &tv);

• timer_ticker(tpl->timer_list, do_jiffies);

• timer_ticker(tpl->timer_list);

}

} else @@ -345,7 +347,7 @@ for( ; ; ) { tv = o_tv; select( 0, 0, 0, 0, &tv);

• utimer_ticker(tpl->utimer_list, do_jiffies);

• utimer_ticker(tpl->utimer_list);

}

} else @@ -353,17 +355,17 @@ for( ; ; ) { tv = o_tv; select( 0, 0, 0, 0, &tv);

• timer_ticker(tpl->timer_list, do_jiffies);
• utimer_ticker(tpl->utimer_list, do_jiffies);

• timer_ticker(tpl->timer_list);
• utimer_ticker(tpl->utimer_list);

}

} else { for( cnt=1 ; ; cnt++ ) { tv = o_tv; select( 0, 0, 0, 0, &tv);

• utimer_ticker(tpl->utimer_list, do_jiffies);

• utimer_ticker(tpl->utimer_list);

if (cnt==multiple) {

• timer_ticker(tpl->timer_list, do_jiffies);

• timer_ticker(tpl->timer_list);

cnt = 0; } }

Hello,

On 07/07/2009 11:51 AM, hans@onsmail.nl wrote:

Daniel,

I'm wondering if the patch you supplied wich solved my fr_inv_timer problem (thanks for that) is due to a bug or is caused by something in my configuration?

I need to investigate a bit more, as I get contradictory reports. Some say that with the patch behaves ok, others say that behaves wrong. So, it could be also a matter of config. I can make the patch optional, via some config parameter, though, so it can be in the trunk for both groups.

Cheers, Daniel

Regards Hans

----- Original Message ----- From: hans@onsmail.nl To: "Daniel-Constantin Mierla" miconda@gmail.com Cc: users@lists.kamailio.org Sent: Tuesday, June 30, 2009 12:30 Subject: Re: [Kamailio-Users] strange fr_inv_timer behaviour

...

Daniel,

After applying the patch the 'fr_inv_timer' is working.

Thanks Hans

----- Original Message ----- From: "Daniel-Constantin Mierla" miconda@gmail.com To: hans@onsmail.nl Cc: users@lists.kamailio.org Sent: Tuesday, June 30, 2009 11:28 Subject: Re: [Kamailio-Users] strange fr_inv_timer behaviour

...

please take this patch and try. The other one I just sent included some work done for nathelper module.

Thanks, Daniel

On 06/30/2009 11:26 AM, Daniel-Constantin Mierla wrote:

...

Hello,

On 06/30/2009 09:26 AM, hans@onsmail.nl wrote:

...

I'm still trying to find out why the fr_inv_timer isn't working properly.

I tried version 1.5 with a very basic configuration and then the timeout is sent to early (about half the 'fr_inv_timer' value) but when running version 1.4 (on the same machine) everything is working fine and the timeout occures after the amount of seconds defined by 'fr_inv_timer'.

Anyone any idea what can cause this behavior in 1.5 (and not in 1.4) ?

can you try attached patch?

Thanks, Daniel

...

----- Original Message ----- From: hans@onsmail.nl To: "Daniel-Constantin Mierla" miconda@gmail.com Cc: users@lists.kamailio.org Sent: Wednesday, June 10, 2009 20:10 Subject: Re: [Kamailio-Users] strange fr_inv_timer behaviour

...

Daniel,

loadmodule "tm.so" modparam("tm", "fr_inv_timer_avp", "$avp(s:callee_fr_inv_timer)") modparam("tm", "fr_timer", 3)

$avp(s:callee_fr_inv_timer) = 90;

This setting causes a 408 to be generated after 30 seconds.

If i don't use the avp but set fr_inv_timer directly i have the same problem.

Kind regards Hans

> Hello, > > can you send me all tm module parameters you set? > > I tried to reproduce, but all was fine: > - 40 sec t/o > INVITE: U 2009/06/10 12:52:54.457315 213.133.111.169:5062 -> > 86.121.130.133:6536 > 408: U 2009/06/10 12:53:35.084385 213.133.111.169:5062 -> > 86.121.130.133:5060 > > - 60 sec t/o > INVITE: U 2009/06/10 12:58:05.806196 213.133.111.169:5062 -> > 86.121.130.133:6536 > 408: U 2009/06/10 12:59:05.644824 213.133.111.169:5062 -> > 86.121.130.133:5060 > > > Thanks, > Daniel > > On 06/03/2009 05:00 PM, hans@onsmail.nl wrote: >> Hi, >> >> When setting ?fr_inv_timer? to 60s and the phone is not answered >> kamailio >> generates a timeout after 20s ? If ?fr_inv_timer? is set to 90s >> the >> timeout is generated after 30s ? >> >> Doing a level 7 debug I received the following tm timer related >> output >> >> Jun 3 15:07:12 sip-proxy-01 /usr/local/sbin/kamailio[1755]: >> DBG:tm:set_timer: relative timeout is 500000 >> Jun 3 15:07:12 sip-proxy-01 /usr/local/sbin/kamailio[1755]: >> DBG:tm:insert_timer_unsafe: [4]: 0xafa6abc4 (16900000) >> Jun 3 15:07:12 sip-proxy-01 /usr/local/sbin/kamailio[1755]: >> DBG:tm:set_timer: relative timeout is 3 >> Jun 3 15:07:12 sip-proxy-01 /usr/local/sbin/kamailio[1755]: >> DBG:tm:insert_timer_unsafe: [0]: 0xafa6abe0 (51) >> Jun 3 15:07:12 sip-proxy-01 /usr/local/sbin/kamailio[1754]: >> DBG:tm:set_timer: relative timeout is 60 >> Jun 3 15:07:12 sip-proxy-01 /usr/local/sbin/kamailio[1754]: >> DBG:tm:insert_timer_unsafe: [1]: 0xafa6abe0 (108) >> Jun 3 15:07:12 sip-proxy-01 /usr/local/sbin/kamailio[1751]: >> DBG:tm:set_timer: relative timeout is 60 >> Jun 3 15:07:12 sip-proxy-01 /usr/local/sbin/kamailio[1751]: >> DBG:tm:insert_timer_unsafe: [1]: 0xafa6abe0 (108) >> Jun 3 15:07:12 sip-proxy-01 /usr/local/sbin/kamailio[1758]: >> DBG:tm:utimer_routine: timer routine:4,tl=0xafa6abc4 next=(nil), >> timeout=16900000 >> >> <phone is ringing ....> >> >> Jun 3 15:07:32 sip-proxy-01 /usr/local/sbin/kamailio[1758]: >> DBG:tm:timer_routine: timer routine:1,tl=0xafa6abe0 next=(nil), >> timeout=108 >> Jun 3 15:07:32 sip-proxy-01 /usr/local/sbin/kamailio[1758]: >> DBG:tm:final_response_handler: stop retr. and send CANCEL >> (0xafa6aa78) >> Jun 3 15:07:32 sip-proxy-01 /usr/local/sbin/kamailio[1758]: >> DBG:tm:t_should_relay_response: T_code=180, new_code=408 >> Jun 3 15:07:32 sip-proxy-01 /usr/local/sbin/kamailio[1758]: >> DBG:tm:t_pick_branch: picked branch 0, code 408 >> Jun 3 15:07:32 sip-proxy-01 /usr/local/sbin/kamailio[1758]: >> DBG:tm:t_check: start=0xafa6aa78 >> Jun 3 15:07:32 sip-proxy-01 /usr/local/sbin/kamailio[1758]: >> DBG:tm:t_check: transaction already found! >> Jun 3 15:07:32 sip-proxy-01 /usr/local/sbin/kamailio[1758]: >> DBG:tm:pv_get_tm_reply_code: reply code is <408> >> >> version: kamailio 1.5.1-notls (i386/linux) >> flags: STATISTICS, USE_IPV6, USE_TCP, DISABLE_NAGLE, USE_MCAST, >> SHM_MMAP, >> PKG_MALLOC, F_MALLOC, FAST_LOCK-ADAPTIVE_WAIT >> ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, >> MAX_LISTEN 16, >> MAX_URI_SIZE 1024, BUF_SIZE 65535, PKG_SIZE 4194304 >> poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. >> svnrevision: 2:5868M >> @(#) $Id: main.c 5608 2009-02-13 16:48:17Z henningw $ >> main.c compiled on 14:40:00 Jun 3 2009 with gcc 4.1.2 >> >> Kind regards >> Hans >> >> >> >> _______________________________________________ >> Kamailio (OpenSER) - Users mailing list >> Users@lists.kamailio.org >> http://lists.kamailio.org/cgi-bin/mailman/listinfo/users >> http://lists.openser-project.org/cgi-bin/mailman/listinfo/users >> >> > > -- > Daniel-Constantin Mierla > http://www.asipto.com/ > >

---

Kamailio (OpenSER) - Users mailing list Users@lists.kamailio.org http://lists.kamailio.org/cgi-bin/mailman/listinfo/users http://lists.openser-project.org/cgi-bin/mailman/listinfo/users

---

Kamailio (OpenSER) - Users mailing list Users@lists.kamailio.org http://lists.kamailio.org/cgi-bin/mailman/listinfo/users http://lists.openser-project.org/cgi-bin/mailman/listinfo/users

-- Daniel-Constantin Mierla http://www.asipto.com/

---

...

Index: timer.c

--- timer.c (revision 5883) +++ timer.c (working copy) @@ -16,8 +16,8 @@

• MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
• GNU General Public License for more details.

• • You should have received a copy of the GNU General Public License
• • along with this program; if not, write to the Free Software

• • You should have received a copy of the GNU General Public License
• • along with this program; if not, write to the Free Software

• Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA

02111-1307 USA

• History:

@@ -145,7 +145,7 @@

• \brief Create a new timer, allocated in private memory
• \return NULL on error, a pointer to the new timer on success

*/ -static inline struct sr_timer* new_sr_timer(timer_function f, +static inline struct sr_timer* new_sr_timer(timer_function f, void* param, unsigned int interval) { struct sr_timer* t; @@ -258,19 +258,16 @@ /*!

• \brief Process all timer on the list

*/ -static inline void timer_ticker(struct sr_timer *timer_list, int do_jiffies) +static inline void timer_ticker(struct sr_timer *timer_list) { struct sr_timer* t; unsigned int prev_jiffies;

prev_jiffies=*jiffies; *jiffies+=TIMER_TICK;

• if (do_jiffies) {
• *jiffies+=TIMER_TICK;
• }

/* test for overflow (if tick= 1s =>overflow in 136 years)*/

• if (*jiffies<prev_jiffies){
• /*force expire & update every timer, a little buggy but it

• if (*jiffies<prev_jiffies){
• /*force expire & update every timer, a little buggy but it

• happens once in 136 years :) */

for(t=timer_list;t;t=t->next){ t->expires=*jiffies+t->interval; @@ -278,7 +275,7 @@ } return; }

for (t=timer_list;t; t=t->next){ if (*jiffies>=t->expires){ t->expires=*jiffies+t->interval; @@ -291,13 +288,11 @@ /*!

• \brief Process all utimer on the list

*/ -static inline void utimer_ticker(struct sr_timer *utimer_list, int do_jiffies) +static inline void utimer_ticker(struct sr_timer *utimer_list) { struct sr_timer* t;

• if (do_jiffies) {
• *ujiffies+=UTIMER_TICK;
• }

• *ujiffies+=UTIMER_TICK;

/* no overflow test as even if we go for 1 microsecond tick, this will

• happen in 14038618 years :P */

@@ -315,6 +310,8 @@ */ static void run_timer_process(struct sr_timer_process *tpl, int do_jiffies) {

• unsigned int local_jiffies=0;
• utime_t local_ujiffies=0;

unsigned int multiple; unsigned int cnt; struct timeval o_tv; @@ -333,11 +330,16 @@ LM_DBG("tv = %ld, %ld , m=%d\n", o_tv.tv_sec,o_tv.tv_usec,multiple);

• if (!do_jiffies) {
• jiffies = &local_jiffies;
• ujiffies = &local_ujiffies;
• }

if (tpl->utimer_list==NULL) { for( ; ; ) { tv = o_tv; select( 0, 0, 0, 0, &tv);

• timer_ticker(tpl->timer_list, do_jiffies);

• timer_ticker(tpl->timer_list);

}

} else @@ -345,7 +347,7 @@ for( ; ; ) { tv = o_tv; select( 0, 0, 0, 0, &tv);

• utimer_ticker(tpl->utimer_list, do_jiffies);

• utimer_ticker(tpl->utimer_list);

}

} else @@ -353,17 +355,17 @@ for( ; ; ) { tv = o_tv; select( 0, 0, 0, 0, &tv);

• timer_ticker(tpl->timer_list, do_jiffies);
• utimer_ticker(tpl->utimer_list, do_jiffies);

• timer_ticker(tpl->timer_list);
• utimer_ticker(tpl->utimer_list);

}

} else { for( cnt=1 ; ; cnt++ ) { tv = o_tv; select( 0, 0, 0, 0, &tv);

• utimer_ticker(tpl->utimer_list, do_jiffies);

• utimer_ticker(tpl->utimer_list);

if (cnt==multiple) {

• timer_ticker(tpl->timer_list, do_jiffies);

• timer_ticker(tpl->timer_list);

cnt = 0; } }

---

Kamailio (OpenSER) - Users mailing list Users@lists.kamailio.org http://lists.kamailio.org/cgi-bin/mailman/listinfo/users http://lists.openser-project.org/cgi-bin/mailman/listinfo/users

---

Kamailio (OpenSER) - Users mailing list Users@lists.kamailio.org http://lists.kamailio.org/cgi-bin/mailman/listinfo/users http://lists.openser-project.org/cgi-bin/mailman/listinfo/users