[OpenSIPS-Devel] [ opensips-Bugs-2609050 ] Segmentation fault in presence module related to MySQL

SourceForge.net noreply at sourceforge.net
Tue Feb 17 15:11:07 CET 2009


Bugs item #2609050, was opened at 2009-02-17 14:26
Message generated for change (Comment added) made by bogdan_iancu
You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=1086410&aid=2609050&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: Open
Resolution: None
Priority: 5
Private: No
Submitted By: Iñaki Baz (ibc_sf)
Assigned to: Nobody/Anonymous (nobody)
Summary: Segmentation fault in presence module related to MySQL

Initial Comment:
After upgrading to OpenSIPS rev 5320 a server acting as presence server crashes very often.
There is no traffic at all, just 4 users so very log presence traffic.


syslog:
----------
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7205]: DBG:presence:search_event: start event= [dialog]
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7205]: DBG:presence:handle_publish: SIP-If-Match header found
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7205]: DBG:presence:handle_publish: existing etag  = a.1234829890.9781.1.1
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7205]: DBG:presence:handle_publish: Expires header found, value= 8484
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7205]: DBG:db_mysql:db_mysql_do_prepared_query: new query=|select body,sender from presentity where domain=? AND username=? AND
event=? AND etag=?|
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7205]: DBG:db_mysql:db_mysql_do_prepared_query: prepared statement successfully set...
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7205]: DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7205]: DBG:db_mysql:db_mysql_val2bind: added val (0): len=9; type=254; is_null=0
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7205]: DBG:db_mysql:db_mysql_val2bind: added val (1): len=3; type=254; is_null=0
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7205]: DBG:db_mysql:db_mysql_val2bind: added val (2): len=6; type=254; is_null=0
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7205]: DBG:db_mysql:db_mysql_val2bind: added val (3): len=21; type=254; is_null=0
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7205]: DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7204]: DBG:db_mysql:db_mysql_do_prepared_query: prepared statement successfully set...
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7204]: DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7204]: DBG:db_mysql:db_mysql_val2bind: added val (0): len=21; type=254; is_null=0
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7204]: DBG:db_mysql:db_mysql_val2bind: added val (1): len=4; type=3; is_null=0
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7204]: DBG:db_mysql:db_mysql_val2bind: added val (2): len=4; type=3; is_null=0
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7204]: DBG:db_mysql:db_mysql_val2bind: added val (3): len=0; type=254; is_null=0
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7204]: DBG:db_mysql:db_mysql_val2bind: added val (4): len=9; type=254; is_null=0
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7204]: DBG:db_mysql:db_mysql_val2bind: added val (5): len=3; type=254; is_null=0
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7204]: DBG:db_mysql:db_mysql_val2bind: added val (6): len=6; type=254; is_null=0
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7204]: DBG:db_mysql:db_mysql_val2bind: added val (7): len=21; type=254; is_null=0
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7204]: DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
Feb 17 11:41:26 presence_server /usr/sbin/opensips_presence[7222]: CRITICAL:core:receive_fd: EOF on 9
----------------


coredump:
----------------
#0  0x00002ae413496588 in mysql_stmt_prepare () from /usr/lib/libmysqlclient.so.15
#1  0x00002ae4134989dc in cli_stmt_execute () from /usr/lib/libmysqlclient.so.15
#2  0x00002ae413498495 in mysql_stmt_execute () from /usr/lib/libmysqlclient.so.15
#3  0x00002ae41332322c in db_mysql_free_result () from /usr/lib/opensips/modules/db_mysql.so
#4  0x00002ae41332453f in db_mysql_update () from /usr/lib/opensips/modules/db_mysql.so
#5  0x00002ae414a31185 in update_presentity () from /usr/lib/opensips/modules/presence.so
#6  0x00002ae414a342d5 in handle_publish () from /usr/lib/opensips/modules/presence.so
#7  0x000000000040f894 in do_action ()
#8  0x000000000040e0f3 in run_action_list ()
#9  0x0000000000411df5 in do_action ()
#10 0x000000000040e0f3 in run_action_list ()
#11 0x000000000041176f in do_action ()
#12 0x000000000040e0f3 in run_action_list ()
#13 0x0000000000411df5 in do_action ()
#14 0x000000000040e0f3 in run_action_list ()
#15 0x000000000041093a in do_action ()
#16 0x000000000040e0f3 in run_action_list ()
#17 0x000000000041176f in do_action ()
#18 0x000000000040e0f3 in run_action_list ()
#19 0x000000000040e480 in run_top_route ()
#20 0x0000000000441b4c in receive_msg ()
#21 0x0000000000472990 in udp_rcv_loop ()
#22 0x0000000000423917 in main ()
----------------

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

>Comment By: Bogdan-Andrei Iancu (bogdan_iancu)
Date: 2009-02-17 16:11

Message:
Hi,

maybe this is related to bug #2608188 - it a report for prepared
statements crashing when reconnecting to mysql server....maybe it is the
same case here...

Regards,
Bogdan

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

Comment By: Iñaki Baz (ibc_sf)
Date: 2009-02-17 16:03

Message:
Hi Anca, tested again with rev5323 and a similar error occurs with exactly
the same backtrace.

syslog:
------------
/usr/sbin/opensips_presence[19199]: DBG:core:parse_msg: SIP Request:
/usr/sbin/opensips_presence[19199]: DBG:core:parse_msg:  method: 
<SUBSCRIBE>
/usr/sbin/opensips_presence[19199]: DBG:core:parse_msg:  uri:    
<sip:manwe at d
/usr/sbin/opensips_presence[19199]: DBG:core:parse_msg:  version:
<SIP/2.0>
/usr/sbin/opensips_presence[19199]: DBG:core:parse_headers: flags=2
/usr/sbin/opensips_presence[19199]: DBG:core:parse_via_param: found param
type
/usr/sbin/opensips_presence[19199]: DBG:core:parse_via: end of header
reached,
/usr/sbin/opensips_presence[19199]: DBG:core:parse_headers: via found,
flags=2
/usr/sbin/opensips_presence[19199]: DBG:core:parse_headers: this is the
first 
/usr/sbin/opensips_presence[19199]: DBG:core:receive_msg: After
parse_msg...
/usr/sbin/opensips_presence[19199]: DBG:core:receive_msg: preparing to run
rou
/usr/sbin/opensips_presence[19199]: DBG:core:parse_headers: flags=100
/usr/sbin/opensips_presence[19199]: DBG:core:parse_via_param: found param
type
/usr/sbin/opensips_presence[19199]: DBG:core:parse_via_param: found param
type
/usr/sbin/opensips_presence[19199]: DBG:core:parse_via_param: found param
type
/usr/sbin/opensips_presence[19199]: DBG:core:parse_via: end of header
reached,
/usr/sbin/opensips_presence[19199]: DBG:core:parse_headers: via found,
flags=1
/usr/sbin/opensips_presence[19199]: DBG:core:parse_headers: parse_headers:
thi
/usr/sbin/opensips_presence[19199]: DBG:maxfwd:is_maxfwd_present: value =
69
/usr/sbin/opensips_presence[19199]: DBG:core:parse_headers: flags=78
/usr/sbin/opensips_presence[19199]: DBG:core:parse_to: end of header
reached, 
/usr/sbin/opensips_presence[19199]: DBG:core:parse_to: display={},
ruri={sip:m
/usr/sbin/opensips_presence[19199]: DBG:core:get_hdr_field: <To> [23];
uri=[si
/usr/sbin/opensips_presence[19199]: DBG:core:get_hdr_field: to body
[<sip:manw
/usr/sbin/opensips_presence[19199]: DBG:core:get_hdr_field: cseq <CSeq>:
<410>
/usr/sbin/opensips_presence[19199]: DBG:tm:t_lookup_request: start
searching: 
/usr/sbin/opensips_presence[19199]: DBG:tm:matching_3261: RFC3261
transaction 
/usr/sbin/opensips_presence[19199]: DBG:tm:t_lookup_request: no
transaction fo
/usr/sbin/opensips_presence[19199]:
/usr/sbin/opensips_presence[19199]: DBG:uri:has_totag: no totag
/usr/sbin/opensips_presence[19199]: DBG:core:tr_eval_string: i=11 j=8
/usr/sbin/opensips_presence[19199]: DBG:core:parse_headers: flags=8000000
/usr/sbin/opensips_presence[19199]: 14:56:12 - request from
92.122.79.216:3689
/usr/sbin/opensips_presence[19199]: SUBSCRIBE sip:manwe at domain.net
/usr/sbin/opensips_presence[19199]: DBG:core:parse_to_param: tag=doohb
/usr/sbin/opensips_presence[19199]: DBG:core:parse_to: end of header
reached, 
/usr/sbin/opensips_presence[19199]: DBG:core:parse_to: display={"Iñaki"},
ruri
/usr/sbin/opensips_presence[19199]: From: "Iñaki" <sip:ibc at domain.net>
/usr/sbin/opensips_presence[19199]: DBG:core:pv_get_xto_attr: no Display
name
/usr/sbin/opensips_presence[19199]: To:   <null> <sip:manwe at domain.net>
/usr/sbin/opensips_presence[19199]: DBG:core:parse_headers:
flags=ffffffffffff
/usr/sbin/opensips_presence[19199]: DBG:core:get_hdr_field:
content_length=0
/usr/sbin/opensips_presence[19199]: DBG:core:get_hdr_field: found end of
heade
/usr/sbin/opensips_presence[19199]: DBG:presence:search_event: start
event= [p
/usr/sbin/opensips_presence[19199]: DBG:presence:extract_sdialog_info:
'Expire
/usr/sbin/opensips_presence[19199]: DBG:presence:extract_sdialog_info:
'To' he
/usr/sbin/opensips_presence[19199]: DBG:presence:extract_sdialog_info:
initial
/usr/sbin/opensips_presence[19199]: DBG:presence:extract_sdialog_info:
subs->c
/usr/sbin/opensips_presence[19199]: DBG:core:print_rr_body: current rr is
<sip
/usr/sbin/opensips_presence[19199]: DBG:core:print_rr_body: current rr is
<sip
/usr/sbin/opensips_presence[19199]: DBG:core:print_rr_body: out rr
[<sip:92.12
/usr/sbin/opensips_presence[19199]: DBG:core:print_rr_body: we have 2
records
/usr/sbin/opensips_presence[19199]:
DBG:db_mysql:db_mysql_do_prepared_query: s
/usr/sbin/opensips_presence[19199]: DBG:db_mysql:db_mysql_val2bind: added
val 
/usr/sbin/opensips_presence[19199]: DBG:db_mysql:db_mysql_val2bind: added
val 
/usr/sbin/opensips_presence[19199]: DBG:db_mysql:db_mysql_val2bind: added
val 
/usr/sbin/opensips_presence[19199]: DBG:db_mysql:db_mysql_val2bind: added
val 
/usr/sbin/opensips_presence[19199]:
DBG:db_mysql:db_mysql_do_prepared_query: d
/usr/sbin/opensips_presence[19207]: DBG:core:handle_tcp_child: dead tcp
child 
/usr/sbin/opensips_presence[19207]: DBG:core:io_watch_del: io_watch_del
(0x5fe
/usr/sbin/opensips_presence[19207]: CRITICAL:core:receive_fd: EOF on 21
/usr/sbin/opensips_presence[19207]: DBG:core:handle_ser_child: dead child
11, 
/usr/sbin/opensips_presence[19207]: DBG:core:io_watch_del: io_watch_del
(0x5fe
/usr/sbin/opensips_presence[19188]: INFO:core:handle_sigs: child process
19199
/usr/sbin/opensips_presence[19188]: INFO:core:handle_sigs: core was
generated
/usr/sbin/opensips_presence[19188]: INFO:core:handle_sigs: terminating due
to 
/usr/sbin/opensips_presence[19207]: INFO:core:sig_usr: signal 15 received
------------


Note however that I'm testing presence_dialoginfo module. I will dissable
it now and try again.

PD: There is an ERROR in the logs:

---------
ERROR:db_mysql:db_mysql_do_prepared_query: mysql_stmt_execute() failed:
Lost connection to MySQL server during query
Feb 17 15:02:42 presence_server /usr/sbin/opensips_presence[20031]:
ERROR:presence:update_presentity: inserting new record in database
---------

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

Comment By: Anca Vamanu (anca_vamanu)
Date: 2009-02-17 15:00

Message:
Hi Inaki,

I also noticed that there are problems with prepare statements and
operations in presentity table. But I thought that they occur only when
querying, because prepare statements put the result in a static buffer.
Just a couple of minutes ago I took out using prepare statements with
queries. 


More information about the Devel mailing list