MySQL Bugs: #69980: InnoDB: Assertion failure in thread 140163462780672 in file btr0btr.cc

Bug #69980	InnoDB: Assertion failure in thread 140163462780672 in file btr0btr.cc
Submitted:	10 Aug 2013 12:57	Modified:	12 Aug 2013 2:11
Reporter:	Shahriyar Rzayev	Email Updates:
Status:	Not a Bug	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S1 (Critical)
Version:	5.6.12	OS:	Linux (Centos 6.4)
Assigned to:		CPU Architecture:	Any

Description:
Dear experts, i encountered interesting issue.
Here is my scenario:
Fresh installed MySQL 5.6.12 on Centos 6.4 with innodb_file_per_table=1.
Created new database,table and inserted something:

mysql> create database test;
mysql> create table test_it(id int not null);
mysql> insert into test_it() values(1),(2),(3),(4),(5);

Records: 5  Duplicates: 0  Warnings: 0

After this i copied test_it.ibd file to another location:

[root@localhost test]# cp test_it.ibd /home/sh

After coping:

mysql> alter table test_it add index(id);
mysql> insert into test_it() values(6),(7),(8),(9),(10);

And now i will remove test_it.ibd from datadir without shutting down:

[root@localhost test]# rm test_it.ibd
rm: remove regular file `test_it.ibd'? y

Surprisingly MySQL did not detect it. Returns as usual:

mysql> select * from test_it;
+----+
| id |
+----+
|  1 |
|  2 |
|  3 |
|  4 |
|  5 |
|  6 |
|  7 |
|  8 |
|  9 |
| 10 |
+----+

After restart it detects and throws error:

mysql> select * from test_it;
ERROR 1146 (42S02): Table 'test.test_it' doesn't exist

And now i copy back previously copied test_it.ibd file. 

[root@localhost sh]# cp test_it.ibd /var/lib/mysql/test
[root@localhost test]# ls
db.opt  test_it.frm  test_it.ibd

After this i restarted MySQL 3 times. 
Want to select and suddenly found that after each select, MySQL is auto-restarted!!!

mysql> select * from test_it;
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/var/lib/mysql/mysql.sock' (2)
ERROR: 
Can't connect to the server

Looking in error log:

20:56:56 UTC - mysqld got signal 11 ;

Thread pointer: 0x251ae00
stack_bottom = 7fde6043fe48 thread_stack 0x40000
.
.
.

This messages occured 3 times after my selects. When i want to drop table it throws another error and restarted again:

2013-08-10 17:03:49 7f9f48231700  InnoDB: Assertion failure in thread 140322086786816 in file btr0btr.cc line 693
InnoDB: Failing assertion: mach_read_from_4(seg_header + FSEG_HDR_SPACE) == space
21:03:49 UTC - mysqld got signal 6 ;

Thread pointer: 0x3872970
stack_bottom = 7f9f48230e48 thread_stack 0x40000
2013-08-10 17:03:49 13717 [Note] InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 50 51 52 53 54 ... 99 
InnoDB: Apply batch completed

When i want to alter table it again throws something new and also restarted:

mysql> alter table test_it drop index id;
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/var/lib/mysql/mysql.sock' (111)

From error log:

InnoDB: flag mismatch in space 6 page 4 index id of table test/test_it
2013-08-10 17:06:40 7f7a5968d700 InnoDB: Page dump in ascii and hex (16384 bytes):
 len 16384; hex 0000000000000000000000000000000000000000000000000000; asc
InnoDB: End of page dump
2013-08-10 17:06:40 7f7a5968d700  InnoDB: Assertion failure in thread 140163462780672 in file btr0btr.cc line 722
.
.
.

It throws different errors with select, drop and alter statements. 
I will attach full error log file.

How to repeat:
simply repeat my scenario

Suggested fix:
no suggest

Full error log FILE

Attachment: localhost.localdomain.err (application/octet-stream, text), 166.74 KiB.

Thank you for the bug report. Please read gthe Manual about table definition are handled even with innodb_file_per_table=1. Thanks.

http://dev.mysql.com/doc/refman/5.5/en/innodb-multiple-tablespaces.html

Did you really read error log which i attached?
i have already read this link...and there is nothing related to my report:
http://dev.mysql.com/doc/refman/5.5/en/innodb-multiple-tablespaces.html 

Part of error log says that maybe i hit a bug...and i think that something wrong here:

2013-08-10 17:03:49 7f9f48231700  InnoDB: Assertion failure in thread 140322086786816 in file btr0btr.cc line 693
InnoDB: Failing assertion: mach_read_from_4(seg_header + FSEG_HDR_SPACE) == space
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.
21:03:49 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=1
max_threads=10000
thread_count=1
connection_count=1
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 3983660 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x3872970
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 = 7f9f48230e48 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x35)[0x8c70d5]
/usr/sbin/mysqld(handle_fatal_signal+0x4a4)[0x65cbe4]
/lib64/libpthread.so.0[0x3d2440f500]
/lib64/libc.so.6(gsignal+0x35)[0x3d23c328a5]
/lib64/libc.so.6(abort+0x175)[0x3d23c34085]
/usr/sbin/mysqld[0x9c5c31]
/usr/sbin/mysqld[0x9c631f]
/usr/sbin/mysqld[0xa036ce]
/usr/sbin/mysqld[0x98a2c0]
/usr/sbin/mysqld[0x98b701]
/usr/sbin/mysqld[0x94bd18]
/usr/sbin/mysqld[0x94c225]
/usr/sbin/mysqld[0x9726b8]
/usr/sbin/mysqld[0x8ed21b]
/usr/sbin/mysqld(_Z15ha_delete_tableP3THDP10handlertonPKcS4_S4_b+0xbe)[0x5a76de]
/usr/sbin/mysqld(_Z23mysql_rm_table_no_locksP3THDP10TABLE_LISTbbbb+0xd12)[0x723f12]
/usr/sbin/mysqld(_Z14mysql_rm_tableP3THDP10TABLE_LISTcc+0x16d)[0x724e9d]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x22ae)[0x6d7b4e]
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x32f)[0x6da5ff]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0xe0c)[0x6db4fc]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0xcf)[0x6a90ff]
/usr/sbin/mysqld(handle_one_connection+0x47)[0x6a9227]
/lib64/libpthread.so.0[0x3d24407851]
/lib64/libc.so.6(clone+0x6d)[0x3d23ce890d]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f9f10004be0): is an invalid pointer
Connection ID (thread ID): 1
Status: NOT_KILLED

You cannot freely move .ibd files between database directories as you can with MyISAM table files. The table definition stored in the InnoDB shared tablespace includes the database name. The transaction IDs and log sequence numbers stored in the tablespace files also differ between databases.

The above include not moving the files in databases but the tablespace keeps information of the table definition..so creating an index and then back the ibd file without it causes errors.

I know that i must not and cant safely move .ibd over databases and can not restore freely just copying back...instead of i can use xtrabackup partial restore and etc. But i know another thing that is something InnoDB internal problem for handling such kind of things as i never see such errors in log.

Can you explain what hapenning here??:

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.
130810 17:03:49 mysqld_safe Number of processes running now: 0
130810 17:03:49 mysqld_safe mysqld restarted
2013-08-10 17:03:49 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2013-08-10 17:03:49 13717 [Note] Plugin 'FEDERATED' is disabled.
2013-08-10 17:03:49 13717 [Note] InnoDB: The InnoDB memory heap is disabled
2013-08-10 17:03:49 13717 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2013-08-10 17:03:49 13717 [Note] InnoDB: Compressed tables use zlib 1.2.3
2013-08-10 17:03:49 13717 [Note] InnoDB: Using Linux native AIO
2013-08-10 17:03:49 13717 [Note] InnoDB: Using CPU crc32 instructions
2013-08-10 17:03:49 13717 [Note] InnoDB: Initializing buffer pool, size = 256.0M
2013-08-10 17:03:49 13717 [Note] InnoDB: Completed initialization of buffer pool
2013-08-10 17:03:49 13717 [Note] InnoDB: Highest supported file format is Barracuda.
2013-08-10 17:03:49 13717 [Note] InnoDB: Log scan progressed past the checkpoint lsn 1670985
2013-08-10 17:03:49 13717 [Note] InnoDB: Database was not shutdown normally!
2013-08-10 17:03:49 13717 [Note] InnoDB: Starting crash recovery.
2013-08-10 17:03:49 13717 [Note] InnoDB: Reading tablespace information from the .ibd files...
2013-08-10 17:03:49 13717 [Note] InnoDB: Restoring possible half-written data pages 
2013-08-10 17:03:49 13717 [Note] InnoDB: from the doublewrite buffer...
InnoDB: Doing recovery: scanned up to log sequence number 1673811
2013-08-10 17:03:49 13717 [Note] InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 
InnoDB: Apply batch completed
InnoDB: Last MySQL binlog file position 0 1272, file name mysql-bin.000001
2013-08-10 17:03:50 13717 [Note] InnoDB: 128 rollback segment(s) are active.
2013-08-10 17:03:50 13717 [Note] InnoDB: Waiting for purge to start
2013-08-10 17:03:50 13717 [Note] InnoDB: 5.6.12 started; log sequence number 1673811
2013-08-10 17:03:50 13717 [Note] Recovering after a crash using /var/lib/mysql/data/mysql-bin
2013-08-10 17:03:50 13717 [Note] Starting crash recovery...
2013-08-10 17:03:50 13717 [Note] Crash recovery finished.
2013-08-10 17:03:50 13717 [Note] Server hostname (bind-address): '*'; port: 3306
2013-08-10 17:03:50 13717 [Note] IPv6 is available.
2013-08-10 17:03:50 13717 [Note]   - '::' resolves to '::';
2013-08-10 17:03:50 13717 [Note] Server socket created on IP: '::'.
2013-08-10 17:03:50 13717 [Warning] 'proxies_priv' entry '@ root@localhost.localdomain' ignored in --skip-name-resolve mode.
2013-08-10 17:03:50 13717 [Note] Event Scheduler: Loaded 0 events
2013-08-10 17:03:50 13717 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.6.12-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server (GPL)
InnoDB: flag mismatch in space 6 page 4 index id of table test/test_it
2013-08-10 17:05:16 7f932bfff700 InnoDB: Page dump in ascii and hex (16384 bytes):
 len 16384; hex 00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000; asc;
InnoDB: End of page dump
2013-08-10 17:05:16 7f932bfff700 InnoDB: uncompressed page, stored checksum in field1 0, calculated checksums for field1: crc32 536728786, innodb 1575996416, none 3735928559, stored checksum in field2 0, calculated checksums for field2: crc32 536728786, innodb 1371122432, none 3735928559, page LSN 0 0, low 4 bytes of LSN at page end 0, page number (if stored to page already) 0, space id (if created with >= MySQL-4.1.1 and stored already) 0
InnoDB: Page may be a freshly allocated page
2013-08-10 17:05:16 7f932bfff700  InnoDB: Assertion failure in thread 140270075115264 in file btr0btr.cc line 722
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.
21:05:16 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=1
max_threads=10000
thread_count=1
connection_count=1
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 3983660 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x31c1e50
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 = 7f932bffee48 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x35)[0x8c70d5]
/usr/sbin/mysqld(handle_fatal_signal+0x4a4)[0x65cbe4]
/lib64/libpthread.so.0[0x3d2440f500]
/lib64/libc.so.6(gsignal+0x35)[0x3d23c328a5]
/lib64/libc.so.6(abort+0x175)[0x3d23c34085]
/usr/sbin/mysqld[0x9c65b2]
/usr/sbin/mysqld[0x9c6899]
/usr/sbin/mysqld[0xa22406]
/usr/sbin/mysqld[0xa247fa]
/usr/sbin/mysqld[0xa248e5]
/usr/sbin/mysqld[0x8ef839]
/usr/sbin/mysqld(_ZN7handler7ha_openEP5TABLEPKcii+0x3e)[0x5a31be]
/usr/sbin/mysqld(_Z21open_table_from_shareP3THDP11TABLE_SHAREPKcjjjP5TABLEb+0x624)[0x75f764]
/usr/sbin/mysqld(_Z10open_tableP3THDP10TABLE_LISTP18Open_table_context+0x1eb)[0x692c4b]
/usr/sbin/mysqld(_Z11open_tablesP3THDPP10TABLE_LISTPjjP19Prelocking_strategy+0xcaa)[0x69541a]
/usr/sbin/mysqld(_Z30open_normal_and_derived_tablesP3THDP10TABLE_LISTj+0x4f)[0x69553f]
/usr/sbin/mysqld(_Z18mysqld_list_fieldsP3THDP10TABLE_LISTPKc+0x25)[0x70ca55]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1baf)[0x6dc29f]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0xcf)[0x6a90ff]
/usr/sbin/mysqld(handle_one_connection+0x47)[0x6a9227]
/lib64/libpthread.so.0[0x3d24407851]
/lib64/libc.so.6(clone+0x6d)[0x3d23ce890d]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f9320004c10): is an invalid pointer
Connection ID (thread ID): 1
Status: NOT_KILLED

There is no bug here.  Firstly, "Surprisingly MySQL did not detect it. Returns as usual:"  <--- because file descriptor is still open. this is expected.

Secondly, you're replacing an ibd with a different structure to the .frm file..
Please, use only supported method to change/move files.