Dealing with Assertion failure in log/log0recv.c – !page || (ibool)!!page_is_comp(page) == dict_table_is_comp(index->table)

This is a somewhat uncommon error, so I wanted to take a moment and post the error and an explanation in order to make it easier for those who run into this in the future.

The main error is this (full pasted below):

InnoDB: Assertion failure in thread 139838283589376 in file log/log0recv.c line 1094
InnoDB: Failing assertion: !page || (ibool)!!page_is_comp(page) == dict_table_is_comp(index->table)

Basically, this is what it can look like after a power outage. In fact, this is the only time I have seen it, but I won’t say that it is the only way you could encounter it.

How do I deal with this, you ask?

Well, the above error shows that the internal InnoDB dictionary is corrupt.

Unfortunately, in this situation, you must recreate the tablespace. And if you don’t have a current backup + binlogs, then that means you will also need to force InnoDB recovery (i.e., set innodb_force_recovery) in order to dump all of your data.

Once you have the dump, you will need to start from scratch with InnoDB, so to speak. This means deleting (or copy to safe location) all ib_logfile*, ibdata*, *.ibd, and *.frm of all InnoDB tables. Then, remove the innodb_force_recovery option and restart mysqld (allowing it to create new ibdata file(s) and ib_logfile files). And finally, reimport the data you obtained from the mysqldump.

Now, I should reiterate that this was due to a power failure. It is possible for InnoDB to handle this in a more graceful fashion (perhaps less/no corruption), but it invloves setting the following two variables (warning: both will have an impact on performance, so best to test thoroughly before implementing in production):

sync_binlog = 1
innodb_flush_log_at_trx_commit = 1

For sync_binlog:

“A value of 1 is the safest choice because in the event of a crash you lose at most one statement or transaction from the binary log. However, it is also the slowest choice (unless the disk has a battery-backed cache, which makes synchronization very fast).”

http://dev.mysql.com/doc/refman/5.5/en/replication-options-binary-log.html#sysvar_sync_binlog

For innodb_flush_log_at_trx_commit:

“When the value is 1 (the default), the log buffer is written out to the log file at each transaction commit and the flush to disk operation is performed on the log file. … The default value of 1 is required for full ACID compliance. You can achieve better performance by setting the value different from 1, but then you can lose up to one second worth of transactions in a crash. With a value of 0, any mysqld process crash can erase the last second of transactions. With a value of 2, only an operating system crash or a power outage can erase the last second of transactions. InnoDB’s crash recovery works regardless of the value. … For the greatest possible durability and consistency in a replication setup using InnoDB with transactions, use innodb_flush_log_at_trx_commit=1 and sync_binlog=1 in your master server my.cnf file.”

However, even with both of these set, do note this caution stated in the manual:

“Caution: Many operating systems and some disk hardware fool the flush-to-disk operation. They may tell mysqld that the flush has taken place, even though it has not. Then the durability of transactions is not guaranteed even with the setting 1, and in the worst case a power outage can even corrupt the InnoDB database. Using a battery-backed disk cache in the SCSI disk controller or in the disk itself speeds up file flushes, and makes the operation safer. You can also try using the Unix command hdparm to disable the caching of disk writes in hardware caches, or use some other command specific to the hardware vendor.”

http://dev.mysql.com/doc/refman/5.5/en/innodb-parameters.html#sysvar_innodb_flush_log_at_trx_commit

And for more details on the how “some disk hardware fool the flush-to-disk operation”, then please see the following links:

http://peter-zaitsev.livejournal.com/12639.html
http://brad.livejournal.com/2116715.html?thread=10292331
http://bugs.mysql.com/bug.php?id=29221

For reference, here is the full error log snippet (after starting up mysqld after the outage):

111026 22:44:35 mysqld_safe Starting mysqld daemon with databases from /mysql/data
111026 22:44:35 [Note] PrimeBase XT (PBXT) Engine 1.0.11-7 Pre-GA loaded...
111026 22:44:35 [Note] Paul McCullagh, PrimeBase Technologies GmbH, http://www.primebase.org
111026 22:44:35 [Note] The server was not shutdown correctly, recovery required
InnoDB: The InnoDB memory heap is disabled
InnoDB: Mutexes and rw_locks use GCC atomic builtins
InnoDB: Compressed tables use zlib 1.2.3
111026 22:44:37  InnoDB: highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 363485996068
111026 22:44:37  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...
InnoDB: Doing recovery: scanned up to log sequence number 363487670956
111026 22:44:38  InnoDB: Error: page 4 log sequence number 363490119646
InnoDB: is in the future! Current system log sequence number 363487670956.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-recovery.html
InnoDB: for more information.
111026 22:44:38  InnoDB: Assertion failure in thread 139838283589376 in file log/log0recv.c line 1094
InnoDB: Failing assertion: !page || (ibool)!!page_is_comp(page) == dict_table_is_comp(index->table)
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-recovery.html
InnoDB: about forcing recovery.
111026 22:44:38 [ERROR] mysqld got signal 6 ;
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=0
read_buffer_size=131072
max_used_connections=0
max_threads=202
threads_connected=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 1683122 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
thd: 0x0
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 = (nil) thread_stack 0x40000
111026 22:44:38  InnoDB: Error: page 147457 log sequence number 363487671024
InnoDB: is in the future! Current system log sequence number 363487670956.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-recovery.html
InnoDB: for more information.
Fatal signal 11 while backtracing
/usr/sbin/mysqld(my_print_stacktrace+0x2e) [0x99199e]
/usr/sbin/mysqld(handle_segfault+0x353) [0x5e9563]
/lib64/libpthread.so.0(+0xf490) [0x7f3514595490]
/lib64/libc.so.6(gsignal+0x35) [0x7f3513881905]
/lib64/libc.so.6(abort+0x175) [0x7f35138830e5]
/usr/sbin/mysqld() [0x89ee6f]
/usr/sbin/mysqld() [0x8a0322]

 

All in all, hope you never encounter this, but if you do, hopefully this helps you get on the right track sooner than later. :)

 
 
 

Tags: , , , , , , , , , , , , , , , ,

2 Responses to “Dealing with Assertion failure in log/log0recv.c – !page || (ibool)!!page_is_comp(page) == dict_table_is_comp(index->table)”

  1. Wlad says:

    I think there is possily some misunderstanding about innodb_flush_log_at_trx_commit. If it is set to 1, Innodb will fsync more often, but that does not guarantee that you’re safe if you get power outage. If it crashes during fsync(), you get data written partially on disk. If fsync() is called more often with innodb_flush_log_at_trx_commit=1, the probability of partial write in case of the power outage actually increases, not decreases.

    So, for me innodb_flush_log_at_trx_commit depends entirely on the application requirements. If one deals with payments and durability is strong requirement, setting it to 1 is in order. If it is ok to lose data of the last second (like, posts to blog or stuff like that) in case of crash, than 0 or 1 is fine.

    But if you want to prevent data corruption on disk dur to partial writes, then probably only battery backed cache will do that.

  2. Dimitri says:

    You have to use doublewrite buffer to avoid partial page writes and as following data files corruptions.. – it was explicitly implemented for such cases..

    Rgds,
    -Dimitri


Period Panties by Period Panteez Menstrual Underwear Menstruation PMS Panty