Bug #62937 InnoDB Page directory corruption
Submitted: 26 Oct 2011 0:32 Modified: 22 Jan 2012 19:57
Reporter: Allan Mak Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S3 (Non-critical)
Version:5.5.15 OS:Linux
Assigned to: CPU Architecture:Any

[26 Oct 2011 0:32] Allan Mak
Description:
MySQL server crashed on RHEL 6.1 32 bit. The server will not start and continuously tries to recover and then start. The server is a read only slave. Details of the dump are:

111024 11:23:13 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
111024 11:23:13 [Note] Plugin 'FEDERATED' is disabled.
111024 11:23:13 InnoDB: The InnoDB memory heap is disabled
111024 11:23:13 InnoDB: Mutexes and rw_locks use InnoDB's own implementation
111024 11:23:13 InnoDB: Compressed tables use zlib 1.2.3
111024 11:23:13 InnoDB: Using Linux native AIO
111024 11:23:14 InnoDB: Initializing buffer pool, size = 2.0G
111024 11:23:16 InnoDB: Completed initialization of buffer pool
111024 11:23:16 InnoDB: highest supported file format is Barracuda.
111024 11:23:18  InnoDB: Waiting for the background threads to start
111024 11:23:19 InnoDB: 1.1.8 started; log sequence number 695890980747
111024 11:23:20 [Note] Recovering after a crash using /var/lib/mysql/logs/mysql-bin
111024 11:23:20 [Note] Starting crash recovery...
111024 11:23:20 [Note] Crash recovery finished.
111024 11:23:22 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.000992' at position 921624816, relay log '/var/lib/mysql/logs/mysql-relay-bin.001738' position: 921624962
111024 11:23:22 [Note] Slave I/O thread: connected to master 'user@172.16.19.4:3306',replication started in log 'mysql-bin.000997' at position 793504255
111024 11:23:22 [Note] Event Scheduler: Loaded 0 events
111024 11:23:22 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.5.15-log'  socket: '/var/lib/mysql/mysql.sock'  port: 13306  MySQL Community Server (GPL)
InnoDB: Page directory corruption: infimum not pointed to
111024 11:23:22  InnoDB: Page dump in ascii and hex (16384 bytes):
 len 16384;

InnoDB: End of page dump
111024 11:23:24  InnoDB: Page checksum 1575996416, prior-to-4.0.14-form checksum 1371122432
InnoDB: stored checksum 0, prior-to-4.0.14-form stored checksum 0
InnoDB: Page lsn 0 0, low 4 bytes of lsn at page end 0
InnoDB: Page number (if stored to page already) 0,
InnoDB: space id (if created with >= MySQL-4.1.1 and stored already) 0
InnoDB: Page may be a freshly allocated page
InnoDB: Page directory corruption: supremum not pointed to
111024 11:23:24  InnoDB: Page dump in ascii and hex (16384 bytes):
 len 16384;

InnoDB: End of page dump
111024 11:23:26  InnoDB: Page checksum 1575996416, prior-to-4.0.14-form checksum 1371122432
InnoDB: stored checksum 0, prior-to-4.0.14-form stored checksum 0
InnoDB: Page lsn 0 0, low 4 bytes of lsn at page end 0
InnoDB: Page number (if stored to page already) 0,
InnoDB: space id (if created with >= MySQL-4.1.1 and stored already) 0
InnoDB: Page may be a freshly allocated page
111024 11:23:26 - mysqld got signal 11 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help diagnose
the problem, but since we have already crashed, something is definitely wrong
and this may fail.

key_buffer_size=268435456
read_buffer_size=262144
max_used_connections=0
max_threads=151
thread_count=0
connection_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 456528 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0xe7d16f0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0xb6d2fd44 thread_stack 0x30000
/usr/sbin/mysqld(my_print_stacktrace+0x39)[0x842c1a9]
/usr/sbin/mysqld(handle_segfault+0x477)[0x8120987]
[0x6c9400]
/usr/sbin/mysqld[0x855caae]
/usr/sbin/mysqld[0x84c6eea]
/usr/sbin/mysqld[0x857a1f9]
/usr/sbin/mysqld[0x857ae7e]
/usr/sbin/mysqld[0x857b35c]
/usr/sbin/mysqld[0x8467281]
/usr/sbin/mysqld[0x8454b5b]
/usr/sbin/mysqld(_ZN7handler12ha_write_rowEPh+0x63)[0x82d9583]
/usr/sbin/mysqld(_Z12write_recordP3THDP5TABLEP12st_copy_info+0x81)[0x818ce31]
/usr/sbin/mysqld(_Z12mysql_insertP3THDP10TABLE_LISTR4ListI4ItemERS3_IS5_ES6_S6_15enum_duplicatesb+0x108d)[0x8194b4d]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x452b)[0x81a709b]
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x116)[0x81ac1b6]
/usr/sbin/mysqld(_ZN15Query_log_event14do_apply_eventEPK14Relay_log_infoPKcj+0x1161)[0x83a19d1]
/usr/sbin/mysqld(_ZN15Query_log_event14do_apply_eventEPK14Relay_log_info+0x32)[0x83a1f42]
/usr/sbin/mysqld(_Z26apply_event_and_update_posP9Log_eventP3THDP14Relay_log_info+0x1b3)[0x8139663]
/usr/sbin/mysqld[0x813be45]
/usr/sbin/mysqld(handle_slave_sql+0xeef)[0x813da9f]
/lib/libpthread.so.0(+0x69e9)[0xacb9e9]
/lib/libc.so.6(clone+0x5e)[0x21cc2e]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0xe7eed4a): insert into ClearingRecord (markAsDeleted, version, acquirerReferenceData_id, clearingFile_id, interchangeRateDesignator, merchantCategoryCode, sourceMessageID, processedPayment_id) values (0, 0, 101, null, '77', '5309', null, 7213)
Connection ID (thread ID): 2
Status: NOT_KILLED

How to repeat:
Not sure how to repeat
[26 Oct 2011 3:32] Valeriy Kravchuk
Can you send entire error log, compressed? 

If page is corrupted all you can do is to try to start with different values of innodb_force_recovery (see http://dev.mysql.com/doc/refman/5.5/en/forcing-innodb-recovery.html) in a hope to dump your data and restore them with new, not corrupted ib* files, or just restore from existing dump/binary logs (as this is read only slave anyway).

What is more interesting in frames of bug report is why server crashed initially.
[26 Oct 2011 4:37] Allan Mak
Hi
The bits I left out of the error log are a whole bunch of zeros, but if you think its useful I can upload the error log. I have since rebuilt the slave but before I did that, I replaced the ib* files from another healthy slave as the files were the exact same size but that did not make any difference. This slave which crashed is a VMware guest and so is the other healthy slave. These guests are on the same hosts using the same shared storage so I too am trying to find out what maybe caused the crash of one slave but didnt affect the other. I did look at maybe using different values of innodb_force_recovery but thought since I had another healthy slave I would use the ib* files from that slave. Would doing the innodb_force_recovery be any different to using the ib* files from the healthy slave?
Thanks
[22 Dec 2011 19:57] Sveta Smirnova
Thank you for the feedback.

Yes, full error log file would be useful.

With replacing InnoDB data files you do some kind of restore of binary backup while innodb_force_recovery fixes existent files. This is up to you to decide which way is best. For verifying if this MySQL bug or not what happened before problem is important, not how exactly you solved it.
[23 Jan 2012 1:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".