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

Cesc cesc.santa at gmail.com
Fri Apr 13 18:46:34 CEST 2007


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