table import does not restart after mysql crash during import

[Aurimas Mikalauskas]

My table import has just crashed:

https://bugs.launchpad.net/percona-server/+bug/1000221

Now I'm looking for a way to resume the import, but can't find it. I can read a part of the table that was being imported, but I get the following errors:

120516 4:55:36 InnoDB: Error: space id and page n:o stored in the page
InnoDB: read in are 192:6615722, should be 34:6615722!
120516 4:55:36 InnoDB: Error: page 6615722 log sequence number 2516079028454
InnoDB: is in the future! Current system log sequence number 5488820.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.5/en/forcing-innodb-recovery.html
InnoDB: for more information.

And it would crash if I dive too deep:

InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.5/en/forcing-innodb-recovery.html
InnoDB: for more information.
120516 4:53:21 InnoDB: Assertion failure in thread 140219101259520 in file btr0sea.c line 1549
InnoDB: Failing assertion: index->id == btr_page_get_index_id(page)
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.5/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.

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 = 7f874db89e58 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x35)[0x7a43a5]
/usr/sbin/mysqld(handle_fatal_signal+0x4a4)[0x67fdc4]
/lib64/libpthread.so.0(+0xf4a0)[0x7f874d8144a0]
/lib64/libc.so.6(gsignal+0x35)[0x7f874c9df885]
/lib64/libc.so.6(abort+0x175)[0x7f874c9e1065]
/usr/sbin/mysqld[0x87671e]
/usr/sbin/mysqld[0x876efe]
/usr/sbin/mysqld[0x86c6d3]
/usr/sbin/mysqld[0x86fd8d]
/usr/sbin/mysqld[0x8702ac]
/usr/sbin/mysqld[0x82124f]
/usr/sbin/mysqld[0x7f5458]
/usr/sbin/mysqld[0x7f28c9]
/usr/sbin/mysqld(_Z13opt_sum_queryP3THDP10TABLE_LISTR4ListI4ItemEPS4_+0x957)[0x744ae7]
/usr/sbin/mysqld(_ZN4JOIN8optimizeEv+0xad0)[0x5bc4f0]
/usr/sbin/mysqld(_Z12mysql_selectP3THDPPP4ItemP10TABLE_LISTjR4ListIS1_ES2_jP8st_orderSB_S2_SB_yP13select_resultP18st_select_lex_unitP13st_select_lex+0xd1)[0x5bfb91]
/usr/sbin/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0x1cd)[0x5c58bd]
/usr/sbin/mysqld[0x5834c2]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x1216)[0x586df6]
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x333)[0x58a6f3]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x15b2)[0x58bd52]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0xd7)[0x623ec7]
/usr/sbin/mysqld(handle_one_connection+0x51)[0x624001]
/lib64/libpthread.so.0(+0x77f1)[0x7f874d80c7f1]
/lib64/libc.so.6(clone+0x6d)[0x7f874ca92ccd]

[Aurimas Mikalauskas (aurimas-mikalauskas)]

Full backtrace of a crash when running SELECT MIN(id), MAX(id) FROM non-fully-imported-table;

#0 0x00007ffff6d9b885 in raise () from /lib64/libc.so.6
#1 0x00007ffff6d9d065 in abort () from /lib64/libc.so.6
#2 0x000000000087671e in btr_search_build_page_hash_index (index=0x7fe59c01f9e8, block=0x7fe65c771b00, n_fields=1, n_bytes=0, left_side=1)
    at /usr/src/debug/Percona-Server-5.5.21-rel25.1/Percona-Server-5.5.21-rel25.1/storage/innobase/btr/btr0sea.c:1549
#3 0x0000000000876efe in btr_search_info_update_slow (info=<value optimized out>, cursor=<value optimized out>)
    at /usr/src/debug/Percona-Server-5.5.21-rel25.1/Percona-Server-5.5.21-rel25.1/storage/innobase/btr/btr0sea.c:695
#4 0x000000000086c6d3 in btr_search_info_update (index=0x7fe59c01f9e8, level=0, tuple=0x7fe59c01c4e8, mode=3, latch_mode=35, cursor=0x7fe59c017188, has_search_latch=0,
    file=0xa54fb0 "/home/jenkins/workspace/percona-server-5.5-rpms/label_exp/centos6-64/target/BUILD/Percona-Server-5.5.21-rel25.1/Percona-Server-5.5.21-rel25.1/storage/innobase/btr/btr0pcur.c", line=490, mtr=0x7ffff7e4ba50) at /usr/src/debug/Percona-Server-5.5.21-rel25.1/Percona-Server-5.5.21-rel25.1/storage/innobase/include/btr0sea.ic:83
#5 btr_cur_search_to_nth_level (index=0x7fe59c01f9e8, level=0, tuple=0x7fe59c01c4e8, mode=3, latch_mode=35, cursor=0x7fe59c017188, has_search_latch=0,
    file=0xa54fb0 "/home/jenkins/workspace/percona-server-5.5-rpms/label_exp/centos6-64/target/BUILD/Percona-Server-5.5.21-rel25.1/Percona-Server-5.5.21-rel25.1/storage/innobase/btr/btr0pcur.c", line=490, mtr=0x7ffff7e4ba50) at /usr/src/debug/Percona-Server-5.5.21-rel25.1/Percona-Server-5.5.21-rel25.1/storage/innobase/btr/btr0cur.c:836
#6 0x000000000086fd8d in btr_pcur_open_with_no_init_func (cursor=0x7fe59c017188, mtr=0x7ffff7e4ba50)
    at /usr/src/debug/Percona-Server-5.5.21-rel25.1/Percona-Server-5.5.21-rel25.1/storage/innobase/include/btr0pcur.ic:482
#7 btr_pcur_restore_position_func (cursor=0x7fe59c017188, mtr=0x7ffff7e4ba50)
    at /usr/src/debug/Percona-Server-5.5.21-rel25.1/Percona-Server-5.5.21-rel25.1/storage/innobase/btr/btr0pcur.c:343
#8 btr_pcur_move_backward_from_page (cursor=0x7fe59c017188, mtr=0x7ffff7e4ba50)
    at /usr/src/debug/Percona-Server-5.5.21-rel25.1/Percona-Server-5.5.21-rel25.1/storage/innobase/btr/btr0pcur.c:490
#9 0x00000000008702ac in btr_pcur_move_to_prev (cursor=0x7fe59c017188, mtr=<value optimized out>)
    at /usr/src/debug/Percona-Server-5.5.21-rel25.1/Percona-Server-5.5.21-rel25.1/storage/innobase/btr/btr0pcur.c:546
#10 0x000000000082124f in row_search_for_mysql (buf=0x7fe59c010f50 "", mode=3, prebuilt=<value optimized out>, match_mode=0, direction=<value optimized out>)
    at /usr/src/debug/Percona-Server-5.5.21-rel25.1/Percona-Server-5.5.21-rel25.1/storage/innobase/row/row0sel.c:4707
#11 0x00000000007f5458 in ha_innobase::index_read (this=0x7fe59c00f320, buf=0x7fe59c010f50 "", key_ptr=0x0, key_len=0, find_flag=<value optimized out>)
    at /usr/src/debug/Percona-Server-5.5.21-rel25.1/Percona-Server-5.5.21-rel25.1/storage/innobase/handler/ha_innodb.cc:6518
#12 0x00000000007f28c9 in ha_innobase::index_last (this=0x7fe59c00f320, buf=0x7fe59c010f50 "")
    at /usr/s...

[Raghavendra D Prabhu (raghavendra-prabhu)]

index->id == btr_page_get_index_id(page) implies that the page for whom the adaptive hash index is to be re/built has a different index id than the index supplied.

Now, from the linked bug lp:1000221 it looks like this behavior is due to FIL_PAGE_TYPE corruption:

"it crashed on an extent descriptor page because it assumed it to be an index page and tried to iterate records on it."

So, it crashed there because the page is not an index page at all. In other words, looks like the import is corrupt.

Only way to fix this is to start mysqld with AHI disabled, drop the table and re-import it. Also, the data dictionary looks corrupted with incorrect space_id recorded in it.

[Alexey Kopytov (akopytov)]

I wonder if the server was restarted with innodb_import_table_from_xtrabackup=1. From the symptoms, it looks like it was disabled. In which case it's clear why the import was not restarted.

[Aurimas Mikalauskas (aurimas-mikalauskas)]

I am 100% sure the server was not started with innodb_import_table_from_xtrabackup=1 I only ever set it dynamically and never over my.cnf. Any chance for autodetection ? What are caveats running server with innodb_import_table_from_xtrabackup always enabled?

[Alexey Kopytov (akopytov)]

I've looked at the code, it appears that if innodb_import_table_from_xtrabackup is enabled in my.cnf, InnoDB will scan _all_ tablespaces on startup, even those that have no corresponding .exp file. Which is of course unacceptable in production. So yes, we have a problem here.

Since in case of a crash on table import, restarting the server with improved import disabled is impossible, I think we should fix this by making it possible to start the server with innodb_import_table_from_xtrabackup enabled. That is, only scan tablespaces for which an .exp file exists, and remove it on successful import?

[Aurimas Mikalauskas (aurimas-mikalauskas)]

sounds good to me

[Laurynas Biveinis (laurynas-biveinis)]

XtraBackup test xb_export.sh now has a workaround for this bug:

# Tablespace import is asynchronous, so shutdown the server to have
# consistent backup results. Otherwise we risk ending up with no test.ibd
# in the backup in case importing has not finished before taking backup

shutdown_server
start_server $mysql_extra_args

Once this bug is fixed, it should be removed.

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-2756