MySQL InnoDB – Data Lost After Crash

innodblogmysql-5.6

I found a 6-days rollback in a MySQL 5.6 community edition server installation.
It seems that some logs were lost, and I cannot understand why.

2013-12-22 20:38:54 380 [Note] Plugin 'FEDERATED' is disabled.
2013-12-22 20:38:54 380 [Warning] option 'innodb-autoextend-increment': unsigned value 67108864 adjusted to 1000
2013-12-22 20:38:54 388 InnoDB: Warning: Using innodb_additional_mem_pool_size is DEPRECATED. This option may be removed in future releases, together with the option innodb_use_sys_malloc and with the InnoDB's internal memory allocator.
2013-12-22 20:38:54 380 [Note] InnoDB: The InnoDB memory heap is disabled
2013-12-22 20:38:54 380 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2013-12-22 20:38:54 380 [Note] InnoDB: Compressed tables use zlib 1.2.3
2013-12-22 20:38:54 380 [Note] InnoDB: Not using CPU crc32 instructions
2013-12-22 20:38:54 380 [Note] InnoDB: Initializing buffer pool, size = 86.0M
2013-12-22 20:38:54 380 [Note] InnoDB: Completed initialization of buffer pool
2013-12-22 20:38:54 380 [Note] InnoDB: Highest supported file format is Barracuda.
2013-12-22 20:38:54 380 [Note] InnoDB: The log sequence numbers 5988825 and 5988825 in ibdata files do not match the log sequence number 6057379 in the ib_logfiles!
2013-12-22 20:38:54 380 [Note] InnoDB: Database was not shutdown normally!
2013-12-22 20:38:54 380 [Note] InnoDB: Starting crash recovery.
2013-12-22 20:38:54 380 [Note] InnoDB: Reading tablespace information from the .ibd files...
2013-12-22 20:38:57 380 [Note] InnoDB: Restoring possible half-written data pages 
2013-12-22 20:38:57 380 [Note] InnoDB: from the doublewrite buffer...
2013-12-22 20:39:07 380 [Note] InnoDB: 128 rollback segment(s) are active.
2013-12-22 20:39:07 380 [Note] InnoDB: Waiting for purge to start
2013-12-22 20:39:07 380 [Note] InnoDB: 5.6.13 started; log sequence number 6057379
2013-12-22 20:39:07 380 [Note] Server hostname (bind-address): '*'; port: 3306
2013-12-22 20:39:07 380 [Note] IPv6 is available.
2013-12-22 20:39:07 380 [Note]   - '::' resolves to '::';
2013-12-22 20:39:07 380 [Note] Server socket created on IP: '::'.
2013-12-22 20:39:12 380 [Note] Event Scheduler: Loaded 0 events
2013-12-22 20:39:12 380 [Note] C:/Program Files/MySQL/MySQL Server 5.6/bin\mysqld: ready for connections.

Can you tell me why this occurs and how to restore that data? Is is possible?
Do you think MyISAM tables are safer and a switch could solve this kind of errors?

EDIT

More informations about this puzzle.

  • This machine has a RAID-1 volume.

  • The problem has occourred after a poweroff on 22 december. After this power off I got the previous log and my database had a many-days data rollback. I found the database exactly with data of 14 december.

  • From 14 to 21 december there were many graceful server shutdowns (every evening) and I found a full backup for every day from 14 to 21 december. The 22 december backup has the 8days data gap.

I think this is very strange. I can understand data loss after a poweroff, but I can not understand this so big rollback (8days) because during this 8 days there were many server shutdowns and mysqldump backup confirm that all data was correctly stored.
I supposed there was a innodb log flush problem, but why so big?

Thanks

Best Answer

This log just indicates that you didn't shut down correctly, so upon startup, InnoDB had to do a "crash recovery". It's not the crash recovery that would have lost data -- it's your operating system or hardware. Crash recovery is designed actually to avoid losing data due to crashes (that's its entire purpose).

The log message indicates a severe problem:

The log sequence numbers 5988825 and 5988825 in ibdata files do not match the log sequence number 6057379 in the ib_logfiles!

This likely means that data is not getting to disk effectively either because of a misconfiguration in MySQL, or a misconfiguration of your operating system or hardware.

If you are running with innodb_flush_log_at_trx_commit set to anything other than 1, this is your fault as this is a dangerous setting. If you are running it with 1, this would imply that InnoDB is requesting data to be written to disk and confirmed, but the system is lying to InnoDB about writing it, causing corruption later.

There is no way to get the data back. If you need data that was lost, you must restore it from backup.

MyISAM is definitely not safer, and in fact MyISAM would more than likely have suffered extreme corruption under the same circumstances.

Related Question