Bug #52132 MySQL Server Crash
Submitted: 17 Mar 2010 10:10 Modified: 29 Apr 2010 10:09
Reporter: Eyal Sorek Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server Severity:S1 (Critical)
Version:5.1.44-community OS:Linux (Centos 5.3 64 bit)
Assigned to: CPU Architecture:Any
Tags: crash recover InnoDB Assertion failure buf0flu.c

[17 Mar 2010 10:10] Eyal Sorek
Description:
Two occasions of mysql and/or innodb crash

100316 15:58:28  InnoDB: Assertion failure in thread 1103141184 in file buf/buf0flu.c line 900
InnoDB: Failing assertion: block->state == BUF_BLOCK_FILE_PAGE
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.
100316 15:58:28 - 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=4194304
read_buffer_size=131072
max_used_connections=12
max_threads=1500
threads_connected=11
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 6355353 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
thd: 0xe631e60
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 = 0x41c09118 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x3a)[0x825ffa]
/usr/sbin/mysqld(handle_segfault+0x1fb)[0x5bab3b]
/lib64/libpthread.so.0[0x3f2240e4c0]
/lib64/libc.so.6(gsignal+0x35)[0x3f21830215]
/lib64/libc.so.6(abort+0x110)[0x3f21831cc0]
/usr/sbin/mysqld(buf_flush_batch+0x399)[0x732899]
/usr/sbin/mysqld(log_preflush_pool_modified_pages+0x3e)[0x76b8ce]
/usr/sbin/mysqld[0x76cb01]
/usr/sbin/mysqld(log_check_margins+0x10)[0x76ce50]
/usr/sbin/mysqld(row_ins_index_entry_low+0x638)[0x78e248]
/usr/sbin/mysqld(row_ins_index_entry+0x80)[0x78e2d0]
/usr/sbin/mysqld(row_ins+0x4b)[0x78e48b]
/usr/sbin/mysqld(row_ins_step+0xde)[0x78e79e]
/usr/sbin/mysqld(row_insert_for_mysql+0x10d)[0x79022d]
/usr/sbin/mysqld(_ZN11ha_innobase9write_rowEPh+0x109)[0x7194c9]
/usr/sbin/mysqld(_ZN7handler12ha_write_rowEPh+0x66)[0x689486]
/usr/sbin/mysqld(_ZN12ha_partition9write_rowEPh+0x102)[0x68d9c2]
/usr/sbin/mysqld(_ZN7handler12ha_write_rowEPh+0x66)[0x689486]
/usr/sbin/mysqld(_Z12write_recordP3THDP8st_tableP12st_copy_info+0x78e)[0x62b38e]
/usr/sbin/mysqld(_Z12mysql_insertP3THDP10TABLE_LISTR4ListI4ItemERS3_IS5_ES6_S6_15enum_duplicatesb+0x9bb)[0x62a31b]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x19c5)[0x5c7585]
/usr/sbin/mysqld(_Z11mysql_parseP3THDPKcjPS2_+0x179)[0x5cbc09]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x413)[0x5c4753]
/usr/sbin/mysqld(_Z10do_commandP3THD+0xd0)[0x5c41e0]
/usr/sbin/mysqld(handle_one_connection+0x126)[0x5c3066]
/lib64/libpthread.so.0[0x3f22406367]
/lib64/libc.so.6(clone+0x6d)[0x3f218d2f7d]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x2aab7c1897b0 is an invalid pointer
thd->thread_id=52
thd->killed=NOT_KILLED
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.
100316 15:58:29 mysqld_safe Number of processes running now: 0
100316 15:58:29 mysqld_safe mysqld restarted
100316 15:58:29 [Warning] option 'innodb-autoextend-increment': unsigned value 536870912 adjusted to 1000
InnoDB: Log scan progressed past the checkpoint lsn 1 999251953
100316 15:58:30  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 1 1004494336
InnoDB: Doing recovery: scanned up to log sequence number 1 1009737216
InnoDB: Doing recovery: scanned up to log sequence number 1 1014980096
.
.
100316 16:00:27  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 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...
InnoDB: Apply batch completed
InnoDB: Last MySQL binlog file position 0 748486605, file name ./mysql-bin.000012
100316 16:02:31  InnoDB: Started; log sequence number 1 1764923094
100316 16:02:31 [Note] Recovering after a crash using mysql-bin
100316 16:02:39 [Note] Starting crash recovery...
100316 16:02:39 [Note] Crash recovery finished.
100316 16:02:40 [Note] Event Scheduler: Loaded 0 events
100316 16:02:40 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.1.44-community-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server (GPL)
100316 16:02:40 [Note] Event Scheduler: scheduler thread started with id 1
InnoDB: Database page corruption on disk or a failed
InnoDB: file read of page 264049.
InnoDB: You may have to recover from a backup.
100317  5:26:53  InnoDB: Page dump in ascii and hex (16384 bytes):
 len 16384; hex 2deee4da000407710004076f0004076e0000000156d375e645bf00000000000000000000004100142583805900000000251d00050
000005700000000000000000000000000000000004f0000000000000000000000000000000000000000010002001c696e66696d756d0008000b000073
757072656d756d041a000010006d011a55fb8fb4700000012a6ebc800000002d008480afcabd800000048000000680000002800000046164646280000
.
.
p   R     6       f     J  ""   . z   cC   V u ;InnoDB: End of page dump
100317  5:26:53  InnoDB: Page checksum 1926881690, prior-to-4.0.14-form checksum 1137689333
InnoDB: stored checksum 770630874, prior-to-4.0.14-form stored checksum 1137689333
InnoDB: Page lsn 1 1456698854, low 4 bytes of lsn at page end 1456698854
InnoDB: Page number (if stored to page already) 264049,
InnoDB: space id (if created with >= MySQL-4.1.1 and stored already) 65
InnoDB: Page may be an index page where index id is 0 79
InnoDB: (index "PRIMARY" of table "puma_users"."ad_mapping" /* Partition "p_734213" */)
InnoDB: Database page corruption on disk or a failed
InnoDB: file read of page 264049.
InnoDB: You may have to recover from a backup.
InnoDB: It is also possible that your operating
InnoDB: system has corrupted its own file cache
InnoDB: and rebooting your computer removes the
InnoDB: error.
InnoDB: If the corrupt page is an index page
InnoDB: you can also try to fix the corruption
InnoDB: by dumping, dropping, and reimporting
InnoDB: the corrupt table. You can use CHECK
InnoDB: TABLE to scan your table for corruption.
InnoDB: See also http://dev.mysql.com/doc/refman/5.1/en/forcing-recovery.html
InnoDB: about forcing recovery.
InnoDB: Ending processing because of a corrupt database page.
100317 05:26:54 mysqld_safe Number of processes running now: 0
100317 05:26:54 mysqld_safe mysqld restarted
100317  5:26:54 [Warning] option 'innodb-autoextend-increment': unsigned value 536870912 adjusted to 1000
InnoDB: Log scan progressed past the checkpoint lsn 1 3710607179
100317  5:26:55  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 1 3715849728
InnoDB: Doing recovery: scanned up to log sequence number 1 3721092608

006d011a55fc8fb4700000012a6ebb800000002d008480afcabd800000048000000680000002800000046164646280000001800000f18000028e80001

How to repeat:
Heavy inserts - 95% (~3500 inserts per second) on partitioned innodb table, with 5% select only on that table. The PRIMARY KEY (`instance_id`,`creation_date`) and PARTITION BY RANGE (to_days(creation_date)).
I did also select count(instance_id) from the table, while the heavy load was done and got: ERROR 2013 (HY000): Lost connection to MySQL server during query and also got MySQL gone away

Suggested fix:
N/A
[17 Mar 2010 12:32] Valeriy Kravchuk
Looks similar to Bug #34076.
[17 Mar 2010 13:57] Eyal Sorek
Hi,
It looks like the table is corrupted.
I am trying to do now again - select count(instance_id) from <table-name>; - and I get - ERROR 2013 (HY000): Lost connection to MySQL server during query.
Anyway I can repair this innodb table ?
Thanks,
Eyal
[17 Mar 2010 14:38] Valeriy Kravchuk
Please, try to run:

check table <table-name>;

and check if it reports any problems.

I'd try to make a dump of this table using mysqldump or select * from table into outfile ..., just for backup.

You can also try to do

alter table <table-name> engine=InnoDB;

to rebuild table and indexes.

alter table <table-name>;
[18 Mar 2010 13:16] Eyal Sorek
Hi,
I tried all options suggested. Nothing helped.
Any other idea ?
It happened to me few times.
Can you elaborate on the root cause of it ?
Any planned fix for it ?
Thanks,
Eyal.
[25 Mar 2010 3:08] MySQL Verification Team
Thank you for the feedback. Could you please provide the create table statement for the table offended?. Thanks in advance.
[25 Mar 2010 14:24] Eyal Sorek
See below:
mysql> show create table ad_mapping\G
*************************** 1. row ***************************
       Table: ad_mapping
Create Table: CREATE TABLE `tab_x` (
  `instance_id` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `creation_date` date NOT NULL DEFAULT '0000-00-00',
  `col1_id` int(11) DEFAULT NULL,
  `col2_id` int(11) NOT NULL,
  `col3_id` int(11) NOT NULL,
  `col4_id` int(11) NOT NULL,
  `col5_id` int(11) NOT NULL,
  `col7` varchar(30) COLLATE utf8_bin NOT NULL,
  `col8_id` int(11) NOT NULL,
  `col9_id` int(11) NOT NULL,
  `col10_id` int(11) NOT NULL,
  `due_timestamp` datetime NOT NULL,
  `col12` varchar(30) COLLATE utf8_bin DEFAULT NULL,
  `col13` int(11) NOT NULL,
  `col14` tinyint(1) NOT NULL,
  `col15` float DEFAULT NULL,
  `col16_id` int(10) unsigned DEFAULT NULL,
  `col17_delta_time` int(11) DEFAULT NULL,
  `col18` tinyint(1) NOT NULL,
  `col19` float NOT NULL,
  `col20_id` int(11) NOT NULL,
  `timestamp` datetime DEFAULT NULL,
  `col22_other_timestamp` datetime DEFAULT NULL,
  `col23_id` int(11) DEFAULT NULL,
  PRIMARY KEY (`instance_id`,`creation_date`)
) ENGINE=InnoDB AUTO_INCREMENT=13386021 DEFAULT CHARSET=utf8 COLLATE=utf8_bin
/*!50100 PARTITION BY RANGE (to_days(creation_date))
(PARTITION p_734203 VALUES LESS THAN (734203) ENGINE = InnoDB,
 PARTITION p_734204 VALUES LESS THAN (734204) ENGINE = InnoDB,
 PARTITION p_734205 VALUES LESS THAN (734205) ENGINE = InnoDB,
 PARTITION p_734206 VALUES LESS THAN (734206) ENGINE = InnoDB,
 PARTITION p_734207 VALUES LESS THAN (734207) ENGINE = InnoDB,
 PARTITION p_734208 VALUES LESS THAN (734208) ENGINE = InnoDB,
 PARTITION p_734209 VALUES LESS THAN (734209) ENGINE = InnoDB,
 PARTITION p_734210 VALUES LESS THAN (734210) ENGINE = InnoDB,
 PARTITION p_734211 VALUES LESS THAN (734211) ENGINE = InnoDB,
 PARTITION p_734212 VALUES LESS THAN (734212) ENGINE = InnoDB,
 PARTITION p_734213 VALUES LESS THAN (734213) ENGINE = InnoDB,
 PARTITION p_734214 VALUES LESS THAN (734214) ENGINE = InnoDB,
 PARTITION p_734215 VALUES LESS THAN (734215) ENGINE = InnoDB,
 PARTITION p_734216 VALUES LESS THAN (734216) ENGINE = InnoDB,
 PARTITION p_734217 VALUES LESS THAN (734217) ENGINE = InnoDB,
 PARTITION p_734218 VALUES LESS THAN (734218) ENGINE = InnoDB,
 PARTITION p_734219 VALUES LESS THAN (734219) ENGINE = InnoDB,
 PARTITION p_734220 VALUES LESS THAN (734220) ENGINE = InnoDB,
 PARTITION p_734221 VALUES LESS THAN (734221) ENGINE = InnoDB,
 PARTITION p_734222 VALUES LESS THAN (734222) ENGINE = InnoDB,
 PARTITION p_734223 VALUES LESS THAN (734223) ENGINE = InnoDB,
 PARTITION p_734224 VALUES LESS THAN (734224) ENGINE = InnoDB,
 PARTITION p_734225 VALUES LESS THAN (734225) ENGINE = InnoDB,
 PARTITION p_734226 VALUES LESS THAN (734226) ENGINE = InnoDB,
 PARTITION p_734227 VALUES LESS THAN (734227) ENGINE = InnoDB,
 PARTITION p_734228 VALUES LESS THAN (734228) ENGINE = InnoDB,
 PARTITION p_734229 VALUES LESS THAN (734229) ENGINE = InnoDB,
 PARTITION p_734230 VALUES LESS THAN (734230) ENGINE = InnoDB,
 PARTITION p_734231 VALUES LESS THAN (734231) ENGINE = InnoDB,
 PARTITION p_734232 VALUES LESS THAN (734232) ENGINE = InnoDB,
 PARTITION p_734233 VALUES LESS THAN (734233) ENGINE = InnoDB,
 PARTITION p_734234 VALUES LESS THAN (734234) ENGINE = InnoDB,
 PARTITION p_734235 VALUES LESS THAN (734235) ENGINE = InnoDB,
 PARTITION p_734236 VALUES LESS THAN (734236) ENGINE = InnoDB,
 PARTITION p_734237 VALUES LESS THAN (734237) ENGINE = InnoDB,
 PARTITION p_734238 VALUES LESS THAN (734238) ENGINE = InnoDB,
 PARTITION p_734239 VALUES LESS THAN (734239) ENGINE = InnoDB,
 PARTITION p_734240 VALUES LESS THAN (734240) ENGINE = InnoDB,
 PARTITION p_734241 VALUES LESS THAN (734241) ENGINE = InnoDB,
 PARTITION p_734242 VALUES LESS THAN (734242) ENGINE = InnoDB,
 PARTITION p_734243 VALUES LESS THAN (734243) ENGINE = InnoDB,
 PARTITION p_734244 VALUES LESS THAN (734244) ENGINE = InnoDB,
 PARTITION p_734245 VALUES LESS THAN (734245) ENGINE = InnoDB,
 PARTITION p_734246 VALUES LESS THAN (734246) ENGINE = InnoDB,
 PARTITION p_734247 VALUES LESS THAN (734247) ENGINE = InnoDB,
 PARTITION p_734248 VALUES LESS THAN (734248) ENGINE = InnoDB,
 PARTITION p_734249 VALUES LESS THAN (734249) ENGINE = InnoDB,
 PARTITION p_734250 VALUES LESS THAN (734250) ENGINE = InnoDB,
 PARTITION p_734251 VALUES LESS THAN (734251) ENGINE = InnoDB,
 PARTITION p_734252 VALUES LESS THAN (734252) ENGINE = InnoDB,
 PARTITION p_734253 VALUES LESS THAN (734253) ENGINE = InnoDB,
 PARTITION p_734254 VALUES LESS THAN (734254) ENGINE = InnoDB,
 PARTITION p_734255 VALUES LESS THAN (734255) ENGINE = InnoDB,
 PARTITION p_734256 VALUES LESS THAN (734256) ENGINE = InnoDB) */
[29 Mar 2010 10:09] Sveta Smirnova
Thank you for the feedback.

I can not repeat described behavior with test data. Please provide example of INSERT and SELECT queries you are using and your configuration file. Please also indicate how much physical RAM do you have.
[29 Apr 2010 23:00] Bugs System
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".