Percona server 5.5.27-29.0 crashed during a bulk delete process

350 views
Skip to first unread message

amol

unread,
Nov 8, 2012, 10:53:17 AM11/8/12
to percona-d...@googlegroups.com
Hi 
i am running 5.5.27-29.0 version of Percona db for my production database and last night during a bulk delete process the mysql instance crashed and would not start even when i added 
innodb_force_recovery = 4
the errors in the mysql error log were


InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
InnoDB: 1 transaction(s) which must be rolled back or cleaned up
InnoDB: in total 298015 row operations to undo
InnoDB: Trx id counter is 131DE00
121108  1:16:18  InnoDB: Waiting for the background threads to start
121108  1:16:19  InnoDB: Waiting for the background threads to start


so then i killed the pid again and started with 
innodb_force_recovery = 1

it started with these messages in the log

InnoDB: End of page dump
121108  1:55:48  InnoDB: Page checksum 2477130822 (32bit_calc: 2803992502), prior-to-4.0.14-form checksum 2861862647
InnoDB: stored checksum 3571226133, prior-to-4.0.14-form stored checksum 2861862647
InnoDB: Page lsn 1 2921818088, low 4 bytes of lsn at page end 2921818088
InnoDB: Page number (if stored to page already) 12280,
InnoDB: space id (if created with >= MySQL-4.1.1 and stored already) 239
InnoDB: Page may be an index page where index id is 441
InnoDB: (index "PRIMARY" of table "prod"."Location")
InnoDB: Database page corruption on disk or a failed
InnoDB: file read of page 12280.
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.5/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
121108  1:55:48 Percona XtraDB (http://www.percona.com) 1.1.8-rel29.0 started; log sequence number 7298862733
121108  1:55:48 InnoDB: !!! innodb_force_recovery is set to 1 !!!
121108  1:55:48 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
121108  1:55:48 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
121108  1:55:48 [Note] Server socket created on IP: '0.0.0.0'.
121108  1:55:49 [Warning] 'user' entry 'root@iform-prod5' ignored in --skip-name-resolve mode.
121108  1:55:49 [Warning] 'proxies_priv' entry '@ root@iform-prod5' ignored in --skip-name-resolve mode.
121108  1:55:49 [Note] Event Scheduler: Loaded 0 events
121108  1:55:49 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.5.27-29.0'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  Percona Server (GPL), Release 29.0
InnoDB: A new raw disk partition was initialized or
InnoDB: innodb_force_recovery is on: we do not allow
InnoDB: database modifications by the user. Shut down
InnoDB: mysqld and edit my.cnf so that newraw is replaced
InnoDB: with raw, and innodb_force_... is removed.
InnoDB: A new raw disk partition was initialized or
InnoDB: innodb_force_recovery is on: we do not allow
InnoDB: database modifications by the user. Shut down
InnoDB: mysqld and edit my.cnf so that newraw is replaced
InnoDB: with raw, and innodb_force_... is removed.
 2 3InnoDB: A new raw disk partition was initialized or
InnoDB: innodb_force_recovery is on: we do not allow
InnoDB: database modifications by the user. Shut down
InnoDB: mysqld and edit my.cnf so that newraw is replaced
InnoDB: with raw, and innodb_force_... is removed.
 4InnoDB: A new raw disk partition was initialized or
InnoDB: innodb_force_recovery is on: we do not allow



and then i had to perform a restore from backup of that table

any idea why the db would have crashed, it was doing a bulk delete on a table that has high amount of inserts 



Laurynas Biveinis

unread,
Nov 10, 2012, 4:56:06 AM11/10/12
to percona-discussion
Hi -

Do you have the 1st crash message in the log?

This could be caused by https://bugs.launchpad.net/percona-server/+bug/1042640, which was fixed in 5.5.28-29.1 release.





--
You received this message because you are subscribed to the Google Groups "Percona Discussion" group.
To post to this group, send email to percona-d...@googlegroups.com.
 
 



--
Laurynas
www.percona.com

amol

unread,
Nov 10, 2012, 12:01:17 PM11/10/12
to percona-d...@googlegroups.com
Hi Laurynas,
thanks for much for taking interest in this and replying, 

yes here is the log from the night the db crashed, you will the timings according to the activity during crash

please let me know if you need anything else


121108  0:15:31  InnoDB: Error: space id and page n:o stored in the page
InnoDB: read in are 808728115:3377681476, should be 239:31651!
InnoDB: Database page corruption on disk or a failed
InnoDB: file read of page 31651.
InnoDB: You may have to recover from a backup.
121108  0:15:31  InnoDB: Page dump in ascii and hex (16384 bytes):

InnoDB: End of page dump
121108  0:15:31  InnoDB: Page checksum 2335292886 (32bit_calc: 2805692839), prior-to-4.0.14-form checksum 3860048700
InnoDB: stored checksum 2071986176, prior-to-4.0.14-form stored checksum 4101310499
InnoDB: Page lsn 943336760 875443507, low 4 bytes of lsn at page end 1798844638
InnoDB: Page number (if stored to page already) 3377681476,
InnoDB: space id (if created with >= MySQL-4.1.1 and stored already) 808728115
InnoDB: Database page corruption on disk or a failed
InnoDB: file read of page 31651.
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: about forcing recovery.
121108  0:15:31  InnoDB: Error: space id and page n:o stored in the page
InnoDB: read in are 808728115:3377681476, should be 239:31651!
InnoDB: Database page corruption on disk or a failed
InnoDB: file read of page 31651.
InnoDB: You may have to recover from a backup.
121108  0:15:31  InnoDB: Page dump in ascii and hex (16384 bytes):

nnoDB: End of page dump
121108  0:15:32  InnoDB: Page checksum 2335292886 (32bit_calc: 2805692839), prior-to-4.0.14-form checksum 3860048700
InnoDB: stored checksum 2071986176, prior-to-4.0.14-form stored checksum 4101310499
InnoDB: Page lsn 943336760 875443507, low 4 bytes of lsn at page end 1798844638
InnoDB: Page number (if stored to page already) 3377681476,
InnoDB: space id (if created with >= MySQL-4.1.1 and stored already) 808728115
InnoDB: Database page corruption on disk or a failed
InnoDB: file read of page 31651.
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: about forcing recovery.
121108  0:15:32  InnoDB: Error: space id and page n:o stored in the page
InnoDB: read in are 808728115:3377681476, should be 239:31651!
InnoDB: Database page corruption on disk or a failed
InnoDB: file read of page 31651.
InnoDB: You may have to recover from a backup.
121108  0:15:32  InnoDB: Page dump in ascii and hex (16384 bytes):

21108  0:15:51  InnoDB: Assertion failure in thread 140346818901760 in file buf0buf.c line 2614
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: about forcing recovery.
05:15:51 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.
Please help us make Percona Server better by reporting any

key_buffer_size=33554432
read_buffer_size=131072
max_used_connections=158
max_threads=500
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 = 1126896 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x5b5fbe0
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 = 7fa50a492e88 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x35)[0x7d3545]
/usr/sbin/mysqld(handle_fatal_signal+0x4a4)[0x69f394]
/lib/x86_64-linux-gnu/libpthread.so.0(+0xfcb0)[0x7fa5aa135cb0]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x35)[0x7fa5a925e445]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x17b)[0x7fa5a9261bab]
/usr/sbin/mysqld[0x8b968f]
/usr/sbin/mysqld[0x8a87cb]
/usr/sbin/mysqld[0x8576b7]
/usr/sbin/mysqld[0x85819a]
/usr/sbin/mysqld[0x82d91d]
/usr/sbin/mysqld(_Z13rr_sequentialP11READ_RECORD+0x1f)[0x77362f]
/usr/sbin/mysqld(_Z12mysql_deleteP3THDP10TABLE_LISTP4ItemP10SQL_I_ListI8st_orderEyy+0x9c5)[0x78fd05]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x9ed)[0x5992dd]
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x333)[0x59d643]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x15df)[0x59eccf]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0xdf)[0x63e2df]
/usr/sbin/mysqld(handle_one_connection+0x51)[0x63e411]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x7e9a)[0x7fa5aa12de9a]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7fa5a931a4bd]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7fa53457e350): is an invalid pointer
Connection ID (thread ID): 20225462
Status: NOT_KILLED

You may download the Percona Server operations manual by visiting
in the manual which will help you identify the cause of the crash.
121108 00:15:52 mysqld_safe mysqld from pid file /var/lib/mysql/iform-prod5.pid ended


InnoDB: Error: Unable to read tablespace 239 page no 31651 into the buffer pool after 100 attempts
InnoDB: The most probable cause of this error may be that the table has been corrupted.
InnoDB: You can try to fix this problem by using innodb_force_recovery.
InnoDB: Please see reference manual for more details.
InnoDB: Aborting...
121108  0:15:51  InnoDB: Assertion failure in thread 140346818901760 in file buf0buf.c line 2614
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: about forcing recovery.
05:15:51 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.
Please help us make Percona Server better by reporting any

key_buffer_size=33554432
read_buffer_size=131072
max_used_connections=158
max_threads=500
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 = 1126896 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Laurynas Biveinis

unread,
Nov 11, 2012, 11:50:03 PM11/11/12
to percona-discussion
Hi -

Are there any anomalies in the error log before these messages?

If these are indeed the first errors then it's hard to say what happened here, besides what the messages say: pages were corrupted and restoring from backup seems like the best course of action. Perhaps others have more ideas.

amol

unread,
Nov 11, 2012, 11:58:03 PM11/11/12
to percona-d...@googlegroups.com
hi 
so the mysql log looked like this, so if you see the 2 dates between 7th nov and 8th nov(when the crash happened)
there is no activity in the log

121107 18:23:41 [Warning] IP address 'xx.xx9.143.239' could not be resolved: Temporary failure in name resolution
121107 18:23:42 [Warning] IP address 'xx.xx9.143.239' could not be resolved: Temporary failure in name resolution
121108  0:15:31  InnoDB: Error: space id and page n:o stored in the page
InnoDB: read in are 808728115:3377681476, should be 239:31651!
InnoDB: Database page corruption on disk or a failed
InnoDB: file read of page 31651.
InnoDB: You may have to recover from a backup.
121108  0:15:31  InnoDB: Page dump in ascii and hex (16384 bytes):

after this message there is a big ascii dump

and the key thing to note here is that there was a daily bulk delete process running at the time of this crash(it deletes abt 1 million rows every night)
Reply all
Reply to author
Forward
0 new messages