percona server crash on table import

[Aurimas Mikalauskas]

I'm importing gigabytes of InnoDB tables, 4 tables in parallel. Most tables import fine, but mysql crashed on some larger ones.

Percona Server (GPL), Release rel25.1, Revision 234

Here's the error:

InnoDB: Import: The extended import of db/table is being started.
InnoDB: Import: 10 indexes have been detected.
InnoDB: Progress in %: 35 82 36 78 37 38 83 39 40 84 41 42 85 43 44120515 11:11:13 InnoDB: Assertion failure in thread 140111167784704 in file rem0rec.c line 561

you see weird numbers here because multiple table imports are running at the same time. Backtrace:

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 = 7f6e2c627e58 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x35)[0x7a43a5]
/usr/sbin/mysqld(handle_fatal_signal+0x4a4)[0x67fdc4]
/lib64/libpthread.so.0(+0xf4a0)[0x7f6e2c2f34a0]
/lib64/libc.so.6(gsignal+0x35)[0x7f6e2b4be885]
/lib64/libc.so.6(abort+0x175)[0x7f6e2b4c0065]
/usr/sbin/mysqld[0x914960]
/usr/sbin/mysqld[0x8bb21a]
/usr/sbin/mysqld[0x819722]
/usr/sbin/mysqld[0x7fab57]
/usr/sbin/mysqld(_Z17mysql_alter_tableP3THDPcS1_P24st_ha_create_informationP10TABLE_LISTP10Alter_infojP8st_orderb+0x265)[0x5e8125]
/usr/sbin/mysqld(_ZN21Alter_table_statement7executeEP3THD+0x44f)[0x786a3f]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x12f0)[0x586ed0]
/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)[0x7f6e2c2eb7f1]
/lib64/libc.so.6(clone+0x6d)[0x7f6e2b571ccd]

Some background information. Before importing these tables, they were in Percona Server 5.0, xtrabackup was taken, backup was then prepared, then I've started mysql on it, ran mysql_upgrade and the table in question was upgraded, only then it was prepared for import and imported. This is true for all tables.

[Aurimas Mikalauskas (aurimas-mikalauskas)]

Apparently it is crashing with just one table import as well. Here's the backtrace:

Program received signal SIGABRT, Aborted.
[Switching to Thread 0x7fe5a7f16700 (LWP 2780)]
0x000000318e232885 in raise () from /lib64/libc.so.6
Missing separate debuginfos, use: debuginfo-install glibc-2.12-1.47.el6_2.9.x86_64 libaio-0.3.107-10.el6.x86_64 libgcc-4.4.6-3.el6.x86_64 nss-softokn-freebl-3.12.9-11.el6.x86_64
(gdb)
(gdb)
(gdb)
(gdb) bt
#0 0x000000318e232885 in raise () from /lib64/libc.so.6
#1 0x000000318e234065 in abort () from /lib64/libc.so.6
#2 0x0000000000915a80 in rec_get_offsets_func (rec=0x7fe5982bb157 "cket.com/albums/aa252/phiednate/scan0003.gif", index=0x7fe598087138, offsets=0x7fe5a7f11d40,
    n_fields=<value optimized out>, heap=0x7fe5a7f122b0, file=<value optimized out>, line=3576)
    at /usr/src/debug/Percona-Server-5.5.22-rel25.2/Percona-Server-5.5.22-rel25.2/storage/innobase/rem/rem0rec.c:561
#3 0x00000000008bc20e in fil_open_single_table_tablespace (check_space_id=<value optimized out>, id=40, flags=0, name=0x7fe598033b70 "art159/img_out159", trx=0x7fe5982b0fd8)
    at /usr/src/debug/Percona-Server-5.5.22-rel25.2/Percona-Server-5.5.22-rel25.2/storage/innobase/fil/fil0fil.c:3575
#4 0x00000000008193b2 in row_import_tablespace_for_mysql (name=0x7fe598033b70 "art159/img_out159", trx=0x7fe5982b0fd8)
    at /usr/src/debug/Percona-Server-5.5.22-rel25.2/Percona-Server-5.5.22-rel25.2/storage/innobase/row/row0mysql.c:2786
#5 0x00000000007fa667 in ha_innobase::discard_or_import_tablespace (this=0x7fe5982aa0d0, discard=0 '\000')
    at /usr/src/debug/Percona-Server-5.5.22-rel25.2/Percona-Server-5.5.22-rel25.2/storage/innobase/handler/ha_innodb.cc:8094
#6 0x00000000005e7cf5 in mysql_discard_or_import_tablespace (thd=0xab486010, new_db=0x7fe598004c30 "art159", new_name=0x0, create_info=0x7fe5a7f14610, table_list=0x7fe598004c80,
    alter_info=0x7fe5a7f146f0, order_num=0, order=0x0, ignore=false) at /usr/src/debug/Percona-Server-5.5.22-rel25.2/Percona-Server-5.5.22-rel25.2/sql/sql_table.cc:4754
#7 mysql_alter_table (thd=0xab486010, new_db=0x7fe598004c30 "art159", new_name=0x0, create_info=0x7fe5a7f14610, table_list=0x7fe598004c80, alter_info=0x7fe5a7f146f0, order_num=0,
    order=0x0, ignore=false) at /usr/src/debug/Percona-Server-5.5.22-rel25.2/Percona-Server-5.5.22-rel25.2/sql/sql_table.cc:5945
#8 0x000000000078657f in Alter_table_statement::execute (this=<value optimized out>, thd=0xab486010)
    at /usr/src/debug/Percona-Server-5.5.22-rel25.2/Percona-Server-5.5.22-rel25.2/sql/sql_alter.cc:106
#9 0x0000000000586b00 in mysql_execute_command (thd=0xab486010) at /usr/src/debug/Percona-Server-5.5.22-rel25.2/Percona-Server-5.5.22-rel25.2/sql/sql_parse.cc:4575
#10 0x000000000058a323 in mysql_parse (thd=0xab486010, rawbuf=<value optimized out>, length=2873654232, parser_state=0x7fe5a7f15bb0)
    at /usr/src/debug/Percona-Server-5.5.22-rel25.2/Percona-Server-5.5.22-rel25.2/sql/sql_parse.cc:5804
#11 0x000000000058b982 in dispatch_command (command=COM_QUERY, thd=0xab486010, packet=0x7fe598004b60 "ALTER TABLE art159.img_out159 IMPORT TABLESPACE", packet_length=2817612952)
    at /usr/src/debug/Percona-Server-5.5.22-rel25.2/Percona-Server-...

[Aurimas Mikalauskas (aurimas-mikalauskas)]

Some corrections on versions now that it's clear exactly which backup made it crash:

- Original database was running on 5.1.57-rel12.8-log Percona Server (GPL), 12.8, Revision 233
- xtrabackup-1.6.5 was used to take the backup
- xtrabackup-2.0.0 was used to prepare the backup
- mysql_upgrade was run on 5.5.21-55-log Percona Server (GPL), Release rel25.1, Revision 234

[Alexey Kopytov (akopytov)]

The reason is that the tablespace has been created with MySQL 5.0 where InnoDB did not set the FIL_PAGE_TYPE field appropriately, so that field may contain garbage for non-index pages. However, expanded import relies on that field to detect and update index pages. In this specific case, it crashed on an extent descriptor page because it assumed it to be an index page and tried to iterate records on it.

[Alexey Kopytov (akopytov)]

See also bug #727704. In fact, this bug is a result of the incomplete fix for that bug.

[Shahriyar Rzayev (rzayev-sehriyar)]

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