MySQL Innodb corruption

innodbMySQL

I recently inherited a Drupal site that has an Innodb corruption. MySQL will run for sometime–usually about 24-hours but will eventually need to be manually restarted(see log output below). I have tried/verified the following:

Renamed existing logfiles, then increased the size of the logfiles to 64M and now up to 256M.
Verified there is plenty of memory
Started in innodb_force_recovery = 4
Verified that every table is ok with CHECK TABLE

Despite all these efforts the problem persists. I don't have a stable backup to recover from. I have read that I may need to do the following:

backup the datadir
uninstall MySQL
reinstall

but I don't understand what this would fix since all the tables pass the CHECK TABLE query.

Here is a sample of my log files. This activity goes back a year:

Number of processes running now: 0
120424 16:05:25  mysqld restarted
120424 16:05:58  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
120424 16:06:14  InnoDB: Starting log scan based on checkpoint at
InnoDB: log sequence number 12 657040373.
InnoDB: Doing recovery: scanned up to log sequence number 12 657234827
120424 16:06:14  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 
InnoDB: Apply batch completed
120424 16:06:14  InnoDB: Started; log sequence number 12 657234827
120424 16:06:15 [Note] /usr/libexec/mysqld: ready for connections.
Version: '5.0.45'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  Source distribution
Number of processes running now: 0
120424 16:11:27  mysqld restarted
120424 16:11:28  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
120424 16:11:28  InnoDB: Starting log scan based on checkpoint at
InnoDB: log sequence number 12 661789262.
InnoDB: Doing recovery: scanned up to log sequence number 12 661789262
120424 16:11:28  InnoDB: Started; log sequence number 12 661789262
120424 16:11:28 [Note] /usr/libexec/mysqld: ready for connections.
Version: '5.0.45'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  Source distribution
Number of processes running now: 0
120424 16:17:48  mysqld restarted
120424 16:17:49  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
120424 16:17:49  InnoDB: Starting log scan based on checkpoint at
InnoDB: log sequence number 12 662677386.
InnoDB: Doing recovery: scanned up to log sequence number 12 662677386
120424 16:17:49  InnoDB: Started; log sequence number 12 662677386
120424 16:17:49 [Note] /usr/libexec/mysqld: ready for connections.
Version: '5.0.45'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  Source distribution

And here is my my.cnf:

[mysqld]
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
user=mysql
#innodb_force_recovery = 4 
# Default to using old password format for compatibility with mysql 3.x
# clients (those using the mysqlclient10 compatibility package).
old_passwords=1
innodb_log_file_size=256M
[mysqld_safe]
log-error=/var/log/mysqld.log
pid-file=/var/run/mysqld/mysqld.pid

Here is my SHOW ENGINE output:

+------------+---------+----------------------------------------------------------------+
| Engine     | Support | Comment                                                        |
+------------+---------+----------------------------------------------------------------+
| MyISAM     | DEFAULT | Default engine as of MySQL 3.23 with great performance         | 
| MEMORY     | YES     | Hash based, stored in memory, useful for temporary tables      | 
| InnoDB     | YES     | Supports transactions, row-level locking, and foreign keys     | 
| BerkeleyDB | YES     | Supports transactions and page-level locking                   | 
| BLACKHOLE  | NO      | /dev/null storage engine (anything you write to it disappears) | 
| EXAMPLE    | NO      | Example storage engine                                         | 
| ARCHIVE    | NO      | Archive storage engine                                         | 
| CSV        | NO      | CSV storage engine                                             | 
| ndbcluster | NO      | Clustered, fault-tolerant, memory-based tables                 | 
| FEDERATED  | NO      | Federated MySQL storage engine                                 | 
| MRG_MYISAM | YES     | Collection of identical MyISAM tables                          | 
| ISAM       | NO      | Obsolete storage engine                                        | 
+------------+---------+----------------------------------------------------------------+

Best Answer

Since the InnoDB Storage Engine looks operational at the time mysql is restated, you should take the time to cleanup the InnoDB infrastructure

mysqldump the entire database instance
reconfigure innodb from scratch
- Start over with a fresh ibdata1 file
  1. Empty Undo Space
  2. Empty Rollback Segments
  3. Empty Data Dictionary
  4. Empty List of Tablespace IDs
- Store Each InnoDB table in its own tablespace
- Configure Buffer Pool to be 4 times the Log File Size
- Perform Better Flushing of the Buffer Pool
reload mysql data

Add this to my.cnf

[mysqld]   
datadir=/var/lib/mysql   
socket=/var/lib/mysql/mysql.sock   
user=mysql   
#innodb_force_recovery = 4    
# Default to using old password format for compatibility with mysql 3.x   
# clients (those using the mysqlclient10 compatibility package).   
old_passwords=1   
innodb_log_file_size=256M   
innodb_file_per_table
innodb_buffer_pool_size=1G
innodb_flush_method=O_DIRECT
[mysqld_safe]   
log-error=/var/log/mysqld.log   
pid-file=/var/run/mysqld/mysqld.pid

Run these commands to install mysql in a new folder

service mysql restart --skip-networking --skip-grant-tables
mysqldump --all-databases --routines --triggers > /root/MySQLData.sql
service mysql stop
mv /var/lib/mysql /var/lib/mysql_old
mkdir /var/lib/mysql
mkdir /var/lib/mysql/mysql
cp /var/lib/mysql_old/mysql/* /var/lib/mysql/mysql/.
chown -R mysql:mysql /var/lib/mysql/mysql/.
service mysql start --skip-networking --skip-grant-tables
mysql < /root/MySQLData.sql
service mysql restart

Give it a Try !!!

ASPECT #1

The first thing that caught my eye was this line

InnoDB: Error: trying to load index PRIMARY for table /

This indicates you have a table using the InnoDB Storage Engine

What is interesting about InnoDB is the way a PRIMARY KEY is stored. It is stored in a structure called the gen_clust_index, or more commonly known as the Clustered Index.

My immediate guess is that a certain PRIMARY KEY entry is too big

Please consider some articles on the good, the bad, and the ugly of using long PRIMARY KEYs:

then see if the <DB Hidden>.<Table Hidden> needs to be redesigned.

ASPECT #2

In terms of your conjecture concerning a parallel truncate table, that sounds kind of dangerous. Why? InnoDB performs TRUNCATE TABLE as DDL not DML. I have written about this before:

Jul 09, 2012 : What can cause TRUNCATE TABLE to take a really long time?
Jan 17, 2012 : Problem with InnoDB "per table" file sizes
Sep 28, 2011 : How to Recover an InnoDB table whose files were moved around

ASPECT #3

Some tuning suggestions

Please add the following to my.ini

[mysqld]
max_allowed_packet=1G
innodb_fast_shutdown=0

Start mysql

In another session, run tail -f <errorlogfile> and watch InnoDB Crash Recovery.

If mysql is fully started back up and InnoDB crash recovery has completed, try to shut mysql down immediately. You may need to resize your InnoDB Transaction Logs.

Sorry for these wild suggestions, but I am flying blind here.

Please post the following in the question:

your entire my.cnf
how much RAM is on board

UPDATE 2012-12-05 12:09 EDT

Please do the following:

STEP 01) Add these changes to my.cnf

[mysqld]
max_allowed_packet=1G
innodb_fast_shutdown=0
innodb_thread_concurrency=0

STEP 02) service mysql restart

to make sure mysql comes up

STEP 03) You need to resize ib_logfile0 and ib_logfile1 (24M might be too small)

service mysql stop
cd /var/lib/mysql
mv ib_logfile0 ib_logfile0.bak
mv ib_logfile1 ib_logfile1.bak

STEP 04) Add these changes to my.cnf

[mysqld]
innodb_log_file_size=512M
innodb_log_buffer_size=8M

STEP 05) service mysql start

mysqld will recreate ib_logfile0 and ib_logfile1 512M each

Now, try and see what happens....

UPDATE 2012-12-05 12:18 EDT

In the meantime, please read my ServerFault post on the mysql packet and its sizing implication with regard to the innodb_log_file_size and innodb_log_buffer_size as I learned from someone else's ServerFault post.

UPDATE 2012-12-05 14:28 EDT

I edited all references to customer tables out of this question.

The root cause was a damaged page in ibdata1 with data and index pages mixed inside. I helped Andrew migrate data out, recreate ibdata1 with innodb_file_per_table, and Andrew reloaded the data.

Best Answer

Related Solutions

Mysql – How to identify InnoDB table corruption

MySQL INNODB corruption after server crash during concurrent truncate command