ERROR:mi_fifo:mi_fifo_server: fifo command must begin with :: early_dialogs (1.5 rev 5834)

[Iñaki Baz Castillo]

Hi, I use the Munin plugin I did in various servers running Kamailio
1.5 (Debian 64 bits).
The munin plugins performs the Mi command:

  kamctl fifo get_statistics inuse_transactions

In one of them the installed revision is 5834 and the plugin works
perfectly, no errors in 3 months with high traffic.

However in the other server (revision  5925) there are no traffic yet
but the plugin fails sometimes (maybe once each 2-3 days). Sometimes
it gets an error:
  ERROR:mi_fifo:mi_fifo_server: fifo command must begin with :: early_dialogs

and sometimes it gets wrong value:
  kamctl fifo get_statistics inuse_transactions => 2819624   (with no
traffic !!!)

In the second case the Munin grapsh gets corrupted due to so high value.

Could it be a bug in dialog module?
Should I upgrade to revision 5939 in which I see a change for
modules/dialog/dlg_handlers.c:

-------------------------------------------------------------------------------------------------------------------------
~# svn diff -r HEAD modules/dialog/dlg_handlers.c

Index: modules/dialog/dlg_handlers.c
===================================================================
--- modules/dialog/dlg_handlers.c       (revisión: 5939)
+++ modules/dialog/dlg_handlers.c       (copia de trabajo)
@@ -824,14 +824,13 @@

        if(dlg->toroute>0 && dlg->toroute<RT_NO)
        {
+               dlg_set_ctx_dialog(dlg);
                fmsg = faked_msg_next();
                if (exec_pre_req_cb(fmsg)>0)
                {
-                       dlg_set_ctx_dialog(dlg);
                        LM_DBG("executing route %d on timeout\n", dlg->toroute);
                        set_route_type(REQUEST_ROUTE);
                        run_top_route(rlist[dlg->toroute], fmsg);
-                       dlg_set_ctx_dialog(0);
                        exec_post_req_cb(fmsg);
                }
        }
------------------------------------------------------------------------------------------------------------------------



I see some differences between the dialog module versions running in
both servers, but I think the main difference is a bug fix for the
case in which there is empty Record-Route in the response (Kamailio
crashed before the fix):

-----------------------------------------------------------------------------------------------------------------------
# svn diff -r 5834:5925 modules/dialog/dlg_handlers.c
Index: modules/dialog/dlg_handlers.c
===================================================================
--- modules/dialog/dlg_handlers.c       (revisión: 5834)
+++ modules/dialog/dlg_handlers.c       (revisión: 5925)
@@ -163,10 +163,10 @@
 int populate_leg_info( struct dlg_cell *dlg, struct sip_msg *msg,
        struct cell* t, unsigned int leg, str *tag)
 {
-       unsigned int skip_recs;
-       str cseq;
-       str contact;
-       str rr_set;
+       unsigned int skip_recs = 0;
+       str cseq = {0, 0};
+       str contact = {0, 0};
+       str rr_set = {0, 0};

        /* extract the cseq number as string */
        if (leg==DLG_CALLER_LEG) {
@@ -184,48 +184,41 @@
        /* extract the contact address */
        if (!msg->contact&&(parse_headers(msg,HDR_CONTACT_F,0)<0||!msg->contact)){
                LM_ERR("bad sip message or missing Contact hdr\n");
-               goto error0;
+       } else {
+               if ( parse_contact(msg->contact)<0 ||
+                               ((contact_body_t
*)msg->contact->parsed)->contacts==NULL ||
+                               ((contact_body_t
*)msg->contact->parsed)->contacts->next!=NULL ) {
+                       LM_ERR("bad Contact HDR\n");
+               } else {
+                       contact = ((contact_body_t
*)msg->contact->parsed)->contacts->uri;
+               }
        }
-       if ( parse_contact(msg->contact)<0 ||
-       ((contact_body_t *)msg->contact->parsed)->contacts==NULL ||
-       ((contact_body_t *)msg->contact->parsed)->contacts->next!=NULL ) {
-               LM_ERR("bad Contact HDR\n");
-               goto error0;
-       }
-       contact = ((contact_body_t *)msg->contact->parsed)->contacts->uri;
-
        /* extract the RR parts */
        if(!msg->record_route && (parse_headers(msg,HDR_RECORDROUTE_F,0)<0)  ){
                LM_ERR("failed to parse record route header\n");
-               goto error0;
-       }
-
-       if (leg==DLG_CALLER_LEG) {
-               skip_recs = 0;
        } else {
-               /* was the 200 OK received or local generated */
-               skip_recs = dlg->from_rr_nb +
-                       ((t->relaied_reply_branch>=0)?
-                               (t->uac[t->relaied_reply_branch].added_rr):0);
-       }
+               if (leg==DLG_CALLEE_LEG) {
+                       /* was the 200 OK received or local generated */
+                       skip_recs = dlg->from_rr_nb +
+                               ((t->relaied_reply_branch>=0)?
+
(t->uac[t->relaied_reply_branch].added_rr):0);
+               }

-       if(msg->record_route){
-               if( print_rr_body(msg->record_route, &rr_set, leg,
-                                                       &skip_recs) != 0 ){
-                       LM_ERR("failed to print route records \n");
-                       goto error0;
+               if(msg->record_route){
+                       if( print_rr_body(msg->record_route, &rr_set, leg,
+
&skip_recs) != 0 ){
+                               LM_ERR("failed to print route records \n");
+                       }
                }
-       } else {
-               rr_set.s = 0;
-               rr_set.len = 0;
        }

        if(leg==DLG_CALLER_LEG)
                dlg->from_rr_nb = skip_recs;

        LM_DBG("route_set %.*s, contact %.*s, cseq %.*s and bind_addr %.*s\n",
-               rr_set.len, rr_set.s, contact.len, contact.s,
-               cseq.len, cseq.s,
+               rr_set.len, (rr_set.len)?rr_set.s:"",
+               contact.len, (contact.len)?contact.s:"",
+               cseq.len, (cseq.len)?cseq.s:"",
                msg->rcv.bind_address->sock_str.len,
                msg->rcv.bind_address->sock_str.s);
-----------------------------------------------------------------------------------------------------------------------



Perhaps a regression in rev 5925 so I should upgrade?
Thanks.


--
Iñaki Baz Castillo
<ibc@...>

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

[miconda]

Hello Inaki,

the fixes you listed below are not related to the statistics in dialog
module. It might be a bug totally different. However, the
inuse_transactions are reported by TM and that should be pretty stable.
The value is pretty odd, since usual bugs in statistics were caused by
going negative, resulting in very high values, but yours is not close at
all to "-1", which gives no immediate hints.

How often to you fetch statistics? FIFO files are well known not to be
scalable and have losses, reason for datagram MI transport or xmlrpc.

Cheers,
Daniel

On 15.10.2009 17:08 Uhr, Iñaki Baz Castillo wrote:

> Hi, I use the Munin plugin I did in various servers running Kamailio
> 1.5 (Debian 64 bits).
> The munin plugins performs the Mi command:
>
>   kamctl fifo get_statistics inuse_transactions
>
> In one of them the installed revision is 5834 and the plugin works
> perfectly, no errors in 3 months with high traffic.
>
> However in the other server (revision  5925) there are no traffic yet
> but the plugin fails sometimes (maybe once each 2-3 days). Sometimes
> it gets an error:
>   ERROR:mi_fifo:mi_fifo_server: fifo command must begin with :: early_dialogs
>
> and sometimes it gets wrong value:
>   kamctl fifo get_statistics inuse_transactions => 2819624   (with no
> traffic !!!)
>
> In the second case the Munin grapsh gets corrupted due to so high value.
>
> Could it be a bug in dialog module?
> Should I upgrade to revision 5939 in which I see a change for
> modules/dialog/dlg_handlers.c:
>
> -------------------------------------------------------------------------------------------------------------------------
> ~# svn diff -r HEAD modules/dialog/dlg_handlers.c
>
> Index: modules/dialog/dlg_handlers.c
> ===================================================================
> --- modules/dialog/dlg_handlers.c       (revisión: 5939)
> +++ modules/dialog/dlg_handlers.c       (copia de trabajo)
> @@ -824,14 +824,13 @@
>
>         if(dlg->toroute>0 && dlg->toroute<RT_NO)
>         {
> +               dlg_set_ctx_dialog(dlg);
>                 fmsg = faked_msg_next();
>                 if (exec_pre_req_cb(fmsg)>0)
>                 {
> -                       dlg_set_ctx_dialog(dlg);
>                         LM_DBG("executing route %d on timeout\n", dlg->toroute);
>                         set_route_type(REQUEST_ROUTE);
>                         run_top_route(rlist[dlg->toroute], fmsg);
> -                       dlg_set_ctx_dialog(0);
>                         exec_post_req_cb(fmsg);
>                 }
>         }
> ------------------------------------------------------------------------------------------------------------------------
>
>
>
> I see some differences between the dialog module versions running in
> both servers, but I think the main difference is a bug fix for the
> case in which there is empty Record-Route in the response (Kamailio
> crashed before the fix):
>
> -----------------------------------------------------------------------------------------------------------------------
> # svn diff -r 5834:5925 modules/dialog/dlg_handlers.c
> Index: modules/dialog/dlg_handlers.c
> ===================================================================
> --- modules/dialog/dlg_handlers.c       (revisión: 5834)
> +++ modules/dialog/dlg_handlers.c       (revisión: 5925)
> @@ -163,10 +163,10 @@
>  int populate_leg_info( struct dlg_cell *dlg, struct sip_msg *msg,
>         struct cell* t, unsigned int leg, str *tag)
>  {
> -       unsigned int skip_recs;
> -       str cseq;
> -       str contact;
> -       str rr_set;
> +       unsigned int skip_recs = 0;
> +       str cseq = {0, 0};
> +       str contact = {0, 0};
> +       str rr_set = {0, 0};
>
>         /* extract the cseq number as string */
>         if (leg==DLG_CALLER_LEG) {
> @@ -184,48 +184,41 @@
>         /* extract the contact address */
>         if (!msg->contact&&(parse_headers(msg,HDR_CONTACT_F,0)<0||!msg->contact)){
>                 LM_ERR("bad sip message or missing Contact hdr\n");
> -               goto error0;
> +       } else {
> +               if ( parse_contact(msg->contact)<0 ||
> +                               ((contact_body_t
> *)msg->contact->parsed)->contacts==NULL ||
> +                               ((contact_body_t
> *)msg->contact->parsed)->contacts->next!=NULL ) {
> +                       LM_ERR("bad Contact HDR\n");
> +               } else {
> +                       contact = ((contact_body_t
> *)msg->contact->parsed)->contacts->uri;
> +               }
>         }
> -       if ( parse_contact(msg->contact)<0 ||
> -       ((contact_body_t *)msg->contact->parsed)->contacts==NULL ||
> -       ((contact_body_t *)msg->contact->parsed)->contacts->next!=NULL ) {
> -               LM_ERR("bad Contact HDR\n");
> -               goto error0;
> -       }
> -       contact = ((contact_body_t *)msg->contact->parsed)->contacts->uri;
> -
>         /* extract the RR parts */
>         if(!msg->record_route && (parse_headers(msg,HDR_RECORDROUTE_F,0)<0)  ){
>                 LM_ERR("failed to parse record route header\n");
> -               goto error0;
> -       }
> -
> -       if (leg==DLG_CALLER_LEG) {
> -               skip_recs = 0;
>         } else {
> -               /* was the 200 OK received or local generated */
> -               skip_recs = dlg->from_rr_nb +
> -                       ((t->relaied_reply_branch>=0)?
> -                               (t->uac[t->relaied_reply_branch].added_rr):0);
> -       }
> +               if (leg==DLG_CALLEE_LEG) {
> +                       /* was the 200 OK received or local generated */
> +                       skip_recs = dlg->from_rr_nb +
> +                               ((t->relaied_reply_branch>=0)?
> +
> (t->uac[t->relaied_reply_branch].added_rr):0);
> +               }
>
> -       if(msg->record_route){
> -               if( print_rr_body(msg->record_route, &rr_set, leg,
> -                                                       &skip_recs) != 0 ){
> -                       LM_ERR("failed to print route records \n");
> -                       goto error0;
> +               if(msg->record_route){
> +                       if( print_rr_body(msg->record_route, &rr_set, leg,
> +
> &skip_recs) != 0 ){
> +                               LM_ERR("failed to print route records \n");
> +                       }
>                 }
> -       } else {
> -               rr_set.s = 0;
> -               rr_set.len = 0;
>         }
>
>         if(leg==DLG_CALLER_LEG)
>                 dlg->from_rr_nb = skip_recs;
>
>         LM_DBG("route_set %.*s, contact %.*s, cseq %.*s and bind_addr %.*s\n",
> -               rr_set.len, rr_set.s, contact.len, contact.s,
> -               cseq.len, cseq.s,
> +               rr_set.len, (rr_set.len)?rr_set.s:"",
> +               contact.len, (contact.len)?contact.s:"",
> +               cseq.len, (cseq.len)?cseq.s:"",
>                 msg->rcv.bind_address->sock_str.len,
>                 msg->rcv.bind_address->sock_str.s);
> -----------------------------------------------------------------------------------------------------------------------
>
>
>
> Perhaps a regression in rev 5925 so I should upgrade?
> Thanks.
>
>
>  

--
Daniel-Constantin Mierla
* Kamailio SIP Masterclass, Nov 9-13, 2009, Berlin
* http://www.asipto.com/index.php/sip-router-masterclass/


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

[Iñaki Baz Castillo]

El Jueves, 15 de Octubre de 2009, Daniel-Constantin Mierla escribió:
> Hello Inaki,
>
> the fixes you listed below are not related to the statistics in dialog
> module. It might be a bug totally different. However, the
> inuse_transactions are reported by TM and that should be pretty stable.

Yes, my fault when copy&pasting my log. In fact, I get that error for dialog
and tm modules:

-------------
Oct 14 21:40:03 localhost kamailio[24042]: ERROR:mi_fifo:mi_fifo_server: fifo
command must begin with :: early_dialogs
Oct 15 06:20:03 localhost kamailio[24042]: ERROR:mi_fifo:mi_fifo_server: fifo
command must begin with :: inuse_transactions
-------------

This is, *all* the MI commands fail.

And the real wrong value returned by the MI command is just related to dialog
module. Please forget the value inuse_transactions = 2819624 as the fact is
the following:

  Wed Oct 14 21:40:03 CEST 2009: dialogs_early = 2819624

(not sure however if same has occurred for inuse_transactions sometimes).





> The value is pretty odd, since usual bugs in statistics were caused by
> going negative, resulting in very high values, but yours is not close at
> all to "-1", which gives no immediate hints.
>
> How often to you fetch statistics?

Munin runs the plugins each 5 minutes. And as I said this is a server with no
traffic yet.


Thanks.


--
Iñaki Baz Castillo <ibc@...>

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

[Iñaki Baz Castillo]

El Viernes, 16 de Octubre de 2009, Iñaki Baz Castillo escribió:

> El Jueves, 15 de Octubre de 2009, Daniel-Constantin Mierla escribió:
> > Hello Inaki,
> >
> > the fixes you listed below are not related to the statistics in dialog
> > module. It might be a bug totally different. However, the
> > inuse_transactions are reported by TM and that should be pretty stable.
>
> Yes, my fault when copy&pasting my log. In fact, I get that error for
>  dialog and tm modules:
>
> -------------
> Oct 14 21:40:03 localhost kamailio[24042]: ERROR:mi_fifo:mi_fifo_server:
>  fifo command must begin with :: early_dialogs
> Oct 15 06:20:03 localhost kamailio[24042]: ERROR:mi_fifo:mi_fifo_server:
>  fifo command must begin with :: inuse_transactions
> -------------
>
> This is, *all* the MI commands fail.
>
> And the real wrong value returned by the MI command is just related to
>  dialog module. Please forget the value inuse_transactions = 2819624 as the
>  fact is the following:
>
>   Wed Oct 14 21:40:03 CEST 2009: dialogs_early = 2819624
>
> (not sure however if same has occurred for inuse_transactions sometimes).
>
> > The value is pretty odd, since usual bugs in statistics were caused by
> > going negative, resulting in very high values, but yours is not close at
> > all to "-1", which gives no immediate hints.
> >
> > How often to you fetch statistics?
>
> Munin runs the plugins each 5 minutes. And as I said this is a server with
>  no traffic yet.

The error remains and it just affects to dialog module. I log in a file when
the Munin plugin performing the fifo command gets a dialg_xxxx value greater
than 200 (note that there is no traffic in this Kamailio !!!), and this is
what I've got from past friday (3 days ago) having the latest 1.5 version
installed:

Sat Oct 17 00:50:03 CEST 2009: dialogs_early = 134217728
Sat Oct 17 00:50:03 CEST 2009: dialogs_total = 134217728
Sat Oct 17 16:50:03 CEST 2009: dialogs_early = 2820392
Sat Oct 17 16:50:03 CEST 2009: dialogs_total = 2820392




--
Iñaki Baz Castillo <ibc@...>

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

[miconda]

On 18.10.2009 22:36 Uhr, Iñaki Baz Castillo wrote:

> El Viernes, 16 de Octubre de 2009, Iñaki Baz Castillo escribió:
>  
>> El Jueves, 15 de Octubre de 2009, Daniel-Constantin Mierla escribió:
>>    
>>> Hello Inaki,
>>>
>>> the fixes you listed below are not related to the statistics in dialog
>>> module. It might be a bug totally different. However, the
>>> inuse_transactions are reported by TM and that should be pretty stable.
>>>      
>> Yes, my fault when copy&pasting my log. In fact, I get that error for
>>  dialog and tm modules:
>>
>> -------------
>> Oct 14 21:40:03 localhost kamailio[24042]: ERROR:mi_fifo:mi_fifo_server:
>>  fifo command must begin with :: early_dialogs
>> Oct 15 06:20:03 localhost kamailio[24042]: ERROR:mi_fifo:mi_fifo_server:
>>  fifo command must begin with :: inuse_transactions
>> -------------
>>
>> This is, *all* the MI commands fail.
>>
>> And the real wrong value returned by the MI command is just related to
>>  dialog module. Please forget the value inuse_transactions = 2819624 as the
>>  fact is the following:
>>
>>   Wed Oct 14 21:40:03 CEST 2009: dialogs_early = 2819624
>>
>> (not sure however if same has occurred for inuse_transactions sometimes).
>>
>>    
>>> The value is pretty odd, since usual bugs in statistics were caused by
>>> going negative, resulting in very high values, but yours is not close at
>>> all to "-1", which gives no immediate hints.
>>>
>>> How often to you fetch statistics?
>>>      
>> Munin runs the plugins each 5 minutes. And as I said this is a server with
>>  no traffic yet.
>>    
>
> The error remains and it just affects to dialog module. I log in a file when
> the Munin plugin performing the fifo command gets a dialg_xxxx value greater
> than 200 (note that there is no traffic in this Kamailio !!!), and this is
> what I've got from past friday (3 days ago) having the latest 1.5 version
> installed:
>
> Sat Oct 17 00:50:03 CEST 2009: dialogs_early = 134217728
> Sat Oct 17 00:50:03 CEST 2009: dialogs_total = 134217728
> Sat Oct 17 16:50:03 CEST 2009: dialogs_early = 2820392
> Sat Oct 17 16:50:03 CEST 2009: dialogs_total = 2820392
>
>
>  

sorry for delay, being offline for some time...

This is interesting as you say there is no traffic on server. Since is a
testing system I guess we can play a bit with it. The error might be due
to a bug in FIFO command parsing or a bug in printing the command to
fifo file.

The best is to add a debug message that will print the entire fifo
command received by kamailio. Should I do a patch for you?

More strange is with dialog value as there is no traffic, that value
should not be affected at all and should be zero. If you do kamctl
get_statistics all from command line, do you get same value?

Thanks,
Daniel


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

[Iñaki Baz Castillo]

2009/10/28 Daniel-Constantin Mierla <miconda@...>:

>> The error remains and it just affects to dialog module. I log in a file
>> when the Munin plugin performing the fifo command gets a dialg_xxxx value
>> greater than 200 (note that there is no traffic in this Kamailio !!!), and
>> this is what I've got from past friday (3 days ago) having the latest 1.5
>> version installed:
>>
>> Sat Oct 17 00:50:03 CEST 2009: dialogs_early = 134217728
>> Sat Oct 17 00:50:03 CEST 2009: dialogs_total = 134217728
>> Sat Oct 17 16:50:03 CEST 2009: dialogs_early = 2820392
>> Sat Oct 17 16:50:03 CEST 2009: dialogs_total = 2820392
>>
>>
> This is interesting as you say there is no traffic on server. Since is a
> testing system I guess we can play a bit with it.

Well, no it's already on production, anyhow I can experiment a bit on it :)



> The error might be due to
> a bug in FIFO command parsing or a bug in printing the command to fifo file.

If it helps, I could reproduce the problem without the munin plugin,
just by running the command "kamctl fifo get_statistics
active_dialogs" several times. Ramdomly it returns an error "fifo
command must begin with :: total_size".



> The best is to add a debug message that will print the entire fifo command
> received by kamailio. Should I do a patch for you?

I will try by myself, thanks.


> More strange is with dialog value as there is no traffic, that value should
> not be affected at all and should be zero. If you do kamctl get_statistics
> all from command line, do you get same value?

The main problem is that this issue occurs jsut *some* times. Note
that munin plugins are executed each 5 minutos and the MI command just
fails "some times", so it would be really impossible to check if
"kamctl get_statistics" also fails.

However, about the big dialogs numbers the command returns, I extract
that value as follows (note that I did some modifications in the munin
plugin trying top detect the isssue):

-------------------
dialogs_early=$(kamctl fifo get_statistics early_dialogs) 2>>
/tmp/munin-kamailio.error
retcode=$?
if [ $retcode -ne 0 ] ; then
  echo "$(date): kamctl fifo get_statistics early_dialogs -> retcode =
$retcode"  >> /tmp/munin-kamailio.error
fi

# This is not a server in production so dialog_early must be near 0:
if [ $dialogs_early -ge 200 ] ; then
  echo "$(date): dialogs_early = $dialogs_early" 2>&1 >>
/tmp/munin-kamailio.error
fi
------------------


And the output I get in  /tmp/munin-kamailio.error is

Sat Oct 17 00:50:03 CEST 2009: dialogs_early = 134217728
Sat Oct 17 16:50:03 CEST 2009: dialogs_early = 2820392
Fri Oct 23 12:45:04 CEST 2009: dialogs_early = 2863080


This is:

The command "dialogs_early=$(kamctl fifo get_statistics early_dialogs)
2>> /tmp/munin-kamailio.error" ALWAYS returns 0 (correct return code
in bash) so it never "fails".

The value the above command returns is obviously wrong (134217728, 2820392...).




--
Iñaki Baz Castillo
<ibc@...>

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

[miconda]

On 28.10.2009 12:55 Uhr, Iñaki Baz Castillo wrote:

> 2009/10/28 Daniel-Constantin Mierla <miconda@...>:
>  
>>> The error remains and it just affects to dialog module. I log in a file
>>> when the Munin plugin performing the fifo command gets a dialg_xxxx value
>>> greater than 200 (note that there is no traffic in this Kamailio !!!), and
>>> this is what I've got from past friday (3 days ago) having the latest 1.5
>>> version installed:
>>>
>>> Sat Oct 17 00:50:03 CEST 2009: dialogs_early = 134217728
>>> Sat Oct 17 00:50:03 CEST 2009: dialogs_total = 134217728
>>> Sat Oct 17 16:50:03 CEST 2009: dialogs_early = 2820392
>>> Sat Oct 17 16:50:03 CEST 2009: dialogs_total = 2820392
>>>
>>>
>>>      
>> This is interesting as you say there is no traffic on server. Since is a
>> testing system I guess we can play a bit with it.
>>    
>
> Well, no it's already on production, anyhow I can experiment a bit on it :)
>  

ok.

>> The error might be due to
>> a bug in FIFO command parsing or a bug in printing the command to fifo file.
>>    
>
> If it helps, I could reproduce the problem without the munin plugin,
> just by running the command "kamctl fifo get_statistics
> active_dialogs" several times. Ramdomly it returns an error "fifo
> command must begin with :: total_size".
>  

I tried (about 100 times) and gives all the time 0. I had no traffic at
all. Shall I do something else to reproduce?

Thanks,
Daniel

>> The best is to add a debug message that will print the entire fifo command
>> received by kamailio. Should I do a patch for you?
>>    
>
> I will try by myself, thanks.
>
>
>  
>> More strange is with dialog value as there is no traffic, that value should
>> not be affected at all and should be zero. If you do kamctl get_statistics
>> all from command line, do you get same value?
>>    
>
> The main problem is that this issue occurs jsut *some* times. Note
> that munin plugins are executed each 5 minutos and the MI command just
> fails "some times", so it would be really impossible to check if
> "kamctl get_statistics" also fails.
>
> However, about the big dialogs numbers the command returns, I extract
> that value as follows (note that I did some modifications in the munin
> plugin trying top detect the isssue):
>
> -------------------
> dialogs_early=$(kamctl fifo get_statistics early_dialogs) 2>>
> /tmp/munin-kamailio.error
> retcode=$?
> if [ $retcode -ne 0 ] ; then
>   echo "$(date): kamctl fifo get_statistics early_dialogs -> retcode =
> $retcode"  >> /tmp/munin-kamailio.error
> fi
>
> # This is not a server in production so dialog_early must be near 0:
> if [ $dialogs_early -ge 200 ] ; then
>   echo "$(date): dialogs_early = $dialogs_early" 2>&1 >>
> /tmp/munin-kamailio.error
> fi
> ------------------
>
>
> And the output I get in  /tmp/munin-kamailio.error is
>
> Sat Oct 17 00:50:03 CEST 2009: dialogs_early = 134217728
> Sat Oct 17 16:50:03 CEST 2009: dialogs_early = 2820392
> Fri Oct 23 12:45:04 CEST 2009: dialogs_early = 2863080
>
>
> This is:
>
> The command "dialogs_early=$(kamctl fifo get_statistics early_dialogs)
> 2>> /tmp/munin-kamailio.error" ALWAYS returns 0 (correct return code
> in bash) so it never "fails".
>
> The value the above command returns is obviously wrong (134217728, 2820392...).
>
>
>
>
>  

--
Daniel-Constantin Mierla
* Kamailio SIP Masterclass, Nov 9-13, 2009, Berlin
* http://www.asipto.com/index.php/sip-router-masterclass/


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

[Iñaki Baz Castillo]

2009/10/28 Daniel-Constantin Mierla <miconda@...>:
>> If it helps, I could reproduce the problem without the munin plugin,
>> just by running the command "kamctl fifo get_statistics
>> active_dialogs" several times. Ramdomly it returns an error "fifo
>> command must begin with :: total_size".
>>
>
> I tried (about 100 times) and gives all the time 0. I had no traffic at all.
> Shall I do something else to reproduce?

No, in my case it just "occurs". I do nothing "interesting" :)
However, a similar kamailio configuration in other server (with high
traffic) has never issued this problem (same munin pluign running,
more or less same Kamailio 1.5 revision...).

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

[miconda]

On 29.10.2009 11:59 Uhr, Iñaki Baz Castillo wrote:

> 2009/10/28 Daniel-Constantin Mierla <miconda@...>:
>  
>>> If it helps, I could reproduce the problem without the munin plugin,
>>> just by running the command "kamctl fifo get_statistics
>>> active_dialogs" several times. Ramdomly it returns an error "fifo
>>> command must begin with :: total_size".
>>>
>>>      
>> I tried (about 100 times) and gives all the time 0. I had no traffic at all.
>> Shall I do something else to reproduce?
>>    
>
> No, in my case it just "occurs". I do nothing "interesting" :)
> However, a similar kamailio configuration in other server (with high
> traffic) has never issued this problem (same munin pluign running,
> more or less same Kamailio 1.5 revision...).
>  

hmm, this is very interesting.... i have ubuntu 9.04 here...

--
Daniel-Constantin Mierla



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

[Iñaki Baz Castillo]

2009/10/29 Daniel-Constantin Mierla <miconda@...>:

>> No, in my case it just "occurs". I do nothing "interesting" :)
>> However, a similar kamailio configuration in other server (with high
>> traffic) has never issued this problem (same munin pluign running,
>> more or less same Kamailio 1.5 revision...).
>>
>
> hmm, this is very interesting.... i have ubuntu 9.04 here...

When I get some time I'll add some logs to the MI code as you suggested.



--
Iñaki Baz Castillo
<ibc@...>

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

[Iñaki Baz Castillo]

El Jueves, 29 de Octubre de 2009, Iñaki Baz Castillo escribió:
> 2009/10/29 Daniel-Constantin Mierla <miconda@...>:
> >> No, in my case it just "occurs". I do nothing "interesting" :)
> >> However, a similar kamailio configuration in other server (with high
> >> traffic) has never issued this problem (same munin pluign running,
> >> more or less same Kamailio 1.5 revision...).
> >
> > hmm, this is very interesting.... i have ubuntu 9.04 here...
>
> When I get some time I'll add some logs to the MI code as you suggested.

Some news Daniel. The problem is not just for dialog statistics but also for
others as TM.
I've got the following value for in inuse_transactions: 2888600.

I still must try what you sugested though.


--
Iñaki Baz Castillo <ibc@...>

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

[miconda]

Hello,

On 19.11.2009 9:38 Uhr, Iñaki Baz Castillo wrote:

> El Jueves, 29 de Octubre de 2009, Iñaki Baz Castillo escribió:
>  
>> 2009/10/29 Daniel-Constantin Mierla <miconda@...>:
>>    
>>>> No, in my case it just "occurs". I do nothing "interesting" :)
>>>> However, a similar kamailio configuration in other server (with high
>>>> traffic) has never issued this problem (same munin pluign running,
>>>> more or less same Kamailio 1.5 revision...).
>>>>        
>>> hmm, this is very interesting.... i have ubuntu 9.04 here...
>>>      
>> When I get some time I'll add some logs to the MI code as you suggested.
>>    
>
> Some news Daniel. The problem is not just for dialog statistics but also for
> others as TM.
> I've got the following value for in inuse_transactions: 2888600.
>  

strange ... once you get this value it keeps being so wrong until
restart or the next fetch of the values gets to normal?

Cheers,
Daniel

> I still must try what you sugested though.
>
>
>  

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


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

[Iñaki Baz Castillo]

El Sábado, 21 de Noviembre de 2009, Daniel-Constantin Mierla escribió:

> Hello,
>
> On 19.11.2009 9:38 Uhr, Iñaki Baz Castillo wrote:
> > El Jueves, 29 de Octubre de 2009, Iñaki Baz Castillo escribió:
> >> 2009/10/29 Daniel-Constantin Mierla <miconda@...>:
> >>>> No, in my case it just "occurs". I do nothing "interesting" :)
> >>>> However, a similar kamailio configuration in other server (with high
> >>>> traffic) has never issued this problem (same munin pluign running,
> >>>> more or less same Kamailio 1.5 revision...).
> >>>
> >>> hmm, this is very interesting.... i have ubuntu 9.04 here...
> >>
> >> When I get some time I'll add some logs to the MI code as you suggested.
> >
> > Some news Daniel. The problem is not just for dialog statistics but also
> > for others as TM.
> > I've got the following value for in inuse_transactions: 2888600.
>
> strange ... once you get this value it keeps being so wrong until
> restart or the next fetch of the values gets to normal?

Next values are normal for hours/days. After some time it fails again.


--
Iñaki Baz Castillo <ibc@...>

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

[miconda]

On 21.11.2009 2:57 Uhr, Iñaki Baz Castillo wrote:

> El Sábado, 21 de Noviembre de 2009, Daniel-Constantin Mierla escribió:
>  
>> Hello,
>>
>> On 19.11.2009 9:38 Uhr, Iñaki Baz Castillo wrote:
>>    
>>> El Jueves, 29 de Octubre de 2009, Iñaki Baz Castillo escribió:
>>>      
>>>> 2009/10/29 Daniel-Constantin Mierla <miconda@...>:
>>>>        
>>>>>> No, in my case it just "occurs". I do nothing "interesting" :)
>>>>>> However, a similar kamailio configuration in other server (with high
>>>>>> traffic) has never issued this problem (same munin pluign running,
>>>>>> more or less same Kamailio 1.5 revision...).
>>>>>>            
>>>>> hmm, this is very interesting.... i have ubuntu 9.04 here...
>>>>>          
>>>> When I get some time I'll add some logs to the MI code as you suggested.
>>>>        
>>> Some news Daniel. The problem is not just for dialog statistics but also
>>> for others as TM.
>>> I've got the following value for in inuse_transactions: 2888600.
>>>      
>> strange ... once you get this value it keeps being so wrong until
>> restart or the next fetch of the values gets to normal?
>>    
>
> Next values are normal for hours/days. After some time it fails again.
>
>
>  

i do charts for inuse_transactions statistics and haven't spotted such
case yet. However, I fetch them in config, in a timer route, and store
in a db table ...

If next value is ok, then there is not a problem with the statistics
framework, it might be in fifo module or something in kamctl.

Cheers,
Daniel

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


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