MySQL Bugs: #95673: Crash on import tablespace

Bug #95673	Crash on import tablespace
Submitted:	6 Jun 2019 13:50	Modified:	3 Jul 2019 20:53
Reporter:	Daniël van Eeden (OCA)	Email Updates:
Status:	Can't repeat	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S3 (Non-critical)
Version:	5.7.26	OS:	Any
Assigned to:		CPU Architecture:	Any
Tags:	crash, innodb, tts

Description:
MySQL/InnoDB crashes on import of a partitioned table.

(gdb) where
#0  mtr_t::x_lock_space (this=this@entry=0x7f1825734840, space_id=space_id@entry=471, 
    file=file@entry=0x160a0b0 "/home/eurrego/rpmbuild/BUILD/mysql-5.7.26-SR1/mysql-5.7.26-SR1/storage/innobase/fsp/fsp0fsp.cc", line=line@entry=2789)
    at /home/eurrego/rpmbuild/BUILD/mysql-5.7.26-SR1/mysql-5.7.26-SR1/storage/innobase/mtr/mtr0mtr.cc:712
#1  0x00000000011968c5 in fseg_n_reserved_pages (header=header@entry=0x7f3139c94054 "", used=used@entry=0x7f18257340d0, mtr=mtr@entry=0x7f1825734840)
    at /home/eurrego/rpmbuild/BUILD/mysql-5.7.26-SR1/mysql-5.7.26-SR1/storage/innobase/fsp/fsp0fsp.cc:2789
#2  0x00000000010d472e in btr_get_size (index=index@entry=0x163594808, flag=flag@entry=2, mtr=mtr@entry=0x7f1825734840)
    at /home/eurrego/rpmbuild/BUILD/mysql-5.7.26-SR1/mysql-5.7.26-SR1/storage/innobase/btr/btr0btr.cc:540
#3  0x00000000011752d3 in dict_stats_analyze_index (index=index@entry=0x163594808)
    at /home/eurrego/rpmbuild/BUILD/mysql-5.7.26-SR1/mysql-5.7.26-SR1/storage/innobase/dict/dict0stats.cc:1909
#4  0x000000000117a1df in dict_stats_update_persistent (table=0x16371e388) at /home/eurrego/rpmbuild/BUILD/mysql-5.7.26-SR1/mysql-5.7.26-SR1/storage/innobase/dict/dict0stats.cc:2210
#5  dict_stats_update (table=table@entry=0x16371e388, stats_upd_option=stats_upd_option@entry=DICT_STATS_RECALC_PERSISTENT)
    at /home/eurrego/rpmbuild/BUILD/mysql-5.7.26-SR1/mysql-5.7.26-SR1/storage/innobase/dict/dict0stats.cc:3107
#6  0x0000000000f357fd in ha_innobase::discard_or_import_tablespace (this=this@entry=0x163380430, discard=discard@entry=0 '\000')
    at /home/eurrego/rpmbuild/BUILD/mysql-5.7.26-SR1/mysql-5.7.26-SR1/storage/innobase/handler/ha_innodb.cc:12414
#7  0x0000000000f4d780 in ha_innopart::discard_or_import_tablespace (this=0x163380430, discard=<optimized out>)
    at /home/eurrego/rpmbuild/BUILD/mysql-5.7.26-SR1/mysql-5.7.26-SR1/storage/innobase/handler/ha_innopart.cc:3057
#8  0x0000000000d24a4c in mysql_discard_or_import_tablespace (thd=thd@entry=0x161248000, table_list=table_list@entry=0x1611ff260, discard=<optimized out>)
    at /home/eurrego/rpmbuild/BUILD/mysql-5.7.26-SR1/mysql-5.7.26-SR1/sql/sql_table.cc:6107
#9  0x0000000000e26ccb in Sql_cmd_discard_import_tablespace::execute (this=0x1611ff7e8, thd=0x161248000)
    at /home/eurrego/rpmbuild/BUILD/mysql-5.7.26-SR1/mysql-5.7.26-SR1/sql/sql_alter.cc:381
#10 0x0000000000cb9480 in mysql_execute_command (thd=thd@entry=0x161248000, first_level=first_level@entry=true)
    at /home/eurrego/rpmbuild/BUILD/mysql-5.7.26-SR1/mysql-5.7.26-SR1/sql/sql_parse.cc:4835
#11 0x0000000000cbf78d in mysql_parse (thd=thd@entry=0x161248000, parser_state=parser_state@entry=0x7f1825739380)
    at /home/eurrego/rpmbuild/BUILD/mysql-5.7.26-SR1/mysql-5.7.26-SR1/sql/sql_parse.cc:5570
#12 0x0000000000cc032a in dispatch_command (thd=thd@entry=0x161248000, com_data=com_data@entry=0x7f1825739c20, command=COM_QUERY)
    at /home/eurrego/rpmbuild/BUILD/mysql-5.7.26-SR1/mysql-5.7.26-SR1/sql/sql_parse.cc:1484
#13 0x0000000000cc1dbf in do_command (thd=thd@entry=0x161248000) at /home/eurrego/rpmbuild/BUILD/mysql-5.7.26-SR1/mysql-5.7.26-SR1/sql/sql_parse.cc:1025
#14 0x0000000000d84290 in handle_connection (arg=arg@entry=0x161e0a180)
    at /home/eurrego/rpmbuild/BUILD/mysql-5.7.26-SR1/mysql-5.7.26-SR1/sql/conn_handler/connection_handler_per_thread.cc:306
#15 0x000000000126b5c4 in pfs_spawn_thread (arg=0x160fdb6a0) at /home/eurrego/rpmbuild/BUILD/mysql-5.7.26-SR1/mysql-5.7.26-SR1/storage/perfschema/pfs.cc:2190
#16 0x00007f325bb9edd5 in start_thread () from /lib64/libpthread.so.0
#17 0x00007f3259f83ead in clone () from /lib64/libc.so.6

2019-06-06T13:37:54.565957Z 805 [Note] InnoDB: Phase III - Flush changes to disk
2019-06-06T13:37:54.571075Z 805 [Note] InnoDB: Phase IV - Flush complete
2019-06-06T13:37:54.571210Z 805 [Note] InnoDB: `YYYYYY`.`XXXXXXXXXXXXXX` /* Partition `ci_2019_12_16` */ autoinc value set to 0
2019-06-06T13:37:54.596661Z 805 [Note] InnoDB: Importing tablespace for table 'YYYYYY/XXXXXXXXXXXXXX#P#ci_2019_12_17' that was exported from host 'Hostname unknown'
2019-06-06T13:37:54.596746Z 805 [Note] InnoDB: Phase I - Update all pages
2019-06-06T13:37:54.596954Z 805 [Note] InnoDB: Sync to disk
2019-06-06T13:37:54.598385Z 805 [Note] InnoDB: Sync to disk - done!
2019-06-06T13:37:54.599560Z 805 [Note] InnoDB: Phase III - Flush changes to disk
2019-06-06T13:37:54.604174Z 805 [Note] InnoDB: Phase IV - Flush complete
2019-06-06T13:37:54.604295Z 805 [Note] InnoDB: `YYYYYY`.`XXXXXXXXXXXXXX` /* Partition `ci_2019_12_17` */ autoinc value set to 0
2019-06-06T13:37:54.632718Z 805 [Note] InnoDB: Importing tablespace for table 'YYYYYY/XXXXXXXXXXXXXX#P#ci_2019_12_18' that was exported from host 'Hostname unknown'
2019-06-06T13:37:54.632811Z 805 [Note] InnoDB: Phase I - Update all pages
2019-06-06T13:37:54.633027Z 805 [Note] InnoDB: Sync to disk
2019-06-06T13:37:54.634294Z 805 [Note] InnoDB: Sync to disk - done!
2019-06-06T13:37:54.635507Z 805 [ERROR] InnoDB: Space id and page no stored in the page, read in are [page id: space=471, page number=3], should be [page id: space=226, page number=3]
2019-06-06T13:37:54.635526Z 805 [ERROR] InnoDB: Page [page id: space=471, page number=3] log sequence number 428296187766 is in the future! Current system log sequence number 71128897.
2019-06-06T13:37:54.635535Z 805 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to http://dev.mysql.com/doc/refman/5.7/en/forcing-innodb-recovery.html for information about forcing recovery.
2019-06-06T13:37:54.635550Z 805 [Note] InnoDB: Phase III - Flush changes to disk
2019-06-06T13:37:54.639790Z 805 [Note] InnoDB: Phase IV - Flush complete
2019-06-06T13:37:54.639916Z 805 [Note] InnoDB: `YYYYYY`.`XXXXXXXXXXXXXX` /* Partition `ci_2019_12_18` */ autoinc value set to 0
2019-06-06T13:42:51.127844Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 296987ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)
13:42:51 UTC - mysqld got signal 11 ;

How to repeat:
Unknown

Hi Daniel,

Thank you for your bug report.

You wrote yourself that you do not know how to repeat this bug. Can you at least give us the indication of that entire installation, including number of schemas, number of tables or tablespaces in each, types of tables and tablespaces, your configuration. Next, what did that tablespace, to be imported, contained exactly. Next, what is the hardware that you used, OS details etc ....

Since this is 5.7, if you could provide us with info on the schema into which you tried to import that tablespace and with the tablespace (compressed) itself, we might try to reproduce it .....

Thanks in advance ......

Hi Daniel,

Just for your information, we are trying to repeat this bug in house. Seems to be a timing issue.

We shall see whether we shall succeed.

This happens when the table has too many partitions. 

The table crashes contains over 3000 partitions.  I could reproduce the crash each time when I import the tablespace. Can you verify if you could trigger it?

Thank you Mr. Wu,

Your input will be forwarded to the team that is trying to reproduce this problem.

HI Daniel, Wu,

So far our efforts in reproducing this bug have failed. Can you upload the output from the SHOW CREATE TABLE for the table in that tablespace ??

Many thanks in advance .....

I have upload the test table structure. 

Cheers

Xin

Thank you, Mr. Wu,

We see it ......

Hi Daniel, Mrs. Wu,

Our colleague Shane Bester has worked on this test case and here are some of his observations ...

Shane used the provided test table, and used lots of rows, 10+ million rows.   One thing he noticed is that when FLUSH TABLE test FOR EXPORT is ran,  the .cfg files get created and when the import of the table is performed again after discarding tablespace,  the auto-increment gets set to 1 for every partition.

Not so for your case,  it's set to 0 according to the log message.

How was this table exported?  Is it a clean export and not a dirty/live copy?

It is important for us to know this.

Hello.
We have used both xtrabackup to export the tablespace and the clean export with stopped replication and flush table for export method manually. Both failed.

xtrabackup:
sudo xtrabackup --databases=“app2" --backup  --slave-info --stream=tar  --target-dir=/mysql/backup/ 
xtrabackup --prepare  --apply-log --export  --target-dir=./

and then doing the standard remove tablespace and import tablespace.

Hi Mrs. Wu,

We do not have any experience with xtrabackup nor do we know how it truly functions.

So, let us know whether second command executes  FLUSH TABLE test FOR EXPORT prior to exporting a tablespace and whether  the .cfg files is created during this FLUSH operation ????

Also, after discarding tablespace, when the import of the table is , does  the auto-increment gets set to 1 for every partition. So, does every partition get auto-inc set to 1 or not ???

If that is the case, then what you are witnessing is possible a bug in xtrabackup.

As far as we could conclude, you have got 0 for the auto-inc, which would lead us to believe that you are experience a bug in xtrabackup.

Hi

It is not only happened during the xtrabackup. Later I removed the xtrabackup, did manually table export. same issue happened again.

Source:
 Flush table xxx for export;

copy all the related files to the target server.

Target:
Alter table xxx discard tablespace;
copy the ibd and cfg file over, set correct permission.
Alter table xxx import tablespacel; --> mysql crash.

As import never works, so I could not check the auto-increment for the new table.

Cheers

Xin

Hi Mrs. Wu,

You have answered all of our questions except one.

Did you use .cfg file when performing IMPORT ???

This is of the vital importance.

the .cfg file is in the same folder with the .ibd file during the import. I believe that means it is in use?

Thank you Mrs. Wu,

Since we are not able to reproduce your problems even with very large table with the same definition as yours, could you supply us with a compressed tablespace and with .cfg file ???

For upload use the above "Files" tab, or if the compressed file is too large, please use our SFTP directly.

If you do not have that tablespaces, then we could try it only with .cfg file.

Last, but not least, please explain in more detail how do you exactly import the tablespace ???

Thank you, Mrs. Wu,

We are starting to work with what you have provided .....