| Bug #64635 | 7.2.4 Windows MySQL cluster with InnoDB database crashes | ||
|---|---|---|---|
| Submitted: | 13 Mar 2012 13:21 | Modified: | 19 Mar 2012 19:17 |
| Reporter: | R van der Wal | Email Updates: | |
| Status: | Verified | Impact on me: | |
| Category: | MySQL Cluster: Cluster (NDB) storage engine | Severity: | S2 (Serious) |
| Version: | 7.2.4 | OS: | Any (MS Windows 2008 Datacenter/Hyper-v, Linux) |
| Assigned to: | CPU Architecture: | Any | |
| Tags: | binlog, error, innodb | ||
[13 Mar 2012 13:21]
R van der Wal
[13 Mar 2012 19:32]
Sveta Smirnova
Thank you for the report. So I assume you actually use MySQL Cluster on Windows. Please correct if I am wrong. You wrote you do PURGE BINARY LOGS for database with InnoDB tables. But there is no PURGE BINARY LOGS for specific database. Please explain what you do.
[13 Mar 2012 19:58]
R van der Wal
Sorry but i don't understand your question? Do you mean InnoDB doesn't support binlogs or this MySQL cluster install?
[13 Mar 2012 20:09]
Sveta Smirnova
Thank you for the feedback. Not. I mean you wrote "We have 1 database with ndbclustertables, 1 database with all MyISAM tables and 1 innodb database. for the last we use purge-bin-logs" How can you purge bin logs for last database? Anyway crash happened when mysqld deleted from table mysql.ndb_binlog_index. Please send us output of SHOW CREATE TABLE mysql.ndb_binlog_index; and CHECK TABLE mysql.ndb_binlog_index;
[13 Mar 2012 20:18]
R van der Wal
"Table" "Create Table" "ndb_binlog_index" "CREATE TABLE `ndb_binlog_index` ( `Position` bigint(20) unsigned NOT NULL, `File` varchar(255) NOT NULL, `epoch` bigint(20) unsigned NOT NULL, `inserts` int(10) unsigned NOT NULL, `updates` int(10) unsigned NOT NULL, `deletes` int(10) unsigned NOT NULL, `schemaops` int(10) unsigned NOT NULL, `orig_server_id` int(10) unsigned NOT NULL, `orig_epoch` bigint(20) unsigned NOT NULL, `gci` int(10) unsigned NOT NULL, PRIMARY KEY (`epoch`,`orig_server_id`,`orig_epoch`) ) ENGINE=MyISAM DEFAULT CHARSET=latin1" || *Table* || *Op* || *Msg_type* || *Msg_text* || || mysql.ndb_binlog_index || check || warning || 2 clients are using or haven't closed the table properly || || mysql.ndb_binlog_index || check || status || OK ||
[13 Mar 2012 20:22]
R van der Wal
of course a stupid question, but i always thought that the binlog.* files on the harddisk always belonged to innodb. Isn't that so?
[13 Mar 2012 20:30]
R van der Wal
select count(*) from mysql.ndb_binlog_index gives a total of 196399 rows. the oldest entries in mysql.ndb_binlog_index contains 141892 references to .\binlog.000023. The oldest binlog file is binlog.000026, the newest is binlog.000040
[14 Mar 2012 6:36]
R van der Wal
a new crash last night: 120313 14:11:52 [Note] NDB Binlog: starting log at epoch 996558/0 120313 14:11:52 [Note] NDB Binlog: ndb tables writable 120313 14:11:52 [Note] NDB Binlog: Node: 4, subscribe from node 9, Subscriber bitmask 0200 120313 14:11:52 [Note] NDB Binlog: Node: 3, subscribe from node 9, Subscriber bitmask 0200 120314 3:08:07 - mysqld got exception 0xc0000005 ; This could be because you hit a bug. It is also possible that this binary or one of the libraries it was linked against is corrupt, improperly built, or misconfigured. This error can also be caused by malfunctioning hardware. We will try our best to scrape up some info that will hopefully help diagnose the problem, but since we have already crashed, something is definitely wrong and this may fail. key_buffer_size=574619648 read_buffer_size=2097152 max_used_connections=62 max_threads=800 thread_count=59 connection_count=59 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2412577 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. Thread pointer: 0x5a126c70 Attempting backtrace. You can use the following information to find out where mysqld died. If you see no messages after this, something went terribly wrong... 000000013FDB2FCE mysqld.exe!?ha_rollback_trans@@YAHPEAVTHD@@_N@Z() 000000013FEB6AFA mysqld.exe!?trans_rollback_stmt@@YA_NPEAVTHD@@@Z() 000000013FDF88C3 mysqld.exe!?mysql_execute_command@@YAHPEAVTHD@@@Z() 000000013FF57073 mysqld.exe!?execute_server_code@Execute_sql_statement@@UEAA_NPEAVTHD@@@Z() 000000013FF583B2 mysqld.exe!?execute_server_runnable@Prepared_statement@@QEAA_NPEAVServer_runnable@@@Z() 000000013FF586D5 mysqld.exe!?execute_direct@Ed_connection@@QEAA_NPEAVServer_runnable@@@Z() 000000013FF58B66 mysqld.exe!?execute_direct@Ed_connection@@QEAA_NUst_mysql_lex_string@@@Z() 000000014010431C mysqld.exe!my_osmaperr() 0000000140104534 mysqld.exe!my_osmaperr() 00000001401049C0 mysqld.exe!my_osmaperr() 00000001400F855A mysqld.exe!my_osmaperr() 000000013FDB5EA6 mysqld.exe!?ha_make_pushed_joins@@YAHPEAVTHD@@PEAVJoin_plan@AQP@@PEAI@Z() 000000013FDB5FBB mysqld.exe!?ha_binlog_index_purge_file@@YAHPEAVTHD@@PEBD@Z() 000000013FDA502B mysqld.exe!?purge_index_entry@MYSQL_BIN_LOG@@QEAAHPEAVTHD@@PEA_K_N@Z() 000000013FDA7A07 mysqld.exe!?purge_logs@MYSQL_BIN_LOG@@QEAAHPEBD_N11PEA_K@Z() 000000013FDA7D39 mysqld.exe!?purge_logs_before_date@MYSQL_BIN_LOG@@QEAAH_J@Z() 000000013FDA8495 mysqld.exe!?purge@MYSQL_BIN_LOG@@QEAAXXZ() 000000013FDA98A2 mysqld.exe!?write@MYSQL_BIN_LOG@@QEAA_NPEAVTHD@@PEAUst_io_cache@@PEAVLog_event@@_N@Z() 000000013FDA9ACA mysqld.exe!?unlog@MYSQL_BIN_LOG@@UEAAHK_K@Z() 000000013FDA9EE3 mysqld.exe!?unlog@MYSQL_BIN_LOG@@UEAAHK_K@Z() 000000013FDB2E51 mysqld.exe!?ha_commit_one_phase@@YAHPEAVTHD@@_N@Z() 000000013FDB7FB1 mysqld.exe!?ha_commit_trans@@YAHPEAVTHD@@_N@Z() 000000013FEB6A56 mysqld.exe!?trans_commit_stmt@@YA_NPEAVTHD@@@Z() 000000013FDF7073 mysqld.exe!?mysql_execute_command@@YAHPEAVTHD@@@Z() 000000013FF55CE8 mysqld.exe!?execute@Prepared_statement@@AEAA_NPEAVString@@_N@Z() 000000013FF58A76 mysqld.exe!?execute_loop@Prepared_statement@@QEAA_NPEAVString@@_NPEAE2@Z() 000000013FF58C54 mysqld.exe!?mysqld_stmt_execute@@YAXPEAVTHD@@PEADI@Z() 000000013FDF9B97 mysqld.exe!?dispatch_command@@YA_NW4enum_server_command@@PEAVTHD@@PEADI@Z() 000000013FDFAABC mysqld.exe!?do_command@@YA_NPEAVTHD@@@Z() 000000013FE20146 mysqld.exe!?do_handle_one_connection@@YAXPEAVTHD@@@Z() 000000013FE20364 mysqld.exe!handle_one_connection() 000000013FFA8E3E mysqld.exe!win_pthread_mutex_trylock() 0000000140236EF7 mysqld.exe!my_mb_ctype_mb() 0000000140236FAB mysqld.exe!my_mb_ctype_mb() 000000007741652D kernel32.dll!BaseThreadInitThunk() 000000007754C521 ntdll.dll!RtlUserThreadStart() Trying to get some variables. Some pointers may be invalid and cause the dump to abort. Query (000000003FE32878): DELETE FROM mysql.ndb_binlog_index WHERE File='.\binlog.000027' Connection ID (thread ID): 34694 Status: NOT_KILLED The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains information that should help you find out what is causing the crash. 120314 7:34:31 [Note] Failed to execute mysql_file_stat on file '.\binlog.000026' 120314 7:34:31 [Note] Plugin 'FEDERATED' is disabled. 120314 7:34:31 InnoDB: The InnoDB memory heap is disabled 120314 7:34:31 InnoDB: Mutexes and rw_locks use Windows interlocked functions 120314 7:34:31 InnoDB: Compressed tables use zlib 1.2.3 120314 7:34:31 InnoDB: Initializing buffer pool, size = 2.0G 120314 7:34:31 InnoDB: Completed initialization of buffer pool 120314 7:34:31 InnoDB: highest supported file format is Barracuda. InnoDB: The log sequence number in ibdata files does not match InnoDB: the log sequence number in the ib_logfiles! 120314 7:34:31 InnoDB: Database was not shut down normally! InnoDB: Starting crash recovery. InnoDB: Reading tablespace information from the .ibd files... InnoDB: Restoring possible half-written data pages from the doublewrite InnoDB: buffer... InnoDB: Last MySQL binlog file position 0 1073520430, file name .\binlog.000040 120314 7:34:32 InnoDB: Waiting for the background threads to start
[19 Mar 2012 7:07]
R van der Wal
Just to inform anybody, mysql crashes every day now during the purge of the binlog.
[19 Mar 2012 19:17]
Sveta Smirnova
Thank you for the feedback. Verified as described. Instructions how to repeat follow. I think if you remove option expire_logs_days from the configuration file issue would be solved. Also, binary logs have nothing to do with InnoDB. Binary logs described at http://dev.mysql.com/doc/refman/5.1/en/binary-log.html InnoDB logs (which are very different concept) described at http://dev.mysql.com/doc/refman/5.1/en/innodb-data-log-reconfiguration.html and http://dev.mysql.com/doc/refman/5.1/en/innodb-configuration.html
[19 Mar 2012 19:27]
Sveta Smirnova
To repeat:
1. Modify sources:
[sveta@delly mysql-test]$ bzr diff
=== modified file 'sql/log.cc'
--- sql/log.cc 2011-03-15 11:14:43 +0000
+++ sql/log.cc 2012-03-19 19:00:01 +0000
@@ -4564,7 +4564,7 @@
*/
if (check_purge && expire_logs_days)
{
- time_t purge_time= my_time(0) - expire_logs_days*24*60*60;
+ time_t purge_time= my_time(0) - expire_logs_days*60;
if (purge_time >= 0)
purge_logs_before_date(purge_time);
}
=== modified file 'sql/mysqld.cc'
--- sql/mysqld.cc 2011-02-23 13:09:10 +0000
+++ sql/mysqld.cc 2012-03-19 19:00:10 +0000
@@ -4198,7 +4198,7 @@
#ifdef HAVE_REPLICATION
if (opt_bin_log && expire_logs_days)
{
- time_t purge_time= server_start_time - expire_logs_days*24*60*60;
+ time_t purge_time= server_start_time - expire_logs_days*60;
if (purge_time >= 0)
mysql_bin_log.purge_logs_before_date(purge_time);
}
2. cd mysql-test, then:
$./mtr --start --suite=ndb_binlog ndb_binlog_multi --mysqld=--expire_logs_days=1 &
$../client/mysql -uroot -S ./var/tmp/mysqld.1.1.sock test
mysql> create table t1(f1 int) engine=ndb;
Query OK, 0 rows affected (0.65 sec)
mysql> insert into t1 values(1);
Query OK, 1 row affected (0.00 sec)
mysql> insert into t1 values(1);
Query OK, 1 row affected (0.00 sec)
mysql> flush logs;
Query OK, 0 rows affected (0.21 sec)
mysql> \q
Bye
$ ../client/mysqladmin shutdown -uroot -S ./var/tmp/mysqld.1.1.sock
$ ./mtr --start-dirty --suite=ndb_binlog ndb_binlog_multi --mysqld=--expire_logs_days=1 &
$ ../client/mysql -uroot -S ./var/tmp/mysqld.1.1.sock test
mysql> insert into t1 values(1);
Query OK, 1 row affected (0.00 sec)
mysql> insert into t1 values(1);
Query OK, 1 row affected (0.00 sec)
mysql> \q
Bye
$ ../client/mysqladmin shutdown -uroot -S ./var/tmp/mysqld.1.1.sock
$ ./mtr --start-dirty --suite=ndb_binlog ndb_binlog_multi --mysqld=--expire_logs_days=1 &
Get crash:
Thread 1 (Thread 0x7fb003887700 (LWP 28297)):
#0 0x0000003a4d00c6bc in pthread_kill () from /lib64/libpthread.so.0
#1 0x00000000006484b6 in handle_segfault ()
#2 <signal handler called>
#3 0x00000000009c6b51 in alloc_root ()
#4 0x00000000009c6cf3 in strmake_root ()
#5 0x0000000000581be6 in get_token(Lex_input_stream*, unsigned int, unsigned int) ()
#6 0x0000000000585bdb in MYSQLlex(void*, void*) ()
#7 0x00000000006738f5 in MYSQLparse(void*) ()
#8 0x000000000065f3eb in mysql_parse(THD*, char*, unsigned int, char const**) ()
#9 0x00000000007f5cf6 in run_query ()
#10 0x00000000007f5f7a in ndbcluster_binlog_index_purge_file(THD*, char const*) ()
#11 0x000000000073460a in binlog_func_foreach(THD*, binlog_func_st*) ()
#12 0x00000000007346f8 in ha_binlog_index_purge_file(THD*, char const*) ()
#13 0x00000000006e7826 in MYSQL_BIN_LOG::purge_index_entry(THD*, unsigned long long*, bool) ()
#14 0x00000000006ea03c in MYSQL_BIN_LOG::purge_logs(char const*, bool, bool, bool, unsigned long long*) ()
#15 0x00000000006ea60f in MYSQL_BIN_LOG::purge_logs_before_date(long) ()
#16 0x0000000000649813 in init_server_components() ()
#17 0x000000000064d27e in main ()
[27 Oct 2017 13:01]
Daniël van Eeden
On 7.6.3 on Linux this happened. I think this is the same bug. 12:12:28 UTC - mysqld got signal 11 ; This could be because you hit a bug. It is also possible that this binary or one of the libraries it was linked against is corrupt, improperly built, or misconfigured. This error can also be caused by malfunctioning hardware. Attempting to collect some information that could help diagnose the problem. As this is a crash and something is definitely wrong, the information collection process might fail. key_buffer_size=805306368 read_buffer_size=131072 max_used_connections=0 max_threads=3000 thread_count=2 connection_count=0 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 4282463 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. Thread pointer: 0x2358600 Attempting backtrace. You can use the following information to find out where mysqld died. If you see no messages after this, something went terribly wrong... stack_bottom = 7ffe9ed90370 thread_stack 0x40000 /usr/sbin/mysqld(my_print_stacktrace+0x3b)[0xf72f7b] /usr/sbin/mysqld(handle_fatal_signal+0x461)[0x82aaa1] /lib64/libpthread.so.0(+0xf5e0)[0x7f20939fe5e0] /usr/sbin/mysqld(_ZN17Cost_model_server4initEv+0x5a)[0xc9d37a] /usr/sbin/mysqld(_Z9lex_startP3THD+0x2d)[0xd21f8d] /usr/sbin/mysqld(_ZN21Execute_sql_statement19execute_server_codeEP3THD+0xe2)[0xd6b392] /usr/sbin/mysqld(_ZN18Prepared_statement23execute_server_runnableEP15Server_runnable+0x1cd)[0xd6ed3d] /usr/sbin/mysqld(_ZN13Ed_connection14execute_directEP15Server_runnable+0xb4)[0xd70c94] /usr/sbin/mysqld(_ZN13Ed_connection14execute_directE19st_mysql_lex_string+0x34)[0xd70d94] /usr/sbin/mysqld(_ZN20Ndb_local_connection13execute_queryE19st_mysql_lex_stringPKjPK10Suppressor+0x5d)[0x132e5cd] /usr/sbin/mysqld(_ZN20Ndb_local_connection17execute_query_isoE19st_mysql_lex_stringPKjPK10Suppressor+0x66)[0x132e786] /usr/sbin/mysqld(_ZN20Ndb_local_connection11delete_rowsEPKcmS1_mbz+0x198)[0x132ebc8] /usr/sbin/mysqld[0x131329e] /usr/sbin/mysqld[0x872f8c] /usr/sbin/mysqld(_Z26ha_binlog_index_purge_fileP3THDPKc+0x33)[0x87ced3] /usr/sbin/mysqld(_ZN13MYSQL_BIN_LOG17purge_index_entryEP3THDPyb+0x359)[0xf04199] /usr/sbin/mysqld(_ZN13MYSQL_BIN_LOG10purge_logsEPKcbbbPyb+0x368)[0xf0e5a8] /usr/sbin/mysqld(_ZN13MYSQL_BIN_LOG22purge_logs_before_dateElb+0x4df)[0xf0f19f] /usr/sbin/mysqld[0x8240d5] /usr/sbin/mysqld(_Z11mysqld_mainiPPc+0x874)[0x824e74] /lib64/libc.so.6(__libc_start_main+0xf5)[0x7f20923dcc05] /usr/sbin/mysqld[0x81aaa5] Trying to get some variables. Some pointers may be invalid and cause the dump to abort. Query (9cf1a638): DELETE FROM mysql.ndb_binlog_index WHERE File='../log/binlog.000142' Connection ID (thread ID): 0 Status: NOT_KILLED The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains information that should help you find out what is causing the crash.
[27 Oct 2017 13:08]
Daniël van Eeden
With some help from c++filt /usr/sbin/mysqld(my_print_stacktrace+0x3b)[0xf72f7b] /usr/sbin/mysqld(handle_fatal_signal+0x461)[0x82aaa1] /lib64/libpthread.so.0(+0xf5e0)[0x7f20939fe5e0] /usr/sbin/mysqld(Cost_model_server::init()+0x5a)[0xc9d37a] /usr/sbin/mysqld(lex_start(THD*)+0x2d)[0xd21f8d] /usr/sbin/mysqld(Execute_sql_statement::execute_server_code(THD*)+0xe2)[0xd6b392] /usr/sbin/mysqld(Prepared_statement::execute_server_runnable(Server_runnable*)+0x1cd)[0xd6ed3d] /usr/sbin/mysqld(Ed_connection::execute_direct(Server_runnable*)+0xb4)[0xd70c94] /usr/sbin/mysqld(Ed_connection::execute_direct(st_mysql_lex_string)+0x34)[0xd70d94] /usr/sbin/mysqld(Ndb_local_connection::execute_query(st_mysql_lex_string, unsigned int const*, Suppressor const*)+0x5d)[0x132e5cd] /usr/sbin/mysqld(Ndb_local_connection::execute_query_iso(st_mysql_lex_string, unsigned int const*, Suppressor const*)+0x66)[0x132e786] /usr/sbin/mysqld(Ndb_local_connection::delete_rows(char const*, unsigned long, char const*, unsigned long, bool, ...)+0x198)[0x132ebc8] /usr/sbin/mysqld[0x131329e] /usr/sbin/mysqld[0x872f8c] /usr/sbin/mysqld(ha_binlog_index_purge_file(THD*, char const*)+0x33)[0x87ced3] /usr/sbin/mysqld(MYSQL_BIN_LOG::purge_index_entry(THD*, unsigned long long*, bool)+0x359)[0xf04199] /usr/sbin/mysqld(MYSQL_BIN_LOG::purge_logs(char const*, bool, bool, bool, unsigned long long*, bool)+0x368)[0xf0e5a8] /usr/sbin/mysqld(MYSQL_BIN_LOG::purge_logs_before_date(long, bool)+0x4df)[0xf0f19f] /usr/sbin/mysqld[0x8240d5] /usr/sbin/mysqld(mysqld_main(int, char**)+0x874)[0x824e74] /lib64/libc.so.6(__libc_start_main+0xf5)[0x7f20923dcc05] /usr/sbin/mysqld[0x81aaa5]
[20 Mar 2018 14:30]
Frazer Clement
Looks like another issue with setting up a valid THD early on in the server lifecycle. Two fix options at least : i) Fix specific problems with THD unearthed here ii) Move ndb_binlog_index DELETE to a higher layer, later (BI init)
