Bug #84038 Errors when restarting MySQL after FLUSH TABLES FOR EXPORT, RENAME and DROP.
Submitted: 2 Dec 2016 10:01 Modified: 21 Mar 2017 17:08
Reporter: Jean-François Gagné Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S3 (Non-critical)
Version:5.7.15-log, 5.7.16 OS:CentOS (CentOS release 6.8 (Final))
Assigned to: CPU Architecture:Any

[2 Dec 2016 10:01] Jean-François Gagné
Description:
Hi,

When I do the sequences of commands below, I get the following in the error logs when restarting MySQL:

2016-12-02T09:54:47.201950Z 0 [ERROR] InnoDB: Operating system error number 2 in a file operation.
2016-12-02T09:54:47.201997Z 0 [ERROR] InnoDB: The error means the system cannot find the path specified.
2016-12-02T09:54:47.202006Z 0 [ERROR] InnoDB: If you are installing InnoDB, remember that you must create directories yourself, InnoDB does not create them.
2016-12-02T09:54:47.202018Z 0 [ERROR] InnoDB: Cannot open datafile for read-only: './test_jfg/test.ibd' OS error: 71

mysql <<< "
DROP DATABASE IF EXISTS test_jfg;
DROP DATABASE IF EXISTS test_jfg2;
CREATE DATABASE test_jfg;
CREATE DATABASE test_jfg2;
CREATE TABLE test_jfg.test (a int unsigned NOT NULL PRIMARY KEY);
FLUSH TABLES test_jfg.test FOR EXPORT;"

mysql <<< "
RENAME TABLE test_jfg.test TO test_jfg2.test;
DROP DATABASE test_jfg;"

If I restart MySQL again, I do not get the errors again.

Thanks in advance for looking into that,

JFG

How to repeat:
See description.
[2 Dec 2016 10:20] MySQL Verification Team
Hello Jean,

Thank you for the report and test case.
Observed this with 5.7.16.

Thanks,
Umesh
[2 Dec 2016 10:21] MySQL Verification Team
-- 5.7.16

2016-12-02T10:18:18.702753Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2016-12-02T10:18:18.710986Z 0 [ERROR] InnoDB: Operating system error number 2 in a file operation.
2016-12-02T10:18:18.711005Z 0 [ERROR] InnoDB: The error means the system cannot find the path specified.
2016-12-02T10:18:18.711011Z 0 [ERROR] InnoDB: If you are installing InnoDB, remember that you must create directories yourself, InnoDB does not create them.
2016-12-02T10:18:18.711017Z 0 [ERROR] InnoDB: Cannot open datafile for read-only: './test_jfg/test.ibd' OS error: 71
2016-12-02T10:18:18.711569Z 0 [Note] InnoDB: The InnoDB data dictionary table SYS_DATAFILES for tablespace ID 23 was updated to use file ./test_jfg2/test.ibd.

-- restart after last statement executed, and check error log
[10 Mar 2017 5:51] MySQL Verification Team
--5.7.17

[umshastr@hod03]/export/umesh/server/binaries/GABuilds/mysql-5.7.17: bin/mysql -uroot -S /tmp/mysql_ushastry.sock <<< "
> DROP DATABASE IF EXISTS test_jfg;
> DROP DATABASE IF EXISTS test_jfg2;
> CREATE DATABASE test_jfg;
> CREATE DATABASE test_jfg2;
> CREATE TABLE test_jfg.test (a int unsigned NOT NULL PRIMARY KEY);
> FLUSH TABLES test_jfg.test FOR EXPORT;"
[umshastr@hod03]/export/umesh/server/binaries/GABuilds/mysql-5.7.17: bin/mysql -uroot -S /tmp/mysql_ushastry.sock <<< "
> RENAME TABLE test_jfg.test TO test_jfg2.test;
> SELECT * FROM INFORMATION_SCHEMA.INNODB_SYS_DATAFILES;
> DROP DATABASE test_jfg;"
SPACE   PATH
2       ./mysql/plugin.ibd
3       ./mysql/servers.ibd
4       ./mysql/help_topic.ibd
5       ./mysql/help_category.ibd
6       ./mysql/help_relation.ibd
7       ./mysql/help_keyword.ibd
8       ./mysql/time_zone_name.ibd
9       ./mysql/time_zone.ibd
10      ./mysql/time_zone_transition.ibd
11      ./mysql/time_zone_transition_type.ibd
12      ./mysql/time_zone_leap_second.ibd
13      ./mysql/innodb_table_stats.ibd
14      ./mysql/innodb_index_stats.ibd
15      ./mysql/slave_relay_log_info.ibd
16      ./mysql/slave_master_info.ibd
17      ./mysql/slave_worker_info.ibd
18      ./mysql/gtid_executed.ibd
19      ./mysql/server_cost.ibd
20      ./mysql/engine_cost.ibd
21      ./sys/sys_config.ibd
23      ./test_jfg/test.ibd

-- extract from error log

2017-03-10T05:50:01.232726Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2017-03-10T05:50:01.241505Z 0 [ERROR] InnoDB: Operating system error number 2 in a file operation.
2017-03-10T05:50:01.241530Z 0 [ERROR] InnoDB: The error means the system cannot find the path specified.
2017-03-10T05:50:01.241536Z 0 [ERROR] InnoDB: If you are installing InnoDB, remember that you must create directories yourself, InnoDB does not create them.
2017-03-10T05:50:01.241542Z 0 [ERROR] InnoDB: Cannot open datafile for read-only: './test_jfg/test.ibd' OS error: 71
2017-03-10T05:50:01.242307Z 0 [Note] InnoDB: The InnoDB data dictionary table SYS_DATAFILES for tablespace ID 23 was updated to use file ./test_jfg2/test.ibd.
2017-03-10T05:50:01.242670Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2017-03-10T05:50:01.242761Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2017-03-10T05:50:01.257604Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2017-03-10T05:50:01.258629Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
[10 Mar 2017 7:46] Aakanksha Verma
Posted by developer:
 
Bug#25189192

As satya mentioned the errors seen on restarting server is even without FLUSH TABLES FOR EXPORT

So when I do 
Server version: 5.7.19-debug Source distribution

Copyright (c) 2000, 2017, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> DROP DATABASE IF EXISTS test_jfg;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> show warnings;
Empty set (0.00 sec)

mysql> DROP DATABASE IF EXISTS test_jfg2;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> CREATE DATABASE test_jfg;
Query OK, 1 row affected (0.00 sec)

mysql> CREATE DATABASE test_jfg2;
Query OK, 1 row affected (0.00 sec)

mysql> CREATE TABLE test_jfg.test (a int unsigned NOT NULL PRIMARY KEY);
Query OK, 0 rows affected (0.05 sec)

mysql>  RENAME TABLE test_jfg.test TO test_jfg2.test;
Query OK, 0 rows affected (0.02 sec)

mysql> SELECT * FROM INFORMATION_SCHEMA.INNODB_SYS_DATAFILES;
+-------+---------------------------------------+
| SPACE | PATH                                  |
+-------+---------------------------------------+
|     2 | ./mysql/plugin.ibd                    |
|     3 | ./mysql/servers.ibd                   |
|     4 | ./mysql/help_topic.ibd                |
|     5 | ./mysql/help_category.ibd             |
|     6 | ./mysql/help_relation.ibd             |
|     7 | ./mysql/help_keyword.ibd              |
|     8 | ./mysql/time_zone_name.ibd            |
|     9 | ./mysql/time_zone.ibd                 |
|    10 | ./mysql/time_zone_transition.ibd      |
|    11 | ./mysql/time_zone_transition_type.ibd |
|    12 | ./mysql/time_zone_leap_second.ibd     |
|    13 | ./mysql/innodb_table_stats.ibd        |
|    14 | ./mysql/innodb_index_stats.ibd        |
|    15 | ./mysql/slave_relay_log_info.ibd      |
|    16 | ./mysql/slave_master_info.ibd         |
|    17 | ./mysql/slave_worker_info.ibd         |
|    18 | ./mysql/gtid_executed.ibd             |
|    19 | ./mysql/server_cost.ibd               |
|    20 | ./mysql/engine_cost.ibd               |
|    21 | ./sys/sys_config.ibd                  |
|    23 | ./test_jfg/test.ibd                   |
+-------+---------------------------------------+
21 rows in set (0.00 sec)

mysql> DROP DATABASE test_jfg;
Query OK, 0 rows affected (0.01 sec)

mysql> SELECT * FROM INFORMATION_SCHEMA.INNODB_SYS_DATAFILES;
+-------+---------------------------------------+
| SPACE | PATH                                  |
+-------+---------------------------------------+
|     2 | ./mysql/plugin.ibd                    |
|     3 | ./mysql/servers.ibd                   |
|     4 | ./mysql/help_topic.ibd                |
|     5 | ./mysql/help_category.ibd             |
|     6 | ./mysql/help_relation.ibd             |
|     7 | ./mysql/help_keyword.ibd              |
|     8 | ./mysql/time_zone_name.ibd            |
|     9 | ./mysql/time_zone.ibd                 |
|    10 | ./mysql/time_zone_transition.ibd      |
|    11 | ./mysql/time_zone_transition_type.ibd |
|    12 | ./mysql/time_zone_leap_second.ibd     |
|    13 | ./mysql/innodb_table_stats.ibd        |
|    14 | ./mysql/innodb_index_stats.ibd        |
|    15 | ./mysql/slave_relay_log_info.ibd      |
|    16 | ./mysql/slave_master_info.ibd         |
|    17 | ./mysql/slave_worker_info.ibd         |
|    18 | ./mysql/gtid_executed.ibd             |
|    19 | ./mysql/server_cost.ibd               |
|    20 | ./mysql/engine_cost.ibd               |
|    21 | ./sys/sys_config.ibd                  |
|    23 | ./test_jfg/test.ibd                   |
+-------+---------------------------------------+
21 rows in set (0.00 sec)

mysql> quit
Bye
So we see without FLUSH TABLES FOR EXPORT the system tablespace is not updated and causing those errors on restaring server

2017-03-10T07:40:02.632997Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2017-03-10T07:40:02.633079Z 0 [Note] --secure-file-priv is set to NULL. Operations related to importing and exporting data are disabled
2017-03-10T07:40:02.633109Z 0 [Note] ./sql/mysqld (mysqld 5.7.19-debug) starting as process 4723 ...
2017-03-10T07:40:02.639047Z 0 [Note] InnoDB: PUNCH HOLE support available
2017-03-10T07:40:02.639072Z 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-03-10T07:40:02.639091Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-03-10T07:40:02.639097Z 0 [Note] InnoDB: Uses event mutexes
2017-03-10T07:40:02.639104Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-03-10T07:40:02.639110Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3
2017-03-10T07:40:02.639116Z 0 [Note] InnoDB: Using Linux native AIO
2017-03-10T07:40:02.639441Z 0 [Note] InnoDB: Number of pools: 1
2017-03-10T07:40:02.639565Z 0 [Note] InnoDB: Using CPU crc32 instructions
2017-03-10T07:40:02.641189Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2017-03-10T07:40:02.695383Z 0 [Note] InnoDB: Completed initialization of buffer pool
2017-03-10T07:40:02.696969Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2017-03-10T07:40:03.328171Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2017-03-10T07:40:03.378993Z 0 [ERROR] InnoDB: Operating system error number 2 in a file operation.
2017-03-10T07:40:03.379017Z 0 [ERROR] InnoDB: The error means the system cannot find the path specified.
2017-03-10T07:40:03.379026Z 0 [ERROR] InnoDB: If you are installing InnoDB, remember that you must create directories yourself, InnoDB does not create them.
2017-03-10T07:40:03.379034Z 0 [ERROR] InnoDB: Cannot open datafile for read-only: './test_jfg/test.ibd' OS error: 71

Need to investigate why RENAME doesnt update the system tablespace.
[21 Mar 2017 17:08] Daniel Price
Posted by developer:
 
Fixed as of the upcoming 5.7.19, 8.0.2 release, and here's the changelog entry:

After a RENAME TABLE operation that moved a table to a different schema,
InnoDB returned an error on restart indicating that it could not locate
the tablespace data file. InnoDB failed to update INNODB_SYS_DATAFILES
data dictionary table during the RENAME TABLE operation. 

Thank you for the bug report.