MySQL Bugs: #27803: Crash with assertion failure in fil0fil.c

Bug #27803	Crash with assertion failure in fil0fil.c
Submitted:	13 Apr 2007 8:48	Modified:	16 Jan 2008 18:38
Reporter:	Eric ten Hoeve	Email Updates:
Status:	No Feedback	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S1 (Critical)
Version:	5.0.34-enterprise-gpl-log	OS:	Linux (Fedora Core 5)
Assigned to:	Assigned Account	CPU Architecture:	Any
Tags:	crash, fil0fil.c, ha_innodb.cc, os0sync.c

Description:
Our server crashed with the following error found in mysql.err:

InnoDB: Error: trying to access page number 4142860560 in space 0,
InnoDB: space name /var/lib/mysql/ibdata1,
InnoDB: which is outside the tablespace bounds.
InnoDB: Byte offset 0, len 16384, i/o type 10.
InnoDB: If you get this error at mysqld startup, please check that
InnoDB: your my.cnf matches the ibdata files that you have in the
InnoDB: MySQL server.
070413 2:24:53InnoDB: Assertion failure in thread 1188809024 in file fil0fil.c line 3959
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.0/en/forcing-recovery.html
InnoDB: about forcing recovery.
InnoDB: Thread 1191205184 stopped in file os0sync.c line 546
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=134217728
read_buffer_size=8384512
max_used_connections=140
max_connections=2000
threads_connected=9
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 49275056 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd=0x2aac0abdaa60
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...
Cannot determine thread, fp=0x46dbbfc8, backtrace may not be correct.
Stack range sanity check OK, backtrace follows:
0x766f635f6c636564
Stack trace seems successful - bottom reached
Please read http://dev.mysql.com/doc/mysql/en/using-stack-trace.html and follow instructions on how to resolve the stack trace. Resolved
stack trace is much more helpful in diagnosing the problem, so please do
resolve it
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0xba08580 = drop table ddtemp.mbcov227337
thd->thread_id=57349
The manual page at http://www.mysql.com/doc/en/Crashing.html contains
information that should help you find out what is causing the crash.
InnoDB: Thread 1174165824 stopped in file ha_innodb.cc line 977

Number of processes running now: 0
070413 02:24:54 mysqld restarted

Resolve of stack dump:
resolve_stack_dump -s /tmp/mysqld.sym -n mysqld.stack

0x766f635f6c636564 _end + 1806231612

uname -a:
Linux dbhost.declaratie-direct.nl 2.6.17-1.2139_FC5 #1 SMP Fri Jun 23 12:40:11 EDT 2006 x86_64 x86_64 x86_64 GNU/Linux

How to repeat:
Attemping to drop the table ddtemp.mbcov227337 will immediately crash the server!

Thank you for a problem report. As you can see from the messages, you tried to access some page in InnoDB data file that does not exist. It can be a result of corruption. So, please, check your hardware, send your my.cnf file content and the results of

df -k

for InnoDB data directory.

[root@dbhost mysql]# pwd
/var/lib/mysql
[root@dbhost mysql]# df -k
Filesystem           1K-blocks      Used Available Use% Mounted on
/dev/md0             137890224  75911196  54861436  59% /
/dev/md1             141310760 124601104   9531420  93% /mysql
/dev/sda1               988088     25984    911100   3% /boot
tmpfs                  4078104         0   4078104   0% /dev/shm
10.11.11.121:/var/backups
                     1418752608 824814272 520707264  62% /var/backups

Sorry, my fault. Not "df -k" but ls -l /var/lib/mysql, surely. I want to check InnoDB data file size.

Have you checked for possible hardware failures already?

[root@dbhost mysql]# ls -l /var/lib/mysql
total 20080672
-rw-r--r-- 1 root  root            0 Mar  1 16:39 binlog.txt
-rw-rw---- 1 mysql mysql         148 Apr 12 21:02 dbhost-relay-bin.000001
-rw-rw---- 1 mysql mysql          98 Apr 12 21:02 dbhost-relay-bin.000002
-rw-rw---- 1 mysql mysql         117 Apr 13 02:25 dbhost-relay-bin.000003
-rw-rw---- 1 mysql mysql         117 Apr 13 10:45 dbhost-relay-bin.000004
-rw-rw---- 1 mysql mysql        1768 Apr 13 10:45 dbhost-relay-bin.index
lrwxrwxrwx 1 mysql mysql          10 Oct  4  2006 dd -> /mysql/dd/
drwxrwxr-x 2 mysql mysql     3252224 Apr 13 12:30 ddtemp
drwxrwxr-x 2 mysql mysql        4096 Jul 12  2006 ddvast
-rw-r--r-- 1 mysql mysql          31 Jun 19  2006 ibbackup_binlog_info
-rw-r----- 1 mysql mysql 18215862272 Apr 13 12:30 ibdata1
-rw-r----- 1 mysql mysql   524288000 Apr 13 12:30 ib_logfile0
-rw-r----- 1 mysql mysql   524288000 Apr 13 12:30 ib_logfile1
-rw-r--r-- 1 root  root       312605 Mar  1 16:46 log.zip
-rw-rw---- 1 mysql mysql          74 Apr 10 12:37 master.info
drwx--x--x 2 mysql mysql        4096 Apr 13 00:27 mysql
-rw-rw---- 1 mysql mysql   996626413 Apr 12 21:02 mysql-bin.000371
-rw-rw---- 1 mysql mysql    68617586 Apr 13 02:24 mysql-bin.000372
-rw-rw---- 1 mysql mysql   132938389 Apr 13 10:44 mysql-bin.000373
-rw-rw---- 1 mysql mysql    39935096 Apr 13 12:30 mysql-bin.000374
-rw-rw---- 1 mysql mysql         128 Apr 13 10:45 mysql-bin.index
-rw-rw---- 1 mysql mysql       49296 Apr 13 12:30 mysql.err
-rw-rw---- 1 mysql mysql       55088 Apr 12 21:02 mysql.err-old
-rw-rw---- 1 mysql mysql           6 Apr 13 10:45 mysql.pid
-rw-rw---- 1 mysql mysql    11845837 Apr 13 12:24 mysql-slow-query.log
-rw-r----- 1 root  root      3676911 Feb 11 00:39
mysql-slow-query.log_pre34enterpr
-rw-r----- 1 mysql mysql    20578407 Jan 18 09:35 mysql-slow-query.old
srwxrwxrwx 1 mysql mysql           0 Apr 13 10:45 mysql.sock
-rw-rw---- 1 mysql mysql          31 Apr 13 10:45 relay-log.info
drwxr-xr-x 2 mysql mysql        4096 Jan  9 14:37 test
drwxr-xr-x 2 mysql mysql       12288 Apr  4 06:30 tmp

We have a software raid 1+0 setup and we do have a faulty disk. Also deleting
the table from our replication server (which runs 5.38 enterprise) succeeds as
expected.

Eric,

please post the entire .err log. The first error is usually the most interesting one.

You probably have a corrupt InnoDB table now. You can try running CHECK TABLE ... (warning: for tables bigger than the main memory, CHECK TABLE can lock the table for hours or days).

Regards,

Heikki

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".

Assigning this to Inaam.

Try to decipher the .err file. Can we see any clue why this crashed?

--Heikki

http://bugs.mysql.com/bug.php?id=29266 may be a duplicate.

thd->query at 0xba08580 = drop table ddtemp.mbcov227337

DROP TABLE may try to access some random page in ibdata1.

Eric,

Have you hit this since April? If so, can you please upload the .err file with resolved stack trace? In the case above, we were unable to generate a complete trace, hence we don't have enough information to investigate it further.

regards,
inaam

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".