Bug #67595 Conflicting table spaces upon application restart
Submitted: 15 Nov 2012 5:06 Modified: 28 Nov 2012 5:27
Reporter: Ryan Carpenter Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S2 (Serious)
Version:5.6.7 OS:Windows (Windows 7 Enterprise, SP1, 64 bit)
Assigned to: CPU Architecture:Any

[15 Nov 2012 5:06] Ryan Carpenter
Description:
Upon restarting the DB server one day, the MySQL service failed to start. All further attempts resulted in the same message in the error log:

InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
121110 21:50:14  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
121110 21:50:14 [ERROR] InnoDB:  InnoDB: Error: Attempt to open a tablespace previously opened.
Previous tablespace mysql/innodb_table_stats uses space ID: 1 at filepath: .\mysql\innodb_table_stats.ibd
Cannot open tablespace recipe_manager/category which uses space ID: 1 at filepath: .\recipe_manager\category.ibd

InnoDB: Error: could not open single-table tablespace file .\recipe_manager\category.ibd
InnoDB: We do not continue the crash recovery, because the table may become
InnoDB: corrupt if we cannot apply the log records in the InnoDB log to it.
InnoDB: To fix the problem and start mysqld:
InnoDB: 1) If there is a permission problem in the file and mysqld cannot
InnoDB: open the file, you should modify the permissions.
InnoDB: 2) If the table is not needed, or you can restore it from a backup,
InnoDB: then you can remove the .ibd file, and InnoDB will do a normal
InnoDB: crash recovery and ignore that table.
InnoDB: 3) If the file system or the disk is broken, and you cannot remove
InnoDB: the .ibd file, you can set innodb_force_recovery > 0 in my.cnf
InnoDB: and force InnoDB to continue crash recovery here.

This was curious as I did not experience a server crash. Because I would have been able to restore the particular table from backup, I followed the instructions in the error log and removed (actually renamed in my case to category.ibd_old) the ibd file and restarted the server again. This time I got the same message for another table:

InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
121114 22:34:30  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
121114 22:34:30 [ERROR] InnoDB:  InnoDB: Error: Attempt to open a tablespace previously opened.
Previous tablespace mysql/innodb_index_stats uses space ID: 2 at filepath: .\mysql\innodb_index_stats.ibd
Cannot open tablespace recipe_manager/component which uses space ID: 2 at filepath: .\recipe_manager\component.ibd

InnoDB: Error: could not open single-table tablespace file .\recipe_manager\component.ibd
InnoDB: We do not continue the crash recovery, because the table may become
InnoDB: corrupt if we cannot apply the log records in the InnoDB log to it.
InnoDB: To fix the problem and start mysqld:
InnoDB: 1) If there is a permission problem in the file and mysqld cannot
InnoDB: open the file, you should modify the permissions.
InnoDB: 2) If the table is not needed, or you can restore it from a backup,
InnoDB: then you can remove the .ibd file, and InnoDB will do a normal
InnoDB: crash recovery and ignore that table.
InnoDB: 3) If the file system or the disk is broken, and you cannot remove
InnoDB: the .ibd file, you can set innodb_force_recovery > 0 in my.cnf
InnoDB: and force InnoDB to continue crash recovery here.

Note that it's the same problem, but with a different set of conflicting tables and a different space ID. If I also rename the idb file for this table, I then get the exact same message for a third pair of tables with the next space ID:

InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
121114 22:38:27  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
121114 22:38:27 [ERROR] InnoDB:  InnoDB: Error: Attempt to open a tablespace previously opened.
Previous tablespace mysql/slave_relay_log_info uses space ID: 3 at filepath: .\mysql\slave_relay_log_info.ibd
Cannot open tablespace recipe_manager/cooking_method which uses space ID: 3 at filepath: .\recipe_manager\cooking_method.ibd

InnoDB: Error: could not open single-table tablespace file .\recipe_manager\cooking_method.ibd
InnoDB: We do not continue the crash recovery, because the table may become
InnoDB: corrupt if we cannot apply the log records in the InnoDB log to it.
InnoDB: To fix the problem and start mysqld:
InnoDB: 1) If there is a permission problem in the file and mysqld cannot
InnoDB: open the file, you should modify the permissions.
InnoDB: 2) If the table is not needed, or you can restore it from a backup,
InnoDB: then you can remove the .ibd file, and InnoDB will do a normal
InnoDB: crash recovery and ignore that table.
InnoDB: 3) If the file system or the disk is broken, and you cannot remove
InnoDB: the .ibd file, you can set innodb_force_recovery > 0 in my.cnf
InnoDB: and force InnoDB to continue crash recovery here.

So it appears that somehow between restarts the space IDs came into conflict between the mysql DB and the recipe_manager DB.

I had experienced a similar problem when installing the product, but repeated the install without one of the sample DBs and it installed fine. The server had then worked fine for several weeks before this problem came up again.

I can restore my DB from a previous week's backup without a loss of too much data (none of which is critically important), but I do need to determine how to avoid this problem in the future as this will obviously not be acceptable in a production environment.

How to repeat:
Defect is repeated exactly every time I attempt to start the MySQL Server. It is not clear to me how I would take a functioning DB and reproduce the space ID conflict.
[19 Nov 2012 7:37] Sunny Bains
If the database was shutdown cleanly then it is difficult to understand why it is reporting that there is a mismatch between the system tablespace flushed LSN and the REDO log max LSN. I can think of the following two possibilities:

  1. Running inside a VM that doesn't honour fsync()

  2. HW issue where a write -> fsync() is not honoured.

In the bug report you mention that it is repeatable, can you try on different HW and see if it is repeatable. If so can you please post the exact steps required to reproduce this problem so that we can try the same.
[19 Nov 2012 20:27] Sunny Bains
First off, we don't know whether it is a bug yet or not. Therefore it is difficult to figure out what to fix. If the system tablespace header is corrupt, for whatever reason, then all bets are off.

1. We need to avoid the hibernate, to rule that out

2. We need to be sure that it was a clean shutdown.

    a. Even if it wasn't a clean shutdown, the space id mismatch shouldn't happen

Is it possible for you to tar up the files and upload them here?
[25 Nov 2012 7:26] Sunny Bains
Ryan, thanks for the files, I've downloaded them.
[25 Nov 2012 7:36] Sunny Bains
Ryan, did you change the InnoDB log file size recently? Do you have the error log file?
[25 Nov 2012 9:00] Sunny Bains
Ryan, Ignore the previous question about the REDO log. I can recover the files (by tweaking the code) and the data looks OK. Though I don't have anything to compare it with: e.g.,

mysql> select count(*) from recipe;
+----------+
| count(*) |
+----------+
|      807 |
+----------+
1 row in set (0.01 sec)

I need to confirm the underlying cause of the bug but currently it does look like a bug in the tablespace (.ibd) load code. Thank you very much for uploading the files. It has helped a lot in confirming and narrowing down the issue. I will set the bug state to verified, I'm reasonably confident that there is a bug.
[25 Nov 2012 9:34] Sunny Bains
Ryan, did you copy the the .ibd files from another instance directly into your 5.6 data directory. Or, did you create a new installation of 5.6 from scratch and then created your tables in this new instance?
[25 Nov 2012 9:42] Sunny Bains
I can reproduce the exact same error by doing the following:

 1. Create an empty database in 5.5
 2. Create a table test/t1
 4. Shutdown
 5. Create an empty database in 5.6
 6. Copy the test/t1.*, ib_logfile* and ibdata1 to the 5.6 installation
 7. Start 5.6 and get the exact same failure

I can also explain why that happens, in 5.6 we now have some replication tables and the persistent stats tables as InnoDB tables. This causes the space id conflict.
[26 Nov 2012 15:49] Ryan Carpenter
I can confirm that the data looks good. 807 records in that particular table is just about right.

When creating the DB, I created the installation from scratch and then created the tables using a data dump backup from a previous installation with mysqldump and the mysql command. I did not copy the ibd files from another installation.

One additional note, if it's helpful: I had the exact same DB schemas (Recipe_Manager and Recipe_Manager_dev) in a previous installation of MySQL 5.6 (in that case 32 bit) which I had installed last spring, and worked fine up until I had to re-install MySQL for a hardware upgrade late this October. It may be that the particular defect was introduced in one of the more recent releases of MySQL 5.6 that came out since March(ish), or that the problem is unique to the 64-bit installation which I'm currently running.

Let me know if there's any more information you need.
[26 Nov 2012 20:10] Sunny Bains
Ryan, what was the version number of the original 5.6 installation where you created the tables?
[26 Nov 2012 20:14] Ryan Carpenter
According to the header at the top of the dump file, it was 5.6.5-m8:

-- MySQL dump 10.13  Distrib 5.6.5-m8, for Win32 (x86)
--
-- Host: localhost    Database: recipe_manager
-- ------------------------------------------------------
-- Server version	5.6.5-m8
[27 Nov 2012 8:39] Sunny Bains
This is a duplicate of bug#67179. Just different side effect. The Windows installer apparently copied the .ibd files around and that caused the problem. The ones in data/mysql. If you want to recover your files you will have to do the following:

  1. Delete the data/mysql/*.ibd files and the corresponding .frm files for the .ibd files
  2. Start the server with --skip-slave-start
  3. You should be able to access and backup your data

What I noticed was that on shutdown, you will get another failure. I need to investigate the cause of this other issue. I will post an update on this later.
[27 Nov 2012 23:32] Ryan Carpenter
That did the trick. Everything seems to be behaving as expected now. Thanks very much.

One thing that isn't clear, though--should this permanently resolve the issue and I'm good to resume using the DB as-is, or should I re-install with a more recent version of MySQL with a patch later if/when it's available?

Upon shutting down the server, I was not able to reproduce the shutdown problem you were describing. The windows error logs were clean and didn't show anything strange that occurred during the shutdown.

thanks
[28 Nov 2012 5:27] Erlend Dahl
Duplicate of Bug#67179
[9 Aug 2014 23:18] Jonathan Alpha
I'm having this exact same problem.  I have a cpanel hosting server with 76 databases.  I upgraded from 5.5 to 5.6 a few weeks ago.  Everything seemed to be running fine until a week and a half ago mysql crashed.  And I couldn't restart it using the normal commands.

I asked the web hosting company to look at it and they had to bump it up to Tier 1 support to get somebody who could figure it out.  But they never told me what they did.

Then two nights ago mysql crashed again.  The web hosting company got it up and running again, but I started to notice some of the websites' databases weren't working.  While others were.  

Yesterday I went into cpanel and deleted the affected databases, and then restored them (through cpanel) from the backup copy from a couple of days before.  

Everything worked fine on these accounts after that.  

Then all of a sudden mysql crashed today AGAIN!  I checked the log files and saw the exact same errors that the OP described here.  And same thing happened, if I deleted (renamed) the mentioned files in the error log, it would just do it again the next time I tried to restart mysql and it would give the same errors for a different website.

I read through all of the comments here, but I wasn't clear on the solution.  

  1. Delete the data/mysql/*.ibd files and the corresponding .frm files for the .ibd files

(Really?  We can delete those files and it won't destroy the database)?  

  2. Start the server with --skip-slave-start

(I have no idea what this means)!

  3. You should be able to access and backup your data

(That's what I'm hoping)!

Could you help walk me through this process for a cpanel server by any chance?  Thank you so much for any help you can give!