Bug #65831 mysql-5.5.25a crash
Submitted: 5 Jul 2012 21:18 Modified: 2 Nov 2012 15:36
Reporter: Jean-Christophe Petit Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: Replication Severity:S1 (Critical)
Version:5.5.25a OS:Linux (RedHat-6.2 x86_64)
Assigned to:
Tags: crash when enabling replication (START SLAVE)

[5 Jul 2012 21:18] Jean-Christophe Petit
Description:
Crash when doing "start slave;"

120705 17:07:00 mysqld_safe mysqld from pid file /var/lib/mysql/mysqld.pid ended
120705 17:07:11 mysqld_safe Starting mysqld daemon with databases from /mysqldata/var/lib/mysql
120705 17:07:11 [Note] Plugin 'FEDERATED' is disabled.
120705 17:07:11 [Note] Plugin 'BLACKHOLE' is disabled.
120705 17:07:11 InnoDB: The InnoDB memory heap is disabled
120705 17:07:11 InnoDB: Mutexes and rw_locks use GCC atomic builtins
120705 17:07:11 InnoDB: Compressed tables use zlib 1.2.3
120705 17:07:11 InnoDB: Using Linux native AIO
120705 17:07:11 InnoDB: Initializing buffer pool, size = 16.0G
120705 17:07:12 InnoDB: Completed initialization of buffer pool
120705 17:07:12 InnoDB: highest supported file format is Barracuda.
120705 17:07:13  InnoDB: Waiting for the background threads to start
120705 17:07:14 InnoDB: 1.1.8 started; log sequence number 171942364362
120705 17:07:14 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
120705 17:07:14 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
120705 17:07:14 [Note] Server socket created on IP: '0.0.0.0'.
120705 17:07:14 [Warning] 'proxies_priv' entry '@ root@mysqls53' ignored in --skip-name-resolve mode.
120705 17:07:14 [Note] Event Scheduler: Loaded 0 events
120705 17:07:14 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.5.25a-log'  socket: '/var/lib/mysql/mysqld.sock'  port: 3306  MySQL Community Server (GPL)
120705 17:07:24 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.562782' at position 842909, relay log '/mysqldata/var/lib/mysql/mysqld-relay-bin.048945' position: 1165
120705 17:07:24 [Note] Slave I/O thread: connected to master 'remote@192.168.0.200:3306',replication started in log 'mysql-bin.562782' at position 1037074
21:07:24 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=536870912
read_buffer_size=2097152
max_used_connections=2
max_threads=4096
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 = 17348288 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7fc1d4000990
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 = 7fc6642fb838 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x35)[0x7a3f15]
/usr/sbin/mysqld(handle_fatal_signal+0x4a4)[0x67ddb4]
/lib64/libpthread.so.0(+0xf4a0)[0x7fc6695ef4a0]
/usr/sbin/mysqld(_Z12mysql_insertP3THDP10TABLE_LISTR4ListI4ItemERS3_IS5_ES6_S6_15enum_duplicatesb+0x274)[0x574c74]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x885)[0x584ac5]
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x188)[0x588ca8]
/usr/sbin/mysqld(_ZN15Query_log_event14do_apply_eventEPK14Relay_log_infoPKcj+0xce8)[0x7250d8]
/usr/sbin/mysqld(_Z26apply_event_and_update_posP9Log_eventP3THDP14Relay_log_info+0x12d)[0x526f6d]
/usr/sbin/mysqld[0x52bd32]
/usr/sbin/mysqld(handle_slave_sql+0x9a1)[0x52d1f1]
/lib64/libpthread.so.0(+0x77f1)[0x7fc6695e77f1]
/lib64/libc.so.6(clone+0x6d)[0x7fc66886dccd]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7fc1d40156f6): is an invalid pointer
Connection ID (thread ID): 13
Status: 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.

How to repeat:
Just doing "start slave;"
[5 Jul 2012 21:19] Jean-Christophe Petit
Going back to 5.5.24 "fix" the problem.
[5 Jul 2012 21:26] Jean-Christophe Petit
with query_cache disabled we have the same problem
[5 Jul 2012 21:32] Jean-Christophe Petit
With RedHat-5.5 x86_64 the problem does not seem to happen
Difference is:
120705 15:12:21 InnoDB: Using Linux native AIO
120705 15:12:21 InnoDB: Error: Linux Native AIO is not supported on tmpdir.
InnoDB: You can either move tmpdir to a file system that supports native AIO
InnoDB: or you can set innodb_use_native_aio to FALSE to avoid this message.
120705 15:12:21 InnoDB: Error: Linux Native AIO check on tmpdir returned error[22]
[5 Jul 2012 22:11] Jean-Christophe Petit
same problem with
innodb_use_native_aio=0
[6 Jul 2012 8:59] Valerii Kravchuk
Please, send my.cnf file content from this slave. Can you try to identify crashing statement from the binary logs?

I wonder if this is related to bug #65740.
[7 Jul 2012 3:04] Jean-Christophe Petit
Hello,

in fact, it looks like an update is causing MySQL to crash, here are the last queries before the crash:

120706 22:59:35   433 Query     start slave
                  438 Query     BEGIN
                  437 Connect Out       remote@xxx.xxx.xxx.xxx:3306
                  439 Connect   root@localhost on
                  439 Query     select @@version_comment limit 1
                  439 Query     SHOW FULL PROCESSLIST
                  439 Quit
                  438 Query     UPDATE ..................................

I uploaded the my.cnf also as requested.

Have a good day
[7 Jul 2012 3:22] Jean-Christophe Petit
just to confirm that the UPDATE is similar to the one in bug #65740
update test set rank=@rnk:=@rnk+1 order by lat;

Even if it is more like:
update test set a='xxx', b='yyy', rank=@rnk:=rank WHERE d = 12345 AND e = 67890;

Jean-Christophe
[7 Jul 2012 10:21] Valerii Kravchuk
Let's call it a duplicate of Bug #65740 then. 5.5.24 should work for you in the meantime.
[13 Jul 2012 16:47] Matthew Yeazel
We are having the same issue running RHEL 5.6 x86_64. Getting the same errors when starting slave replication and crashes mysql.
[16 Jul 2012 22:06] Max Bowsher
This bug has been marked as a duplicate of another, but that other bug is apparently restricted access / private. This is unhelpful :-/
[17 Jul 2012 21:25] Hank Eskin
I don't know why that bug is marked private. I've requested to find out why.
[20 Jul 2012 16:25] Hank Eskin
From Bug #65740 - Fixed in 5.1.65/5.5.27.

I still do not know why it is marked as private.
[20 Aug 2012 17:12] Andrew Garner
I do not believe this is fixed - and there is no way to confirm - 5.5.27 changelogs do not reference this bug nor the private bug in any way.

5.5.27 server that just crashed this morning gave this traceback:

Thread pointer: 0x7f63a4077460
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 = 7f6998a18758 thread_stack 0x40000
/usr/libexec/mysqld(my_print_stacktrace+0x2e)[0x78461e]
/usr/libexec/mysqld(handle_fatal_signal+0x493)[0x66f373]
/lib64/libpthread.so.0[0x3eb940f490]
/usr/libexec/mysqld(_Z11open_tablesP3THDPP10TABLE_LISTPjjP19Prelocking_strategy+0x575)[0x550d95]
/usr/libexec/mysqld(_Z12mysql_updateP3THDP10TABLE_LISTR4ListI4ItemES6_PS4_jP8st_ordery15enum_duplicatesbPySB_+0x10a)[0x5e96da]
/usr/libexec/mysqld(_Z21mysql_execute_commandP3THD+0x1bf8)[0x580e88]
/usr/libexec/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x1bb)[0x5839eb]
/usr/libexec/mysqld(_ZN15Query_log_event14do_apply_eventEPK14Relay_log_infoPKcj+0xae4)[0x70e864]
/usr/libexec/mysqld(_Z26apply_event_and_update_posP9Log_eventP3THDP14Relay_log_info+0x135)[0x5280a5]
/usr/libexec/mysqld[0x52cb0b]
/usr/libexec/mysqld(handle_slave_sql+0x946)[0x52dee6]
/lib64/libpthread.so.0[0x3eb94077e1]
/lib64/libc.so.6(clone+0x6d)[0x3eb90e577d]
[21 Aug 2012 3:23] Hank Eskin
We are aware that there is no mention in the changelog.  Please see this page:

http://ronaldbradford.com/blog/when-is-a-crashing-mysql-bug-not-a-bug-2012-08-15/
[13 Sep 2012 18:05] Valerii Kravchuk
I do not see any my.cnf here. All reporters, please, check if you use any replicate-* options in my.cnf.
[13 Sep 2012 18:58] Sveta Smirnova
Jean-Christophe Petit,

I jsut checked test case for bug #65740 and it does not crash in 5.5.27 anymore. Please upgrade and test, so we can be sure your case is solved as well.

Andrew,

your case seems to be different from Bug #65740. I think you need to open new report, so we can start collecting information necessary to repeat your case.
[20 Sep 2012 13:20] Miguel Angel Nieto
Sveta,

You have a reproducible test case on #66890. It affects 5.5.27.
[2 Nov 2012 15:36] Jean-Christophe Petit
Hello,

bug seems to be fixed in MySQL-5.5.28
We've been running a slave for a more than a week now.

JC