[OpenSIPS-Users] OpenSIPS libmysqlclient.so segfault after MySQL restart

Bogdan-Andrei Iancu bogdan at voice-system.ro
Mon Mar 2 10:53:38 CET 2009


Hi Om,

Can you send me the full debug log (debug=6) for this scenario (you can 
send it privately, if too big).

I just want to check exactly what is going one.

Thanks for your help,
Bogdan

Om Bikram Thapa wrote:
> Hi Bogdan,
>
> Seems like I replied too soon. OpenSIPS again crashed on INVITE,
> although REGISTER operation was fine after a couple of MySQL restarts.
> I again restarted MySQL and got the server crashing on REGISTER as
> well. gdb trace for both the event crashes point to the same code:
>
> ---
> Core was generated by `/usr/local/sbin/opensips -P
> /var/run/opensips/opensips.pid -m 64 -u root -g roo'.
> Program terminated with signal 11, Segmentation fault.
> [New process 7352]
> #0  0x00007f13a0f38283 in mysql_stmt_result_metadata () from
> /usr/lib/libmysqlclient.so.15
> (gdb) bt
> #0  0x00007f13a0f38283 in mysql_stmt_result_metadata () from
> /usr/lib/libmysqlclient.so.15
> #1  0x00007f13a12ea4ba in db_mysql_do_prepared_query (conn=0x7cf7c0,
> query=<value optimized out>, v=0x7fffaa088fa0, n=<value optimized
> out>, uv=0x0, un=0)
>     at dbase.c:370
> #2  0x00007f13a12ecb41 in db_mysql_query (_h=0x7cf7c0, _k=<value
> optimized out>, _op=<value optimized out>, _v=0x7fffaa088fa0,
> _c=<value optimized out>,
>     _n=1, _nc=2, _o=0x0, _r=0x7fffaa089040) at dbase.c:621
> #3  0x00007f139da6547c in authorize (_m=0x7d0490, _realm=<value
> optimized out>, _table=<value optimized out>, _hftype=<value optimized
> out>)
>     at authorize.c:107
> #4  0x000000000040f849 in do_action (a=0x7bd1f8, msg=0x7d0490) at action.c:961
> #5  0x000000000040e7a5 in run_action_list (a=<value optimized out>,
> msg=0x7d0490) at action.c:139
> #6  0x0000000000470394 in eval_elem (e=0x7bd318, msg=0x7d0490,
> val=0x0) at route.c:1189
> #7  0x0000000000471b0d in eval_expr (e=0x14e0160, msg=0x7d0490,
> val=0x0) at route.c:1486
> #8  0x0000000000471abc in eval_expr (e=0x7bd3b0, msg=0x7d0490,
> val=0x0) at route.c:1502
> #9  0x0000000000471ae5 in eval_expr (e=0x7bd448, msg=0x7d0490,
> val=0x0) at route.c:1507
> #10 0x000000000040f8fc in do_action (a=0x7be468, msg=0x7d0490) at action.c:688
> #11 0x000000000040e7a5 in run_action_list (a=<value optimized out>,
> msg=0x7d0490) at action.c:139
> #12 0x000000000041159b in do_action (a=0x7be788, msg=0x7d0490) at action.c:705
> #13 0x000000000040e7a5 in run_action_list (a=<value optimized out>,
> msg=0x7d0490) at action.c:139
> #14 0x000000000041159b in do_action (a=0x7bfaa8, msg=0x7d0490) at action.c:705
> #15 0x000000000040e7a5 in run_action_list (a=<value optimized out>,
> msg=0x7d0490) at action.c:139
> #16 0x0000000000410e9f in do_action (a=0x7b80a0, msg=0x7d0490) at action.c:119
> #17 0x000000000040e7a5 in run_action_list (a=<value optimized out>,
> msg=0x7d0490) at action.c:139
> #18 0x0000000000411a1b in do_action (a=0x7b81c0, msg=0x7d0490) at action.c:711
> #19 0x000000000040e7a5 in run_action_list (a=<value optimized out>,
> msg=0x7d0490) at action.c:139
> #20 0x00000000004126a5 in run_top_route (a=0x7ace70, msg=0x7d0490) at
> action.c:119
> #21 0x000000000045f7a8 in receive_msg (
>     buf=0x74e140 "INVITE sip:xxx at x.x.x.x SIP/2.0\r\nDate: Sun, 01 Mar
> 2009 09:06:10 GMT\r\nCSeq: 2 INVITE\r\nVia: SIP/2.0/UDP
> x.x.x.x:5063;branch=z9hG4bK4e6660e0-ad04-de11-8875-001302b72316;rport\r\nUser-Agent:
> E"..., len=1297, rcv_info=0x7fffaa08aba0) at receive.c:165
> #22 0x000000000049eda6 in udp_rcv_loop () at udp_server.c:449
> #23 0x00000000004298bb in main (argc=<value optimized out>,
> argv=0x7fffaa08ad88) at main.c:778
>
> ---
>
> Thanks,
> Om.
>
> On Sun, Mar 1, 2009 at 12:45 PM, Om Bikram Thapa <om.thapa at gmail.com> wrote:
>   
>> Hi Bogdan,
>>
>> Solved! OpenSIPS (latest SVN) no longer crashes after MySQL restarts.
>>
>> Thanks,
>> Om.
>>
>> On Sun, Mar 1, 2009 at 11:33 AM, Om Bikram Thapa <om.thapa at gmail.com> wrote:
>>     
>>> Hi Bogdan,
>>>
>>> I will update and let you know the results.
>>>
>>> Regards,
>>> Om.
>>>
>>> On Sat, Feb 28, 2009 at 3:08 AM, Bogdan-Andrei Iancu
>>> <bogdan at voice-system.ro> wrote:
>>>       
>>>> Hi Om,
>>>>
>>>> finally, after some struggle with the libmysqlclient, I hope the issue is
>>>> solve. Please give it another try and let me know the result.
>>>>
>>>> Thanks and regards,
>>>> Bogdan
>>>>
>>>> Om Bikram Thapa wrote:
>>>>         
>>>>> Hi Bogdan,
>>>>>
>>>>> Just updated to latest svn, but I still see crashes after MySQL
>>>>> restart. The syslog shows following 3 lines after MySQL restart and
>>>>> registration attempt:
>>>>>
>>>>> --
>>>>> Feb 19 12:17:43 proxy /usr/local/sbin/opensips[2333]:
>>>>> ERROR:db_mysql:db_mysql_do_prepared_query: mysql_stmt_execute()
>>>>> failed: (1) Unknown prepared statement handler (1) given to
>>>>> mysql_stmt_execute
>>>>> Feb 19 12:17:43 proxy /usr/local/sbin/opensips[2333]:
>>>>> ERROR:auth_db:get_ha1: failed to query database
>>>>> Feb 19 12:18:13 proxy kernel: [  105.116919] opensips[2333]: segfault
>>>>> at 4c8 ip 7f167c109283 sp 7fff8525b270 error 4 in
>>>>> libmysqlclient.so.15.0.0[7f167c0ac000+1bf000]
>>>>> --
>>>>>
>>>>> At first attempt, the registration fails with "SIP/2.0 500 Server
>>>>> Internal Error" returned by the server, and subsequent registration
>>>>> attempt crashes the server.
>>>>>
>>>>> gdb backtrace gives following details:
>>>>>
>>>>> ---
>>>>> #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
>>>>> ---
>>>>>
>>>>> I have tried several times and each time I get the same sequence of
>>>>> results.
>>>>>
>>>>> Thanks,
>>>>> Om.
>>>>>
>>>>> On Thu, Feb 19, 2009 at 11:22 AM, Om Bikram Thapa <om.thapa at gmail.com>
>>>>> wrote:
>>>>>
>>>>>           
>>>>>> Thanks Bogdan. I will update and let you know.
>>>>>>
>>>>>> Regards,
>>>>>> Om.
>>>>>>
>>>>>> On Thu, Feb 19, 2009 at 2:48 AM, Bogdan-Andrei Iancu
>>>>>> <bogdan at voice-system.ro> wrote:
>>>>>>
>>>>>>             
>>>>>>> Hi Om,
>>>>>>>
>>>>>>> There is a fix available on SVN - please update and see if it works now.
>>>>>>>
>>>>>>> Thanks and regards,
>>>>>>> Bogdan
>>>>>>>
>>>>>>> Om Bikram Thapa wrote:
>>>>>>>
>>>>>>>               
>>>>>>>> Hi Bogdan,
>>>>>>>>
>>>>>>>> I have submitted the bug on the tracker.
>>>>>>>>
>>>>>>>> Thanks,
>>>>>>>> Om.
>>>>>>>>
>>>>>>>> On Tue, Feb 17, 2009 at 3:50 AM, Bogdan-Andrei Iancu
>>>>>>>> <bogdan at voice-system.ro> wrote:
>>>>>>>>
>>>>>>>>
>>>>>>>>                 
>>>>>>>>> Hi Om,
>>>>>>>>>
>>>>>>>>> Thanks for the report - I may have an idea what is the problem; I will
>>>>>>>>> try
>>>>>>>>> to reproduce the crash in the following days.
>>>>>>>>>
>>>>>>>>> Could you please open a bug report on the tracker - just not to forget
>>>>>>>>> about
>>>>>>>>> it :D (see http://www.opensips.org/index.php?n=Development.Tracker)
>>>>>>>>>
>>>>>>>>> Regards,
>>>>>>>>> Bogdan
>>>>>>>>>
>>>>>>>>> Om Bikram Thapa wrote:
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>                   
>>>>>>>>>> Hi,
>>>>>>>>>>
>>>>>>>>>> OpenSIPS is dying with "libmysqlclient.so Segmentation Fault" after
>>>>>>>>>> MySQL server 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 shows:
>>>>>>>>>>
>>>>>>>>>> -------------
>>>>>>>>>> #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
>>>>>>>>>> #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:xxxxx 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
>>>>>>>>>> ------------
>>>>>>>>>>
>>>>>>>>>> Server runs fine after restart until MySQL is restarted again. In my
>>>>>>>>>> lab setup, OpenSIPS is getting killed triggered by registration
>>>>>>>>>> request every morning (probably due to MySQL being restarted daily
>>>>>>>>>> with logrotate).
>>>>>>>>>>
>>>>>>>>>> The server is the latest trunk on Debian lenny/AMD64.
>>>>>>>>>>
>>>>>>>>>> Thanks,
>>>>>>>>>> Om.
>>>>>>>>>>
>>>>>>>>>> _______________________________________________
>>>>>>>>>> Users mailing list
>>>>>>>>>> Users at lists.opensips.org
>>>>>>>>>> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>                     
>>>>>>>>>                   
>>>>>>>>                 
>>>>>>>               
>>>>>           
>>>>         
>
>   




More information about the Users mailing list