Bug #69573 Regression in 5.6.12 debug builds with multiple files in innodb_data_file_path
Submitted: 25 Jun 2013 13:03 Modified: 11 Jul 2013 5:52
Reporter: Alexey Kopytov Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S2 (Serious)
Version:5.5.32, 5.6.12 OS:Any
Assigned to: CPU Architecture:Any

[25 Jun 2013 13:03] Alexey Kopytov
Description:
Debug 5.6.12 builds crash on startup when the shared tablespace uses
multiple data files. This appears to be a regression from the following
change:

" InnoDB: After a clean shutdown, InnoDB does not check .ibd file
headers at startup. As a result, in a crash recovery scenario, InnoDB
could load a corrupted tablespace file. This fix implements consistency
and status checks to avoid loading corrupted files. (Bug #16720368) "

There's the following 5.6-specific code in buf_page_is_corrupted():

	/* declare empty pages non-corrupted */
	if (checksum_field1 == 0 && checksum_field2 == 0
	    && mach_read_from_4(read_buf + FIL_PAGE_LSN) == 0) {
		/* make sure that the page is really empty */
		ut_d(for (ulint i = 0; i < UNIV_PAGE_SIZE; i++) {
		     ut_a(read_buf[i] == 0); });

		return(FALSE);
	}

which asserts empty pages are really empty. However, if the server
creates and initializes multiple ibdata files, first pages of data files
after the first one (i.e. normally ibdata2, etc.) will be filled with
zeroes except the FIL_PAGE_FILE_FLUSH_LSN field which is stored to each
node of the shared tablespace on shutdown bypassing the buffer pool in
fil_write_flushed_lsn_to_data_files(). 

Which means the above check will fail on the next startup for non-first
data files of the shared tablespace.

Backtrace:

(gdb) bt
#0  0x00007fff98104212 in __pthread_kill ()
#1  0x00007fff8d2e2b54 in pthread_kill ()
#2  0x00007fff8d326dce in abort ()
#3  0x0000000100639c58 in buf_page_is_corrupted (check_lsn=false, read_buf=0x126000000 "", zip_size=0) at /Users/kaa/src/launchpad/mysql-5.6/storage/innobase/buf/buf0buf.cc:551
#4  0x00000001006b739e in fil_check_first_page (page=0x126000000 "", first_page=0) at /Users/kaa/src/launchpad/mysql-5.6/storage/innobase/fil/fil0fil.cc:1993
#5  0x00000001006b6f29 in fil_read_first_page (data_file=3, one_read_already=1, flags=0x7fff5fbfb0a8, space_id=0x7fff5fbfb0a0, min_flushed_lsn=0x7fff5fbfeeb8, max_flushed_lsn=0x7fff5fbfeeb0) at /Users/kaa/src/launchpad/mysql-5.6/storage/innobase/fil/fil0fil.cc:2051
#6  0x00000001008a3f81 in open_or_create_data_files (create_new_db=0x7fff5fbfeec0, min_flushed_lsn=0x7fff5fbfeeb8, max_flushed_lsn=0x7fff5fbfeeb0, sum_of_new_sizes=0x7fff5fbfeea8) at /Users/kaa/src/launchpad/mysql-5.6/storage/innobase/srv/srv0start.cc:965
#7  0x00000001008a1b51 in innobase_start_or_create_for_mysql () at /Users/kaa/src/launchpad/mysql-5.6/storage/innobase/srv/srv0start.cc:1963
#8  0x000000010071f1ea in innobase_init (p=0x101c10660) at /Users/kaa/src/launchpad/mysql-5.6/storage/innobase/handler/ha_innodb.cc:3229
#9  0x0000000100095ea3 in ha_initialize_handlerton (plugin=0x10210da08) at /Users/kaa/src/launchpad/mysql-5.6/sql/handler.cc:659
#10 0x0000000100386e7d in plugin_initialize (plugin=0x10210da08) at /Users/kaa/src/launchpad/mysql-5.6/sql/sql_plugin.cc:1126
#11 0x0000000100386222 in plugin_init (argc=0x1011e78dc, argv=0x101c0a4e8, flags=0) at /Users/kaa/src/launchpad/mysql-5.6/sql/sql_plugin.cc:1417
#12 0x00000001004b19e1 in init_server_components () at /Users/kaa/src/launchpad/mysql-5.6/sql/mysqld.cc:4738
#13 0x00000001004afe51 in mysqld_main (argc=5, argv=0x101c0a4e8) at /Users/kaa/src/launchpad/mysql-5.6/sql/mysqld.cc:5319
#14 0x0000000100001a22 in main (argc=3, argv=0x7fff5fbffa50) at /Users/kaa/src/launchpad/mysql-5.6/sql/main.cc:25

How to repeat:
1. Create a server configuration with multiple datafiles in innodb_data_file_path.
2. Start a debug server binary.
[25 Jun 2013 13:21] Umesh Shastry
Hello Alexey,

Thank you for the report.
Verified as described.

//

(gdb) bt
#0  0x0000003281c329a5 in raise () from /lib64/libc.so.6
#1  0x0000003281c34185 in abort () from /lib64/libc.so.6
#2  0x0000000000cdd492 in buf_page_is_corrupted (check_lsn=false, read_buf=0x1d08000 "", zip_size=0)
    at /home/ushastry/mybuilds/mysql-5.6.12-release/storage/innobase/buf/buf0buf.cc:551
#3  0x0000000000d43c30 in fil_check_first_page (page=0x1d08000 "", first_page=0) at /home/ushastry/mybuilds/mysql-5.6.12-release/storage/innobase/fil/fil0fil.cc:1992
#4  0x0000000000d43d6c in fil_read_first_page (data_file=9, one_read_already=1, flags=0x7fffffff9998, space_id=0x7fffffff9990, min_flushed_lsn=0x7fffffffd5f0, 
    max_flushed_lsn=0x7fffffffd5e8) at /home/ushastry/mybuilds/mysql-5.6.12-release/storage/innobase/fil/fil0fil.cc:2051
#5  0x0000000000c62b33 in open_or_create_data_files (create_new_db=0x7fffffffd5f8, min_flushed_lsn=0x7fffffffd5f0, max_flushed_lsn=0x7fffffffd5e8, 
    sum_of_new_sizes=0x7fffffffd5e0) at /home/ushastry/mybuilds/mysql-5.6.12-release/storage/innobase/srv/srv0start.cc:970
#6  0x0000000000c644b7 in innobase_start_or_create_for_mysql () at /home/ushastry/mybuilds/mysql-5.6.12-release/storage/innobase/srv/srv0start.cc:1968
#7  0x0000000000b1f5cf in innobase_init (p=0x192d8b0) at /home/ushastry/mybuilds/mysql-5.6.12-release/storage/innobase/handler/ha_innodb.cc:3235
#8  0x00000000006356fc in ha_initialize_handlerton (plugin=0x1921958) at /home/ushastry/mybuilds/mysql-5.6.12-release/sql/handler.cc:659
#9  0x00000000007e5be4 in plugin_initialize (plugin=0x1921958) at /home/ushastry/mybuilds/mysql-5.6.12-release/sql/sql_plugin.cc:1126
#10 0x00000000007e6638 in plugin_init (argc=0x17cf4c8, argv=0x1824c08, flags=0) at /home/ushastry/mybuilds/mysql-5.6.12-release/sql/sql_plugin.cc:1417
#11 0x00000000006213a9 in init_server_components () at /home/ushastry/mybuilds/mysql-5.6.12-release/sql/mysqld.cc:4738
#12 0x0000000000622253 in mysqld_main (argc=23, argv=0x1824c08) at /home/ushastry/mybuilds/mysql-5.6.12-release/sql/mysqld.cc:5319
#13 0x0000000000617984 in main (argc=4, argv=0x7fffffffdfc8) at /home/ushastry/mybuilds/mysql-5.6.12-release/sql/main.cc:25

Thanks,
Umesh
[1 Jul 2013 18:01] Valeriy Kravchuk
As same Bug #16720368 was fixed in 5.5.32 also, can we, please, get 5.5.32 added to versions affected or at least verify if the same problem happens with 5.5.32?

I have reasons to think that 5.5.32 is affected in the same way, and not only debug builds...
[1 Jul 2013 18:16] Shane Bester
also: http://bugs.mysql.com/bug.php?id=69623
[11 Jul 2013 5:52] Erlend Dahl
Fixed as a duplicate of bug#69623 in 5.5.33, 5.6.13, 5.7.2.