[MDEV-21419] Server crash upon startup after restoring from backup: InnoDB: Trying to load index `FTS_INDEX_TABLE_IND`, but the index tree has been freed Created: 2020-01-03  Updated: 2020-07-23  Resolved: 2020-07-23

Status: Closed
Project: MariaDB Server
Component/s: Full-text Search, mariabackup, Storage Engine - InnoDB
Affects Version/s: 10.3, 10.4
Fix Version/s: 10.2.33, 10.3.24, 10.4.14, 10.5.5

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Thirunarayanan Balathandayuthapani
Resolution: Duplicate Votes: 0
Labels: need_rr

Attachments: File mdev21419_backup.tar.gz    
Issue Links:
Relates
relates to MDEV-23134 SEGV in dict_load_table_one during re... Closed

 Description   

10.3 02e30069

 
2020-01-03 17:58:29 0 [ERROR] InnoDB: Trying to load index `FTS_INDEX_TABLE_IND` for table `test`.`FTS_0000000000000167_000000000000019c_INDEX_1`, but the index tree has been freed!
 
2020-01-03 17:58:29 0 [Note] InnoDB: Index is corrupt but forcing load into data dictionary
 
200103 17:58:29 [ERROR] mysqld got signal 11 ;
 
 
 
#3  <signal handler called>
 
#4  0x0000557aac547338 in dict_load_table_one (name=..., ignore_err=6, fk_tables=std::deque with 0 elements) at /data/src/10.3/storage/innobase/dict/dict0load.cc:2998
 
#5  0x0000557aac5461de in dict_load_table (name=0x7ffd9c1ef650 "test/FTS_", '0' <repeats 13 times>, "167_", '0' <repeats 13 times>, "19c_INDEX_1", ignore_err=6) at /data/src/10.3/storage/innobase/dict/dict0load.cc:2751
 
#6  0x0000557aac52442c in dict_table_open_on_name (table_name=0x7ffd9c1ef650 "test/FTS_", '0' <repeats 13 times>, "167_", '0' <repeats 13 times>, "19c_INDEX_1", dict_locked=1, try_drop=0, ignore_err=6) at /data/src/10.3/storage/innobase/dict/dict0dict.cc:1154
 
#7  0x0000557aac5b3824 in fts_drop_table (trx=0x7f9fd72160f0, table_name=0x7ffd9c1ef650 "test/FTS_", '0' <repeats 13 times>, "167_", '0' <repeats 13 times>, "19c_INDEX_1") at /data/src/10.3/storage/innobase/fts/fts0fts.cc:1451
 
#8  0x0000557aac5b406d in fts_drop_index_split_tables (trx=0x7f9fd72160f0, index=0x557aafb1df88) at /data/src/10.3/storage/innobase/fts/fts0fts.cc:1630
 
#9  0x0000557aac5b40ea in fts_drop_index_tables (trx=0x7f9fd72160f0, index=0x557aafb1df88) at /data/src/10.3/storage/innobase/fts/fts0fts.cc:1650
 
#10 0x0000557aac5b4178 in fts_drop_all_index_tables (trx=0x7f9fd72160f0, fts=0x557aafb1bd58) at /data/src/10.3/storage/innobase/fts/fts0fts.cc:1677
 
#11 0x0000557aac5b41ff in fts_drop_tables (trx=0x7f9fd72160f0, table=0x557aafb1b388) at /data/src/10.3/storage/innobase/fts/fts0fts.cc:1708
 
#12 0x0000557aac36202f in row_drop_ancillary_fts_tables (table=0x557aafb1b388, trx=0x7f9fd72160f0) at /data/src/10.3/storage/innobase/row/row0mysql.cc:3232
 
#13 0x0000557aac3635f0 in row_drop_table_for_mysql (name=0x557aafb155c8 "test/#sql-b28_11#P#ver_p4", trx=0x7f9fd72160f0, sqlcom=SQLCOM_DROP_TABLE, create_failed=false, nonatomic=true) at /data/src/10.3/storage/innobase/row/row0mysql.cc:3734
 
#14 0x0000557aac360f4c in row_mysql_drop_garbage_tables () at /data/src/10.3/storage/innobase/row/row0mysql.cc:2782
 
#15 0x0000557aac292ef3 in recv_recovery_rollback_active () at /data/src/10.3/storage/innobase/log/log0recv.cc:3988
 
#16 0x0000557aac3e97db in srv_start (create_new_db=false) at /data/src/10.3/storage/innobase/srv/srv0start.cc:2292
 
#17 0x0000557aac1bd9eb in innodb_init (p=0x557aaecee080) at /data/src/10.3/storage/innobase/handler/ha_innodb.cc:4261
 
#18 0x0000557aabf96cf7 in ha_initialize_handlerton (plugin=0x557aaecdeeb0) at /data/src/10.3/sql/handler.cc:549
 
#19 0x0000557aabc96db1 in plugin_initialize (tmp_root=0x7ffd9c1f7080, plugin=0x557aaecdeeb0, argc=0x557aad4e2330 <remaining_argc>, argv=0x557aaec8afb8, options_only=false) at /data/src/10.3/sql/sql_plugin.cc:1433
 
#20 0x0000557aabc97b3d in plugin_init (argc=0x557aad4e2330 <remaining_argc>, argv=0x557aaec8afb8, flags=2) at /data/src/10.3/sql/sql_plugin.cc:1715
 
#21 0x0000557aabb525c9 in init_server_components () at /data/src/10.3/sql/mysqld.cc:5416
 
#22 0x0000557aabb53788 in mysqld_main (argc=11, argv=0x557aaec8afb8) at /data/src/10.3/sql/mysqld.cc:6023
 
#23 0x0000557aabb47d70 in main (argc=11, argv=0x7ffd9c1f78b8) at /data/src/10.3/sql/main.cc:25

To reproduce:

  • download and extract mdev21419_backup.tar.gz
  • run 

    mariabackup --prepare --target-dir=`pwd`/mdev21419_backup
    		 
    mariabackup --copy-back --target-dir=`pwd`/mdev21419_backup --datadir=`pwd`/mdev21419_data

  • start the server with mdev21419_data for the datadir.

The backup was created on 10.3-enterprise ced5aad2 by running full backup on a server performing concurrent DML/DDL operations.

The failure to start is reproducible on 10.3-10.5. Since the datadir belongs to 10.3, I can't check whether earlier versions are affected.

 Comments   
Comment by Thirunarayanan Balathandayuthapani [ 2020-04-14 ]

Redo log contains the following redo logs:
MLOG_FILE_DELETE 324:0
MLOG_FILE_DELETE 325:0
MLOG_FILE_DELETE 326:0
MLOG_FILE_DELETE 327:0
MLOG_FILE_DELETE 328:0

All space ids belong to ./test/FTS_0000000000000167_BEING_DELETED.ibd, ./test/FTS_0000000000000167_BEING_DELETED_CACHE.ibd,
FTS_0000000000000167_CONFIG, ./test/FTS_0000000000000167_DELETED.ibd, ./test/FTS_0000000000000167_DELETED_CACHE.ibd

Maybe the backup was taken during drop table or truncate table.

Comment by Marko Mäkelä [ 2020-04-14 ]

Apart from DROP TABLE or TRUNCATE, possible culprits could include OPTIMIZE TABLE and a table-rebuilding ALTER TABLE.

For this kind of bugs, it would be very useful to have an rr record trace of the server that was running when mariabackup --prepare was executed.

Comment by Marko Mäkelä [ 2020-07-23 ]

It looks like this report duplicates MDEV-23134.

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