[Devel] Re: crash after xlite shutdown ...

Cesc cesc.santa at gmail.com
Fri Apr 13 18:57:41 CEST 2007


Hi,

My bad ... partly.
I changed the e-tag generation algorithm ... and it turned out to be
not working ... too long e-tag? i changed it for something shorter and
it works ... but the "too long" problem stays ...

Cesc

On 4/13/07, Cesc <cesc.santa at gmail.com> wrote:
> Hi Anca,
>
> Maybe I was too fast in saying it worked ...
> This was a fresh start, with an empty database ...
>
>
>
>  1(10728)  method:  <PUBLISH>
>  1(10728)  uri:     <sip:Klaas at cafes.org>
>  1(10728)  version: <SIP/2.0>
>  1(10728) parse_headers: flags=2
>  1(10728) Found param type 232, <branch> = <z9hG4bK5c43.eccf8be2.0>; state=16
>  1(10728) end of header reached, state=5
>  1(10728) parse_headers: Via found, flags=2
>  1(10728) parse_headers: this is the first via
>  1(10728) After parse_msg...
>  1(10728) preparing to run routing scripts...
>  1(10728) parse_headers: flags=100
>  1(10728) Found param type 234, <received> = <192.168.3.170>; state=6
>  1(10728) Found param type 232, <branch> = <0>; state=16
>  1(10728) end of header reached, state=5
>  1(10728) parse_headers: Via found, flags=100
>  1(10728) parse_headers: this is the second via
>  1(10728) Found param type 232, <branch> =
> <z9hG4bK-d87543-3b05355b231a0a20-1--d87543->; state=6
>  1(10728) Found param type 235, <rport> = <34214>; state=16
>  1(10728) end of header reached, state=5
>  1(10728) parse_headers: Via found, flags=100
>  1(10728) DEBUG:maxfwd:is_maxfwd_present: value = 15
>  1(10728) ==============================================================================================
>  1(10728) parse_headers: flags=10
>  1(10728) DEBUG:parse_to:end of header reached, state=10
>  1(10728) DBUG:parse_to: display={"X-lite user 1"}, ruri={sip:Klaas at cafes.org}
>  1(10728) DEBUG: get_hdr_field: <To> [38]; uri=[sip:Klaas at cafes.org]
>  1(10728) DEBUG: to body ["X-lite user 1"<sip:Klaas at cafes.org>
> ]
>  1(10728) DEBUG: add_param: tag=f677e724
>  1(10728) DEBUG:parse_to:end of header reached, state=29
>  1(10728) DBUG:parse_to: display={"X-lite user 1"}, ruri={sip:Klaas at cafes.org}
>  1(10728) New Message received: [1] from [sip:Klaas at cafes.org]
>  1(10728) Request method used:[PUBLISH].
>  1(10728) =============================================================================================
>  1(10728) DEBUG: t_newtran:  T on entrance=0xffffffff
>  1(10728) parse_headers: flags=ffffffffffffffff
>  1(10728) get_hdr_field: cseq <CSeq>: <1> <PUBLISH>
>  1(10728) DEBUG: get_hdr_body : content_length=481
>  1(10728) found end of header
>  1(10728) parse_headers: flags=78
>  1(10728) t_lookup_request: start searching: hash=13509, isACK=0
>  1(10728) DEBUG: RFC3261 transaction matching failed
>  1(10728) DEBUG: t_lookup_request: no transaction found
>  1(10728) =============================================================================================
>  1(10728) The request method used is to [PUBLISH] information. (handle publish)
>  1(10728) =============================================================================================
>  1(10728) parse_headers: flags=ffffffffffffffff
>  1(10728) PRESENCE:handle_publish: SIP-If-Match not found
>  1(10728) PRESENCE: publish: generate_ETag: callid is not NULL ... using it ...
>  1(10728) PRESENCE: generate_ETag: etag=
> cafes.etag.a.N2RkYmU1MTVjZjkzOWYwNjQwNzFhNjg3ZGQyNDcxZWE. / 57
>   1(10728) PRESENCE:handle_publish: new etag  =
> cafes.etag.a.N2RkYmU1MTVjZjkzOWYwNjQwNzFhNjg3ZGQyNDcxZWE.
>  1(10728) PRESENCE: handle_publish: 'expires' found
>  1(10728) PRESENCE: handle_publish: lexpire= 3600
>  1(10728) PRESENCE: handle_publish: 'To' header ALREADY PARSED:
> <sip:Klaas at cafes.org>
>  1(10728) parse_headers: flags=ffffffffffffffff
>  1(10728) presentity.c: update_presentity: querying: domain = cafes.org
>  1(10728) presentity.c: update_presentity: querying: username = Klaas
>  1(10728) presentity.c: update_presentity: querying: etag =
> cafes.etag.a.N2RkYmU1MTVjZjkzOWYwNjQwNzFp
>  1(10728) PRESENCE:update_presentity: inserting 7 cols intotable
>  1(10728) DBT:dbt_load_file: request for table [presentity]
>  1(10728) DBT:dbt_load_file: db is [/cafes/openser.1.2/cafesConf/dbtext]
>  1(10728) DBT:dbt_load_file: loading file
> [/cafes/openser.1.2/cafesConf/dbtext/presentity]
>  1(10728) DBT: column[0] is INT!
>  1(10728) DBT: column[1] is STR!
>  1(10728) DBT: column[2] is STR!
>  1(10728) DBT: column[3] is STR!
>  1(10728) DBT: column[4] is STR!
>  1(10728) DBT: column[5] is INT!
>  1(10728) DBT: column[6] is INT!
>  1(10728) DBT: column[7] is STR!
>  1(10728) DTB:dbt_db_get_table: presentity
>
>
> #0  fm_malloc (qm=0x8166600, size=32) at mem/f_malloc.c:267
> #1  0xb7f08bee in dbt_get_refs (_dtp=0xb5cec0e0, _k=0xbf9237a0, _n=7)
> at dbt_res.c:160
> #2  0xb7f030e2 in dbt_insert (_h=0x816fd98, _k=0xbf9237a0,
> _v=0xbf9236e4, _n=7) at dbt_base.c:343
> #3  0xb7d34397 in update_presentity (presentity=0x8170548,
> body=0xbf9239d0, new_t=1) at presentity.c:204
> #4  0xb7d3716d in handle_publish (msg=0x8170190, str1=0x0, str2=0x0)
> at publish.c:466
> #5  0x08051354 in do_action (a=0x816eff8, msg=0x8170190) at action.c:883
> #6  0x080505aa in run_action_list (a=0x816eb38, msg=0x8170190) at action.c:131
> #7  0x080529ea in do_action (a=0x816fad0, msg=0x8170190) at action.c:801
> #8  0x080505aa in run_action_list (a=0x816c408, msg=0x8170190) at action.c:131
> #9  0x08053855 in run_top_route (a=0x816c408, msg=0x81668c8) at action.c:111
> #10 0x08080b20 in receive_msg (
>     buf=0x8135d20 "PUBLISH sip:Klaas at cafes.org
> SIP/2.0\r\nRecord-Route:
> <sip:192.168.1.150;r2=on;ftag=f677e724;lr=on>\r\nRecord-Route:
> <sip:230.0.1.75;r2=on;ftag=f677e724;lr=on>\r\nRecord-Route:
> <sip:230.0.1.75;r2=on;ftag=f67"..., len=1430, rcv_info=0xbf923e78) at
> receive.c:156
> #11 0x080aecfa in udp_rcv_loop () at udp_server.c:465
> #12 0x0806ee7e in main_loop () at main.c:834
> #13 0x080704cb in main (argc=3, argv=0xbf924024) at main.c:1399
>
>
>
> On 4/13/07, Anca-Maria Vamanu <anca at voice-system.ro> wrote:
> > Hi Cesc,
> >
> > I am glad it works.
> > That with not printing the last two values was something left from the
> > beginning when the filling was not done on the condition if the value is
> > not NULL. It should indeed be removed now. I will do that right ahead.
> > It might be easier to find where the messages come from, but since the
> > name of the function is always printed in debug messages it is sould not
> > be that hard even so.
> >
> > Best regards,
> >
> > Anca Vamanu
> >
> > Cesc wrote:
> >
> > > Hi Anca,
> > >
> > > It seems to work ... at least I cannot reproduce the problem anymore.
> > > As usual, thanks a lot!
> > >
> > > One small thing, not related to this problem ...
> > > when inserting, you print the values in DBG mode ... except the last
> > > two (n_query_cols - 2 ) ... why not all? See the diff
> > >
> > > An another small thing ... this is purely my taste ... when debugging
> > > the presence module, I found quite annoying the fact that debug
> > > messages are split into two lines, which makes it difficult to grep
> > > to find on which line they are ... I understand that this way they fit
> > > the 80columns editors, but I still think they should be all in one
> > > line ...
> > >
> > >
> > > Index: modules/presence/subscribe.c
> > > ===================================================================
> > > --- modules/presence/subscribe.c        (revision 1999)
> > > +++ modules/presence/subscribe.c        (working copy)
> > > @@ -438,23 +438,25 @@
> > >
> > >                        DBG("PRESENCE:update_subscription:Inserting
> > > into database:"
> > >                                "\nn_query_cols:%d\n",n_query_cols);
> > > -                       for(i = 0;i< n_query_cols-2; i++)
> > > +//                     for(i = 0;i< n_query_cols-2; i++)
> > > +                       for(i = 0;i< n_query_cols; i++)
> > >                        {
> > > -                               if(query_vals[i].type==DB_STR)
> > > -                               DBG("[%d] = %s %.*s\n",i, query_cols[i],
> > > -
> > > query_vals[i].val.str_val.len,query_vals[i].val.str_val.s );
> > > -                               if(query_vals[i].type==DB_INT)
> > > +                               if(query_vals[i].type==DB_STR) {
> > > +                                       DBG("[%d] = %s %.*s\n",i,
> > > query_cols[i],
> > > +
> > > query_vals[i].val.str_val.len,query_vals[i].val.str_val.s );
> > > +                               } else if(query_vals[i].type==DB_INT) {
> > >                                        DBG("[%d] = %s %d\n",i,
> > > query_cols[i],
> > >
> > > query_vals[i].val.int_val);
> > > +                               } else {
> > > +                                       DBG("[%d] = %s (unknown value
> > > type)\n",i, query_cols[i] );
> > > +                               }
> > >                        }
> > >
> > >
> > >
> > > On 4/13/07, Anca-Maria Vamanu <anca at voice-system.ro> wrote:
> > >
> > >> It is probably safer to check if expired messages exist before
> > >> attempting to delete them, assuming that a query in an empty table does
> > >> not generate an error. I have added this and commited the change.
> > >> Please tell me if you encounter further errors.
> > >>
> > >> Cesc wrote:
> > >>
> > >> > Hi Anca,
> > >> >
> > >> > I think I have further info ...
> > >> > the crash happens for i = j = 0 ...  (2(6495) DBT:dbt_get_refs:
> > >> > looping ... i=0 (4), j=0(8))
> > >> > and the reason, i think, is when file has NO data-row ... that is:
> > >> >
> > >> > file content:
> > >> > id(int) ...... NO_RETURN
> > >> > NO_DATA_ROWS
> > >> >
> > >> > If I add just a return after the table fields definition, it seems to
> > >> > be ok ...
> > >> >
> > >> > Cesc
> > >> >
> > >> > On 4/13/07, Anca-Maria Vamanu <anca at voice-system.ro> wrote:
> > >> >
> > >> >> For this problem with watchers table I can't figure where the problem
> > >> >> is. It would be very helpful if you would print the values for i
> > >> and j
> > >> >> and send the result.
> > >> >>
> > >> >> Cesc wrote:
> > >> >>
> > >> >> > I think related .... in another run of openser, i got another crash
> > >> >> > ... same backtrace on gdb ...
> > >> >> >
> > >> >> > [root at mandriva2006 openser.1.2]#  5(5142) PRESENCE:
> > >> >> > msg_watchers_clean:cleaning pending subscriptions
> > >> >> > 5(5142) DBT:dbt_load_file: request for table [watchers]
> > >> >> > 5(5142) DBT:dbt_load_file: db is
> > >> [/cafes/openser.1.2/cafesConf/dbtext]
> > >> >> > 5(5142) DBT:dbt_load_file: loading file
> > >> >> > [/cafes/openser.1.2/cafesConf/dbtext/watchers]
> > >> >> > 5(5142) DBT:dbt_load_file: state FLINE!
> > >> >> > 5(5142) DBT: column[0] is INT!
> > >> >> > 5(5142) DBT:dbt_load_file: state FLINE!
> > >> >> > 5(5142) DBT: column[1] is STR!
> > >> >> > 5(5142) DBT:dbt_load_file: state FLINE!
> > >> >> > 5(5142) DBT: column[2] is STR!
> > >> >> > 5(5142) DBT:dbt_load_file: state FLINE!
> > >> >> > 5(5142) DBT: column[3] is STR!
> > >> >> > 5(5142) DBT:dbt_load_file: state FLINE!
> > >> >> > 5(5142) DBT: column[4] is STR!
> > >> >> > 5(5142) DBT:dbt_load_file: state FLINE!
> > >> >> > 5(5142) DBT: column[5] is STR!
> > >> >> > 5(5142) DBT:dbt_load_file: state FLINE!
> > >> >> > 5(5142) DBT: column[6] is STR!
> > >> >> > 5(5142) DBT:dbt_load_file: state FLINE!
> > >> >> > 5(5142) DBT: column[7] is INT!
> > >> >> > 5(5142) DTB:dbt_db_get_table: watchers
> > >> >> >
> > >> >> >
> > >> >> > On 4/13/07, Cesc <cesc.santa at gmail.com> wrote:
> > >> >> >
> > >> >> >> Hi,
> > >> >> >>
> > >> >> >> doing some progress ... still with openser1.2 and dbtext ...
> > >> >> >>
> > >> >> >> on xlite shutdown ... crash
> > >> >> >>
> > >> >> >> #0  0xb7f89e52 in dbt_get_refs (_dtp=0xb5d6c848, _k=0xbffa6ea0,
> > >> _n=2)
> > >> >> >> at dbt_res.c:168
> > >> >> >> 168
> > >> >> >> if(strlen(_k[i])==_dtp->colv[j]->name.len
> > >> >> >> (gdb)
> > >> >> >> (gdb)
> > >> >> >> (gdb) bt
> > >> >> >> #0  0xb7f89e52 in dbt_get_refs (_dtp=0xb5d6c848, _k=0xbffa6ea0,
> > >> _n=2)
> > >> >> >> at dbt_res.c:168
> > >> >> >> #1  0xb7f8495b in dbt_delete (_h=0x816fd98, _k=0xbffa6ea0,
> > >> >> >> _o=0xbffa6e94, _v=0xbffa6e64, _n=2) at dbt_base.c:455
> > >> >> >> #2  0xb7dba7e9 in msg_watchers_clean (ticks=100, param=0x0) at
> > >> >> >> subscribe.c:539
> > >> >> >> #3  0x080a73bf in run_timer () at timer.c:226
> > >> >> >> #4  0x0806ec11 in main_loop () at main.c:896
> > >> >> >> #5  0x080704cb in main (argc=3, argv=0xbffa7054) at main.c:1399
> > >> >> >>
> > >> >> >
> > >> >> > _______________________________________________
> > >> >> > Devel mailing list
> > >> >> > Devel at openser.org
> > >> >> > http://openser.org/cgi-bin/mailman/listinfo/devel
> > >> >> >
> > >> >>
> > >> >>
> > >> >
> > >>
> > >>
> > >
> >
> >
>



More information about the Devel mailing list