Bug #81957 Segmentation fault during crash recovery after server couldn't write binlogs
Submitted: 21 Jun 2016 16:52 Modified: 28 Jun 2016 11:21
Reporter: Geoff Montee Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S3 (Non-critical)
Version:5.5.48 OS:Any
Assigned to: CPU Architecture:Any
Tags: binlogs, crash recovery, innodb

[21 Jun 2016 16:52] Geoff Montee
Description:
A user's server recently ran out of disk space on the partition that they used to store the server's binlogs. The server had its other data files in other partitions, so only binlogs should have been affected.

The server could not write binlogs during this time, so the log started filling up with errors like the following:

160619  4:08:00 [Warning] Disk is full writing '/mysql/binlogs/binlog.027579' (Errcode: 28). Waiting for someone to free space... (Expect up to 60 secs delay for server to continue after freeing disk space)
160619  4:08:00 [Warning] Retry in 60 secs. Message reprinted in 600 secs

Eventually, the user restarted the server and freed some disk space. When mysqld was restarted, it crashed during crash recovery:

InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
160620 13:03:38  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: Last MySQL binlog file position 0 15740928, file name /mysql/binlogs/binlog.027579
160620 13:03:41  InnoDB: Waiting for the background threads to start
160620 13:03:42 InnoDB: 5.5.48 started; log sequence number 43288325174
11:03:42 UTC - mysqld got signal 11 ;
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=134217728
read_buffer_size=131072
max_used_connections=0
max_threads=1600
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 = 210069559 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/sbin/mysqld(my_print_stacktrace+0x35)[0x7b1ce5]
/usr/sbin/mysqld(handle_fatal_signal+0x4a4)[0x689274]
/lib64/libpthread.so.0[0x37f600f7e0]

I will also attach the full error log.

How to repeat:
Allow the server's binlog partition to fill up, and then get the server to perform crash recovery on the next restart.

Suggested fix:
Prevent the server from crashing during crash recovery.
[21 Jun 2016 16:52] Geoff Montee
The MySQL error log

Attachment: mysql.err (application/octet-stream, text), 262.62 KiB.

[28 Jun 2016 11:21] MySQL Verification Team
Hello Geoff Montee,

Thank you for the report.
This reminds me of similar issue observed in Bug #76852, please Bug #76852.

Thanks,
Umesh