| Bug #36810 | Frequent core dumps mysql_ping with 4.007 | ||
|---|---|---|---|
| Submitted: | 19 May 2008 22:17 | Modified: | 20 Feb 2013 22:17 |
| Reporter: | Ask Hansen (Basic Quality Contributor) | Email Updates: | |
| Status: | Unsupported | Impact on me: | |
| Category: | Connectors: DBD::mysql ( Perl ) | Severity: | S2 (Serious) |
| Version: | 4.007, 4.008 | OS: | Linux (x86_64) |
| Assigned to: | CPU Architecture: | Any | |
| Tags: | crash, mysql_ping, qc, regression | ||
[19 May 2008 22:17]
Ask Hansen
[19 May 2008 22:18]
Ask Hansen
The changelog indicates a simple "took out mysql_server_init call where not needed" change. The diff shows *a lot* more changes though: http://search.cpan.org/diff?from=DBD-mysql-4.006&to=DBD-mysql-4.007#dbdimp.c
[19 May 2008 22:18]
Ask Hansen
This was on x86_64 Linux
[20 May 2008 14:34]
Sveta Smirnova
Thank you for the report. Please provide some clue what your application does. Which connection options do you use?
[21 May 2008 3:40]
Ask Hansen
Nothing special that we could discern; my best guess is that the sigsegv seems to happen sometimes when the ping fails. I can try to get a DBI.pm trace for you early next month.
[27 May 2008 14:06]
Jose Fonseca
Hi, same issue here. Have been in the datacenter for the past 25 hours non-stop just to find out the DBD::mysql upgrade caused our downtime. It was the last thing I thought of could cause this.
Core was generated by `/usr/local/apache/bin/httpd -f /usr/local/apache/conf/httpd.conf'.
Program terminated with signal 11, Segmentation fault.
[New process 1047]
#0 0x00b9e46b in mysql_ping () from /usr/local/mysql//lib/mysql/libmysqlclient.so.15
(gdb) where
#0 0x00b9e46b in mysql_ping () from /usr/local/mysql//lib/mysql/libmysqlclient.so.15
#1 0x004d99f2 in XS_DBD__mysql__db_ping (cv=0x94d2680) at mysql.xs:516
#2 0x001edbf4 in XS_DBI_dispatch () from /usr/lib/perl5/site_perl/5.10.0/i686-linux/auto/DBI/DBI.so
#3 0x084bfa43 in Perl_pp_entersub ()
#4 0x084be32e in Perl_runops_standard ()
#5 0x084ba15d in Perl_call_sv ()
#6 0x0043ae8f in EMBPERL2_CallStoredCV () from /usr/lib/perl5/site_perl/5.10.0/i686-linux/auto/Embperl/Embperl.so
#7 0x00453cf0 in embperl_Execute () from /usr/lib/perl5/site_perl/5.10.0/i686-linux/auto/Embperl/Embperl.so
#8 0x0045a008 in ProviderEpRun_GetContentIndex () from /usr/lib/perl5/site_perl/5.10.0/i686-linux/auto/Embperl/Embperl.so
#9 0x0045891a in Cache_GetContentIndex () from /usr/lib/perl5/site_perl/5.10.0/i686-linux/auto/Embperl/Embperl.so
#10 0x00434a63 in ProcessFile () from /usr/lib/perl5/site_perl/5.10.0/i686-linux/auto/Embperl/Embperl.so
#11 0x004355da in embperl_RunRequest () from /usr/lib/perl5/site_perl/5.10.0/i686-linux/auto/Embperl/Embperl.so
#12 0x00435b8c in embperl_ExecuteRequest () from /usr/lib/perl5/site_perl/5.10.0/i686-linux/auto/Embperl/Embperl.so
#13 0x0043233f in XS_Embperl__Req_ExecuteRequest () from /usr/lib/perl5/site_perl/5.10.0/i686-linux/auto/Embperl/Embperl.so
#14 0x084bfa43 in Perl_pp_entersub ()
#15 0x084be32e in Perl_runops_standard ()
#16 0x084ba15d in Perl_call_sv ()
#17 0x08371d3b in perl_call_handler (sv=0x96a8d20, r=0x9541c14, args=0x0) at mod_perl.c:1668
#18 0x083723f9 in perl_run_stacked_handlers (hook=0x85ef03b "PerlHandler", r=0x9541c14, handlers=0x96a8cb0)
at mod_perl.c:1381
#19 0x08373861 in perl_handler (r=0x9541c14) at mod_perl.c:904
#20 0x08395497 in ap_invoke_handler (r=0x9541c14) at http_config.c:476
#21 0x083acd2f in process_request_internal (r=0x9541c14) at http_request.c:1299
#22 0x083ad1a0 in ap_internal_redirect (new_uri=0x951427c "/lodging/vn/booknow.trv?hotelcode=221003", r=0x9512ae4)
at http_request.c:1440
#23 0x00386fe4 in mod_gzip_redir1_handler () from /usr/local/apache/modules/mod_gzip.so
#24 0x00385219 in mod_gzip_handler () from /usr/local/apache/modules/mod_gzip.so
#25 0x08395497 in ap_invoke_handler (r=0x9512ae4) at http_config.c:476
#26 0x083acd2f in process_request_internal (r=0x9512ae4) at http_request.c:1299
#27 0x083acd8c in ap_process_request (r=0x9512ae4) at http_request.c:1315
#28 0x083a2ef6 in child_main (child_num_arg=12) at http_main.c:4971
#29 0x083a3227 in make_child (s=0x87be05c, slot=12, now=1211894763) at http_main.c:5150
#30 0x083a32c2 in startup_children (number_to_start=23) at http_main.c:5178
#31 0x083a3a66 in standalone_main (argc=3, argv=0xbfe95934) at http_main.c:5525
#32 0x083a434f in main (argc=3, argv=0xbfe95934) at http_main.c:5883
CPAN Modules
DBI is up to date (1.604).
DBD::mysql is up to date (4.007).
Running Apache 1.3.41 compiled with -g
PHP 5.2.4 without built-in mysql (using external --with-mysql=/usr/local/mysql/)
mod_perl 1.29
Enabled core dumps with ulimit -c unlimited
Edit httpd.conf to add CoreDumpDirectory /yourfavoritedumpster
gdb httpd -c core.xxxx
This was the single most expensive bug in our experience with MySQL.
Regards,
Jose Fonseca
[11 Jun 2008 18:15]
Chris Jacobson
Solaris 10 mod_perl 2.0.3 perl 5.8.8 (non-threaded) Just to add in here that we have experienced the same issue with DBD::mysql 4.007. The failure always occurs in mysql_ping(), and the way we are able to trigger it on demand is to kill the connection thread and then issue a ping on the dbh. Spent over a week tracking this one down, and found this bug report. Reverting to 4.006 has fixed the issue for us as well, for the time being.
[13 Jun 2008 19:41]
dylan beukenkamp
Same here on FreeBSD 6.2-RELEASE-p11/amd64 MySQL Client 4.1.22 #0 0x0000000804d5497a in mysql_ping () from /usr/local/lib/mysql/libmysqlclient.so.14 #1 0x0000000808f56353 in XS_DBD__mysql__db_ping (cv=0x2a4e808) at mysql.xs:516 #2 0x0000000808031781 in XS_DBI_dispatch () from /usr/local/lib/perl5/site_perl/5.8.8/mach/auto/DBI/DBI.so #3 0x0000000806dfc17c in Perl_pp_entersub () from /usr/local/lib/perl5/5.8.8/mach/CORE/libperl.so #4 0x0000000806df4e1e in Perl_runops_standard () from /usr/local/lib/perl5/5.8.8/mach/CORE/libperl.so #5 0x0000000806da5c5c in Perl_call_sv () from /usr/local/lib/perl5/5.8.8/mach/CORE/libperl.so #6 0x0000000806c549e9 in modperl_callback () from /usr/local/apache2/modules/mod_perl.so #7 0x0000000806c54f03 in modperl_callback_run_handlers () from /usr/local/apache2/modules/mod_perl.so #8 0x0000000806c551af in modperl_callback_per_dir () from /usr/local/apache2/modules/mod_perl.so #9 0x0000000806c51eb0 in modperl_response_handler_run () from /usr/local/apache2/modules/mod_perl.so #10 0x0000000806c52098 in modperl_response_handler_cgi () from /usr/local/apache2/modules/mod_perl.so #11 0x00000000004331a3 in ap_run_handler (r=0x5145098) at config.c:157 #12 0x0000000000433641 in ap_invoke_handler (r=0x5145098) at config.c:372 #13 0x000000000043fda0 in ap_process_request (r=0x5145098) at http_request.c:258 #14 0x000000000043d51d in ap_process_http_connection (c=0x51261c8) at http_core.c:190 #15 0x0000000000439c03 in ap_run_process_connection (c=0x51261c8) at connection.c:43 #16 0x0000000000443b80 in child_main (child_num_arg=44361736) at prefork.c:640 #17 0x0000000000443ed4 in make_child (s=0x583708, slot=4) at prefork.c:736 #18 0x0000000000443f6e in startup_children (number_to_start=1) at prefork.c:754 #19 0x0000000000444744 in ap_mpm_run (_pconf=0x7fffffffea20, plog=0xe, s=0x7fffffffea2c) at prefork.c:975 #20 0x0000000000420af5 in main (argc=3, argv=0x7fffffffeb88) at main.c:730 Trying to revert to 4.006 as well to see if it goes away.
[5 Jul 2008 12:31]
Matthew Byng-Maddick
We saw the same on linux (x86_64). mysql_ping() appears to segfault (with DBD::mysql version 4.007) when the database connection has been closed. In a syscall trace, you see: poll() => returns one filehandle read(...) = 0 shutdown(..., 2) = 0 close(...) = 0 SIGSEGV Since MySQL does idle timeouts by default, and often people load-balance (loadbalancers are notoriously bad at keeping connections open, IMLE), this seems to be a reasonably serious bug.
[22 Aug 2008 7:08]
Sveta Smirnova
Bug #38953 was marked as duplicate of this one.
[6 Oct 2008 22:00]
Jason Terry
4.008 segfaults as well.
[7 Oct 2008 6:14]
Bron Gondwana
Bug exists on 32 bit as well, and with 5.0.67 libraries. Google search shows multiple people coming to the same conclusion, though often reverting back to 4.004 which has been stable for them.
[7 Oct 2008 23:18]
Bron Gondwana
Test program to see if you have this bug
Attachment: dbd_mysql_test.pl (application/x-perl, text), 750 bytes.
[8 Oct 2008 6:14]
Sveta Smirnova
Bron,
thank you for the test case. Verified as described.
bt from the test case attached:
Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread -1208686912 (LWP 2256)]
0x0064d74a in mysql_send_query (mysql=0x96b4a38, query=0x96c80c0 "SELECT 1", length=8) at client.c:2830
2830 DBUG_RETURN(simple_command(mysql, COM_QUERY, (uchar*) query, length, 1));
(gdb) bt
#0 0x0064d74a in mysql_send_query (mysql=0x96b4a38, query=0x96c80c0 "SELECT 1", length=8) at client.c:2830
#1 0x0064d857 in mysql_real_query (mysql=0x96b4a38, query=0x96c80c0 "SELECT 1", length=8) at client.c:2841
#2 0x0013d924 in mysql_st_internal_execute (h=0x968b6b4, statement=0x968b6d8, attribs=0x0, num_params=0, params=0x0, result=0x96c7e90, svsock=0x96b4a38, use_mysql_use_result=0) at dbdimp.c:2913
#3 0x0013e110 in mysql_st_execute (sth=0x968b6b4, imp_sth=0x96c7e08) at dbdimp.c:3136
#4 0x0013fb6f in XS_DBD__mysql__db_selectrow_arrayref (my_perl=0x94e6008, cv=0x9680e6c) at mysql.xsi:173
#5 0x0011f19e in XS_DBI_dispatch (my_perl=0x94e6008, cv=0x9650ca0) at DBI.xs:3086
#6 0x004ffbcc in Perl_pp_entersub () from /usr/lib/perl5/5.8.6/i386-linux-thread-multi/CORE/libperl.so
#7 0x004e1b01 in Perl_runops_debug () from /usr/lib/perl5/5.8.6/i386-linux-thread-multi/CORE/libperl.so
#8 0x00494f51 in perl_run () from /usr/lib/perl5/5.8.6/i386-linux-thread-multi/CORE/libperl.so
#9 0x080493f4 in main ()
(gdb) bt full
#0 0x0064d74a in mysql_send_query (mysql=0x96b4a38, query=0x96c80c0 "SELECT 1", length=8) at client.c:2830
_db_func_ = 0x6bf942 "mysql_real_query"
_db_file_ = 0x6beec2 "client.c"
_db_level_ = 2
_db_framep_ = (char **) 0xbfdef2c4
#1 0x0064d857 in mysql_real_query (mysql=0x96b4a38, query=0x96c80c0 "SELECT 1", length=8) at client.c:2841
_db_func_ = 0x6bec6d "?func"
_db_file_ = 0x6bec73 "?file"
_db_level_ = 1
_db_framep_ = (char **) 0x0
#2 0x0013d924 in mysql_st_internal_execute (h=0x968b6b4, statement=0x968b6d8, attribs=0x0, num_params=0, params=0x0, result=0x96c7e90, svsock=0x96b4a38, use_mysql_use_result=0) at dbdimp.c:2913
slen = 8
sbuf = 0x0
salloc = 0x0
rows = Variable "rows" is not available.
(gdb)
If change string before last to "my ($val) = $dbh->ping();" I get segfault in mysql_ping as well:
Program received signal EXC_BAD_ACCESS, Could not access memory.
Reason: KERN_PROTECTION_FAILURE at address: 0x00000004
0x0100c4c1 in mysql_ping (mysql=0x1881600) at libmysql.c:1421
1421 res= simple_command(mysql,COM_PING,0,0,0);
(gdb) bt
#0 0x0100c4c1 in mysql_ping (mysql=0x1881600) at libmysql.c:1421
#1 0x0009cfff in XS_DBD__mysql__db_ping (my_perl=0x1800400, cv=0x186f918) at mysql.xs:516
#2 0x000520f7 in XS_DBI_dispatch (my_perl=0x1800400, cv=0x1857950) at DBI.xs:3128
#3 0x96b20185 in Perl_pp_entersub ()
#4 0x96b1724f in Perl_runops_standard ()
#5 0x96aaa5d8 in perl_run ()
#6 0x000020d2 in ?? ()
#7 0x00001f56 in ?? ()
#8 0x00001e71 in ?? ()
(gdb) bt full
#0 0x0100c4c1 in mysql_ping (mysql=0x1881600) at libmysql.c:1421
res = 3384608
_db_func_ = 0x10b7470 "?func"
_db_file_ = 0x10b7478 "?file"
_db_level_ = 1
_db_framep_ = (char **) 0x0
#1 0x0009cfff in XS_DBD__mysql__db_ping (my_perl=0x1800400, cv=0x186f918) at mysql.xs:516
dbh = (SV *) 0x18466f0
RETVAL = (SV *) 0x33a520
sp = (SV **) 0x1
mark = (SV **) 0x33a520
ax = 1
#2 0x000520f7 in XS_DBI_dispatch (my_perl=0x1800400, cv=0x1857950) at DBI.xs:3128
markix = 0
xscv = (CV *) 0x0
sp = (SV **) 0x0
mark = (SV **) 0x0
ax = 1
items = 1
perinterp_sv = (SV *) 0x0
PERINTERP = (PERINTERP_t *) 0x356d80
h = (SV *) 0x18466f0
st1 = (SV *) 0x1857950
st2 = (SV *) 0x1858454
err_sv = (SV *) 0x187059c
tmp_svp = (SV **) 0x1800400
hook_svp = (SV **) 0x2
mg = (MAGIC *) 0x3278b0
gimme = 1
trace_flags = 0
trace_level = 0
is_DESTROY = 0
is_unrelated_to_Statement = 1024
keep_error = 1
ErrCount = 0
i = -1610559420
outitems = 1
call_depth = 1
is_nested_call = 0
profile_t1 = 0
meth_name = 0x3f4150 "ping"
ima = (const dbi_ima_t *) 0x3f4060
ima_flags = 1029
imp_xxh = (imp_xxh_t *) 0x33a520
imp_msv = (SV *) 0x0
qsv = (SV *) 0x0
#3 0x96b20185 in Perl_pp_entersub ()
No symbol table info available.
#4 0x96b1724f in Perl_runops_standard ()
No symbol table info available.
#5 0x96aaa5d8 in perl_run ()
No symbol table info available.
#6 0x000020d2 in ?? ()
No symbol table info available.
#7 0x00001f56 in ?? ()
No symbol table info available.
#8 0x00001e71 in ?? ()
No symbol table info available.
(gdb)
[29 Nov 2008 12:28]
Arkadiusz Miskiewicz
Seems that 4.010 fixes the problem.
[20 Feb 2013 22:17]
Sveta Smirnova
Thank you for the report. We don't work on DBD::mysql bugs anymore. All its bugs should go to CPAN: https://rt.cpan.org/Public/Dist/Display.html?Name=DBD-mysql Since this seems to be fixed in version 4.0.10 and up, I don't copy this issue to CPAN. Please upgrade.
