MySQL Bugs: #62581: InnoDB: Assertion failure ibuf0ibuf.c line 4185 unrecoverable data crash.

Bug #62581	InnoDB: Assertion failure ibuf0ibuf.c line 4185 unrecoverable data crash.
Submitted:	30 Sep 2011 7:54	Modified:	13 Jan 2012 11:01
Reporter:	Youngwoo Yang	Email Updates:
Status:	Duplicate	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S1 (Critical)
Version:	5.5.15	OS:	Linux (CentOS 5.5 kernel 2.6.18-238)
Assigned to:		CPU Architecture:	Any
Tags:	4185, crash, failing assertion, ibuf0ibuf.c, linux, page_get_n_recs

Description:
 Hi,

I get this assertion failure on mysql 5.5.15 version.

-here is the mysql server errors-

110927 21:56:51  InnoDB: Assertion failure in thread 1126107456 in file ibuf0ibuf.c line 4185
InnoDB: Failing assertion: page_get_n_recs(page) > 1
InnoDB: We intentionally generate a memory trap.
.
.
InnoDB: about forcing recovery.
110927 21:56:51 - mysqld got signal 6 ;
.
.
key_buffer_size=536870912
read_buffer_size=4194304
max_used_connections=446
max_threads=2500
thread_count=341
connection_count=341
.
.
110927 21:56:54 mysqld_safe Number of processes running now: 0
110927 21:56:54 mysqld_safe mysqld restarted
110927 21:56:54 InnoDB: The InnoDB memory heap is disabled
110927 21:56:54 InnoDB: Mutexes and rw_locks use GCC atomic builtins
110927 21:56:54 InnoDB: Compressed tables use zlib 1.2.3
110927 21:56:54 InnoDB: Initializing buffer pool, size = 48.0G
110927 21:56:56 InnoDB: Completed initialization of buffer pool
110927 21:56:56 InnoDB: highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 2476542143668
110927 21:56:56  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 2476547386368
InnoDB: Doing recovery: scanned up to log sequence number 2476552629248
InnoDB: Doing recovery: scanned up to log sequence number 2476557872128
InnoDB: Doing recovery: scanned up to log sequence number 2476563115008
.
.
.
InnoDB: 45 transaction(s) which must be rolled back or cleaned up
InnoDB: in total 45 row operations to undo
InnoDB: Trx id counter is E6B79400
110927 21:58:04  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 0 1 2 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 
110927 21:59:08  InnoDB: Assertion failure in thread 1104251200 in file ibuf0ibuf.c line 4185
InnoDB: Failing assertion: page_get_n_recs(page) > 1
=================

After this error, mysql couldn't recovery complite 
and mysql server had been shutdown.

I tried to do the innodb force recovery.
I couldn't recover crashed data using innodb force recovery level 0 to 3 but level 4.

It turned out I just can sqldump data.

As long as change one of a slavedb as a masterdb, my services out of service.

I'm afraid that a same or similar error will be able to repeat again on the new
masterdb.

Please help me out. plz...

=============================

The crashed mysql server's my.cnf options.

max_allowed_packet = 1024M
net_buffer_length = 32768
binlog_cache_size = 16M
bulk_insert_buffer_size = 64M
datadir = /data/mysql/data
table_cache = 2048
sort_buffer_size = 4M
read_buffer_size = 4M
join_buffer_size = 2M
read_rnd_buffer_size = 4M
myisam_sort_buffer_size = 4M
thread_cache_size = 8
query_cache_size = 1024M
query_cache_limit = 2M
thread_stack = 192K
thread_concurrency = 48
max_connections = 2500
max_connect_errors = 1000
max_heap_table_size = 64M
back_log = 200

innodb_file_per_table = 1
innodb = on
innodb_additional_mem_pool_size = 20M
innodb_buffer_pool_size = 48G
innodb_data_file_path = inno:1G:autoextend
innodb_data_home_dir = /data/mysql/data
innodb_thread_concurrency = 48
innodb_commit_concurrency = 48
innodb_flush_log_at_trx_commit = 1
innodb_log_buffer_size = 8M
innodb_log_file_size = 1024M
innodb_log_files_in_group = 3
innodb_log_group_home_dir = /data/mysql/data
innodb_max_dirty_pages_pct = 90
innodb_lock_wait_timeout = 120
innodb_open_files = 102400

at the point time.
=== status ===
Threads: 354  Questions: 187502669  Slow queries: 209  Opens: 3150  Flush tables: 1  Open tables: 617  Queries per second avg: 4089.301

top - 21:56:01 up 4 days, 20:59,  0 users,  load average: 5.05, 5.41, 5.64
Tasks:   1 total,   0 running,   1 sleeping,   0 stopped,   0 zombie
Cpu(s):  1.5%us,  0.3%sy,  0.0%ni, 95.8%id,  2.2%wa,  0.0%hi,  0.2%si,  0.0%st
Mem:  98929268k total, 97815088k used,  1114180k free,   245976k buffers
Swap:        0k total,        0k used,        0k free, 40979780k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
26019 mysql     15   0 58.1g  52g 7012 S 321.8 55.5   1128:48 mysqld

*after mysql's crashed
=== status ===

top - 21:58:01 up 4 days, 21:01,  0 users,  load average: 2.47, 4.59, 5.33
Tasks:   1 total,   0 running,   1 sleeping,   0 stopped,   0 zombie
Cpu(s):  1.5%us,  0.3%sy,  0.0%ni, 95.8%id,  2.2%wa,  0.0%hi,  0.2%si,  0.0%st
Mem:  98929268k total, 55021972k used, 43907296k free,   246568k buffers
Swap:        0k total,        0k used,        0k free, 40997228k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
13077 mysql     25   0 53.8g  11g 3904 D 86.0 12.3   1:06.61 mysqld

How to repeat:
-

Let me make one wild guess... Do you have AMD CPUs?

Please, send the output of

cat /proc/cpuinfo

processor       : 23
vendor_id       : GenuineIntel
cpu family      : 6
model           : 44
model name      : Intel(R) Xeon(R) CPU           X5690  @ 3.47GHz
stepping        : 2
cpu MHz         : 3458.536
cache size      : 12288 KB
physical id     : 1
siblings        : 12
core id         : 10
cpu cores       : 6
apicid          : 53
fpu             : yes
fpu_exception   : yes
cpuid level     : 11
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm syscall nx pdpe1gb rdtscp lm constant_tsc ida nonstop_tsc arat pni monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr sse4_1 sse4_2 popcnt lahf_lm
bogomips        : 6916.85
clflush size    : 64
cache_alignment : 64
address sizes   : 40 bits physical, 48 bits virtual
power management: [8]

===================

No I've a Intel CPU..

Thanks for your interesting.

A similar crash from yesterday, on Percona Server 5.5.16-55-log, Intel CPU:

111204 23:26:20  InnoDB: Assertion failure in thread 1114233152 in file ibuf0ibuf.c line 4233
InnoDB: Failing assertion: page_get_n_recs(page) > 1
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.
111204 23:26:20 - 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=104857600
read_buffer_size=131072
max_used_connections=25
max_threads=2000
thread_count=1
connection_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 4478603 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 = (nil) thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x39)[0x7ced59]
/usr/sbin/mysqld(handle_segfault+0x379)[0x500e09]
/lib64/libpthread.so.0[0x3bcd80eb10]
/lib64/libc.so.6(gsignal+0x35)[0x3bcd030265]
/lib64/libc.so.6(abort+0x110)[0x3bcd031d10]
/usr/sbin/mysqld[0x9139f1]
/usr/sbin/mysqld[0x8bab6e]
/usr/sbin/mysqld[0x8f3828]
/usr/sbin/mysqld[0x86aaa0]
/lib64/libpthread.so.0[0x3bcd80673d]
/lib64/libc.so.6(clone+0x6d)[0x3bcd0d44bd]
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.
111204 23:26:22 mysqld_safe Number of processes running now: 0
111204 23:26:22 mysqld_safe mysqld restarted

maybe a duplicate of Bug #61104

This is a duplicate of Bug #61104.