Bug #110722 Failed to upgrade from 5.7 to 8.0 because of orphan tmp tables created in 5.6
Submitted: 19 Apr 2023 3:29 Modified: 11 Apr 4:36
Reporter: Huaxiong Song (OCA) Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Data Dictionary Severity:S2 (Serious)
Version:5.7, 8.0.33 OS:Any
Assigned to: CPU Architecture:Any
Tags: Contribution

[19 Apr 2023 3:29] Huaxiong Song
Description:
1. In the instance of version 5.6, the frm file and ibd file prefixed with #sql will be generated in the tmp directory due to operations such as ddl residue, and this part of information will be recorded in the system table.

2. If the instance is upgraded to version 5.7 with residual #sql files, 5.7 will delete the ibd and frm files prefixed with #sql, but the records in the system table are not deleted at this time, and the 5.7 instance can run normally. The remnants of the #sql table could be found in information_schema.

3. During the upgrade process from 5.7 to 8.0, the records in the system table will be checked one by one, and it is found that the corresponding temporary tablespace in the system table does not exist, and an error is reported, which eventually leads to the upgrade failure. 
  Error detail:
2023-04-19T03:11:47.512215Z 1 [System] [MY-011012] [Server] Starting upgrade of data directory.
2023-04-19T03:11:47.512261Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2023-04-19T03:11:47.819354Z 1 [Warning] [MY-012177] [InnoDB] The datafile '/tmp/#sql1dc6f_2_0.ibd' for tablespace tmp/#sql1dc6f_2_0 is in an unprotected location. This file cannot be recovered after a crash until this location is added to innodb_directories.
2023-04-19T03:11:47.819416Z 1 [ERROR] [MY-012592] [InnoDB] Operating system error number 2 in a file operation.
2023-04-19T03:11:47.819431Z 1 [ERROR] [MY-012593] [InnoDB] The error means the system cannot find the path specified.
2023-04-19T03:11:47.819439Z 1 [ERROR] [MY-012216] [InnoDB] Cannot open datafile for read-only: '/tmp/#sql1dc6f_2_0.ibd' OS error: 71
2023-04-19T03:11:47.819449Z 1 [Warning] [MY-012019] [InnoDB] Ignoring tablespace `tmp/#sql1dc6f_2_0` because it could not be opened.
2023-04-19T03:11:47.871059Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2023-04-19T03:11:48.082682Z 1 [ERROR] [MY-011006] [Server] Got error 197 from SE while migrating tablespaces.
2023-04-19T03:11:48.086208Z 0 [ERROR] [MY-010020] [Server] Data Dictionary initialization failed.
2023-04-19T03:11:48.086240Z 0 [ERROR] [MY-010119] [Server] Aborting

How to repeat:
1. Create temporary table in MySQL5.6 (my version 5.6.51).
	CREATE DATABASE test;
	CREATE TEMPORARY TABLE temp(id int);
.ibd file and .frm can be found on $tmpdir, like "#sql1dc6f_1_0.ibd", "#sql1dc6f_1_0.frm".

2. Kill MySQL5.6 process to simulate an abnormal exit(When a crash occurs during DDL, temporary tables/files will remains).
.ibd file and .frm can still be found on $tmpdir, like "#sql1dc6f_1_0.ibd", "#sql1dc6f_1_0.frm".

3. Start with MySQL5.7(my version 5.7.41) and do msyql_upgrade.
.ibd file and .frm can not be found on $tmpdir, they were deleted by MySQL5.7. However, the informations of temporary tables are save in system tables.
MySQL [(none)]> SELECT * FROM INFORMATION_SCHEMA.INNODB_SYS_TABLES WHERE NAME LIKE '%#sql%';
+----------+-------------------+------+--------+-------+-------------+------------+---------------+------------+
| TABLE_ID | NAME              | FLAG | N_COLS | SPACE | FILE_FORMAT | ROW_FORMAT | ZIP_PAGE_SIZE | SPACE_TYPE |
+----------+-------------------+------+--------+-------+-------------+------------+---------------+------------+
|       21 | tmp/#sql1dc6f_2_0 |    1 |      4 |     7 | Antelope    | Compact    |             0 | Single     |
+----------+-------------------+------+--------+-------+-------------+------------+---------------+------------+

MySQL [(none)]> SELECT * FROM INFORMATION_SCHEMA.INNODB_SYS_TABLESPACES WHERE NAME LIKE '%#sql%';
+-------+-------------------+------+-------------+----------------------+-----------+---------------+------------+---------------+-----------+----------------+
| SPACE | NAME              | FLAG | FILE_FORMAT | ROW_FORMAT           | PAGE_SIZE | ZIP_PAGE_SIZE | SPACE_TYPE | FS_BLOCK_SIZE | FILE_SIZE | ALLOCATED_SIZE |
+-------+-------------------+------+-------------+----------------------+-----------+---------------+------------+---------------+-----------+----------------+
|     7 | tmp/#sql1dc6f_2_0 |    0 | Antelope    | Compact or Redundant |     16384 |             0 | Single     |             0 |         0 |              0 |
+-------+-------------------+------+-------------+----------------------+-----------+---------------+------------+---------------+-----------+----------------+

4. Shutdown MySQL 5.7 and start with MySQL8.0(my version 8.0.32), upgrade failed because tmp table can not be opened which is deleted by MySQL5.7.

Suggested fix:
As I see it, the problem is that files on device and records in system tables are not being updated in sync. 

Besides removing #sql files, the process of upgrading to 57 should also update the system table to ensure that the recoeds of #sql is deleted also.
[19 Apr 2023 6:50] MySQL Verification Team
Hello Huaxiong Song,

Thank you for the report and steps.
Verified as described.

regards,
Umesh
[19 Apr 2023 6:53] MySQL Verification Team
failed 5.6->5.7->8.0 upgrade details

Attachment: 110722.results (application/octet-stream, text), 8.82 KiB.

[17 May 2023 1:41] Steve Wendt
I believe our MySQL 5.7 is failing to upgrade for the same (or similar) reason.  However, I get no feedback from the log file to be 100% certain:

2023-05-10T02:55:17.078462Z 0 [System] [MY-010116] [Server] C:\Program Files\MySQL\MySQL Server 8.0\bin\mysqld.exe (mysqld 8.0.33) starting as process 30544
2023-05-10T02:55:17.092385Z 1 [System] [MY-011012] [Server] Starting upgrade of data directory.
2023-05-10T02:55:17.092654Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2023-05-10T02:55:18.805311Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2023-05-10T02:55:19.061040Z 1 [ERROR] [MY-011006] [Server] Got error 197 from SE while migrating tablespaces.
2023-05-10T02:55:19.078472Z 0 [ERROR] [MY-010020] [Server] Data Dictionary initialization failed.
2023-05-10T02:55:19.078736Z 0 [ERROR] [MY-010119] [Server] Aborting
2023-05-10T02:55:20.335599Z 0 [System] [MY-010910] [Server] C:\Program Files\MySQL\MySQL Server 8.0\bin\mysqld.exe: Shutdown complete (mysqld 8.0.33)  MySQL Community Server - GPL.

I have no orphans in innodb_sys_tables:
mysql> select * from information_schema.innodb_sys_tables where name like 'tmp%';
Empty set (0.00 sec)

But I *do* have orphans in innodb_sys_tablespaces:
mysql> select * from information_schema.innodb_sys_tablespaces where name like 'tmp%';
+-------+-----------------------+------+-------------+----------------------+-----------+---------------+------------+---------------+-----------+----------------+
| SPACE | NAME                  | FLAG | FILE_FORMAT | ROW_FORMAT           | PAGE_SIZE | ZIP_PAGE_SIZE | SPACE_TYPE | FS_BLOCK_SIZE | FILE_SIZE | ALLOCATED_SIZE |
+-------+-----------------------+------+-------------+----------------------+-----------+---------------+------------+---------------+-----------+----------------+
|  6105 | tmp/#sql5305_9967f5_0 |    0 | Antelope    | Compact or Redundant |     16384 |             0 | Single     |             0 |         0 |              0 |
|  6106 | tmp/#sql5305_9967f5_1 |    0 | Antelope    | Compact or Redundant |     16384 |             0 | Single     |             0 |         0 |              0 |
|  6107 | tmp/#sql5305_99683f_0 |    0 | Antelope    | Compact or Redundant |     16384 |             0 | Single     |             0 |         0 |              0 |
|  6108 | tmp/#sql5305_99683f_1 |    0 | Antelope    | Compact or Redundant |     16384 |             0 | Single     |             0 |         0 |              0 |
|  6109 | tmp/#sql5305_99683f_2 |    0 | Antelope    | Compact or Redundant |     16384 |             0 | Single     |             0 |         0 |              0 |
|  6110 | tmp/#sql5305_99683f_3 |    0 | Antelope    | Compact or Redundant |     16384 |             0 | Single     |             0 |         0 |              0 |
|  6111 | tmp/#sql5305_99683f_4 |    0 | Antelope    | Compact or Redundant |     16384 |             0 | Single     |             0 |         0 |              0 |
|  6112 | tmp/#sql5305_99683f_5 |    0 | Antelope    | Compact or Redundant |     16384 |             0 | Single     |             0 |         0 |              0 |
|  6113 | tmp/#sql5305_99683f_6 |    0 | Antelope    | Compact or Redundant |     16384 |             0 | Single     |             0 |         0 |              0 |
|  6114 | tmp/#sql5305_99683f_7 |    0 | Antelope    | Compact or Redundant |     16384 |             0 | Single     |             0 |         0 |              0 |
|  6115 | tmp/#sql5305_99683f_8 |    0 | Antelope    | Compact or Redundant |     16384 |             0 | Single     |             0 |         0 |              0 |
|  6116 | tmp/#sql5305_99683f_9 |    0 | Antelope    | Compact or Redundant |     16384 |             0 | Single     |             0 |         0 |              0 |
|  6117 | tmp/#sql5305_99683f_a |    0 | Antelope    | Compact or Redundant |     16384 |             0 | Single     |             0 |         0 |              0 |
|  6118 | tmp/#sql5305_99683f_b |    0 | Antelope    | Compact or Redundant |     16384 |             0 | Single     |             0 |         0 |              0 |
|  6119 | tmp/#sql5305_99683f_c |    0 | Antelope    | Compact or Redundant |     16384 |             0 | Single     |             0 |         0 |              0 |
+-------+-----------------------+------+-------------+----------------------+-----------+---------------+------------+---------------+-----------+----------------+
15 rows in set (0.01 sec)

I tried various things attempting to remove those based on what I found here:
https://dev.mysql.com/doc/refman/5.7/en/innodb-troubleshooting-datadict.html

But nothing I tried worked.  

So, questions:

1) Can the data dictionary upgrade logging be improved, so that it is more informative when it fails?  Increasing the log verbosity shows a lot of other information, but nothing additional about the DD upgrade.

2) Is it known what these "tmp/#sql5305_" tablespaces originated from?  Clearly they are different from the "#sql-ib" and "#sql-540_3" listed in the documentation.  Our database has been through several prior upgrades over the years, so it could be leftovers from MySQL 5.5 or even 5.1.

3) Any hints on how I can remove these orphaned tablespaces?

4) Presumably, the ideal scenario is that the DD upgrade in a future 8.0.x release will automatically clean these up?
[17 May 2023 1:59] Huaxiong Song
Hi Steve,
In fact, the situation I encountered is the same as yours. I artificially constructed a temporary table in order to reproduce this problem. My initial question is the same as yours. There is no information in innodb_sys_tables, but innodb_sys_tablespaces and innodb_sys_datafiles can find problem tables(files).

May I know how the temporary table in your question is generated?
Thanks.
[17 May 2023 2:02] Steve Wendt
> May I know how the temporary table in your question is generated?

Unfortunately, I do not know.  I suspect they have been carried around in our database for quite some time.
[17 May 2023 2:05] Steve Wendt
And I also have entries in innodb_sys_datafiles, as you suggested:

mysql> select * from information_schema.innodb_sys_datafiles where path like '%#sql%';
+-------+----------------------------+
| SPACE | PATH                       |
+-------+----------------------------+
|  6105 | /tmp/#sql5305_9967f5_0.ibd |
|  6106 | /tmp/#sql5305_9967f5_1.ibd |
|  6107 | /tmp/#sql5305_99683f_0.ibd |
|  6108 | /tmp/#sql5305_99683f_1.ibd |
|  6109 | /tmp/#sql5305_99683f_2.ibd |
|  6110 | /tmp/#sql5305_99683f_3.ibd |
|  6111 | /tmp/#sql5305_99683f_4.ibd |
|  6112 | /tmp/#sql5305_99683f_5.ibd |
|  6113 | /tmp/#sql5305_99683f_6.ibd |
|  6114 | /tmp/#sql5305_99683f_7.ibd |
|  6115 | /tmp/#sql5305_99683f_8.ibd |
|  6116 | /tmp/#sql5305_99683f_9.ibd |
|  6117 | /tmp/#sql5305_99683f_a.ibd |
|  6118 | /tmp/#sql5305_99683f_b.ibd |
|  6119 | /tmp/#sql5305_99683f_c.ibd |
+-------+----------------------------+
15 rows in set (0.00 sec)
[24 Jan 4:31] Jinyou Ma
The patch on 5.7.26

Attachment: remove_invalid_table_from_data_dict.patch (application/octet-stream, text), 4.74 KiB.

[10 Apr 6:37] MySQL Verification Team
Bug #114584 likely duplicate of this one
[11 Apr 4:36] Huaxiong Song
Since 5.7 is no longer under maintenance, I think it is a good way to fix it directly on 8.0.
[11 Apr 4:37] Huaxiong Song
code and test case

(*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.

Contribution: skip_orphan_table.diff (application/octet-stream, text), 8.67 KiB.

[11 Apr 4:38] Huaxiong Song
Data from 5.7

(*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.

Contribution: data_57_skip_orphan_tmp_table.zip (application/zip, text), 470.77 KiB.