MySQL cannot start

MySQL

I try to start MySQL /etc/init.d/mysqld start but a get the following messages in mysqld.log

130130 12:12:53 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
130130 12:12:53  InnoDB: Initializing buffer pool, size = 8.0M
130130 12:12:53  InnoDB: Completed initialization of buffer pool
InnoDB: Log scan progressed past the checkpoint lsn 0 1317402030
130130 12:12:53  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 0 1317403042
130130 12:12:53  InnoDB: Assertion failure in thread 140446525204448 in file trx/trx0undo.c line 726
InnoDB: Failing assertion: mach_read_from_2(undo_page + TRX_UNDO_PAGE_HDR + TRX_UNDO_PAGE_TYPE) == TRX_UNDO_INSERT
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-innodb-recovery.html
InnoDB: about forcing recovery.
10:12:53 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.

key_buffer_size=8384512
read_buffer_size=131072
max_used_connections=0
max_threads=151
thread_count=0
connection_count=0
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 338332 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 = 0 thread_stack 0x40000
/usr/libexec/mysqld(my_print_stacktrace+0x29) [0x84e0a9]
/usr/libexec/mysqld(handle_fatal_signal+0x483) [0x6a2743]
/lib64/libpthread.so.0(+0xf500) [0x7fbc40fd1500]
/lib64/libc.so.6(gsignal+0x35) [0x7fbc3f6628a5]
/lib64/libc.so.6(abort+0x175) [0x7fbc3f664085]
/usr/libexec/mysqld() [0x7dab7d]
/usr/libexec/mysqld(trx_undo_parse_page_header+0x56) [0x7daf26]
/usr/libexec/mysqld() [0x7853db]
/usr/libexec/mysqld(recv_recover_page+0x34f) [0x786c3f]
/usr/libexec/mysqld(buf_page_io_complete+0x548) [0x7485d8]
/usr/libexec/mysqld() [0x74d830]
/usr/libexec/mysqld(buf_read_page+0x225) [0x74e1b5]
/usr/libexec/mysqld(buf_page_get_gen+0x393) [0x747693]
/usr/libexec/mysqld(trx_undo_lists_init+0x1f6) [0x7ddaa6]
/usr/libexec/mysqld() [0x7d3f29]
/usr/libexec/mysqld(trx_rseg_list_and_array_init+0xaf) [0x7d415f]
/usr/libexec/mysqld(trx_sys_init_at_db_start+0x160) [0x7d5000]
/usr/libexec/mysqld(innobase_start_or_create_for_mysql+0x11fb) [0x7c5b0b]
/usr/libexec/mysqld() [0x72d53b]
/usr/libexec/mysqld(ha_initialize_handlerton(st_plugin_int*)+0x31) [0x696291]
/usr/libexec/mysqld() [0x7155db]
/usr/libexec/mysqld(plugin_init(int*, char**, int)+0x6e4) [0x7178d4]
/usr/libexec/mysqld() [0x5be742]
/usr/libexec/mysqld(main+0x1b3) [0x5c1023]
/lib64/libc.so.6(__libc_start_main+0xfd) [0x7fbc3f64ecdd]
/usr/libexec/mysqld() [0x509439]
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.
130130 12:12:53 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended

Can anyone figure out what is going wrong, or suggest what i could try to do to understand the problem?

My system is Centos 6.3 x86_64 and MySQL is Server version: 5.1.66

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

EDIT (logs with force recovery 6)

command

/etc/init.d/mysqld start --innodb_force_recovery=6

logs

130131 11:45:57 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
130131 11:45:57  InnoDB: Initializing buffer pool, size = 8.0M
130131 11:45:57  InnoDB: Completed initialization of buffer pool
InnoDB: Log scan progressed past the checkpoint lsn 0 1317402030
130131 11:45:57  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 0 1317403042
130131 11:45:57  InnoDB: Assertion failure in thread 140143100229600 in file trx/trx0undo.c line 726
InnoDB: Failing assertion: mach_read_from_2(undo_page + TRX_UNDO_PAGE_HDR + TRX_UNDO_PAGE_TYPE) == TRX_UNDO_INSERT
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-innodb-recovery.html
InnoDB: about forcing recovery.
09:45:57 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.

key_buffer_size=8384512
read_buffer_size=131072
max_used_connections=0
max_threads=151
thread_count=0
connection_count=0
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 338332 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 = 0 thread_stack 0x40000
/usr/libexec/mysqld(my_print_stacktrace+0x29) [0x84e0a9]
/usr/libexec/mysqld(handle_fatal_signal+0x483) [0x6a2743]
/lib64/libpthread.so.0(+0xf500) [0x7f759b736500]
/lib64/libc.so.6(gsignal+0x35) [0x7f7599dc78a5]
/lib64/libc.so.6(abort+0x175) [0x7f7599dc9085]
/usr/libexec/mysqld() [0x7dab7d]
/usr/libexec/mysqld(trx_undo_parse_page_header+0x56) [0x7daf26]
/usr/libexec/mysqld() [0x7853db]
/usr/libexec/mysqld(recv_recover_page+0x34f) [0x786c3f]
/usr/libexec/mysqld(buf_page_io_complete+0x548) [0x7485d8]
/usr/libexec/mysqld() [0x74d830]
/usr/libexec/mysqld(buf_read_page+0x225) [0x74e1b5]
/usr/libexec/mysqld(buf_page_get_gen+0x393) [0x747693]
/usr/libexec/mysqld(trx_undo_lists_init+0x1f6) [0x7ddaa6]
/usr/libexec/mysqld() [0x7d3f29]
/usr/libexec/mysqld(trx_rseg_list_and_array_init+0xaf) [0x7d415f]
/usr/libexec/mysqld(trx_sys_init_at_db_start+0x160) [0x7d5000]
/usr/libexec/mysqld(innobase_start_or_create_for_mysql+0x11fb) [0x7c5b0b]
/usr/libexec/mysqld() [0x72d53b]
/usr/libexec/mysqld(ha_initialize_handlerton(st_plugin_int*)+0x31) [0x696291]
/usr/libexec/mysqld() [0x7155db]
/usr/libexec/mysqld(plugin_init(int*, char**, int)+0x6e4) [0x7178d4]
/usr/libexec/mysqld() [0x5be742]
/usr/libexec/mysqld(main+0x1b3) [0x5c1023]
/lib64/libc.so.6(__libc_start_main+0xfd) [0x7f7599db3cdd]
/usr/libexec/mysqld() [0x509439]
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.
130131 11:45:57 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended

Best Answer

InnoDB: We intentionally generate a memory trap.

It looks like InnoDB is deliberately crashing itself because it's encountering a problem with your on-disk data structures that it cannot safely recover from.

What right happened before this? Unexpected power loss, hard reboot, lock-up? Upgrade? Updates? Restoring files from a backup? Is there anything interesting at the OS level in /var/log/messages?

Knowing that information might change the way you proceed somewhat, but the net effect is that this portion of the error message is leading you in the right direction:

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-innodb-recovery.html
InnoDB: about forcing recovery.

You will need to force recovery to have any chance of getting to your data. Be patient and use the lowest value possible to get the server started so you can make a backup of as much data as possible.

Of course, if there are any underlying hardware issues, those need to be addressed first.


Update: suggestion: put innodb_force_recovery = 6 into the [mysqld] section of your my.cnf file instead of passing it on the command line. I don't know how the initscripts will handle it. Or, you can leave it where it is but put a nonsense value like --innodb_force_recovery=kitten ... just to make sure the option is really being seen by mysqld.

At some point, you should get a message in the log about the option being set, but I'm not sure where it is, in time, related to what you're seeing... so I want to be sure it's really getting set.

Here's a normal 5.5.28 startup with innodb_force_recovery = 1. (Sorry, I don't have a 5.1 that I can take offline at the moment).

130131 12:47:16 InnoDB: Completed initialization of buffer pool
130131 12:47:16 InnoDB: highest supported file format is Barracuda.
130131 12:47:21  InnoDB: Waiting for the background threads to start
130131 12:47:22 InnoDB: 1.1.8 started; log sequence number 2872409775300
130131 12:47:22 InnoDB: !!! innodb_force_recovery is set to 1 !!!

It seems to me that this message is appearing a little too late in the show, which may be the simple explanation for why you aren't seeing it.