Bug #64579 Strange insertion in the binary log index file after a mysqld crash
Submitted: 7 Mar 2012 11:07 Modified: 23 Apr 2018 5:42
Reporter: Cedric PEINTRE Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server: Replication Severity:S2 (Serious)
Version:5.1.50, 5.5.35, 5.6.13 OS:Linux (debian 4.0 (2.6.18-6-amd64))
Assigned to: CPU Architecture:Any
Tags: binary log, crash, index file, replication

[7 Mar 2012 11:07] Cedric PEINTRE
Description:
After the mysql server crash (mysqld got signal 6), a strange string appears in the binary log index file (mysql-bin.index) :

/var/database/bin-log/mysql-bin.126242
/var/database/bin-log/mysql-bin.126243
/var/database/bin-log/mysql-bin.126244
/var/database/bin-log/mysql-bin.126245
*** glibc detected *** malloc(): memory corruption: 0x00002aac2d5ab460 ***

Then, the mysql server doesn't want to start :

/usr/local/mysql/bin/mysqld: File '*** glibc detected *** malloc(): memory corruption: 0x00002aac2d5ab460 ***' not found (Errcode: 2)
120306 17:19:47 [ERROR] Failed to open log (file '*** glibc detected *** malloc(): memory corruption: 0x00002aac2d5ab460 ***', errno 2)
120306 17:19:47 [ERROR] Could not open log file
120306 17:19:47 [ERROR] Can't init tc log
120306 17:19:47 [ERROR] Aborting

120306 17:19:47  InnoDB: Starting shutdown...
120306 17:19:53  InnoDB: Shutdown completed; log sequence number 55 1061584593
120306 17:19:53 [Note] /usr/local/mysql/bin/mysqld: Shutdown complete

120306 17:19:53 mysqld_safe mysqld from pid file /var/database/mysql50/eul2400060.pid ended

How to repeat:
It was the first time I had this issue

Suggested fix:
The workaround is to delete or edit this index file.
[7 Mar 2012 18:47] Valeriy Kravchuk
Sorry, I meant 5.1.61.
[7 Mar 2012 21:54] Cedric PEINTRE
I don't know how to repeat this problem, so, I don't know if I can reproduce in 5.1.61
[9 Mar 2012 18:42] Sveta Smirnova
Thank you for the feedback.

Please send us full error log file: I want to see why crash initially happened.
[12 Mar 2012 10:37] Cedric PEINTRE
120306 16:20:01 - 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=1073741824
read_buffer_size=262144
max_used_connections=533
max_threads=1200
threads_connected=20
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 11198588 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0xab2ed30
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 = 0x489cb1b0 thread_stack 0x40000
/usr/local/mysql/bin/mysqld(my_print_stacktrace+0x2e)[0x8b35ae]
/usr/local/mysql/bin/mysqld(handle_segfault+0x322)[0x5e3382]
/lib/libpthread.so.0[0x2abcec827410]
/lib/libc.so.6(gsignal+0x3b)[0x2abcece3107b]
/lib/libc.so.6(abort+0x10e)[0x2abcece3284e]
/lib/libc.so.6[0x2abcece675f9]
/lib/libc.so.6[0x2abcece6e852]
/lib/libc.so.6(malloc+0x7d)[0x2abcece7016d]
/usr/local/mysql/bin/mysqld(my_malloc+0x32)[0x89ec42]
/usr/local/mysql/bin/mysqld(_ZN3THD21binlog_setup_trx_dataEv+0x4f)[0x67c49f]
/usr/local/mysql/bin/mysqld(_ZN13MYSQL_BIN_LOG5writeEP9Log_event+0x174)[0x6833a4]
/usr/local/mysql/bin/mysqld(_ZN3THD12binlog_queryENS_22enum_binlog_query_typeEPKcmbbi+0xcb)[0x5d22db]
/usr/local/mysql/bin/mysqld(_Z13write_bin_logP3THDbPKcm+0x6e)[0x6e6d9e]
/usr/local/mysql/bin/mysqld(_Z21mysql_execute_commandP3THD+0x49d9)[0x5f8399]
/usr/local/mysql/bin/mysqld(_Z11mysql_parseP3THDPcjPPKc+0x3d8)[0x5f94e8]
/usr/local/mysql/bin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x542)[0x5f9a32]
/usr/local/mysql/bin/mysqld(_Z10do_commandP3THD+0xe6)[0x5fad36]
/usr/local/mysql/bin/mysqld(handle_one_connection+0x246)[0x5ed3f6]
/lib/libpthread.so.0[0x2abcec820f1a]
/lib/libc.so.6(__clone+0x72)[0x2abcececb5d2]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x2aac2d19f520 is an invalid pointer
thd->thread_id=127661164
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.
[8 May 2012 6:26] MySQL Verification Team
I guess file descriptors get corrupted or mixed up in memory. I've seen also mysql error log content being written directly into MYD tables under harsh circumstances...
[28 Aug 2013 10:32] MySQL Verification Team
Seen once again on OSX 10.6.8 with MySQL 5.5.30 after an innodb assert:

[ERROR] Failed to open log (file '11:22:33 UTC - mysqld got signal 6 ;', errno 2)
[ERROR] Could not open log file
[ERROR] Can't init tc log
[ERROR] Aborting
[17 Jul 2014 21:12] Moritz Sch?pp
Hit the same bug today after hitting bug http://bugs.mysql.com/bug.php?id=70327.

Server version on MASTER: 5.6.13

Can someone change Version number from 5.1.50 to (at least) 5.6.13? If you need full log file entries please let me know.
[20 Jan 2015 17:40] Sveta Smirnova
Re-opening since more users see it.

All who see the bug, please, send us your OS detils: accurate version of OD, version of glibc.
[24 Mar 2016 19:29] MySQL Verification Team
All reporters: 

Please let us know if you have any plugins loaded.  For example innodb plugin (5.1),  thread pool plugin, semisync, PAM auth, audit log plugin, or third party plugins.
[25 Mar 2016 9:15] MySQL Verification Team
so my theory is some code does a double close() of a file descriptor which leads to other thread reusing it for wrong purpose.

i believe that my_file_close results should always be checked and handled.
and all closed fd's should be set to -1 (under proper locking to avoid races).
[24 Apr 2018 1: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".