[OpenSIPS-Devel] [ opensips-Bugs-2609529 ] Segmentation fault related to 'presence' module and MySQL

SourceForge.net noreply at sourceforge.net
Mon Mar 23 13:12:08 CET 2009


Bugs item #2609529, was opened at 2009-02-17 18:35
Message generated for change (Settings changed) made by anca_vamanu
You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=1086410&aid=2609529&group_id=232389

Please note that this message will contain a full copy of the comment thread,
including the initial issue submission, for this request,
not just the latest update.
Category: modules
Group: trunk
>Status: Closed
>Resolution: Fixed
Priority: 5
Private: No
Submitted By: Iñaki Baz Castillo (ibc_sf)
Assigned to: Anca Vamanu (anca_vamanu)
Summary: Segmentation fault related to 'presence' module and MySQL

Initial Comment:
OpenSIPS rev 5323.

This OpenSIPS acts as a proxy for presence messages which are routed to an OpenSIPS presence server running in a different port.


syslog:
---------------
/usr/sbin/opensips[20978]: DBG:core:parse_msg:  version: <SIP/2.
/usr/sbin/opensips[20978]: DBG:core:parse_msg:  status:  <489>
/usr/sbin/opensips[20978]: DBG:core:parse_msg:  reason:  <Bad Ev
/usr/sbin/opensips[20978]: DBG:core:parse_headers: flags=2
/usr/sbin/opensips[20978]: DBG:core:parse_via_param: found param
/usr/sbin/opensips[20978]: DBG:core:parse_via: end of header rea
/usr/sbin/opensips[20978]: DBG:core:parse_headers: via found, fl
/usr/sbin/opensips[20978]: DBG:core:parse_headers: this is the f
/usr/sbin/opensips[20978]: DBG:core:receive_msg: After parse_msg
/usr/sbin/opensips[20978]: DBG:core:forward_reply: found module 
/usr/sbin/opensips[20978]: DBG:core:parse_headers: flags=4
/usr/sbin/opensips[20978]: DBG:core:parse_via_param: found param
/usr/sbin/opensips[20978]: DBG:core:parse_via_param: found param
/usr/sbin/opensips[20978]: DBG:core:parse_via_param: found param
/usr/sbin/opensips[20978]: DBG:core:parse_via: end of header rea
/usr/sbin/opensips[20978]: DBG:core:parse_headers: via found, fl
/usr/sbin/opensips[20978]: DBG:core:parse_headers: parse_headers
/usr/sbin/opensips[20978]: DBG:core:forward_reply: found module 
/usr/sbin/opensips[20978]: DBG:tm:t_check: start=0xfffffffffffff
/usr/sbin/opensips[20978]: DBG:core:parse_headers: flags=22
/usr/sbin/opensips[20978]: DBG:core:parse_to_param: tag=82e3ea5b
/usr/sbin/opensips[20978]: DBG:core:parse_to: end of header reac
/usr/sbin/opensips[20978]: DBG:core:parse_to: display={}, ruri={
/usr/sbin/opensips[20978]: DBG:core:get_hdr_field: <To> [63]; ur
/usr/sbin/opensips[20978]: DBG:core:get_hdr_field: to body [<sip
/usr/sbin/opensips[20978]: DBG:core:get_hdr_field: cseq <CSeq>: 
/usr/sbin/opensips[20978]: DBG:tm:t_reply_matching: hash 65085 l
/usr/sbin/opensips[20978]: DBG:tm:t_reply_matching: REF_UNSAFE: 
/usr/sbin/opensips[20978]: DBG:tm:t_reply_matching: reply matche
/usr/sbin/opensips[20978]: DBG:tm:run_trans_callbacks: trans=0x2
/usr/sbin/opensips[20978]: DBG:tm:t_check: end=0x2b936cb4ff10
/usr/sbin/opensips[20978]: DBG:tm:reply_received: org. status ua
/usr/sbin/opensips[20978]:  ## onreply_route[ON_REPLY_DEFAULT]
/usr/sbin/opensips[20978]: DBG:core:tr_eval_string: i=11 j=8
/usr/sbin/opensips[20978]: DBG:core:parse_headers: flags=8000000
/usr/sbin/opensips[20978]: DBG:core:get_hdr_field: content_lengt
/usr/sbin/opensips[20978]: DBG:core:get_hdr_field: found end of 
/usr/sbin/opensips[20978]: DBG:core:pv_get_useragent: no User-Ag
/usr/sbin/opensips[20978]: 15:43:27 - Reply from 99.131.79.216:5
/usr/sbin/opensips[20978]: 489 (SUBSCRIBE): Bad Event
/usr/sbin/opensips[20978]: DBG:tm:t_should_relay_response: T_cod
/usr/sbin/opensips[20978]: DBG:tm:t_pick_branch: picked branch 0
/usr/sbin/opensips[20978]: DBG:tm:is_3263_failure: dns-failover 
/usr/sbin/opensips[20978]: DBG:tm:relay_reply: branch=0, save=0,
/usr/sbin/opensips[20978]: DBG:core:build_res_buf_from_sip_res: 
/usr/sbin/opensips[20978]: DBG:core:build_res_buf_from_sip_res: 
/usr/sbin/opensips[20978]: DBG:core:_shm_resize: resize(0) calle
/usr/sbin/opensips[20978]: DBG:tm:insert_timer_unsafe: [2]: 0x2b
/usr/sbin/opensips[20978]: DBG:tm:relay_reply: sent buf=0x6b7920
/usr/sbin/opensips[20978]: DBG:tm:cleanup_uac_timers: RETR/FR ti
/usr/sbin/opensips[20978]: DBG:tm:t_unref: UNREF_UNSAFE: after i
/usr/sbin/opensips[20978]: DBG:core:destroy_avp_list: destroying
/usr/sbin/opensips[20978]: DBG:core:receive_msg: cleaning up
/usr/sbin/opensips[20934]: DBG:core:tcp_send: buf= SUBSCRIBE sip
/usr/sbin/opensips[20934]: DBG:tm:set_timer: relative timeout is
/usr/sbin/opensips[20934]: DBG:tm:insert_timer_unsafe: [0]: 0x2b
/usr/sbin/opensips[20934]: DBG:tm:t_relay_to: new transaction fw
/usr/sbin/opensips[20934]: DBG:tm:t_unref: UNREF_UNSAFE: after i
/usr/sbin/opensips[20934]: DBG:core:destroy_avp_list: destroying
/usr/sbin/opensips[20934]: DBG:core:receive_msg: cleaning up
/usr/sbin/opensips[20994]: CRITICAL:core:receive_fd: EOF on 46
---------------



coredump:
---------------
Core was generated by `/usr/sbin/opensips -P /var/run/opensips/opensips.pid -m 128 -u opensips -g open'.
Program terminated with signal 11, Segmentation fault.
#0  0x00002b936a901d78 in publ_build_hdr () from /usr/lib/opensips/modules/pua.so
(gdb) bt
#0  0x00002b936a901d78 in publ_build_hdr () from /usr/lib/opensips/modules/pua.so
#1  0x00002b936a8fee4c in bind_pua () from /usr/lib/opensips/modules/pua.so
#2  0x000000000046960c in start_timer_processes ()
#3  0x0000000000423661 in main ()
---------------

----------------------------------------------------------------------

>Comment By: Anca Vamanu (anca_vamanu)
Date: 2009-03-23 14:12

Message:
Fixed in commit rev 5512.

Thanks to Inaki.

----------------------------------------------------------------------

Comment By: Iñaki Baz Castillo (ibc_sf)
Date: 2009-03-19 02:40

Message:
Sorry, one more (crash in  "memcpy", does it help?):

---------
(gdb) bt
#0  0x00002af42d037fb3 in memcpy () from /lib/libc.so.6
#1  0x00002af42d487f69 in mysql_stmt_bind_param () from
/usr/lib/libmysqlclient.so.15
#2  0x00002af42d3136fb in db_mysql_free_result () from
/usr/lib/opensips/modules/db_mysql.so
#3  0x00002af42d314ee0 in db_mysql_query () from
/usr/lib/opensips/modules/db_mysql.so
#4  0x00002af42eb49683 in get_db_subs_auth () from
/usr/lib/opensips/modules/presence.so
#5  0x00002af42eb4b0a1 in handle_subscribe () from
/usr/lib/opensips/modules/presence.so
--------

----------------------------------------------------------------------

Comment By: Iñaki Baz Castillo (ibc_sf)
Date: 2009-03-19 02:38

Message:
And one more:

-----------
(gdb) bt
#0  0x00002b1cbb5f2a54 in net_clear () from /usr/lib/libmysqlclient.so.15
#1  0x00002b1cbb5c7888 in cli_stmt_execute () from
/usr/lib/libmysqlclient.so.15
#2  0x00002b1cbb5c7495 in mysql_stmt_execute () from
/usr/lib/libmysqlclient.so.15
#3  0x00002b1cbb451743 in db_mysql_free_result () from
/usr/lib/opensips/modules/db_mysql.so
#4  0x00002b1cbb452ee0 in db_mysql_query () from
/usr/lib/opensips/modules/db_mysql.so
#5  0x00002b1cbcc87683 in get_db_subs_auth () from
/usr/lib/opensips/modules/presence.so
#6  0x00002b1cbcc890a1 in handle_subscribe () from
/usr/lib/opensips/modules/presence.so
#7  0x000000000040d653 in do_action ()
#8  0x000000000040fef3 in run_action_list ()
#9  0x000000000040f359 in do_action ()
#10 0x000000000040fef3 in run_action_list ()
#11 0x000000000040e665 in do_action ()
#12 0x000000000040fef3 in run_action_list ()
#13 0x000000000040f359 in do_action ()
#14 0x000000000040fef3 in run_action_list ()
#15 0x0000000000410280 in run_top_route ()
#16 0x00000000004406c2 in receive_msg ()
#17 0x0000000000471900 in udp_rcv_loop ()
#18 0x0000000000421cc7 in main ()
(gdb)                      
-----------

----------------------------------------------------------------------

Comment By: Iñaki Baz Castillo (ibc_sf)
Date: 2009-03-19 02:35

Message:
Another example of crash (this time in "handle_publish"):

-----------------
(gdb) bt
#0  0x00002b56d0bdd5df in db_mysql_val2bind () from
/usr/lib/opensips/modules/db_mysql.so
#1  0x00002b56d0bd942e in db_mysql_free_result () from
/usr/lib/opensips/modules/db_mysql.so
#2  0x00002b56d0bdadfb in db_mysql_insert () from
/usr/lib/opensips/modules/db_mysql.so
#3  0x00002b56d2403239 in update_presentity () from
/usr/lib/opensips/modules/presence.so
#4  0x00002b56d24070c4 in handle_publish () from
/usr/lib/opensips/modules/presence.so
#5  0x000000000040d653 in do_action ()
#6  0x000000000040fef3 in run_action_list ()
#7  0x000000000040f565 in do_action ()
#8  0x000000000040fef3 in run_action_list ()
#9  0x000000000040f359 in do_action ()
#10 0x000000000040fef3 in run_action_list ()
#11 0x000000000040f565 in do_action ()
#12 0x000000000040fef3 in run_action_list ()
#13 0x000000000040e665 in do_action ()
#14 0x000000000040fef3 in run_action_list ()
#15 0x000000000040f359 in do_action ()
#16 0x000000000040fef3 in run_action_list ()
#17 0x0000000000410280 in run_top_route ()
#18 0x00000000004406c2 in receive_msg ()
#19 0x0000000000471900 in udp_rcv_loop ()
#20 0x0000000000421cc7 in main ()
(gdb)                      
-----------------

----------------------------------------------------------------------

Comment By: Iñaki Baz Castillo (ibc_sf)
Date: 2009-03-19 02:11

Message:
I'm using rev 5472 and the problem still occurs:

------------
(gdb) bt
#0  0x00002b9e67de4a92 in mysql_stmt_result_metadata () from
/usr/lib/libmysqlclient.so.15
#1  0x00002b9e67c6e714 in db_mysql_free_result () from
/usr/lib/opensips/modules/db_mysql.so
#2  0x00002b9e67c6fee0 in db_mysql_query () from
/usr/lib/opensips/modules/db_mysql.so
#3  0x00002b9e694a4683 in get_db_subs_auth () from
/usr/lib/opensips/modules/presence.so
#4  0x00002b9e694a60a1 in () from /usr/lib/opensips/modules/presence.so
#5  0x000000000040d653 in do_action ()
#6  0x000000000040fef3 in run_action_list ()
#7  0x000000000040f359 in do_action ()
#8  0x000000000040fef3 in run_action_list ()
#9  0x000000000040e665 in do_action ()
#10 0x000000000040fef3 in run_action_list ()
#11 0x000000000040f359 in do_action ()
#12 0x000000000040fef3 in run_action_list ()
#13 0x0000000000410280 in run_top_route ()
#14 0x00000000004406c2 in receive_msg ()
#15 0x00000000004637e7 in tcp_read_req ()
#16 0x00000000004654e0 in tcp_read_req ()
#17 0x0000000000466cd4 in tcp_receive_loop ()
#18 0x000000000045a5c5 in tcp_init_children ()
#19 0x0000000000421a5e in main ()
(gdb)                                        
-----------

This OpenSIPS is acting just as presence server (no usrloc, no registrar,
no pua). The coredump clearly shows that the bug occurs after
"handle_subscribe" function (presence module).

----------------------------------------------------------------------

Comment By: Anca Vamanu (anca_vamanu)
Date: 2009-02-23 17:27

Message:
Hi Inaki,

It seems to be related to mysql prepare statements. There are some other
bug reports with this. Let
s wait for this problem to be fixed and see if the crash occurs also
after.

regards,
Anca

----------------------------------------------------------------------

Comment By: Iñaki Baz Castillo (ibc_sf)
Date: 2009-02-23 17:20

Message:
@anca: I copied a core to the sources as you suggested:

------------------------------
(gdb) bt full
#0  0x00002b86e53b8a92 in mysql_stmt_result_metadata () from
/usr/lib/libmysqlclient.so.15
No symbol table info available.
#1  0x00002b86e524323c in db_mysql_free_result () from
/usr/lib/opensips/modules/db_mysql.so
No symbol table info available.
#2  0x00002b86e52443b6 in db_mysql_query () from
/usr/lib/opensips/modules/db_mysql.so
No symbol table info available.
#3  0x00002b86e64de8f8 in ?? () from /usr/lib/opensips/modules/auth_db.so
No symbol table info available.
#4  0x000000000040f894 in do_action ()
No symbol table info available.
#5  0x000000000040e0f3 in run_action_list ()
No symbol table info available.
#6  0x000000000044c957 in eval_expr ()
No symbol table info available.
#7  0x000000000044c3d0 in eval_expr ()
No symbol table info available.
#8  0x000000000044c34f in eval_expr ()
No symbol table info available.
#9  0x000000000040f939 in do_action ()
No symbol table info available.
#10 0x000000000040e0f3 in run_action_list ()
No symbol table info available.
#11 0x000000000041093a in do_action ()
No symbol table info available.
#12 0x000000000040e0f3 in run_action_list ()
No symbol table info available.
#13 0x000000000041176f in do_action ()
No symbol table info available.
#14 0x000000000040e0f3 in run_action_list ()
No symbol table info available.
#15 0x000000000040e480 in run_top_route ()
No symbol table info available.
#16 0x0000000000441b4c in receive_msg ()
No symbol table info available.
#17 0x0000000000464bfd in tcp_read_req ()
No symbol table info available.
#18 0x000000000046691e in tcp_read_req ()
No symbol table info available.
#19 0x0000000000468114 in tcp_receive_loop ()
No symbol table info available.
#20 0x000000000045b83d in tcp_init_children ()
No symbol table info available.
#21 0x000000000042368e in main ()
No symbol table info available.
------------------------------

I see no more useful info here anyway. Are the line numbers appear or
should I run the "ulimit" command?

Thanks.

----------------------------------------------------------------------

Comment By: Iñaki Baz Castillo (ibc_sf)
Date: 2009-02-18 19:34

Message:
Ok, I'll do that.
BTW my OpenSIPS proxy has crashed now with this backtrace:

------------
#0  0x00002b6c934ffa92 in mysql_stmt_result_metadata () from
/usr/lib/libmysqlclient.so.15
#1  0x00002b6c9338a1de in db_mysql_free_result () from
/usr/lib/opensips/modules/db_mysql.so
#2  0x00002b6c9338b156 in db_mysql_query () from
/usr/lib/opensips/modules/db_mysql.so
#3  0x00002b6c946258f8 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  0x000000000040f939 in do_action ()
#9  0x000000000040e0f3 in run_action_list ()
#10 0x000000000041093a in do_action ()
#11 0x000000000040e0f3 in run_action_list ()
#12 0x000000000041176f in do_action ()
#13 0x000000000040e0f3 in run_action_list ()
#14 0x000000000041176f in do_action ()
#15 0x000000000040e0f3 in run_action_list ()
#16 0x000000000040e480 in run_top_route ()
#17 0x0000000000441b4c in receive_msg ()
#18 0x0000000000464bfd in tcp_read_req ()
#19 0x000000000046691e in tcp_read_req ()
#20 0x0000000000468114 in tcp_receive_loop ()
#21 0x000000000045b83d in tcp_init_children ()
#22 0x000000000042368e in main ()
------------

----------------------------------------------------------------------

Comment By: Anca Vamanu (anca_vamanu)
Date: 2009-02-18 17:39

Message:
Hi Inaki,

Neither the gdb back trace nor the log offer much information. Can you try
to copy the core in the directory where you have the sources and run from
there: 'gdb opensips core'. If still there are no line numbers - run
'ulimit -c unlimited' delete the old core and run the opensips again with
the same usage case to get a new core.
Please print here the output of the gdb back trace with 'bt full'.

regards,
Anca

----------------------------------------------------------------------

You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=1086410&aid=2609529&group_id=232389



More information about the Devel mailing list