| Bug #69898 | change_master() invokes ha_innobase::truncate() in a DML transaction | ||
|---|---|---|---|
| Submitted: | 1 Aug 2013 13:47 | Modified: | 19 Sep 2013 14:02 |
| Reporter: | Shahriyar Rzayev | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Replication | Severity: | S1 (Critical) |
| Version: | 5.6.12 | OS: | Any (Centos 6.4) |
| Assigned to: | CPU Architecture: | Any | |
[1 Aug 2013 13:47]
Shahriyar Rzayev
[1 Aug 2013 15:29]
Valeriy Kravchuk
Looks very similar to http://bugs.mysql.com/bug.php?id=69825 (same assertion failure), can be a duplicate. Is this a slave, does it use GTID-based replication?
[1 Aug 2013 15:33]
Shahriyar Rzayev
Changed severity from non-critical to critical.
[1 Aug 2013 15:37]
Shahriyar Rzayev
No this not a slave but i enabled GTID yes.
[2 Aug 2013 7:52]
Shahriyar Rzayev
I must update some information . this situation occur after using: mysqlreplicate --master=root:12345@localhost:3306 --slave=remote:12345@192.168.1.106 --rpl-user=repl:12345@192.168.1.106 -vv But replication did not setup properly and in fact there is no slave connected to my master: mysql> show slave hosts; Empty set (0.00 sec)
[2 Aug 2013 18:11]
MySQL Verification Team
Does a crash happens every time you start a server ??? If it does, please, start a debug 5.6.12 binary and make sure it can dump core. If a core gets dumped, then tar gzip both a binary and a core file and upload it to this bug. Bug # 69825 is a duplicate of this one, but as both do not have sufficient info, it is irrelevant. Seems that we have a case that both a dictionary and normal table can be locked during recovery. A gdb session with core file and a binary that produced it could show the cause and help us fix a bug !!!
[2 Aug 2013 22:15]
Shahriyar Rzayev
core dump of MySQL 5.6.12
Attachment: core4.tar.gz (application/gzip, text), 2.19 MiB.
[2 Aug 2013 22:26]
Shahriyar Rzayev
just For testing i setup new MySQL 5.6.12 in another laptop with Virtualbox. And try again to setup replication between thems using mysqlreplicate utility. And surely this tool crash my new/fresh installed MySQL too!!! Something wrong with this tool! i will report this as separate bug. But now i activated core-file as you say in my NEW installation(not previous that i test): InnoDB: 2 transaction(s) which must be rolled back or cleaned up InnoDB: in total 4 row operations to undo InnoDB: Trx id counter is 10240 2013-08-03 11:21:47 7fc7f339d720 InnoDB: Error: a record lock wait happens in a dictionary operation! InnoDB: index "CLUST_IND" of table "SYS_INDEXES". InnoDB: Submit a detailed bug report to http://bugs.mysql.com 2013-08-03 11:21:47 7fc7f339d720 InnoDB: Assertion failure in thread 140496755873568 in file lock0wait.cc line 297 InnoDB: We intentionally generate a memory trap. InnoDB: Submit a detailed bug report to http://bugs.mysql.com. InnoDB: If you get repeated assertion failures or crashes, even InnoDB: immediately after the mysqld startup, there may be InnoDB: corruption in the InnoDB tablespace. Please refer to InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html InnoDB: about forcing recovery. 06:21:47 UTC - mysqld got signal 6 ; 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=8388608 read_buffer_size=131072 max_used_connections=0 max_threads=1 thread_count=0 connection_count=0 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 8589 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. Thread pointer: 0x0 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 = 0 thread_stack 0x40000 /usr/sbin/mysqld(my_print_stacktrace+0x35)[0x8c70d5] /usr/sbin/mysqld(handle_fatal_signal+0x4a4)[0x65cbe4] /lib64/libpthread.so.0(+0xf500)[0x7fc7f498a500] /lib64/libc.so.6(gsignal+0x35)[0x7fc7f36358a5] /lib64/libc.so.6(abort+0x175)[0x7fc7f3637085] /usr/sbin/mysqld[0x9171c5] /usr/sbin/mysqld[0x94bd64] /usr/sbin/mysqld[0x94c225] /usr/sbin/mysqld[0x963d97] /usr/sbin/mysqld[0x91d1b5] /usr/sbin/mysqld[0x99aad4] /usr/sbin/mysqld[0x8e311d] /usr/sbin/mysqld(_Z24ha_initialize_handlertonP13st_plugin_int+0x48)[0x5a36c8] /usr/sbin/mysqld[0x6e13c1] /usr/sbin/mysqld(_Z11plugin_initPiPPci+0xb16)[0x6e4f76] /usr/sbin/mysqld[0x596921] /usr/sbin/mysqld(_Z11mysqld_mainiPPc+0x405)[0x59b4a5] /lib64/libc.so.6(__libc_start_main+0xfd)[0x7fc7f3621cdd] /usr/sbin/mysqld[0x58d701] 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. Writing a core file 130803 11:21:48 mysqld_safe mysqld from pid file /var/lib/mysql/localhost.localdomain.pid ended As you see it is the same error from my previous installation.
[2 Aug 2013 22:30]
Shahriyar Rzayev
i tried to use gdb but got a: [root@localhost ~]# gdb /usr/sbin/mysqld /var/lib/mysql/core.2275 GNU gdb (GDB) Red Hat Enterprise Linux (7.2-60.el6_4.1) Copyright (C) 2010 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html> This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "x86_64-redhat-linux-gnu". For bug reporting instructions, please see: <http://www.gnu.org/software/gdb/bugs/>... Reading symbols from /usr/sbin/mysqld...done. [New Thread 2275] [New Thread 2279] [New Thread 2280] [New Thread 2281] [New Thread 2282] [New Thread 2283] [New Thread 2284] [New Thread 2285] [New Thread 2286] [New Thread 2287] [New Thread 2288] Reading symbols from /lib64/libpthread.so.0...(no debugging symbols found)...done. [Thread debugging using libthread_db enabled] Loaded symbols for /lib64/libpthread.so.0 Reading symbols from /lib64/libaio.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libaio.so.1 Reading symbols from /lib64/librt.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/librt.so.1 Reading symbols from /lib64/libcrypt.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libcrypt.so.1 Reading symbols from /lib64/libdl.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libdl.so.2 Reading symbols from /usr/lib64/libstdc++.so.6...(no debugging symbols found)...done. Loaded symbols for /usr/lib64/libstdc++.so.6 Reading symbols from /lib64/libm.so.6...(no debugging symbols found)...done. Loaded symbols for /lib64/libm.so.6 Reading symbols from /lib64/libgcc_s.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libgcc_s.so.1 Reading symbols from /lib64/libc.so.6...(no debugging symbols found)...done. Loaded symbols for /lib64/libc.so.6 Reading symbols from /lib64/ld-linux-x86-64.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/ld-linux-x86-64.so.2 Reading symbols from /lib64/libfreebl3.so...(no debugging symbols found)...done. Loaded symbols for /lib64/libfreebl3.so Core was generated by `/usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib6'. Program terminated with signal 6, Aborted. #0 0x00007fc7f498769c in pthread_kill () from /lib64/libpthread.so.0 Missing separate debuginfos, use: debuginfo-install MySQL-server-5.6.12-2.el6.x86_64 Then: [root@localhost ~]# debuginfo-install MySQL-server-5.6.12-2.el6.x86_64 Loaded plugins: fastestmirror, refresh-packagekit Loading mirror speeds from cached hostfile * base: mirror.logol.ru * extras: mirror.logol.ru * updates: mirror.logol.ru Checking for new repos for mirrors Could not find debuginfo for main pkg: MySQL-server-5.6.12-2.el6.x86_64 Could not find debuginfo pkg for dependency package libaio-0.3.107-10.el6.x86_64 Could not find debuginfo pkg for dependency package libaio-0.3.107-10.el6.x86_64 Could not find debuginfo pkg for dependency package libaio-0.3.107-10.el6.x86_64 Could not find debuginfo pkg for dependency package glibc-2.12-1.107.el6_4.2.x86_64 Could not find debuginfo pkg for dependency package glibc-2.12-1.107.el6_4.2.x86_64 Could not find debuginfo pkg for dependency package glibc-2.12-1.107.el6_4.2.x86_64 Could not find debuginfo pkg for dependency package glibc-2.12-1.107.el6_4.2.x86_64 Could not find debuginfo pkg for dependency package glibc-2.12-1.107.el6_4.2.x86_64 Could not find debuginfo pkg for dependency package glibc-2.12-1.107.el6_4.2.x86_64 Could not find debuginfo pkg for dependency package glibc-2.12-1.107.el6_4.2.x86_64 Could not find debuginfo pkg for dependency package glibc-2.12-1.107.el6_4.2.x86_64 Could not find debuginfo pkg for dependency package glibc-2.12-1.107.el6_4.2.x86_64 Could not find debuginfo pkg for dependency package glibc-2.12-1.107.el6_4.2.x86_64 Could not find debuginfo pkg for dependency package glibc-2.12-1.107.el6_4.2.x86_64 Could not find debuginfo pkg for dependency package glibc-2.12-1.107.el6_4.2.x86_64 Could not find debuginfo pkg for dependency package libgcc-4.4.7-3.el6.x86_64 Could not find debuginfo pkg for dependency package libgcc-4.4.7-3.el6.x86_64 Could not find debuginfo pkg for dependency package glibc-2.12-1.107.el6_4.2.x86_64 Could not find debuginfo pkg for dependency package glibc-2.12-1.107.el6_4.2.x86_64 Could not find debuginfo pkg for dependency package glibc-2.12-1.107.el6_4.2.x86_64 Could not find debuginfo pkg for dependency package glibc-2.12-1.107.el6_4.2.x86_64 Could not find debuginfo pkg for dependency package glibc-2.12-1.107.el6_4.2.x86_64 Could not find debuginfo pkg for dependency package glibc-2.12-1.107.el6_4.2.x86_64 Could not find debuginfo pkg for dependency package glibc-2.12-1.107.el6_4.2.x86_64 Could not find debuginfo pkg for dependency package libstdc++-4.4.7-3.el6.x86_64 Could not find debuginfo pkg for dependency package libstdc++-4.4.7-3.el6.x86_64 Could not find debuginfo pkg for dependency package libstdc++-4.4.7-3.el6.x86_64 Could not find debuginfo pkg for dependency package libstdc++-4.4.7-3.el6.x86_64 No debuginfo packages available to install So cant attach any other file.
[5 Aug 2013 12:30]
MySQL Verification Team
Hi! Thank you for your efforts but we need mysqld binary which produced this core dump, as well. I do hope it is a debug binary as we already asked. Thanks in advance.
[6 Aug 2013 6:42]
Marko Mäkelä
This looks like a duplicate of Bug#69285, which contains a useful gdb stack trace. To analyze the problem, we really need one of the following: * the ibdata* files from the failing data set * the core dump, mysqld and any shared libraries linked to it I would prefer the ibdata* files, if possible.
[6 Aug 2013 6:43]
Marko Mäkelä
Sorry, I meant that this looks like a duplicate of Bug#69825 InnoDB: Assertion failure in thread ... in file lock0wait.cc line 297
[6 Aug 2013 8:17]
Shahriyar Rzayev
Core dump
Attachment: core.tar.gz (application/x-gzip, text), 1.68 MiB.
[6 Aug 2013 8:22]
Shahriyar Rzayev
ibdata1
Attachment: ibdata1.tar.gz (application/x-gzip, text), 41.33 KiB.
[6 Aug 2013 12:24]
Marko Mäkelä
Thank you, I can verify the hang with the attached ibdata1 file. Now, the question is: how was the data file created? In my debugger session, I see that the system recovered 4 transactions (3405, 3387, 3369, 3351) and allocated a 5th one (id=5376) to execute row_merge_drop_temp_indexes(). It looks like one of these 4 transactions is not flagged as a data dictionary transaction, even though it is holding a lock on the SYS_INDEXES table in the InnoDB data dictionary. The recovered transaction 3405 is holding a record lock on (space_id,page_no,heap_no)=(0,11,12). The internal DDL recovery transaction (id=5376) has locked all heap_no on this page from 2 to 11, and is apparently hanging on this very record. Page 11 in the attached ibdata1 belongs to SYS_INDEXES. I used this to extract the page: dd ibs=16384 count=1 skip=11 if=ibdata1 of=page11 It looks like heap_no=12 is the last record on the page, immediately preceding the page supremum, at offset 0x342 (REC_OLD_HEAP_NO bytes 0x0060). Let me decode the payload of that record: PHYSICAL RECORD: n_fields 9; 1-byte offsets; info bits 0 0: len 8; hex 0000000000000017; asc ;; table_id=0x17 1: len 8; hex 0000000000000015; asc ;; index_id=0x15 2: len 6; hex 000000000d4d; asc M;; DB_TRX_ID=0xd4d==3405 3: len 7; hex be0000015b020c; asc [ ;; DB_ROLL_PTR=(update) 4: len 7; hex 5052494d415259; asc PRIMARY;; NAME='PRIMARY' 5: len 4; hex 00000001; asc ;; N_FIELDS=1 6: len 4; hex 00000003; asc ;; TYPE=DICT_CLUSTERED|DICT_UNIQUE 7: len 4; hex 00000009; asc ;; SPACE=9 8: len 4; hex 00000003; asc ;; PAGE_NO=3 So, it looks like the recovered transaction 3405 updated this record for the clustered index (primary key) of table 0x17. The bug is that transaction 3405 was not flagged as a data dictionary transaction. If it had been, it would have been rolled back before we execute row_merge_drop_temp_indexes(). Can you please check which *.ibd file carries space_id=9, and check the SQL logs for DDL operations on this table name? You can use a command like this: for i in */*.ibd; do echo -n $i:; od -j 34 -N 4 -Ax -t x1 $i; done For the matching file, it should display foo.ibd:000022 00 00 00 09 000026 We need to identify the DDL statement that fails to declare the transaction as a DDL transaction. The bug is not in the recovery, but in an operation that happened during an earlier run.
[6 Aug 2013 12:35]
Marko Mäkelä
Theoretically, we could work around these problems by introducing a start-up option that disables the background rollback of recovered transactions, and synchronously rolls back all recovered transactions instead. That could mean a much longer start-up phase, during which no connections are accepted. In any case, the root cause (wrongly logged DDL statement inside InnoDB) needs to be identified and fixed.
[6 Aug 2013 14:40]
MySQL Verification Team
Shahriyar, We need both, the binary that produced a core file, plus the output of the command that is requested by our Marko Makela. Please, try to understand that this is a bug without a test case. Actually a test case would be incredibly hard or impossible to make. Hence, we require so much other info in order to get to the cause of this bug.
[7 Aug 2013 5:46]
Marko Mäkelä
Sinisa, actually we do not need the core file or the executable any more. The data files are more valuable in cases where the system consistently refuses to start up.
In this case, we need to know which DDL operation was executed improperly on the table.
I had another look at the data file. There are only a few tables in the clustered index of SYS_TABLES (page 8), all probably created on database setup. Here are the records dumped in collation order (sorted by table name). I got the record start offsets directly from the ibdata1 file:
(gdb) find_page_in_pool buf_pool_ptr 0 8
$8 = (buf_block_t *) 0x7ffff01ceaf0
(gdb) p $8.page
$9 = {space = 0, offset = 8, state = 5, flush_type = 0, io_fix = 0, buf_fix_count = 0, buf_pool_index = 0, zip = {data = 0x0, m_start = 0, m_external = false, m_end = 0, m_nonempty = 0, n_blobs = 0, ssize = 0}, hash = 0x0, in_page_hash = 1, in_zip_hash = 0, list = {prev = 0x0, next = 0x7ffff01cecd8}, in_flush_list = 0, in_free_list = 0, newest_modification = 0, oldest_modification = 0, LRU = {prev = 0x7ffff01cecd8, next = 0x7ffff01ce908}, in_LRU_list = 1, old = 0, freed_page_clock = 0, access_time = 1463664491, file_page_was_freed = 0}
(gdb) p $8.frame+0x16e
$10 = (unsigned char *) 0x7ffff050c16e "SYS_DATAFILES"
(gdb) call rec_print_old(stderr,$8.frame+0x16e)
PHYSICAL RECORD: n_fields 10; 1-byte offsets; info bits 0
0: len 13; hex 5359535f4441544146494c4553; asc SYS_DATAFILES;;
1: len 6; hex 000000000301; asc ;;
2: len 7; hex 81000001320194; asc 2 ;;
3: len 8; hex 000000000000000e; asc ;;
4: len 4; hex 00000002; asc ;;
5: len 4; hex 00000001; asc ;;
6: len 8; hex 0000000000000000; asc ;;
7: len 4; hex 00000000; asc ;;
8: SQL NULL, size 0 ;
9: len 4; hex 00000000; asc ;;
(gdb) call rec_print_old(stderr,$8.frame+0x8d)
PHYSICAL RECORD: n_fields 10; 1-byte offsets; info bits 0
0: len 11; hex 5359535f464f524549474e; asc SYS_FOREIGN;;
1: len 6; hex 000000000300; asc ;;
2: len 7; hex 800000012d0110; asc - ;;
3: len 8; hex 000000000000000b; asc ;;
4: len 4; hex 00000004; asc ;;
5: len 4; hex 00000001; asc ;;
6: len 8; hex 0000000000000000; asc ;;
7: len 4; hex 00000000; asc ;;
8: SQL NULL, size 0 ;
9: len 4; hex 00000000; asc ;;
(gdb) call rec_print_old(stderr,$8.frame+0xd5)
PHYSICAL RECORD: n_fields 10; 1-byte offsets; info bits 0
0: len 16; hex 5359535f464f524549474e5f434f4c53; asc SYS_FOREIGN_COLS;;
1: len 6; hex 000000000300; asc ;;
2: len 7; hex 800000012d0201; asc - ;;
3: len 8; hex 000000000000000c; asc ;;
4: len 4; hex 00000004; asc ;;
5: len 4; hex 00000001; asc ;;
6: len 8; hex 0000000000000000; asc ;;
7: len 4; hex 00000000; asc ;;
8: SQL NULL, size 0 ;
9: len 4; hex 00000000; asc ;;
(gdb) call rec_print_old(stderr,$8.frame+0x122)
PHYSICAL RECORD: n_fields 10; 1-byte offsets; info bits 0
0: len 15; hex 5359535f5441424c45535041434553; asc SYS_TABLESPACES;;
1: len 6; hex 000000000301; asc ;;
2: len 7; hex 81000001320110; asc 2 ;;
3: len 8; hex 000000000000000d; asc ;;
4: len 4; hex 00000003; asc ;;
5: len 4; hex 00000001; asc ;;
6: len 8; hex 0000000000000000; asc ;;
7: len 4; hex 00000000; asc ;;
8: SQL NULL, size 0 ;
9: len 4; hex 00000000; asc ;;
(gdb) call rec_print_old(stderr,$8.frame+0x20d)
PHYSICAL RECORD: n_fields 10; 1-byte offsets; info bits 0
0: len 24; hex 6d7973716c2f696e6e6f64625f696e6465785f7374617473; asc mysql/innodb_index_stats;;
1: len 6; hex 000000000303; asc ;;
2: len 7; hex 83000001360110; asc 6 ;;
3: len 8; hex 0000000000000010; asc ;;
4: len 4; hex 80000008; asc ;;
5: len 4; hex 00000001; asc ;;
6: len 8; hex 0000000000000000; asc ;;
7: len 4; hex 00000010; asc ;;
8: SQL NULL, size 0 ;
9: len 4; hex 00000002; asc ;;
(gdb) call rec_print_old(stderr,$8.frame+0x1b8)
PHYSICAL RECORD: n_fields 10; 1-byte offsets; info bits 0
0: len 24; hex 6d7973716c2f696e6e6f64625f7461626c655f7374617473; asc mysql/innodb_table_stats;;
1: len 6; hex 000000000302; asc ;;
2: len 7; hex 82000001350110; asc 5 ;;
3: len 8; hex 000000000000000f; asc ;;
4: len 4; hex 80000006; asc ;;
5: len 4; hex 00000001; asc ;;
6: len 8; hex 0000000000000000; asc ;;
7: len 4; hex 00000010; asc ;;
8: SQL NULL, size 0 ;
9: len 4; hex 00000001; asc ;;
(gdb) call rec_print_old(stderr,$8.frame+0x2b9)
PHYSICAL RECORD: n_fields 10; 1-byte offsets; info bits 0
0: len 23; hex 6d7973716c2f736c6176655f6d61737465725f696e666f; asc mysql/slave_master_info;;
1: len 6; hex 000000000305; asc ;;
2: len 7; hex 85000001380110; asc 8 ;;
3: len 8; hex 0000000000000012; asc ;;
4: len 4; hex 80000017; asc ;;
5: len 4; hex 00000001; asc ;;
6: len 8; hex 0000000000000000; asc ;;
7: len 4; hex 00000010; asc ;;
8: SQL NULL, size 0 ;
9: len 4; hex 00000004; asc ;;
(gdb) call rec_print_old(stderr,$8.frame+0x262)
PHYSICAL RECORD: n_fields 10; 1-byte offsets; info bits 0
0: len 26; hex 6d7973716c2f736c6176655f72656c61795f6c6f675f696e666f; asc mysql/slave_relay_log_info;;
1: len 6; hex 000000000304; asc ;;
2: len 7; hex 84000001370110; asc 7 ;;
3: len 8; hex 0000000000000011; asc ;;
4: len 4; hex 80000008; asc ;;
5: len 4; hex 00000001; asc ;;
6: len 8; hex 0000000000000000; asc ;;
7: len 4; hex 00000010; asc ;;
8: SQL NULL, size 0 ;
9: len 4; hex 00000003; asc ;;
(gdb) call rec_print_old(stderr,$8.frame+0x30d)
PHYSICAL RECORD: n_fields 10; 1-byte offsets; info bits 0
0: len 23; hex 6d7973716c2f736c6176655f776f726b65725f696e666f; asc mysql/slave_worker_info;;
1: len 6; hex 000000000d4d; asc M;;
2: len 7; hex 3e0000015a0110; asc > Z ;;
3: len 8; hex 0000000000000017; asc ;;
4: len 4; hex 8000000c; asc ;;
5: len 4; hex 00000001; asc ;;
6: len 8; hex 0000000000000000; asc ;;
7: len 4; hex 00000010; asc ;;
8: SQL NULL, size 0 ;
9: len 4; hex 00000009; asc ;;
The table_id that we are interested in is 0x17. It is field 3, right after NAME,DB_TRX_ID,DB_ROLL_PTR.
So, this would be the last table, mysql.slave_worker_info. Which CREATE, DROP or ALTER statements were executed on it?
I would like to know the complete history of this database instance. Which exact steps were performed to create the ibdata1 file (and other files)? Was the setup procedure interrupted?
[7 Aug 2013 7:16]
Shahriyar Rzayev
Dear Marko Mäkelä , first of all i must state again that, i think this crash occured because of mysqlreplicate utility that i used to setup replication. Tested in 2 different laptops and find same crash. I have already reported this as bug: http://bugs.mysql.com/bug.php?id=69914 Now here is output of what you want. [root@dhcppc2 mysql]# for i in */*.ibd; do echo -n $i:; od -j 34 -N 4 -Ax -t x1 $i; done mysql/innodb_index_stats.ibd:000022 00 00 00 02 000026 mysql/innodb_table_stats.ibd:000022 00 00 00 01 000026 mysql/slave_master_info.ibd:000022 00 00 00 04 000026 mysql/slave_relay_log_info.ibd:000022 00 00 00 03 000026 mysql/slave_worker_info.ibd:000022 00 00 00 09 000026 "So, this would be the last table, mysql.slave_worker_info. Which CREATE, DROP or ALTER statements were executed on it?" : Actually nothing special. Processed binary logs: [root@dhcppc2 data]# mysqlbinlog -vv --base64-output=DECODE-ROWS mysql-bin.[0-9]* > /home/shahriyar/Documents/binlog2.txt /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!40019 SET @@session.max_insert_delayed_threads=0*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; # at 4 #130801 12:15:40 server id 2 end_log_pos 120 CRC32 0xf0034d21 Start: binlog v 4, server v 5.6.12-log created 130801 12:15:40 at startup ROLLBACK/*!*/; # at 120 #130801 12:15:40 server id 2 end_log_pos 151 CRC32 0xd8f26fcb Previous-GTIDs # [empty] # at 151 #130801 12:29:23 server id 2 end_log_pos 174 CRC32 0xa26b4d81 Stop DELIMITER ; DELIMITER /*!*/; # at 4 #130801 12:29:32 server id 2 end_log_pos 120 CRC32 0x56b2d546 Start: binlog v 4, server v 5.6.12-log created 130801 12:29:32 at startup ROLLBACK/*!*/; # at 120 #130801 12:29:32 server id 2 end_log_pos 151 CRC32 0xb7d8f497 Previous-GTIDs # [empty] # at 151 #130801 13:02:54 server id 2 end_log_pos 174 CRC32 0xd47c8e9c Stop DELIMITER ; DELIMITER /*!*/; # at 4 #130801 13:03:01 server id 2 end_log_pos 120 CRC32 0x8f83e4c9 Start: binlog v 4, server v 5.6.12-log created 130801 13:03:01 at startup ROLLBACK/*!*/; # at 120 #130801 13:03:01 server id 2 end_log_pos 151 CRC32 0xfae7b227 Previous-GTIDs # [empty] # at 151 #130801 13:24:06 server id 2 end_log_pos 199 CRC32 0xab3d0555 GTID [commit=yes] SET @@SESSION.GTID_NEXT= '55d8d268-fa76-11e2-9ebf-080027894092:1'/*!*/; # at 199 #130801 13:24:06 server id 2 end_log_pos 361 CRC32 0xec03198e Query thread_id=2 exec_time=0 error_code=0 SET TIMESTAMP=1375345446/*!*/; SET @@session.pseudo_thread_id=2/*!*/; SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/; SET @@session.sql_mode=1073741824/*!*/; SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/; /*!\C utf8 *//*!*/; SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=8/*!*/; SET @@session.lc_time_names=0/*!*/; SET @@session.collation_database=DEFAULT/*!*/; CREATE USER 'remote'@'%' IDENTIFIED BY PASSWORD '*00A51F3F48415C7D4E8908980D443C29C69B60C9' /*!*/; # at 361 #130801 13:24:28 server id 2 end_log_pos 409 CRC32 0xb8ab5974 GTID [commit=yes] SET @@SESSION.GTID_NEXT= '55d8d268-fa76-11e2-9ebf-080027894092:2'/*!*/; # at 409 #130801 13:24:28 server id 2 end_log_pos 528 CRC32 0xde4a8414 Query thread_id=2 exec_time=0 error_code=0 SET TIMESTAMP=1375345468/*!*/; grant all on *.* to 'remote'@'%' /*!*/; # at 528 #130801 14:46:59 server id 2 end_log_pos 551 CRC32 0x6b4bd7b9 Stop DELIMITER ; DELIMITER /*!*/; # at 4 #130802 12:07:13 server id 2 end_log_pos 120 CRC32 0xf3a9460b Start: binlog v 4, server v 5.6.12-log created 130802 12:07:13 at startup ROLLBACK/*!*/; # at 120 #130802 12:07:14 server id 2 end_log_pos 191 CRC32 0x226e1a0c Previous-GTIDs # 55d8d268-fa76-11e2-9ebf-080027894092:1-2 # at 191 #130802 12:55:20 server id 2 end_log_pos 214 CRC32 0xdd80bc32 Stop DELIMITER ; DELIMITER /*!*/; # at 4 #130802 15:25:11 server id 2 end_log_pos 120 CRC32 0xd05f3efd Start: binlog v 4, server v 5.6.12-log created 130802 15:25:11 at startup ROLLBACK/*!*/; # at 120 #130802 15:25:11 server id 2 end_log_pos 191 CRC32 0x85b1ea3e Previous-GTIDs # 55d8d268-fa76-11e2-9ebf-080027894092:1-2 # at 191 #130802 15:33:54 server id 2 end_log_pos 214 CRC32 0x12c7e278 Stop DELIMITER ; DELIMITER /*!*/; # at 4 #130806 12:10:33 server id 2 end_log_pos 120 CRC32 0xf5815422 Start: binlog v 4, server v 5.6.12-log created 130806 12:10:33 at startup ROLLBACK/*!*/; # at 120 #130806 12:10:33 server id 2 end_log_pos 191 CRC32 0xb3fe059a Previous-GTIDs # 55d8d268-fa76-11e2-9ebf-080027894092:1-2 # at 191 #130806 12:12:22 server id 2 end_log_pos 214 CRC32 0x210f032e Stop DELIMITER ; # End of log file ROLLBACK /* added by mysqlbinlog */; /*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/; /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/; "I would like to know the complete history of this database instance. Which exact steps were performed to create the ibdata1 file (and other files)? Was the setup procedure interrupted?" The complete history is very simple. i have Centos 6.4 on my laptop. Setup Virtualbox on it with another Centos 6.4. Then installed 2 fresh MySQL 5.6.12. Both servers started normally After all tried with mysqlreplicate utility to setup replication after this crash occured. thats all. Here is configs from SLAVE's my.cnf: # BINARY LOGGING and Replication for Slave setup with GTID# server_id = 2 log_bin = /var/lib/mysql/data/mysql-bin log_bin_index = /var/lib/mysql/data/mysql-bin expire_logs_days = 14 sync_binlog = 1 binlog_format = row relay_log = /var/lib/mysql/data/mysql-relay-bin log_slave_updates = 1 read_only = 1 gtid-mode = on enforce-gtid-consistency = true master-info-repository = TABLE relay-log-info-repository = TABLE slave-parallel-workers = 2 binlog-checksum = CRC32 master-verify-checksum = 1 slave-sql-verify-checksum = 1 binlog-rows-query-log_events = 1 InnoDB related variables: # INNODB # innodb_flush_method = O_DIRECT innodb_log_files_in_group = 2 innodb_log_file_size = 32M innodb_flush_log_at_trx_commit = 1 innodb_file_per_table = 1 innodb_buffer_pool_size = 128M innodb_stats_on_metadata = 0 innodb_old_blocks_time = 1000
[7 Aug 2013 10:31]
Marko Mäkelä
A minor correction: The DB_ROLL_PTR field in the SYS_INDEXES record that is implicitly locked by DB_TRX_ID=0xd4d, is 0xbe0000015b020c. That is, the high-order bit is set, meaning that this was a fresh insert and not an update. In the SYS_TABLES record that is implicitly locked by DB_TRX_ID=0xd4d, we have DB_ROLL_PTR=0x3e0000015a0110, indicating an update of an already inserted record. (It could have been inserted earlier by the same transaction; I did not check the undo log records to review the history.) This could theoretically be an indication that the slave was killed while it was executing one of the following: CREATE TABLE slave_worker_info (...); or TRUNCATE TABLE slave_worker_info; Note that CREATE TABLE creates the *.frm file before invoking the storage engine. Because the *.frm file operations are not logged, the *.frm files can get out of sync with the InnoDB data dictionary on a crash. But, this bug clearly happens entirely inside InnoDB. Can we have the slave error log too? In Bug#69914 you only showed the tail of the error log. In Bug#69907, the error message tells you to look at the server error log, but you did not include it in the report. I have asked our replication experts to try to repeat the scenario.
[7 Aug 2013 10:47]
Shahriyar Rzayev
Sadly i removed the very first error log. But i have already paste at beginning of report, log from slave. I think you can repeat this scenario and find very first log before slave crashed on your own. As i stated in this report: http://bugs.mysql.com/bug.php?id=69914
[7 Aug 2013 13:57]
Marko Mäkelä
The failing crash recovery is just a sign of a failure that happened earlier, before the crash recovery was initiated. That is why I am interested in an earlier part of the slave log, or (even better) the exact steps to reproduce. We are trying to repeat the scenario (creating the database from the scratch), but have not succeeded so far. There are so many possibilities. It could require the exact kind of wrong parameters or killing the slave at the right point of time. Since you have succeeded in repeating the scenario on different systems, I hope you still remember the exact steps you used. With the broken data file, the most we can do is to write a work-around that would allow you to start up the server with the broken data files. When we can repeat the failure ourselves, we can also fix the root cause (and prevent this start-up hang from happening).
[7 Aug 2013 15:09]
MySQL Verification Team
Shahriyar, We do require lot's of additional information from you, which is a sole reason I change a status of this bug.
[7 Aug 2013 15:38]
Shahriyar Rzayev
Marko Mäkelä , i will erase all previous installation from my laptop. and will install mysqls from scratch for repeating this scenario. For attaching to this bug i will document all steps that i will do. Sinisa Milivojevic, as you see i am very interested in this bug fix and finding what is going on..thats why i am trying to provide you with all information on my hand :)
[7 Aug 2013 17:44]
MySQL Verification Team
Shahriyar, your efforts are very much appreciated !!!! This could be a very important bug that you have hit upon and fixing it is important for us.
[7 Aug 2013 19:28]
Shahriyar Rzayev
Dear experts. As i promise i test again in my another laptop. And document every step as separate files. master_server.txt --- here i stated all steps in master server slave_server.txt --- here i stated all steps in slave server replication_steps.txt --- here i stated all steps for replication setup. Beside from these files i also want to apload fresh error logs of both master and slave servers.
[7 Aug 2013 19:29]
Shahriyar Rzayev
MASTER server step-by-step
Attachment: master_server (application/octet-stream, text), 3.84 KiB.
[7 Aug 2013 19:30]
Shahriyar Rzayev
SLAVE server step-by-step
Attachment: slave_server (application/octet-stream, text), 2.17 KiB.
[7 Aug 2013 19:32]
Shahriyar Rzayev
replication step-by-step
Attachment: replication_steps (application/octet-stream, text), 10.69 KiB.
[7 Aug 2013 19:35]
Shahriyar Rzayev
MASTER error log file
Attachment: localhost.localdomain.err (application/octet-stream, text), 13.13 KiB.
[7 Aug 2013 19:39]
Shahriyar Rzayev
SLAVE error log file
Attachment: localhost.localdomain.err (application/octet-stream, text), 26.46 KiB.
[8 Aug 2013 5:36]
Marko Mäkelä
Thank you, the files look detailed enough. I do not have much experience in MySQL replication; I work on the InnoDB storage engine. The root cause of the bug seems to be this assertion failure on slave shutdown: 2013-08-08 07:39:24 4203 [Note] InnoDB: Starting shutdown... 2013-08-08 07:39:26 7fc23080e700 InnoDB: Assertion failure in thread 140472014137088 in file trx0rseg.cc line 125 InnoDB: Failing assertion: UT_LIST_GET_LEN(rseg->update_undo_list) == 0 Something is corrupting the undo logs. I am guessing that this corruption makes the crash recovery "see" transactions that were committed a long time ago. Maybe the DDL statement execution itself is not to blame.
[8 Aug 2013 6:38]
MySQL Verification Team
It is repeatable on 5.6.13. The 'change master' asserts my debug slave: InnoDB: Failing assertion: (trx)->start_file == 0 mysqld-debug.exe!my_sigabrt_handler()[my_thr_init.c:499] mysqld-debug.exe!raise()[winsig.c:586] mysqld-debug.exe!abort()[abort.c:74] mysqld-debug.exe!row_truncate_table_for_mysql()[row0mysql.cc:3233] mysqld-debug.exe!ha_innobase::truncate()[ha_innodb.cc:9836] mysqld-debug.exe!Rpl_info_table::do_reset_info()[rpl_info_table.cc:332 mysqld-debug.exe!Rpl_info_factory::reset_workers()[rpl_info_factory.cc mysqld-debug.exe!change_master()[rpl_slave.cc:8489] mysqld-debug.exe!mysql_execute_command()[sql_parse.cc:2770] mysqld-debug.exe!mysql_parse()[sql_parse.cc:6204] mysqld-debug.exe!dispatch_command()[sql_parse.cc:1332] mysqld-debug.exe!do_command()[sql_parse.cc:1036] mysqld-debug.exe!do_handle_one_connection()[sql_connect.cc:977] mysqld-debug.exe!handle_one_connection()[sql_connect.cc:893] mysqld-debug.exe!pfs_spawn_thread()[pfs.cc:1858] mysqld-debug.exe!pthread_start()[my_winthread.c:61] mysqld-debug.exe!_callthreadstartex()[threadex.c:314] mysqld-debug.exe!_threadstartex()[threadex.c:297] On release build, I get crash on shutdown: InnoDB: Failing assertion: UT_LIST_GET_LEN(rseg->update_undo_list) == 0 And on startup: InnoDB: Error: a record lock wait happens in a dictionary operation!
[8 Aug 2013 7:04]
MySQL Verification Team
-------------- How to repeat: -------------- Startup a single server: ---------------- mysqld-debug.exe --no-defaults --server_id=1 --log_bin --binlog_format=row --log_slave_updates=1 --read_only=1 --gtid-mode=on --enforce-gtid-consistency=true --master-info-repository=TABLE --relay-log-info-repository=TABLE --slave-parallel-workers=2 Run: ----- stop slave; set session autocommit=0; change master to master_host='127.0.0.1', master_port=3306, master_user='root', master_password='', MASTER_AUTO_POSITION=1; Restart server and repeat the above again.
[8 Aug 2013 7:52]
Shahriyar Rzayev
Dear experts, Thank you for verifing my effort. I have another report primarily related to this BUG. For test i decided to start MySQL with innodb_force_recovery=3 and got another issue/bug. Please give some more information how i can workaround and start my crashed server, even innodb_force_recovery=3 does not help. Please refer for more information: http://bugs.mysql.com/bug.php?id=69907
[8 Aug 2013 8:10]
Marko Mäkelä
Hi,
If you are able to compile MySQL from source code, you could try to start up with this patch:
=== modified file 'storage/innobase/log/log0recv.cc'
--- storage/innobase/log/log0recv.cc revid:marko.makela@oracle.com-20130807071906-5oxhiga7zjwpu9gy
+++ storage/innobase/log/log0recv.cc 2013-08-08 08:06:53 +0000
@@ -3436,7 +3436,7 @@ recv_recovery_from_checkpoint_finish(voi
The data dictionary latch should guarantee that there is at
most one data dictionary transaction active at a time. */
if (srv_force_recovery < SRV_FORCE_NO_TRX_UNDO) {
- trx_rollback_or_clean_recovered(FALSE);
+ trx_rollback_or_clean_recovered(TRUE);
}
}
It would roll back all recovered transactions in the master thread. Normally, only data dictionary transactions are rolled back in the master thread, and everything else is rolled back in a background thread.
I was working on something else, did not repeat the failure yet. It is fully possible that the undo logs are badly corrupted and the above patch will not help.
[8 Aug 2013 12:22]
Marko Mäkelä
I wrote a mtr test: cat > mysql-test/suite/innodb/t/innodb_bug69898-master.opt << EOF --server_id=1 --log_bin --binlog_format=row --log_slave_updates=1 --read_only=1 --gtid-mode=on --enforce-gtid-consistency=true --master-info-repository=TABLE --relay-log-info-repository=TABLE --slave-parallel-workers=2 EOF cat > mysql-test/suite/innodb/t/innodb_bug69898.test << EOF -- source include/have_innodb.inc stop slave; set session autocommit=0; change master to master_host='127.0.0.1', master_port=3306, master_user='root', master_password='', MASTER_AUTO_POSITION=1; -- source include/restart_mysqld.inc stop slave; set session autocommit=0; change master to master_host='127.0.0.1', master_port=3306, master_user='root', master_password='', MASTER_AUTO_POSITION=1; EOF This would crash the server on line 11 (the CHANGE MASTER after the slave restart), with a different assertion in a debug build: #0 ut_dbg_assertion_failed (expr=0x10e5378 "(trx)->start_file == 0", file=0x10e3ee8 "mysql-5.6/storage/innobase/row/row0mysql.cc", line=3233) at mysql-5.6/storage/innobase/ut/ut0dbg.cc:48 #1 0x0000000000ce1699 in row_truncate_table_for_mysql (table=0x1b44b48, trx=0x1b6b028) at mysql-5.6/storage/innobase/row/row0mysql.cc:3233 #2 0x0000000000bea4e2 in ha_innobase::truncate (this=0x1b56d80) at mysql-5.6/storage/innobase/handler/ha_innodb.cc:9860 #3 0x0000000000abb73f in Rpl_info_table::do_reset_info (nparam=12, param_schema=0xfbb298 "mysql", param_table=0xfbb2da "slave_worker_info") at mysql-5.6/sql/rpl_info_table.cc:332 #4 0x0000000000ab045f in Rpl_info_factory::reset_workers (rli=0x1b46440) at mysql-5.6/sql/rpl_info_factory.cc:336 #5 0x0000000000aa3dce in change_master (thd=0x1b77280, mi=0x1af1d40) at mysql-5.6/sql/rpl_slave.cc:8542 #6 0x000000000080b6a9 in mysql_execute_command (thd=0x1b77280) at mysql-5.6/sql/sql_parse.cc:2770 #7 0x00000000008149af in mysql_parse (thd=0x1b77280, rawbuf=0x1b66930 "change master to master_host='127.0.0.1', master_port=3306, master_user='root', master_password='', MASTER_AUTO_POSITION=1", length=122, parser_state=0x7fffeeb7ffd0) at mysql-5.6/sql/sql_parse.cc:6204 The problem appears to be that the internal TRUNCATE TABLE is trying to reuse a non-DDL trx_t object, in the trx_start_for_ddl() call. According to debug information, the transaction was started in row0upd.cc:2641, or at the start of row_upd_step(): #0 row_upd_step (thr=0x1b66270) at mysql-5.6/storage/innobase/row/row0upd.cc:2634 #1 0x0000000000cdef67 in row_update_for_mysql (mysql_rec=0x1b64e68 "\a", prebuilt=0x1b65678) at mysql-5.6/storage/innobase/row/row0mysql.cc:1724 #2 0x0000000000be5005 in ha_innobase::update_row (this=0x1b63310, old_row=0x1b64e68 "\a", new_row=0x1b64e30 "\a") at mysql-5.6/storage/innobase/handler/ha_innodb.cc:7033 #3 0x0000000000675f6d in handler::ha_update_row (this=0x1b63310, old_data=0x1b64e68 "\a", new_data=0x1b64e30 "\a") at mysql-5.6/sql/handler.cc:7232 #4 0x0000000000abb11e in Rpl_info_table::do_flush_info (this=0x1af4910, force=true) at mysql-5.6/sql/rpl_info_table.cc:207 #5 0x0000000000aa74fa in Rpl_info_handler::flush_info (this=0x1af4910, force=true) at mysql-5.6/sql/rpl_info_handler.h:92 #6 0x0000000000aadb23 in Relay_log_info::flush_info (this=0x1b47cb0, force=true) at mysql-5.6/sql/rpl_rli.cc:2025 #7 0x0000000000aa3d0b in change_master (thd=0x7fffe40631b0, mi=0x1af1ce0) at mysql-5.6/sql/rpl_slave.cc:8530 #8 0x000000000080b6a9 in mysql_execute_command (thd=0x7fffe40631b0) at mysql-5.6/sql/sql_parse.cc:2770 #9 0x00000000008149af in mysql_parse (thd=0x7fffe40631b0, rawbuf=0x1b78470 "change master to master_host='127.0.0.1', master_port=3306, master_user='root', master_password='', MASTER_AUTO_POSITION=1", length=122, parser_state=0x7fffeeb7ffd0) at mysql-5.6/sql/sql_parse.cc:6204 This looks like a misuse of the InnoDB storage engine API by replication. DML and DDL transactions must not be mixed.
[8 Aug 2013 12:33]
Marko Mäkelä
MySQL has usually followed the convention that starting any DDL operation (such as TRUNCATE) will commit any pending DML transaction. This could be fixed by either adding an explicit commit call at the start of ha_innobase::truncate() [which I find somewhat ugly] or by adding the commit call to change_master() or its callees, before ha_innobase::truncate() is invoked. But, I do not think that it is nice to split one logical operation to multiple transactions. It would no longer be atomic in case of a server kill. Even cleaner would be to use the same code as DELETE FROM t; -- without WHERE clause In InnoDB, this will scan the table and write undo log, so that the operation can be rolled back if the operation is interrupted, for example by a server kill (or assertion failure). TRUNCATE inside InnoDB is a DDL operation that cannot be rolled back. It could make sense to use TRUNCATE instead of DELETE on a huge table, but not on a small table, like the replication metadata is likely to be.
[19 Sep 2013 14:02]
Jon Stephens
Fixed in 5.6+. Documented in the MySQL 5.6.14 and 5.7.2 changelogs, as follows:
The server attempted to perform an internal truncatation of the
slave_worker_info table while resetting it, even though this is
a DDL operation and should not be used conccurrently with DML
operations. To prevent this from happening, the reset now
performs sequential row deletion in place of the truncation
operation.
Closed.
[1 Jul 2014 6:14]
Max Gao
still hit this bug @ 5.6.19 after i upgrade my slave db from 5.6.10 downgrade back to 5.6.10 and every thing works fine. please some one check it ? 140701 14:08:13 mysqld_safe Starting mysqld daemon with databases from /home/mysql 2014-07-01 14:08:14 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details). 2014-07-01 14:08:14 11224 [Warning] Buffered warning: Using unique option prefix max_connection instead of max_connections is deprecated and will be removed in a future release. Please use the full name instead. 2014-07-01 14:08:14 11224 [Note] Plugin 'FEDERATED' is disabled. 2014-07-01 14:08:14 11224 [Note] InnoDB: Using atomics to ref count buffer pool pages 2014-07-01 14:08:14 11224 [Note] InnoDB: The InnoDB memory heap is disabled 2014-07-01 14:08:14 11224 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2014-07-01 14:08:14 11224 [Note] InnoDB: Compressed tables use zlib 1.2.3 2014-07-01 14:08:14 11224 [Note] InnoDB: Using Linux native AIO 2014-07-01 14:08:14 11224 [Note] InnoDB: Not using CPU crc32 instructions 2014-07-01 14:08:14 11224 [Note] InnoDB: Initializing buffer pool, size = 4.0G 2014-07-01 14:08:15 11224 [Note] InnoDB: Completed initialization of buffer pool 2014-07-01 14:08:15 11224 [Note] InnoDB: Highest supported file format is Barracuda. 2014-07-01 14:08:15 7fd24b04c720 InnoDB: Error: a record lock wait happens in a dictionary operation! InnoDB: index "CLUST_IND" of table "SYS_TABLES". InnoDB: Submit a detailed bug report to http://bugs.mysql.com 2014-07-01 14:08:15 7fd24b04c720 InnoDB: Assertion failure in thread 140541178464032 in file lock0wait.cc line 297 InnoDB: We intentionally generate a memory trap. InnoDB: Submit a detailed bug report to http://bugs.mysql.com. InnoDB: If you get repeated assertion failures or crashes, even InnoDB: immediately after the mysqld startup, there may be InnoDB: corruption in the InnoDB tablespace. Please refer to InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html InnoDB: about forcing recovery. 06:08:15 UTC - mysqld got signal 6 ; 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=4294967296 read_buffer_size=4194304 max_used_connections=0 max_threads=512 thread_count=0 connection_count=0 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 7347048 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. Thread pointer: 0x0 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 = 0 thread_stack 0x40000 /usr/sbin/mysqld(my_print_stacktrace+0x35)[0x8d68f5] /usr/sbin/mysqld(handle_fatal_signal+0x4a4)[0x663224] /lib64/libpthread.so.0(+0xf710)[0x7fd24ac2e710] /lib64/libc.so.6(gsignal+0x35)[0x7fd249ada925] /lib64/libc.so.6(abort+0x175)[0x7fd249adc105] /usr/sbin/mysqld[0x927725] /usr/sbin/mysqld[0x95c934] /usr/sbin/mysqld[0x95cdf5] /usr/sbin/mysqld[0x983af8] /usr/sbin/mysqld[0xa5a04d] /usr/sbin/mysqld[0x92e10f] /usr/sbin/mysqld[0x9ac3b1] /usr/sbin/mysqld[0x8f318d] /usr/sbin/mysqld(_Z24ha_initialize_handlertonP13st_plugin_int+0x48)[0x5a7ac8] /usr/sbin/mysqld[0x6ea751] /usr/sbin/mysqld(_Z11plugin_initPiPPci+0xb76)[0x6ee636] /usr/sbin/mysqld[0x59a7b8] /usr/sbin/mysqld(_Z11mysqld_mainiPPc+0x455)[0x59f845] /lib64/libc.so.6(__libc_start_main+0xfd)[0x7fd249ac6d1d] /usr/sbin/mysqld[0x591ac9] 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. 140701 14:08:15 mysqld_safe mysqld from pid file /home/mysql/localhost.localdomain.pid ended
[1 Jul 2014 14:09]
MySQL Verification Team
Hello Max, Your report looks very interesting. I must admit that your report looks very similar to the original problem. Can you try to repeat the bug just as described with the original reporter ??? Can you use mysqlreplicate as described ??? We would also need you to try this with both 5.6.10 and 5.6.19. Last, but not least, it would be nice to repeat this bug with debug binaries of 5.6.10 and 5.6.19. We must have these results in order to ascertain that it is about the same bug. Many thanks in advance !!!!
[2 Jul 2014 6:17]
Marko Mäkelä
Hi Max, The stack trace that you posted did not contain function names for InnoDB functions, so we do not know which operation triggered the assertion failure. Would it be possible to rerun with core dumps enabled, and to obtain a stack trace? With gdb, it should be something like this: gdb /path/to/mysqld core (gdb) bt (gdb) quit
[17 Jul 2014 17:54]
Sveta Smirnova
See also bug #73155
