MySQL Bugs: #65181: The tablespace free space info is corrupt

Bug #65181	The tablespace free space info is corrupt
Submitted:	2 May 2012 13:43	Modified:	22 May 2012 17:59
Reporter:	Alex	Email Updates:
Status:	Not a Bug	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S2 (Serious)
Version:	5.1.41-3ubuntu12	OS:	Linux (Ubuntu 10.04 LTS)
Assigned to:		CPU Architecture:	Any

Description:
Mysql Version: 5.1.41-3ubuntu12
Storage Engine: InnoDB using raw partition to store InnoDB data.

During a long query I hard stopped the machine on which mysql server was running. After reboot mysql was not able to start due to InnoDB corrupt database. Here are some logs:

120502 11:29:22  InnoDB: Error: page 383 log sequence number 0 659092428
InnoDB: is in the future! Current system log sequence number 0 88846.
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.
InnoDB: Dump of the tablespace extent descriptor:  len 40; hex 000000000000001a00000000013e00000000018e00000004ffbfffbffffffebfbfffbeefffffffff; asc              >                          ;
InnoDB: Serious error! InnoDB is trying to free page 371
InnoDB: though it is already marked as free in the tablespace!
InnoDB: The tablespace free space info is corrupt.
InnoDB: You may need to dump your InnoDB tables and recreate the whole
InnoDB: database!
InnoDB: Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-recovery.html
InnoDB: about forcing recovery.
120502 11:29:22  InnoDB: Assertion failure in thread 2943466352 in file ../../../storage/innobase/fsp/fsp0fsp.c line 3007
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.
120502 11:29:22 - 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=16777216
read_buffer_size=131072
max_used_connections=0
max_threads=151
threads_connected=0
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 345919 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 0x30000
/usr/sbin/mysqld(my_print_stacktrace+0x2d) [0xb75aa30d]
/usr/sbin/mysqld(handle_segfault+0x494) [0xb72763d4]
[0xb6ff1400]
/lib/libc.so.6(abort+0x182) [0xb6d0dab2]
/usr/sbin/mysqld(+0x486851) [0xb7495851]
/usr/sbin/mysqld(btr_page_free_low+0x122) [0xb7521cd2]
/usr/sbin/mysqld(btr_compress+0x684) [0xb7525354]
/usr/sbin/mysqld(btr_cur_compress_if_useful+0xe7) [0xb7458b97]
/usr/sbin/mysqld(btr_cur_pessimistic_delete+0x332) [0xb745a522]
/usr/sbin/mysqld(+0x4d8e41) [0xb74e7e41]
/usr/sbin/mysqld(row_purge_step+0x67b) [0xb74e864b]
/usr/sbin/mysqld(que_run_threads+0x5b0) [0xb74d38b0]
/usr/sbin/mysqld(trx_purge+0x375) [0xb7505e65]
/usr/sbin/mysqld(srv_master_thread+0xf80) [0xb74fca50]
/lib/libpthread.so.0(+0x57f0) [0xb6fd67f0]
/lib/libc.so.6(clone+0x5e) [0xb6daf3de]

I've read Bug 55284 but I'm not sure if this is the same problem.

Thx,
Alex

How to repeat:
We didn't find a way to reproduce this but the problem appeared when we hard rebooted the machine when a heavy query was executed on mysql server.

mysql configuration file

Attachment: my.cnf (application/octet-stream, text), 3.64 KiB.

mysql error log file

Attachment: error.log (application/octet-stream, text), 452.11 KiB.

I want to mention that InnoDB data is stored on raw partitions:

[mysqld]
..........
innodb_data_home_dir   =
innodb_data_file_path  = /dev/sda9:1Graw
innodb_file_per_table = 0
...........

After setting innodb_force_recovery = 2 in my.cnf I tried to make a dump of our databases but with no success. Output of mysqldump:

mysqldump: Error 2013: Lost connection to MySQL server during query when dumping table `SystemEvents` at row: 384281

and when setting  innodb_force_recovery = 4 the error was:

mysqldump: Got error: 2013: Lost connection to MySQL server during query when using LOCK TABLES

Thank you for the report.

I doubt this is Bug #55284: that bug hit assertion in another place.

In your case problem is dataspace corruption. Does innodb_force_recovery allows to make dump?

Please also check operating system logs in case if there was disk failure.

No, we are not able to make a dump using mysqldump. Here are the test we did:

innodb_force_recovery = 2 in my.cnf I tried to make a dump of our databases but with no success. Output of mysqldump:

mysqldump: Error 2013: Lost connection to MySQL server during query when dumping table `SystemEvents` at row: 384281

and when setting  innodb_force_recovery = 4 the error was:

mysqldump: Got error: 2013: Lost connection to MySQL server during query when using LOCK TABLES

There was no disk failure.

Thank you for the feedback.

But what did you get with innodb_force_recovery = 6?

Setting innodb_force_recovery = 6 didn't changed anything. Mysql is starting but I'm not able to make a dump of the database.

I'll attache the log file.

Log file when setting innodb_force_recovery = 6

Attachment: error2.log (application/octet-stream, text), 3.81 KiB.

Thank you for the feedback.

I assume mysqldump with default options is not good tool to make backup of corrupted table. Try to use SELECT * INTO OUTFILE

After a re-install I was not able to reproduce the problem... even having a dd image of the partition used to store innodb data. I forget to also make a backup of /var/lib/mysql and because of this (I suppose) I'm not able to start mysql not even with innodb_force_recovery = 6

But beside the fact I'm not able to make a dump of mysql data, is the problem reported initially a bug?

Thx,
Alex

Thank you for the feedback.

> But beside the fact I'm not able to make a dump of mysql data, is the problem reported initially a bug?

In the initial description you wrote:

> During a long query I hard stopped the machine on which mysql server was running.

If you hard stopped the machine mysqld could not close all used files properly, therefore it is not a bug it could not stopped, because corruption. You should do InnoDB Force Recovery. So this is not a bug since force recovery works.