[MDEV-27272] Crash on EXPORT/IMPORT tablespace with column added in the middle Created: 2021-12-15  Updated: 2022-04-26  Resolved: 2022-01-18

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.6.5, 10.4, 10.5, 10.6, 10.7
Fix Version/s: 10.4.23, 10.5.14, 10.6.6, 10.7.2

Type: Bug Priority: Critical
Reporter: Hartmut Holzgraefe Assignee: Eugene Kosov (Inactive)
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-18543 IMPORT TABLESPACE fails after instant... Closed
relates to MDEV-25066 IMPORT TABLESPACE not possible if sou... Closed

 Description   

When adding a column in the middle of a table, then adding another column in the middle of the table using ADD COLUMN ... AFTER, in INSTANT mode; and then accidentally trying to export the tablespace and import into a table with the original schema without the extra column, the server crashes, and then can't recover properly from the situation it got stuck in on next restart.

How to reproduce:

Run 

DROP TABLE IF EXISTS t1;
 
CREATE TABLE t1 (
 
  id INT NOT NULL,
 
  i1 INT,
 
  i2 INT,
 
  PRIMARY KEY (id)
 
) ENGINE=INNODB;
 
 
 
DROP TABLE IF EXISTS t2;
 
CREATE TABLE t2 (
 
  id INT NOT NULL,
 
  i1 INT,
 
  i2 INT,
 
  PRIMARY KEY (id)
 
) ENGINE=INNODB;
 
 
 
ALTER TABLE test.t1 add COLUMN i3 INT AFTER i1;
 
 
 
ALTER TABLE t2 DISCARD TABLESPACE;
 
FLUSH TABLES t1 FOR EXPORT;

to create tables and prepare for import. Then copy tablespace and config file, using a different terminal:

cd /var/lib/mysql/test
cp -vp t1.ibd t2.ibd
cp -vp t1.cfg t2.cfg

and finish the import in the same mysql client session as above

UNLOCK TABLES;
 
ALTER TABLE t2 IMPORT TABLESPACE;

This should abort with a column count mismatch error, but instead crashes the server when not specifying the algorithm, and so using INPLACE by default. When doing the same with ALGORITHM=COPY it does not crash and reports the almost correct 

ALTER TABLE t2 IMPORT TABLESPACE, ALGORITHM=COPY;
 
ERROR 1808 (HY000): Schema mismatch (Number of columns don't match, table has 6 columns but the tablespace meta-data file has 7 columns)

(separate bug report will be filed for the wrong column counts in that error message)

Backtrace (note: this is a standalone setup, Galera not loaded/enabled)

Dec 15 13:04:56 ubuntu-focal mariadbd[769]: ??:0(my_print_stacktrace)[0x55791c17a442]
 
Dec 15 13:04:56 ubuntu-focal mariadbd[769]: ??:0(handle_fatal_signal)[0x55791bc2d6a5]
 
Dec 15 13:04:56 ubuntu-focal mariadbd[769]: ??:0(__restore_rt)[0x7f28deaad3c0]
 
Dec 15 13:04:56 ubuntu-focal mariadbd[769]: ??:0(std::thread::thread<void (&)(), , void>(void (&)()))[0x55791c09c723]
 
Dec 15 13:04:56 ubuntu-focal mariadbd[769]: ??:0(Wsrep_server_service::log_dummy_write_set(wsrep::client_state&, wsrep::ws_meta const&))[0x55791b8b72b4]
 
Dec 15 13:04:56 ubuntu-focal mariadbd[769]: ??:0(Wsrep_server_service::log_dummy_write_set(wsrep::client_state&, wsrep::ws_meta const&))[0x55791b8b8127]
 
Dec 15 13:04:56 ubuntu-focal mariadbd[769]: ??:0(wsrep_notify_status(wsrep::server_state::state, wsrep::view const*))[0x55791bf1cc2d]
 
Dec 15 13:04:56 ubuntu-focal mariadbd[769]: ??:0(mysql_discard_or_import_tablespace(THD*, TABLE_LIST*, bool))[0x55791ba9e06b]
 
Dec 15 13:04:56 ubuntu-focal mariadbd[769]: ??:0(Sql_cmd_discard_import_tablespace::execute(THD*))[0x55791bb148d4]
 
Dec 15 13:04:56 ubuntu-focal mariadbd[769]: ??:0(mysql_execute_command(THD*, bool))[0x55791ba01e66]
 
Dec 15 13:04:56 ubuntu-focal mariadbd[769]: ??:0(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x55791b9f1b97]
 
Dec 15 13:04:56 ubuntu-focal mariadbd[769]: ??:0(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x55791b9fdde5]
 
Dec 15 13:04:56 ubuntu-focal mariadbd[769]: ??:0(do_command(THD*, bool))[0x55791b9fffe8]
 
Dec 15 13:04:56 ubuntu-focal mariadbd[769]: ??:0(do_handle_one_connection(CONNECT*, bool))[0x55791bb10147]
 
Dec 15 13:04:56 ubuntu-focal mariadbd[769]: ??:0(handle_one_connection)[0x55791bb1049d]
 
Dec 15 13:04:56 ubuntu-focal mariadbd[769]: ??:0(MyCTX_nopad::finish(unsigned char*, unsigned int*))[0x55791be6f9cd]
 
Dec 15 13:04:56 ubuntu-focal mariadbd[769]: ??:0(start_thread)[0x7f28deaa1609]
 
Dec 15 13:04:56 ubuntu-focal mariadbd[769]: ??:0(clone)[0x7f28de68f293]

And this the recovery failure on next restart

Dec 15 13:05:04 ubuntu-focal mariadbd[2459]: 2021-12-15 13:05:04 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=42335,42335
 
Dec 15 13:05:04 ubuntu-focal mariadbd[2459]: 2021-12-15 13:05:04 0 [ERROR] InnoDB: Attempted to open a previously opened tablespace. Previous tablespace: ./test/t1.ibd uses space ID: 5. Cannot open filepath: ./test/t2.ibd which uses the same space ID.
 
Dec 15 13:05:04 ubuntu-focal mariadbd[2459]: 2021-12-15 13:05:04 0 [Warning] InnoDB: We do not continue the crash recovery, because the table may become corrupt if we cannot apply the log records in the InnoDB log to it. To fix the problem and start mysqld:
 
Dec 15 13:05:04 ubuntu-focal mariadbd[2459]: 2021-12-15 13:05:04 0 [Note] InnoDB: 1) If there is a permission problem in the file and mysqld cannot open the file, you should modify the permissions.
 
Dec 15 13:05:04 ubuntu-focal mariadbd[2459]: 2021-12-15 13:05:04 0 [Note] InnoDB: 2) If the tablespace is not needed, or you can restore an older version from a backup, then you can remove the .ibd file, and use --innodb_force_recovery=1 to force startup without this file.
 
Dec 15 13:05:04 ubuntu-focal mariadbd[2459]: 2021-12-15 13:05:04 0 [Note] InnoDB: 3) If the file system or the disk is broken, and you cannot remove the .ibd file, you can set --innodb_force_recovery.
 
Dec 15 13:05:04 ubuntu-focal mariadbd[2459]: 2021-12-15 13:05:04 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
 
Dec 15 13:05:04 ubuntu-focal mariadbd[2459]: 2021-12-15 13:05:04 0 [Note] InnoDB: Starting shutdown...



 Comments   
Comment by Alice Sherepa [ 2021-12-15 ] 

--source include/have_innodb.inc
 
 
 
CREATE TABLE t1 ( id INT NOT NULL, i1 INT, i2 INT, PRIMARY KEY (id)) engine=innodb;
 
CREATE TABLE t2 ( id INT NOT NULL, i1 INT, i2 INT, PRIMARY KEY (id)) engine=innodb;
 
 
ALTER TABLE test.t1 add COLUMN i3 INT AFTER i1;
 
 
ALTER TABLE t2 DISCARD TABLESPACE;
 
FLUSH TABLES t1 FOR EXPORT;
 
 
 
--let $datadir = `SELECT @@datadir`
 
--copy_file $datadir/test/t1.ibd $datadir/test/t2.ibd
 
--copy_file $datadir/test/t1.cfg $datadir/test/t2.cfg
 
 
 
UNLOCK TABLES;
 
--error 1808
 
ALTER TABLE t2 IMPORT TABLESPACE;

10.4 74b3d4252a291456982c8e6

 
10.4/src/storage/innobase/dict/dict0mem.cc:1247: void dict_index_t::reconstruct_fields(): Assertion `old < &fields[n_fields]' failed.
 
211215 15:29:05 [ERROR] mysqld got signal 6 ;
 
 
 
Server version: 10.4.23-MariaDB-debug-log
 
 
 
dict/dict0mem.cc:1248(dict_index_t::reconstruct_fields())[0x555eae493a06]
 
dict/dict0mem.cc:1327(dict_table_t::deserialise_columns(unsigned char const*, unsigned long))[0x555eae49127c]
 
row/row0import.cc:3412(handle_instant_metadata(dict_table_t*, row_import const&))[0x555eae081469]
 
row/row0import.cc:4446(row_import_for_mysql(dict_table_t*, row_prebuilt_t*))[0x555eae0896d5]
 
handler/ha_innodb.cc:13098(ha_innobase::discard_or_import_tablespace(char))[0x555eadda1060]
 
sql/handler.cc:4612(handler::ha_discard_or_import_tablespace(char))[0x555ead3564c1]
 
sql/sql_table.cc:6085(mysql_discard_or_import_tablespace(THD*, TABLE_LIST*, bool))[0x555eacdf30cd]
 
sql/sql_alter.cc:558(Sql_cmd_discard_import_tablespace::execute(THD*))[0x555eacf957a3]
 
sql/sql_parse.cc:6192(mysql_execute_command(THD*))[0x555eacba3315]
 
sql/sql_parse.cc:7995(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x555eacbaee51]
 
sql/sql_parse.cc:1860(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x555eacb855d8]
 
sql/sql_parse.cc:1373(do_command(THD*))[0x555eacb82055]
 
sql/sql_connect.cc:1420(do_handle_one_connection(CONNECT*))[0x555eacf7c979]
 
sql/sql_connect.cc:1317(handle_one_connection)[0x555eacf7c0d2]
 
perfschema/pfs.cc:1871(pfs_spawn_thread)[0x555eadc7ae45]
 
nptl/pthread_create.c:478(start_thread)[0x7fd6cf285609]
 
/lib/x86_64-linux-gnu/libc.so.6(clone+0x43)[0x7fd6cee58293]
 
 
 
Query (0x62b0000a1290): ALTER TABLE t2 IMPORT TABLESPACE

Comment by Marko Mäkelä [ 2022-01-03 ]

I can repeat SIGSEGV of a RelWithDebInfo build with the test that alice supplied. This means that the fix of MDEV-18543 was insufficient. In dict_index_t::reconstruct_fields(), the contents of f looks like garbage, and we are crashing when dereferencing the garbage pointer f.col.

Comment by Matthias Leich [ 2022-01-17 ] 

Same assert hit on 10.8 development tree
 
origin/bb-10.8-MDEV-14425 7f75466f539b61d3dc8696e72a2d715c59aa04d6 2022-01-14T19:52:40+02:00  + some patch
 
Workflow:
 
1. Have the server under load, one session only
 
2. Kill server
 
3. Try restart
 
[rr 1802081 6957]mysqld: /data/Server/bb-10.8-MDEV-14425_patched/storage/innobase/dict/dict0mem.cc:1236: void dict_index_t::reconstruct_fields(): Assertion `old < &fields[n_fields]' failed.
 
(rr) bt
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#1  0x00007f56363cb859 in __GI_abort () at abort.c:79
 
#2  0x00007f56363cb729 in __assert_fail_base (fmt=0x7f5636561588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x557f84781c40 "old < &fields[n_fields]", file=0x557f84780700 "/data/Server/bb-10.8-MDEV-14425_patched/storage/innobase/dict/dict0mem.cc", 
    line=1236, function=<optimized out>) at assert.c:92
 
#3  0x00007f56363dcf36 in __GI___assert_fail (assertion=0x557f84781c40 "old < &fields[n_fields]", file=0x557f84780700 "/data/Server/bb-10.8-MDEV-14425_patched/storage/innobase/dict/dict0mem.cc", line=1236, 
    function=0x557f84781b20 "void dict_index_t::reconstruct_fields()") at assert.c:101
 
#4  0x0000557f8368583f in dict_index_t::reconstruct_fields (this=0x616000457308) at /data/Server/bb-10.8-MDEV-14425_patched/storage/innobase/dict/dict0mem.cc:1236
 
#5  0x0000557f836830c4 in dict_table_t::deserialise_columns (this=0x618000002d08, metadata=0x7f5628ed003c "", len=14) at /data/Server/bb-10.8-MDEV-14425_patched/storage/innobase/dict/dict0mem.cc:1315
 
#6  0x0000557f8354cde0 in btr_cur_instant_init_low (index=0x616000457308, mtr=0x7ffdb42e2b20) at /data/Server/bb-10.8-MDEV-14425_patched/storage/innobase/btr/btr0cur.cc:575
 
#7  0x0000557f8354db92 in btr_cur_instant_init (table=0x618000002d08) at /data/Server/bb-10.8-MDEV-14425_patched/storage/innobase/btr/btr0cur.cc:656
 
#8  0x0000557f8367213a in dict_load_table_one (name=..., ignore_err=DICT_ERR_IGNORE_RECOVER_LOCK, fk_tables=std::deque with 0 elements) at /data/Server/bb-10.8-MDEV-14425_patched/storage/innobase/dict/dict0load.cc:2387
 
#9  0x0000557f83672e6a in dict_sys_t::load_table (this=0x557f8568b780 <dict_sys>, name=..., ignore=DICT_ERR_IGNORE_RECOVER_LOCK) at /data/Server/bb-10.8-MDEV-14425_patched/storage/innobase/dict/dict0load.cc:2461
 
#10 0x0000557f83673767 in dict_load_table_on_id (table_id=32, ignore_err=DICT_ERR_IGNORE_RECOVER_LOCK) at /data/Server/bb-10.8-MDEV-14425_patched/storage/innobase/dict/dict0load.cc:2549
 
#11 0x0000557f83639a43 in dict_table_open_on_id (table_id=32, dict_locked=false, table_op=DICT_TABLE_OP_LOAD_TABLESPACE, thd=0x0, mdl=0x0) at /data/Server/bb-10.8-MDEV-14425_patched/storage/innobase/dict/dict0dict.cc:851
 
#12 0x0000557f834c8cd1 in trx_resurrect_table_locks (trx=0x7f562a4c69a8, undo=0x611000005540) at /data/Server/bb-10.8-MDEV-14425_patched/storage/innobase/trx/trx0trx.cc:602
 
#13 0x0000557f834c9c40 in trx_resurrect (undo=0x611000005540, rseg=0x557f855f0340 <trx_sys+17664>, start_time=1642430266, start_time_micro=10775493579, rows_to_undo=0x7ffdb42e54a0) at /data/Server/bb-10.8-MDEV-14425_patched/storage/innobase/trx/trx0trx.cc:685
 
#14 0x0000557f834ca397 in trx_lists_init_at_db_start () at /data/Server/bb-10.8-MDEV-14425_patched/storage/innobase/trx/trx0trx.cc:735
 
#15 0x0000557f8345ce9c in srv_start (create_new_db=false) at /data/Server/bb-10.8-MDEV-14425_patched/storage/innobase/srv/srv0start.cc:1229
 
#16 0x0000557f82fe31a2 in innodb_init (p=0x615000003298) at /data/Server/bb-10.8-MDEV-14425_patched/storage/innobase/handler/ha_innodb.cc:4155
 
#17 0x0000557f82757af3 in ha_initialize_handlerton (plugin=0x621000037268) at /data/Server/bb-10.8-MDEV-14425_patched/sql/handler.cc:649
 
#18 0x0000557f81fb8a43 in plugin_initialize (tmp_root=0x7ffdb42e88a0, plugin=0x621000037268, argc=0x557f859d9960 <remaining_argc>, argv=0x6160000003f8, options_only=false) at /data/Server/bb-10.8-MDEV-14425_patched/sql/sql_plugin.cc:1462
 
#19 0x0000557f81fba7a8 in plugin_init (argc=0x557f859d9960 <remaining_argc>, argv=0x6160000003f8, flags=0) at /data/Server/bb-10.8-MDEV-14425_patched/sql/sql_plugin.cc:1755
 
#20 0x0000557f81bfeacc in init_server_components () at /data/Server/bb-10.8-MDEV-14425_patched/sql/mysqld.cc:5082
 
#21 0x0000557f81c00645 in mysqld_main (argc=55, argv=0x6160000003f8) at /data/Server/bb-10.8-MDEV-14425_patched/sql/mysqld.cc:5698
 
#22 0x0000557f81beef0d in main (argc=54, argv=0x7ffdb42eb0c8) at /data/Server/bb-10.8-MDEV-14425_patched/sql/main.cc:34
 
pluto:/data/results/1642429632/TBR-1323/dev/shm/rqg/1642429632/188/1/rr
 
(rr)

Comment by Marko Mäkelä [ 2022-01-18 ]

The suggested fix looks good to me, but I think that it needs to be tested. The stack trace that mleich posted so far is for a 10.8 based branch that is lacking this fix.

Comment by Matthias Leich [ 2022-01-18 ] 

The tree
 
origin/bb-10.4-MDEV-27272-import-instant-add 01065155508905503cc85e7c954de83e3017e0ab 2022-01-17T19:32:28+03:00
 
performed well in RQG testing. Bad effects observed are known and occur on main trees too.

Generated at Thu Feb 08 09:51:40 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.