MySQL Bugs: #56855: MySQL Crash - InnoDB: Assertion failure

Bug #56855	MySQL Crash - InnoDB: Assertion failure
Submitted:	19 Sep 2010 10:42	Modified:	8 May 2011 23:10
Reporter:	Ross Whitehead	Email Updates:
Status:	No Feedback	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S2 (Serious)
Version:	5.1.50	OS:	Windows (2003 x64 SP2)
Assigned to:	Assigned Account	CPU Architecture:	Any

Description:
Yesterday we upgraded from 5.0.67. After the upgraded I ran check, analyze, optimize on all tables and everything was fine. During our weekly maintenance task, while executing "optimize vb_post" MySQL Crashed. I believe the optimize was almost done.

Here is a snippet of the log file:
InnoDB: ###### Diagnostic info printed to the standard error stream
InnoDB: Error: semaphore wait has lasted > 600 seconds
InnoDB: We intentionally crash the server, because it appears to be hung.
100919 5:16:15 InnoDB: Assertion failure in thread 188 in file .\srv\srv0srv.c line 2236
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.
InnoDB: Thread 1120 stopped in file G:\mysql-5.1.50-winbuild\mysql-community-nt-5.1.50-build\storage\innobase\include\sync0sync.ic line 115
100919 5:16:15 - mysqld got exception 0xc0000005 ;
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=57671680
read_buffer_size=65536
max_used_connections=801
max_threads=800
threads_connected=800
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 1753188 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...
000000014021C7EE mysqld.exe!srv_error_monitor_thread()[srv0srv.c:2236]
0000000077D6B71A kernel32.dll!BaseThreadStart()
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.
InnoDB: Thread 1040 stopped in file G:\mysql-5.1.50-winbuild\mysql-community-nt-5.1.50-build\storage\innobase\include\sync0sync.ic line 115

How to repeat:
This is the first time it has crashed, so I am not sure it is repeatable.

it looks like the bug similar http://bugs.mysql.com/bug.php?id=52409

Thank you for the report.

Looks like you have InnoDB Monitor turned on. Could you please send us full error log with records before crash: I want to check which kind of transactions you were running before crash happened.

The full log is approx. 2.5 MB and the upload is limited to 500 KB.  How do I upload the full error log?

Thank you for the feedback.

Please upload it to our FTP server as described in "Files" tab of the bug report:

If the data you need to attach is more than 500KB, you should create a compressed archive of the data and a README file that describes the data with a filename that includes the bug number (example: bug-data-56855.zip), and use FTP to upload the archive to ftp://ftp.mysql.com/pub/mysql/upload/. Once you have uploaded the file, add a comment to this bug to notify us about it. Note: This directory is unlistable, which means that once you have uploaded your file, you will not be able to see it.

Doh, I did not see that message yesterday... or consider compressing them.  Sorry for that.

I have uploaded the my.ini file as well as the compressed log.

Server crashed again this morning as it finished creating a new index on our largest table.

I have compressed and attached the log file.

FYI, since the last crash we have created additional indexes and ran check, analyze, optimize without a crash.

This appears to be similar to bug #50723 where the watchdog thread timeout isn't large enough for long-running DDL statements.

This really takes a fix from the InnoDB team but as a workaround if you're using innodb_file_per_table you can try defragmenting it, since it often causes extreme fragmentation that can make these sorts of operation very slow. If you have no defragmenting tool for your filesystem you can copy the file then copy it back, replacing the original. This includes Linux filesystems.

I would rather say that this looks similar to Bug #52409, where the watchdog apparently kicks in during a table-copying ALTER TABLE of a table that lacks a PRIMARY KEY. I have not yet finished analyzing the core dump that we luckily have for Bug #52409.

Can we have the output of SHOW CREATE TABLE vb_host, please?

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

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

The crash in OPTIMIZE TABLE was probably due to a bug in the InnoDB watchdog. Quoting Bug #11877216 INNODB TOO EAGER TO COMMIT SUICIDE ON A BUSY SERVER:

Added to changelog for 5.1.57, 5.5.12, 5.6.3:

The server could halt if InnoDB interpreted a very heavy I/O load for
15 minutes or more as an indication that the server was hung. This
change fixes the logic that measures how long InnoDB threads were
waiting, which formerly could produce false positives.