Description:
After installing MySQL 5.7.3 (from Windows MSI Installer) InnoDB reports starting "crash recovery" and "ibdata files do not match the log sequence" every time mysqld service starts.
(Extract from error-log)
2013-12-18T13:57:15.223655Z 0 [Note] InnoDB: The log sequence numbers 1583926704082 and 1583926704082 in ibdata files do not match the log sequence number 1917939819615 in the ib_logfiles!
2013-12-18T13:57:15.224655Z 0 [Note] InnoDB: Database was not shutdown normally!
2013-12-18T13:57:15.225655Z 0 [Note] InnoDB: Starting crash recovery.
2013-12-18T13:57:15.226656Z 0 [Note] InnoDB: Reading tablespace information from the .ibd files...
2013-12-18T13:57:16.582791Z 0 [Note] InnoDB: Restoring possible half-written data pages
2013-12-18T13:57:16.582791Z 0 [Note] InnoDB: from the doublewrite buffer...
(Extract from error-log)
I use "NET START/STOP MySQL57" to start and stop the MySQL service, but every time the service restarts I get the same error...
(Extract from error-log)
2013-12-18T13:55:35.495683Z 0 [Note] E:\MySQL Server 5.7\bin\mysqld: Normal shutdown
2013-12-18T13:55:35.498684Z 0 [Note] Giving 4 client threads a chance to die gracefully
2013-12-18T13:55:35.498684Z 0 [Note] Shutting down slave threads
2013-12-18T13:55:37.499884Z 0 [Note] Forcefully disconnecting 4 remaining clients
2013-12-18T13:55:37.500884Z 0 [Warning] E:\MySQL Server 5.7\bin\mysqld: Forcing close of thread 664 user: 'webgcrd'
2013-12-18T13:55:37.501884Z 0 [Warning] E:\MySQL Server 5.7\bin\mysqld: Forcing close of thread 663 user: 'webgcrd'
2013-12-18T13:55:37.503884Z 0 [Warning] E:\MySQL Server 5.7\bin\mysqld: Forcing close of thread 553 user: 'repgcrd'
2013-12-18T13:55:37.504884Z 0 [Warning] E:\MySQL Server 5.7\bin\mysqld: Forcing close of thread 552 user: 'repgcrd'
2013-12-18T13:55:37.505884Z 0 [Note] Event Scheduler: Purging the queue. 0 events
2013-12-18T13:55:37.507885Z 0 [Note] Binlog end
2013-12-18T13:56:19.202054Z 0 [Note] Plugin 'FEDERATED' is disabled.
2013-12-18T13:56:19.208054Z 0 [Note] InnoDB: The InnoDB memory heap is disabled
2013-12-18T13:56:19.209054Z 0 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2013-12-18T13:56:19.209054Z 0 [Note] InnoDB: Uses system mutexes
2013-12-18T13:56:19.210054Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3
2013-12-18T13:56:19.211055Z 0 [Note] InnoDB: Number of pools: 1
2013-12-18T13:56:19.212055Z 0 [Note] InnoDB: Not using CPU crc32 instructions
2013-12-18T13:56:19.214055Z 0 [Note] InnoDB: Initializing buffer pool, total size = 4.0G, instances = 4
2013-12-18T13:56:19.454079Z 0 [Note] InnoDB: Completed initialization of buffer pool
2013-12-18T13:56:19.480081Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2013-12-18T13:56:19.523086Z 0 [Note] InnoDB: The log sequence numbers 1583926704082 and 1583926704082 in ibdata files do not match the log sequence number 1917939421892 in the ib_logfiles!
2013-12-18T13:56:19.524086Z 0 [Note] InnoDB: Database was not shutdown normally!
2013-12-18T13:56:19.525086Z 0 [Note] InnoDB: Starting crash recovery.
2013-12-18T13:56:19.526086Z 0 [Note] InnoDB: Reading tablespace information from the .ibd files...
2013-12-18T13:56:35.946728Z 0 [Note] InnoDB: Restoring possible half-written data pages
2013-12-18T13:56:35.946728Z 0 [Note] InnoDB: from the doublewrite buffer...
2013-12-18T13:56:36.742808Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2013-12-18T13:56:36.743808Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2013-12-18T13:56:36.744808Z 0 [Note] InnoDB: Setting file ".\ibtmp1" size to 12 MB
2013-12-18T13:56:36.745808Z 0 [Note] InnoDB: Database physically writes the file full: wait ...
2013-12-18T13:56:36.905824Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2013-12-18T13:56:36.906824Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2013-12-18T13:56:36.963830Z 0 [Note] InnoDB: Waiting for purge to start
2013-12-18T13:56:37.014835Z 0 [Note] InnoDB: 5.7.3 started; log sequence number 1917939421892
2013-12-18T13:56:37.020835Z 0 [Note] Server hostname (bind-address): '*'; port: 3306
2013-12-18T13:56:37.021835Z 0 [Note] IPv6 is available.
2013-12-18T13:56:37.022836Z 0 [Note] - '::' resolves to '::';
2013-12-18T13:56:37.022836Z 0 [Note] Server socket created on IP: '::'.
2013-12-18T13:56:37.479881Z 0 [Note] Event Scheduler: Loaded 0 events
2013-12-18T13:56:37.479881Z 0 [Note] E:\MySQL Server 5.7\bin\mysqld: ready for connections.
Version: '5.7.3-m13-log' socket: '' port: 3306 MySQL Community Server (GPL)
2013-12-18T13:57:05.812714Z 0 [Note] E:\MySQL Server 5.7\bin\mysqld: Normal shutdown
2013-12-18T13:57:05.812714Z 0 [Note] Giving 2 client threads a chance to die gracefully
2013-12-18T13:57:05.813714Z 0 [Note] Shutting down slave threads
2013-12-18T13:57:07.814914Z 0 [Note] Forcefully disconnecting 2 remaining clients
2013-12-18T13:57:07.815915Z 0 [Warning] E:\MySQL Server 5.7\bin\mysqld: Forcing close of thread 1 user: 'webgcrd'
2013-12-18T13:57:07.816915Z 0 [Warning] E:\MySQL Server 5.7\bin\mysqld: Forcing close of thread 2 user: 'webgcrd'
2013-12-18T13:57:07.817915Z 0 [Note] Event Scheduler: Purging the queue. 0 events
2013-12-18T13:57:07.818915Z 0 [Note] Binlog end
2013-12-18T13:57:14.852618Z 0 [Note] Plugin 'FEDERATED' is disabled.
2013-12-18T13:57:14.854618Z 0 [Note] InnoDB: The InnoDB memory heap is disabled
2013-12-18T13:57:14.854618Z 0 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2013-12-18T13:57:14.855618Z 0 [Note] InnoDB: Uses system mutexes
2013-12-18T13:57:14.856619Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3
2013-12-18T13:57:14.857619Z 0 [Note] InnoDB: Number of pools: 1
2013-12-18T13:57:14.858619Z 0 [Note] InnoDB: Not using CPU crc32 instructions
2013-12-18T13:57:14.860619Z 0 [Note] InnoDB: Initializing buffer pool, total size = 4.0G, instances = 4
2013-12-18T13:57:15.090642Z 0 [Note] InnoDB: Completed initialization of buffer pool
2013-12-18T13:57:15.182651Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2013-12-18T13:57:15.223655Z 0 [Note] InnoDB: The log sequence numbers 1583926704082 and 1583926704082 in ibdata files do not match the log sequence number 1917939819615 in the ib_logfiles!
2013-12-18T13:57:15.224655Z 0 [Note] InnoDB: Database was not shutdown normally!
2013-12-18T13:57:15.225655Z 0 [Note] InnoDB: Starting crash recovery.
2013-12-18T13:57:15.226656Z 0 [Note] InnoDB: Reading tablespace information from the .ibd files...
2013-12-18T13:57:16.582791Z 0 [Note] InnoDB: Restoring possible half-written data pages
2013-12-18T13:57:16.582791Z 0 [Note] InnoDB: from the doublewrite buffer...
2013-12-18T13:57:17.382871Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2013-12-18T13:57:17.383871Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2013-12-18T13:57:17.384871Z 0 [Note] InnoDB: Setting file ".\ibtmp1" size to 12 MB
2013-12-18T13:57:17.385871Z 0 [Note] InnoDB: Database physically writes the file full: wait ...
2013-12-18T13:57:17.534886Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2013-12-18T13:57:17.535886Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2013-12-18T13:57:17.595892Z 0 [Note] InnoDB: Waiting for purge to start
2013-12-18T13:57:17.646898Z 0 [Note] InnoDB: 5.7.3 started; log sequence number 1917939819615
2013-12-18T13:57:17.648898Z 0 [Note] Server hostname (bind-address): '*'; port: 3306
2013-12-18T13:57:17.650898Z 0 [Note] IPv6 is available.
2013-12-18T13:57:17.650898Z 0 [Note] - '::' resolves to '::';
2013-12-18T13:57:17.651898Z 0 [Note] Server socket created on IP: '::'.
2013-12-18T13:57:17.685901Z 0 [Note] Event Scheduler: Loaded 0 events
2013-12-18T13:57:17.686902Z 0 [Note] E:\MySQL Server 5.7\bin\mysqld: ready for connections.
Version: '5.7.3-m13-log' socket: '' port: 3306 MySQL Community Server (GPL)
(Extract from error-log)
How to repeat:
This is happening EVERY time I restart (START and STOP) MySQL service
