[MDEV-14029] Server does not remove #sql*.frm files after crash during ALTER TABLE Created: 2017-10-09  Updated: 2017-11-05  Resolved: 2017-11-05

Status: Closed
Project: MariaDB Server
Component/s: Tests
Affects Version/s: 10.0
Fix Version/s: 10.0.34, 10.1.29, 10.2.11

Type: Bug Priority: Major
Reporter: Alice Sherepa Assignee: Elena Stepanova
Resolution: Fixed Votes: 0
Labels: None
Environment:

windows


Issue Links:
Relates
relates to MDEV-11369 Instant add column for InnoDB Closed
relates to MDEV-14245 tokudb_alter_table.drop_add_pk_part_1... Closed
Sprint: 10.1.29

 Description   

http://buildbot.askmonty.org/buildbot/builders/win32-debug/builds/5751/steps/test/logs/stdio

innodb.log_file_name 'innodb'            w1 [ fail ]
        Test ended at 2017-10-09 06:52:48
 
CURRENT_TEST: innodb.log_file_name
--- D:/win32-debug/build/src/mysql-test/suite/innodb/r/log_file_name.result	2017-10-09 05:53:43.564389700 +0000
+++ D:\win32-debug\build\src\mysql-test\suite\innodb\r\log_file_name.reject	2017-10-09 06:52:47.598666800 +0000
@@ -98,5 +98,7 @@
 FOUND 1 /\[Warning\] InnoDB: Tablespace \d+ was not found at .*u[1-5].ibd, and innodb_force_recovery was set. All redo log for this tablespace will be ignored!.*/ in mysqld.1.err
 DROP TABLE u1,u2,u3,u6;
 # List of files:
+#sql-1a18_1e.frm
+#sql-1bc8_9.frm
 SHOW TABLES;
 Tables_in_test
 
mysqltest: Result length mismatch
 
 - saving 'D:/win32-debug/build/mysql-test/var/1/log/innodb.log_file_name-innodb/' to 'D:/win32-debug/build/mysql-test/var/log/innodb.log_file_name-innodb/'
 
Retrying test innodb.log_file_name, attempt(2/3)...
 
***Warnings generated in error logs during shutdown after running tests: innodb.log_file_name
 
2017-10-09  6:52:11 0 [ERROR] InnoDB: Cannot rename '.\test\t1.ibd' to '.\test\t2.ibd' for space ID 928 because the target file exists. Remove the target file and try again.
2017-10-09  6:52:11 0 [ERROR] InnoDB:  Cannot replay file rename. Remove either file and try again.
2017-10-09  6:52:11 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[2200] with error Generic error
2017-10-09  6:52:11 0 [ERROR] Plugin 'InnoDB' init function returned error.
2017-10-09  6:52:11 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2017-10-09  6:52:14 0 [ERROR] InnoDB: Tablespace 929 was not found at .\test\t3.ibd.
2017-10-09  6:52:14 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore this and to permanently lose all changes to the tablespace.
2017-10-09  6:52:14 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[2200] with error Tablespace not found
2017-10-09  6:52:14 0 [ERROR] Plugin 'InnoDB' init function returned error.
2017-10-09  6:52:14 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2017-10-09  6:52:17 0 [ERROR] InnoDB: Tablespace 928 was not found at .\test\t1.ibd.
2017-10-09  6:52:17 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore this and to permanently lose all changes to the tablespace.
2017-10-09  6:52:17 0 [ERROR] InnoDB: Tablespace 929 was not found at .\test\t3.ibd.
2017-10-09  6:52:17 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[2200] with error Tablespace not found
2017-10-09  6:52:17 0 [ERROR] Plugin 'InnoDB' init function returned error.
2017-10-09  6:52:17 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2017-10-09  6:52:20 0 [ERROR] InnoDB: Tablespace 928 was not found at .\test\t1.ibd.
2017-10-09  6:52:20 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore this and to permanently lose all changes to the tablespace.
2017-10-09  6:52:20 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[2200] with error Tablespace not found
2017-10-09  6:52:21 0 [ERROR] Plugin 'InnoDB' init function returned error.
2017-10-09  6:52:21 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2017-10-09  6:52:23 0 [ERROR] InnoDB: Tablespace 928 was not found at .\test\t1.ibd.
2017-10-09  6:52:23 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore this and to permanently lose all changes to the tablespace.
2017-10-09  6:52:23 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[2200] with error Tablespace not found
2017-10-09  6:52:23 0 [ERROR] Plugin 'InnoDB' init function returned error.
2017-10-09  6:52:23 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2017-10-09  6:52:26 0 [ERROR] InnoDB: Cannot read first page of '.\test\t2.ibd' I/O error
2017-10-09  6:52:26 0 [ERROR] InnoDB: Cannot read first page in datafile: .\test\t2.ibd, Space ID:4294967295, Flags: 0. Please refer to http://dev.mysql.com/doc/refman/5.7/en/innodb-troubleshooting-datadict.html for how to resolve the issue.
2017-10-09  6:52:26 0 [ERROR] InnoDB: Datafile '.\test\t2.ibd' is corrupted. Cannot determine the space ID from the first 64 pages.
2017-10-09  6:52:26 0 [ERROR] InnoDB: Tablespace 928 was not found at .\test\t1.ibd.
2017-10-09  6:52:26 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore this and to permanently lose all changes to the tablespace.
2017-10-09  6:52:26 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[2200] with error Tablespace not found
2017-10-09  6:52:26 0 [ERROR] Plugin 'InnoDB' init function returned error.
2017-10-09  6:52:26 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2017-10-09  6:52:31 8 [ERROR] InnoDB: Operating system error number 80 in a file operation.
2017-10-09  6:52:31 8 [ERROR] InnoDB: Cannot create file '.\test\t0.ibd'
2017-10-09  6:52:32 0 [ERROR] InnoDB: Header page consists of zero bytes in datafile: .\test\u1.ibd, Space ID:0, Flags: 0. Please refer to http://dev.mysql.com/doc/refman/5.7/en/innodb-troubleshooting-datadict.html for how to resolve the issue.
2017-10-09  6:52:32 0 [ERROR] InnoDB: Datafile '.\test\u1.ibd' is corrupted. Cannot determine the space ID from the first 64 pages.
2017-10-09  6:52:32 0 [ERROR] InnoDB: Cannot read first page of '.\test\u2.ibd' I/O error
2017-10-09  6:52:32 0 [ERROR] InnoDB: Cannot read first page in datafile: .\test\u2.ibd, Space ID:4294967295, Flags: 0. Please refer to http://dev.mysql.com/doc/refman/5.7/en/innodb-troubleshooting-datadict.html for how to resolve the issue.
2017-10-09  6:52:32 0 [ERROR] InnoDB: Datafile '.\test\u2.ibd' is corrupted. Cannot determine the space ID from the first 64 pages.
2017-10-09  6:52:32 0 [ERROR] InnoDB: Cannot rename '.\test\u5.ibd' to '.\test\u6.ibd' for space ID 935 because the target file exists. Remove the target file and try again.
2017-10-09  6:52:32 0 [ERROR] InnoDB:  Cannot replay file rename. Remove either file and try again.
2017-10-09  6:52:32 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[2200] with error Generic error
2017-10-09  6:52:32 0 [ERROR] Plugin 'InnoDB' init function returned error.
2017-10-09  6:52:32 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2017-10-09  6:52:34 0 [ERROR] InnoDB: Header page consists of zero bytes in datafile: .\test\u1.ibd, Space ID:0, Flags: 0. Please refer to http://dev.mysql.com/doc/refman/5.7/en/innodb-troubleshooting-datadict.html for how to resolve the issue.
2017-10-09  6:52:34 0 [ERROR] InnoDB: Datafile '.\test\u1.ibd' is corrupted. Cannot determine the space ID from the first 64 pages.
2017-10-09  6:52:34 0 [ERROR] InnoDB: Cannot rename '.\test\u5.ibd' to '.\test\u6.ibd' for space ID 935 because the target file exists. Remove the target file and try again.
2017-10-09  6:52:34 0 [ERROR] InnoDB:  Cannot replay file rename. Remove either file and try again.
2017-10-09  6:52:34 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[2200] with error Generic error
2017-10-09  6:52:35 0 [ERROR] Plugin 'InnoDB' init function returned error.
2017-10-09  6:52:35 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2017-10-09  6:52:37 0 [ERROR] InnoDB: Header page consists of zero bytes in datafile: .\test\u1.ibd, Space ID:0, Flags: 0. Please refer to http://dev.mysql.com/doc/refman/5.7/en/innodb-troubleshooting-datadict.html for how to resolve the issue.
2017-10-09  6:52:37 0 [ERROR] InnoDB: Datafile '.\test\u1.ibd' is corrupted. Cannot determine the space ID from the first 64 pages.
2017-10-09  6:52:37 0 [Warning] InnoDB: Tablespace 932 was not found at .\test\u1.ibd, and innodb_force_recovery was set. All redo log for this tablespace will be ignored!
2017-10-09  6:52:37 0 [Warning] InnoDB: Tablespace 933 was not found at .\test\u2.ibd, and innodb_force_recovery was set. All redo log for this tablespace will be ignored!
2017-10-09  6:52:37 0 [Warning] InnoDB: Tablespace 934 was not found at .\test\u3.ibd, and innodb_force_recovery was set. All redo log for this tablespace will be ignored!
2017-10-09  6:52:39 0 [ERROR] InnoDB: Header page consists of zero bytes in datafile: .\test\u1.ibd, Space ID:0, Flags: 0. Please refer to http://dev.mysql.com/doc/refman/5.7/en/innodb-troubleshooting-datadict.html for how to resolve the issue.
2017-10-09  6:52:39 0 [Warning] InnoDB: Ignoring tablespace for `test`.`u1` because it could not be opened.
2017-10-09  6:52:39 0 [ERROR] InnoDB: Operating system error number 2 in a file operation.
2017-10-09  6:52:39 0 [ERROR] InnoDB: Cannot open datafile for read-only: '.\test\u2.ibd' OS error: 71
2017-10-09  6:52:39 0 [Warning] InnoDB: Ignoring tablespace for `test`.`u2` because it could not be opened.
2017-10-09  6:52:39 0 [ERROR] InnoDB: Operating system error number 2 in a file operation.
2017-10-09  6:52:39 0 [ERROR] InnoDB: Cannot open datafile for read-only: '.\test\u3.ibd' OS error: 71
2017-10-09  6:52:39 0 [Warning] InnoDB: Ignoring tablespace for `test`.`u3` because it could not be opened.
2017-10-09  6:52:46 0 [ERROR] InnoDB: Header page consists of zero bytes in datafile: .\test\u1.ibd, Space ID:0, Flags: 0. Please refer to http://dev.mysql.com/doc/refman/5.7/en/innodb-troubleshooting-datadict.html for how to resolve the issue.
2017-10-09  6:52:46 0 [Warning] InnoDB: Ignoring tablespace for `test`.`u1` because it could not be opened.
2017-10-09  6:52:46 0 [ERROR] InnoDB: Operating system error number 2 in a file operation.
2017-10-09  6:52:46 0 [ERROR] InnoDB: Cannot open datafile for read-only: '.\test\u2.ibd' OS error: 71
2017-10-09  6:52:46 0 [Warning] InnoDB: Ignoring tablespace for `test`.`u2` because it could not be opened.
2017-10-09  6:52:46 0 [ERROR] InnoDB: Operating system error number 2 in a file operation.
2017-10-09  6:52:46 0 [ERROR] InnoDB: Cannot open datafile for read-only: '.\test\u3.ibd' OS error: 71
2017-10-09  6:52:46 0 [Warning] InnoDB: Ignoring tablespace for `test`.`u3` because it could not be opened.
2017-10-09  6:52:47 8 [ERROR] InnoDB: Header page consists of zero bytes in datafile: .\test\u1.ibd, Space ID:0, Flags: 0. Please refer to http://dev.mysql.com/doc/refman/5.7/en/innodb-troubleshooting-datadict.html for how to resolve the issue.
2017-10-09  6:52:47 8 [ERROR] InnoDB: Table test/u1 in the InnoDB data dictionary has tablespace id 932, but tablespace with that id or name does not exist. Have you deleted or moved .ibd files?
2017-10-09  6:52:47 8 [ERROR] InnoDB: Operating system error number 2 in a file operation.
2017-10-09  6:52:47 8 [ERROR] InnoDB: Cannot open datafile for read-only: '.\test\u2.ibd' OS error: 71
2017-10-09  6:52:47 8 [ERROR] InnoDB: Table test/u2 in the InnoDB data dictionary has tablespace id 933, but tablespace with that id or name does not exist. Have you deleted or moved .ibd files?
2017-10-09  6:52:47 8 [ERROR] InnoDB: Operating system error number 2 in a file operation.
2017-10-09  6:52:47 8 [ERROR] InnoDB: Cannot open datafile for read-only: '.\test\u3.ibd' OS error: 71
2017-10-09  6:52:47 8 [ERROR] InnoDB: Table test/u3 in the InnoDB data dictionary has tablespace id 934, but tablespace with that id or name does not exist. Have you deleted or moved .ibd files?



 Comments   
Comment by Marko Mäkelä [ 2017-10-09 ]

I worked around the bug by explicitly removing the two files in innodb.instant_alter_crash (which was the test that killed the server twice during ALTER TABLE).

We might want the server startup to remove the files. But maybe we should not do that until we have crash-safe DDL (MDEV-11655).

So, until the server bug has been fixed, maybe mysql-test-run should complain about the extra #sql*.frm files at the end of each test, and remove them before the next test starts.

Comment by Marko Mäkelä [ 2017-10-09 ]

The test innodb.instant_alter_crash was added in MDEV-11369.

Generated at Thu Feb 08 08:10:21 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.