Learn how easy it is to sync an existing GitHub or Google Code repo to a SourceForge project! See Demo

Close

#92 OpenSIPS latest trunk libmysqlclient segfault

trunk
closed-fixed
modules (454)
9
2009-03-05
2009-02-17
Om Bikram Thapa
No

OpenSIPS latest trunk on Debian Lenny/AMD64 dies with libmysqlclient segfault after a MySQL restart. The event that triggers this crash is registration related database query immediately after a MySQL restart. Once OpenSIPS is restarted after a crash, everything runs fine until next MySQL restart.

The log shows:

"opensips[16769]: segfault at 4c8 ip 7f36728bf283 sp 7fff7ba11a90 error 4 in libmysqlclient.so.15.0.0[7f3672862000+1bf000]"

and gdb bt gives following results:

---------------
Program terminated with signal 11, Segmentation fault.
[New process 16769]
#0 0x00007f36728bf283 in mysql_stmt_result_metadata ()
from /usr/lib/libmysqlclient.so.15
(gdb) bt
#0 0x00007f36728bf283 in mysql_stmt_result_metadata ()
from /usr/lib/libmysqlclient.so.15
#1 0x00007f3672c707b7 in db_mysql_do_prepared_query (conn=0x78b278,
query=<value optimized out>, v=0x7fff7ba11d20, n=1, uv=0x0, un=0)
at dbase.c:363
#2 0x00007f3672c72e1f in db_mysql_query (_h=0x78b278,
_k=<value optimized out>, _op=<value optimized out>, _v=0x7fff7ba11d20,
_c=<value optimized out>, _n=1, _nc=2, _o=0x0, _r=0x7fff7ba11dc0)
at dbase.c:591
#3 0x00007f366f3f0398 in authorize (_m=0x78fe98,
_realm=<value optimized out>, _table=<value optimized out>,
_hftype=<value optimized out>) at authorize.c:107
#4 0x000000000040f869 in do_action (a=0x780a48, msg=0x78fe98) at action.c:961
#5 0x000000000040e7e5 in run_action_list (a=<value optimized out>,
msg=0x78fe98) at action.c:139
#6 0x000000000046f194 in eval_elem (e=0x780b18, msg=0x78fe98, val=0x0)
at route.c:1189
#7 0x00000000004708ed in eval_expr (e=0x120b1e0, msg=0x78fe98, val=0x0)
at route.c:1486
#8 0x000000000047089c in eval_expr (e=0x780b60, msg=0x78fe98, val=0x0)
at route.c:1502
#9 0x00000000004708c5 in eval_expr (e=0x780ba8, msg=0x78fe98, val=0x0)
at route.c:1507
---Type <return> to continue, or q <return> to quit---
#10 0x000000000040f91c in do_action (a=0x780f40, msg=0x78fe98) at action.c:688
#11 0x000000000040e7e5 in run_action_list (a=<value optimized out>,
msg=0x78fe98) at action.c:139
#12 0x00000000004114d3 in do_action (a=0x781eb0, msg=0x78fe98) at action.c:705
#13 0x000000000040e7e5 in run_action_list (a=<value optimized out>,
msg=0x78fe98) at action.c:139
#14 0x0000000000410e07 in do_action (a=0x77ee88, msg=0x78fe98) at action.c:119
#15 0x000000000040e7e5 in run_action_list (a=<value optimized out>,
msg=0x78fe98) at action.c:139
#16 0x00000000004114d3 in do_action (a=0x77f028, msg=0x78fe98) at action.c:705
#17 0x000000000040e7e5 in run_action_list (a=<value optimized out>,
msg=0x78fe98) at action.c:139
#18 0x00000000004125fe in run_top_route (a=0x777e78, msg=0x78fe98)
at action.c:119
#19 0x000000000045e898 in receive_msg (
buf=0x749180 "REGISTER sip:x.x.x.x SIP/2.0\r\nCSeq: 2 REGISTER\r\nVia: SIP/2.0/UDP x.x.x.x:5061;branch=z9hG4bK60f1b2dd-57fa-dd11-9401-0015c5404858;rport\r\nUser-Agent: Ekiga/2.0.12\r\nAuthorization: Dige"...,
len=749, rcv_info=0x7fff7ba13530) at receive.c:165
#20 0x000000000049d3a6 in udp_rcv_loop () at udp_server.c:449
#21 0x00000000004291fb in main (argc=<value optimized out>,
argv=0x7fff7ba13718) at main.c:778
----------------

Discussion

    • priority: 5 --> 8
    • assigned_to: nobody --> bogdan_iancu
    • status: open --> open-accepted
     
  • I modified domain in opensips domain table, immediately after that the server crashed upon registration event with log general protection ip:7f249016986c sp:7fff992bf320 error:0 in libmysqlclient.so.15.0.0[7f2490110000+1bf000]" and gdb backtrace now points to different code:

    ----------
    #0 0x00007f7a4c26f86c in mysql_stmt_fetch () from /usr/lib/libmysqlclient.so.15
    #1 0x00007f7a4c628a48 in db_mysql_convert_result (_h=0x78b278, _r=0x78ba28) at res.c:161
    #2 0x00007f7a4c626aaa in db_mysql_store_result (_h=0x78b278, _r=0x7fff553c5770) at dbase.c:513
    #3 0x00007f7a4c626e39 in db_mysql_query (_h=0x78b278, _k=<value optimized out>, _op=<value optimized out>, _v=0x7fff553c56d0, _c=<value optimized out>,
    _n=1, _nc=2, _o=0x0, _r=0x7fff553c5770) at dbase.c:593
    #4 0x00007f7a48da4398 in authorize (_m=0x78fe98, _realm=<value optimized out>, _table=<value optimized out>, _hftype=<value optimized out>)
    at authorize.c:107
    #5 0x000000000040f869 in do_action (a=0x780a48, msg=0x78fe98) at action.c:961
    #6 0x000000000040e7e5 in run_action_list (a=<value optimized out>, msg=0x78fe98) at action.c:139
    #7 0x000000000046f194 in eval_elem (e=0x780b18, msg=0x78fe98, val=0x20) at route.c:1189
    #8 0x00000000004708ed in eval_expr (e=0xe543d0, msg=0x78fe98, val=0x0) at route.c:1486
    #9 0x000000000047089c in eval_expr (e=0x780b60, msg=0x78fe98, val=0x0) at route.c:1502
    #10 0x00000000004708c5 in eval_expr (e=0x780ba8, msg=0x78fe98, val=0x0) at route.c:1507
    #11 0x000000000040f91c in do_action (a=0x780f40, msg=0x78fe98) at action.c:688
    #12 0x000000000040e7e5 in run_action_list (a=<value optimized out>, msg=0x78fe98) at action.c:139
    #13 0x00000000004114d3 in do_action (a=0x781eb0, msg=0x78fe98) at action.c:705
    #14 0x000000000040e7e5 in run_action_list (a=<value optimized out>, msg=0x78fe98) at action.c:139
    #15 0x0000000000410e07 in do_action (a=0x77ee88, msg=0x78fe98) at action.c:119
    #16 0x000000000040e7e5 in run_action_list (a=<value optimized out>, msg=0x78fe98) at action.c:139
    #17 0x00000000004114d3 in do_action (a=0x77f028, msg=0x78fe98) at action.c:705
    #18 0x000000000040e7e5 in run_action_list (a=<value optimized out>, msg=0x78fe98) at action.c:139
    #19 0x00000000004125fe in run_top_route (a=0x777e78, msg=0x78fe98) at action.c:119
    #20 0x000000000045e898 in receive_msg (
    buf=0x749180 "REGISTER sip:x.x.x.x;transport=UDP SIP/2.0\r\nVia: SIP/2.0/UDP x.x.x.x:5060;branch=z9hG4bKgcjsr9edklicvlhif2tfvub;rport\r\nFrom: <sip:300000@x.x."..., len=693, rcv_info=0x7fff553c6ee0) at receive.c:165
    #21 0x000000000049d3a6 in udp_rcv_loop () at udp_server.c:449
    #22 0x00000000004291fb in main (argc=<value optimized out>, argv=0x7fff553c70c8) at main.c:778
    -----------------

    I think this crash is also related to the same issue.

     
  • Hi Om,

    I hopefully fixed the problem - please update from SVN and give it another try. Let me know if now works.

    Thanks and regards,
    Bogdan

     
    • status: open-accepted --> open-fixed
     
  • Hi Bogdan,

    The issue remains with latest SVN also.

    Here is the gdb trace now:

    #0 0x00007f0119426283 in mysql_stmt_result_metadata () from /usr/lib/libmysqlclient.so.15
    (gdb) bt
    #0 0x00007f0119426283 in mysql_stmt_result_metadata () from /usr/lib/libmysqlclient.so.15
    #1 0x00007f01197d8f82 in db_mysql_do_prepared_query (conn=0x78b278, query=<value optimized out>, v=0x7fff22576880, n=<value optimized out>, uv=0x0, un=0)
    at dbase.c:368
    #2 0x00007f01197daccd in db_mysql_query (_h=0x78b278, _k=<value optimized out>, _op=<value optimized out>, _v=0x7fff22576880, _c=<value optimized out>,
    _n=1, _nc=2, _o=0x0, _r=0x7fff22576920) at dbase.c:603
    #3 0x00007f0115f56398 in authorize (_m=0x78fe98, _realm=<value optimized out>, _table=<value optimized out>, _hftype=<value optimized out>)
    at authorize.c:107
    #4 0x000000000040f869 in do_action (a=0x780a48, msg=0x78fe98) at action.c:961
    #5 0x000000000040e7e5 in run_action_list (a=<value optimized out>, msg=0x78fe98) at action.c:139
    #6 0x000000000046f194 in eval_elem (e=0x780b18, msg=0x78fe98, val=0x0) at route.c:1189
    #7 0x00000000004708ed in eval_expr (e=0x27648e0, msg=0x78fe98, val=0x0) at route.c:1486
    #8 0x000000000047089c in eval_expr (e=0x780b60, msg=0x78fe98, val=0x0) at route.c:1502
    #9 0x00000000004708c5 in eval_expr (e=0x780ba8, msg=0x78fe98, val=0x0) at route.c:1507
    #10 0x000000000040f91c in do_action (a=0x780f40, msg=0x78fe98) at action.c:688
    #11 0x000000000040e7e5 in run_action_list (a=<value optimized out>, msg=0x78fe98) at action.c:139
    #12 0x00000000004114d3 in do_action (a=0x781eb0, msg=0x78fe98) at action.c:705
    #13 0x000000000040e7e5 in run_action_list (a=<value optimized out>, msg=0x78fe98) at action.c:139
    #14 0x0000000000410e07 in do_action (a=0x77ee88, msg=0x78fe98) at action.c:119
    #15 0x000000000040e7e5 in run_action_list (a=<value optimized out>, msg=0x78fe98) at action.c:139
    #16 0x00000000004114d3 in do_action (a=0x77f028, msg=0x78fe98) at action.c:705
    #17 0x000000000040e7e5 in run_action_list (a=<value optimized out>, msg=0x78fe98) at action.c:139
    #18 0x00000000004125fe in run_top_route (a=0x777e78, msg=0x78fe98) at action.c:119
    #19 0x000000000045e898 in receive_msg (
    buf=0x749180 "REGISTER sip:x.x.x.x SIP/2.0\r\nCSeq: 58 REGISTER\r\nVia: SIP/2.0/UDP x.x.x.x:5068;branch=z9hG4bK5ca4685b-befc-dd11-911f-0015c5404858;rport\r\nUser-Agent: Ekiga/2.0.12\r\nAuthorization: Dig"..., len=750, rcv_info=0x7fff22578090) at receive.c:165
    #20 0x000000000049d3a6 in udp_rcv_loop () at udp_server.c:449
    #21 0x00000000004291fb in main (argc=<value optimized out>, argv=0x7fff22578278) at main.c:778

     
  • Hi Bogdan,

    The issue remains with latest SVN also.

    Here is the gdb trace now:

    #0 0x00007f0119426283 in mysql_stmt_result_metadata () from /usr/lib/libmysqlclient.so.15
    (gdb) bt
    #0 0x00007f0119426283 in mysql_stmt_result_metadata () from /usr/lib/libmysqlclient.so.15
    #1 0x00007f01197d8f82 in db_mysql_do_prepared_query (conn=0x78b278, query=<value optimized out>, v=0x7fff22576880, n=<value optimized out>, uv=0x0, un=0)
    at dbase.c:368
    #2 0x00007f01197daccd in db_mysql_query (_h=0x78b278, _k=<value optimized out>, _op=<value optimized out>, _v=0x7fff22576880, _c=<value optimized out>,
    _n=1, _nc=2, _o=0x0, _r=0x7fff22576920) at dbase.c:603
    #3 0x00007f0115f56398 in authorize (_m=0x78fe98, _realm=<value optimized out>, _table=<value optimized out>, _hftype=<value optimized out>)
    at authorize.c:107
    #4 0x000000000040f869 in do_action (a=0x780a48, msg=0x78fe98) at action.c:961
    #5 0x000000000040e7e5 in run_action_list (a=<value optimized out>, msg=0x78fe98) at action.c:139
    #6 0x000000000046f194 in eval_elem (e=0x780b18, msg=0x78fe98, val=0x0) at route.c:1189
    #7 0x00000000004708ed in eval_expr (e=0x27648e0, msg=0x78fe98, val=0x0) at route.c:1486
    #8 0x000000000047089c in eval_expr (e=0x780b60, msg=0x78fe98, val=0x0) at route.c:1502
    #9 0x00000000004708c5 in eval_expr (e=0x780ba8, msg=0x78fe98, val=0x0) at route.c:1507
    #10 0x000000000040f91c in do_action (a=0x780f40, msg=0x78fe98) at action.c:688
    #11 0x000000000040e7e5 in run_action_list (a=<value optimized out>, msg=0x78fe98) at action.c:139
    #12 0x00000000004114d3 in do_action (a=0x781eb0, msg=0x78fe98) at action.c:705
    #13 0x000000000040e7e5 in run_action_list (a=<value optimized out>, msg=0x78fe98) at action.c:139
    #14 0x0000000000410e07 in do_action (a=0x77ee88, msg=0x78fe98) at action.c:119
    #15 0x000000000040e7e5 in run_action_list (a=<value optimized out>, msg=0x78fe98) at action.c:139
    #16 0x00000000004114d3 in do_action (a=0x77f028, msg=0x78fe98) at action.c:705
    #17 0x000000000040e7e5 in run_action_list (a=<value optimized out>, msg=0x78fe98) at action.c:139
    #18 0x00000000004125fe in run_top_route (a=0x777e78, msg=0x78fe98) at action.c:119
    #19 0x000000000045e898 in receive_msg (
    buf=0x749180 "REGISTER sip:x.x.x.x SIP/2.0\r\nCSeq: 58 REGISTER\r\nVia: SIP/2.0/UDP x.x.x.x:5068;branch=z9hG4bK5ca4685b-befc-dd11-911f-0015c5404858;rport\r\nUser-Agent: Ekiga/2.0.12\r\nAuthorization: Dig"..., len=750, rcv_info=0x7fff22578090) at receive.c:165
    #20 0x000000000049d3a6 in udp_rcv_loop () at udp_server.c:449
    #21 0x00000000004291fb in main (argc=<value optimized out>, argv=0x7fff22578278) at main.c:778

     
  • My OpenSIPS rev-5351 crahses daily without restarting MySQL (Debian Etch 64 bits). Simple backtrace:

    #0 0x00002b1cd7475a92 in mysql_stmt_result_metadata () from /usr/lib/libmysqlclient.so.15
    #1 0x00002b1cd730023c in db_mysql_free_result () from /usr/lib/opensips/modules/db_mysql.so
    #2 0x00002b1cd73013b6 in db_mysql_query () from /usr/lib/opensips/modules/db_mysql.so
    #3 0x00002b1cd859b8f8 in ?? () from /usr/lib/opensips/modules/auth_db.so
    #4 0x000000000040f894 in do_action ()
    #5 0x000000000040e0f3 in run_action_list ()
    #6 0x000000000044c957 in eval_expr ()
    #7 0x000000000044c3d0 in eval_expr ()
    #8 0x000000000044c34f in eval_expr ()
    #9 0x000000000040f939 in do_action ()
    #10 0x000000000040e0f3 in run_action_list ()
    #11 0x000000000041093a in do_action ()
    #12 0x000000000040e0f3 in run_action_list ()
    #13 0x000000000041176f in do_action ()
    #14 0x000000000040e0f3 in run_action_list ()
    #15 0x000000000040e480 in run_top_route ()
    #16 0x0000000000441b4c in receive_msg ()
    #17 0x0000000000464bfd in tcp_read_req ()
    #18 0x000000000046691e in tcp_read_req ()
    #19 0x0000000000468114 in tcp_receive_loop ()
    #20 0x000000000045b83d in tcp_init_children ()
    #21 0x000000000042368e in main ()

     
  • Although this isn't a segfault, it's likely that fixing one MySQL problem will fix others. Below is the result of a fresh install on a newly formatted system (debian 2.6.26-1-amd64) and the latest OpenSIPS trunk:

    DBG:db_mysql:db_mysql_do_prepared_query: new query=|select password,account_id from subscriber where username=?|
    ERROR:db_mysql:get_new_stmt_ctx: failed while mysql_stmt_prepare()
    ERROR:db_mysql:db_mysql_do_prepared_query: failed to create new context
    ERROR:auth_db:get_ha1: failed to query database

     
  • Sorry, my problem was self-inflicted.

     
  • OK - a new fix is available on SVN.

    Please test.

    Regards,
    Bogdan

     
    • priority: 8 --> 9
     
  • finally fixed and confirmed.

    Thanks a lot to Om for helping with testing and debugging.

     
    • status: open-fixed --> closed-fixed