Bug #65071 innodb crash with file corruption, probably related to insufficient memory
Submitted: 23 Apr 2012 9:52 Modified: 25 Apr 2012 18:04
Reporter: Aleksander Kamenik Email Updates:
Status: Can't repeat Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S1 (Critical)
Version:5.5.23 OS:Linux (sles11sp2 x86_64 vmware)
Assigned to: CPU Architecture:Any

[23 Apr 2012 9:52] Aleksander Kamenik
Description:
Mysql/InnoDB crashes at various queries, we've seen it with alter table, select as well as truncate. After the crash the InnoDB data files are corrupted. The db comes online only with innodb_force_recovery = 6, 5 does not work.

I've been simply deleting and recreating the datadir, as we're still developing the application.

We've experienced the issue on tables with partitioning by hash as well as linear hash enabled.

From the error file:

07:36:18 UTC - 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=33554432
read_buffer_size=2097152
max_used_connections=3
max_threads=100
thread_count=1
connection_count=1
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 1057909 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 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 = 0 thread_stack 0x30000
/usr/sbin/mysqld(my_print_stacktrace+0x35)[0x7c2f05]
/usr/sbin/mysqld(handle_fatal_signal+0x403)[0x68d013]
/lib64/libpthread.so.0(+0xf7c0)[0x7f334682e7c0]
/usr/sbin/mysqld[0x91b952]
/usr/sbin/mysqld[0x93f697]
/usr/sbin/mysqld[0x8aac36]
/usr/sbin/mysqld[0x94573b]
/usr/sbin/mysqld[0x945ef4]
/usr/sbin/mysqld[0x93b412]
/usr/sbin/mysqld[0x87a5e5]
/usr/sbin/mysqld[0x86e7c0]
/lib64/libpthread.so.0(+0x77b6)[0x7f33468267b6]
/lib64/libc.so.6(clone+0x6d)[0x7f3345abf9cd]
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
120420 10:36:18 mysqld_safe Number of processes running now: 0
120420 10:36:18 mysqld_safe mysqld restarted
120420 10:36:18 [Note] Plugin 'FEDERATED' is disabled.
120420 10:36:18 InnoDB: The InnoDB memory heap is disabled
120420 10:36:18 InnoDB: Mutexes and rw_locks use GCC atomic builtins
120420 10:36:18 InnoDB: Compressed tables use zlib 1.2.3
120420 10:36:18 InnoDB: Using Linux native AIO
120420 10:36:18 InnoDB: Initializing buffer pool, size = 1.0G
120420 10:36:18 InnoDB: Completed initialization of buffer pool
120420 10:36:18 InnoDB: highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 28213299
120420 10:36:18  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 30242700
120420 10:36:19  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 120420 10:36:19  InnoDB: Assertion failure in thread 140358176990976 in file ut0mem.c line 103
InnoDB: Failing assertion: ret || !assert_on_error
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.5/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
07:36:19 UTC - 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=33554432
read_buffer_size=2097152
max_used_connections=0
max_threads=100
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 = 1057909 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 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 = 0 thread_stack 0x30000
/usr/sbin/mysqld(my_print_stacktrace+0x35)[0x7c2f05]
/usr/sbin/mysqld(handle_fatal_signal+0x403)[0x68d013]
/lib64/libpthread.so.0(+0xf7c0)[0x7fa7af0637c0]
/lib64/libc.so.6(gsignal+0x35)[0x7fa7ae24fb55]
/lib64/libc.so.6(abort+0x181)[0x7fa7ae251131]
/usr/sbin/mysqld[0x892f7a]
/usr/sbin/mysqld[0x947036]
/usr/sbin/mysqld[0x8ba506]
/usr/sbin/mysqld[0x9182c9]
/usr/sbin/mysqld[0x8b55d8]
/usr/sbin/mysqld[0x8c392e]
/usr/sbin/mysqld[0x8c3bdd]
/usr/sbin/mysqld[0x918bf0]
/usr/sbin/mysqld[0x91434a]
/usr/sbin/mysqld[0x91476f]
/usr/sbin/mysqld[0x8eb60e]
/usr/sbin/mysqld[0x874d5a]
/usr/sbin/mysqld[0x84632d]
/usr/sbin/mysqld(_Z24ha_initialize_handlertonP13st_plugin_int+0x48)[0x68fa08]
/usr/sbin/mysqld[0x59e82a]
/usr/sbin/mysqld(_Z11plugin_initPiPPci+0xbae)[0x5a22ae]
/usr/sbin/mysqld[0x521516]
/usr/sbin/mysqld(_Z11mysqld_mainiPPc+0x412)[0x522132]
/lib64/libc.so.6(__libc_start_main+0xe6)[0x7fa7ae23bc36]
/usr/sbin/mysqld[0x517df5]
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
120420 10:36:19 mysqld_safe mysqld from pid file /var/lib/mysql/ladu.pid ended

In addition I've been using the innodb_file_per_table setting too.

The binary package was built from the MySQL-5.5.23-1.sles11.src.rpm spec file for SLES11 SP2 x86_64, mysql running on a VMWare ESXi VM. I didn't find anything obvious missing.

The table looks like this:

CREATE TABLE IF NOT EXISTS chunks (
fileID INT NOT NULL, 
position INT NOT NULL, 
data MEDIUMBLOB
) ENGINE=InnoDB PARTITION BY LINEAR HASH(fileID) PARTITIONS 256;

We've seen a crash where we did a select count(*) against a simpler table, which didn't have a blob either and had less partitions (64).

We are trying to reproduce the error now but with the tables having no partitions. If we don't succeed it would point to being an issue with partitioning. I also gave the virtual machine more memory, increased from 2GB to 4GB.

Any ideas how I could narrow this down any more? 

How to repeat:
I don't know how to repeat reliably, as it happens only sometimes seemingly at random.
[24 Apr 2012 11:39] Aleksander Kamenik
It looks like the issue was memory related. I'm unable to reproduce the error now that the memory has been increased to 4gb, regardless of partitioning settings.

Shouldn't this have been handled better by InnoDB?
[25 Apr 2012 18:04] Sveta Smirnova
Thank you for the report.

> It looks like the issue was memory related. I'm unable to reproduce the error now that the
> memory has been increased to 4gb, regardless of partitioning settings.

So closing as "Can't repeat" because this.

> Shouldn't this have been handled better by InnoDB?

This depends from your options. Study how MySQL server uses memory, then analyse. For example, if you set innodb_buffer_pool_size to 2G on your machine with 2G RAM it will take all 2G at the some time moment and crash would be expected behavior. Same for other buffers.