Bug #66915 Replication thread crashes server on specific query
Submitted: 21 Sep 2012 17:57 Modified: 12 Oct 2012 3:12
Reporter: Baron Schwartz (Basic Quality Contributor) Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: DML Severity:S3 (Non-critical)
Version:5.5.27 OS:Linux
Assigned to: CPU Architecture:Any

[21 Sep 2012 17:57] Baron Schwartz
Description:
The server crashes when the replication thread executes specific queries from the binlog. Here is the error log entry:

15:44:52 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=205520896
read_buffer_size=1048576
max_used_connections=0
max_threads=120
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 = 570711 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0xf848b40
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 = 7f7cf68d7e88 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x20)[0x73fe4a]
/usr/sbin/mysqld(handle_fatal_signal+0x3f1)[0x645321]
/lib64/libpthread.so.0(+0xfa60)[0x7f7cf5f0ba60]
/usr/sbin/mysqld[0x8a7706]
/usr/sbin/mysqld(_ZN28ACL_internal_schema_registry6lookupEPKc+0x44)[0x51fd1e]
/usr/sbin/mysqld(_Z24get_cached_schema_accessP22st_grant_internal_infoPKc+0x1c)[0x51fd57]
/usr/sbin/mysqld(_Z23get_cached_table_accessP22st_grant_internal_infoPKcS2_+0x22)[0x51fd8b]
/usr/sbin/mysqld(_Z11check_grantP3THDmP10TABLE_LISTbjb+0x13a)[0x52570a]
/usr/sbin/mysqld(_Z25check_single_table_accessP3THDmP10TABLE_LISTb+0xa7)[0x565a92]
/usr/sbin/mysqld(_Z22check_one_table_accessP3THDmP10TABLE_LIST+0x14)[0x565b01]
120921 11:44:52 [Note] Slave I/O thread: connected to master 'repl@10.8.0.75:3306',replication started in log 'mysql-bin.005857' at position 803287035
/usr/sbin/mysqld(_Z15insert_precheckP3THDP10TABLE_LIST+0x34)[0x566b8a]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x1c87)[0x56b20a]
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x141)[0x56d8ae]
/usr/sbin/mysqld(_ZN15Query_log_event14do_apply_eventEPK14Relay_log_infoPKcj+0xa70)[0x6d2160]
/usr/sbin/mysqld(_Z26apply_event_and_update_posP9Log_eventP3THDP14Relay_log_info+0x105)[0x51761e]
/usr/sbin/mysqld[0x51bcb4]
/usr/sbin/mysqld(handle_slave_sql+0x950)[0x51f17f]
/lib64/libpthread.so.0(+0x79dc)[0x7f7cf5f039dc]
/lib64/libc.so.6(clone+0x6d)[0x7f7cf4c88dcd]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (f84fef5): insert into [redacted] ( SELECT * FROM [redacted] WHERE CLIENT=@client AND DAY >= @start AND DAY < @end and engineacct = @engineacct )
Connection ID (thread ID): 2

How to repeat:
It will be difficult and expensive for me to provide a repeatable test case. Please advise whether the contents of the error log will help your developers figure out what might be wrong, or whether I need to follow up later when I have the hardware resources to set up a repeatable test case.
[23 Sep 2012 16:20] MySQL Verification Team
Most likely a duplicate of:

Bug 14597605 - SLAVES CRASHES WITH USER VARIABLES AND REPLICATE-IGNORE-TABLE OPTIONS
[24 Sep 2012 15:47] Baron Schwartz
We do use replicate-ignore-table options.
[11 Oct 2012 11:45] Arnaud Gadal
I think I got the same one (crash on 5.5.28, 27, 25a but OK on 5.5.24).

09:48:08 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=2147483648
read_buffer_size=1048576
max_used_connections=1
max_threads=500
thread_count=2
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 3126862 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x14838530
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 = 7f597969bea8 thread_stack 0x40000
/usr/local/mysql/bin/mysqld(my_print_stacktrace+0x35)[0x79e385]
/usr/local/mysql/bin/mysqld(handle_fatal_signal+0x403)[0x66e113]
/lib/libpthread.so.0(+0xeff0)[0x7f5979346ff0]
/lib/libc.so.6(+0x106eca)[0x7f5978616eca]
/usr/local/mysql/bin/mysqld(_ZN5TABLE4initEP3THDP10TABLE_LIST+0x4d)[0x5edeed]
/usr/local/mysql/bin/mysqld(_Z10open_tableP3THDP10TABLE_LISTP11st_mem_rootP18Open_table_context+0x14e)[0x54196e]
/usr/local/mysql/bin/mysqld(_Z11open_tablesP3THDPP10TABLE_LISTPjjP19Prelocking_strategy+0x42b)[0x54316b]
/usr/local/mysql/bin/mysqld(_Z20open_and_lock_tablesP3THDP10TABLE_LISTbjP19Prelocking_strategy+0x44)[0x543b84]
/usr/local/mysql/bin/mysqld(_Z12mysql_insertP3THDP10TABLE_LISTR4ListI4ItemERS3_IS5_ES6_S6_15enum_duplicatesb+0xc1)[0x567a11]
/usr/local/mysql/bin/mysqld(_Z21mysql_execute_commandP3THD+0x8bf)[0x57757f]
/usr/local/mysql/bin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x18a)[0x57b50a]
/usr/local/mysql/bin/mysqld(_ZN15Query_log_event14do_apply_eventEPK14Relay_log_infoPKcj+0xd5c)[0x71affc]
/usr/local/mysql/bin/mysqld(_Z26apply_event_and_update_posP9Log_eventP3THDP14Relay_log_info+0x125)[0x516b25]
/usr/local/mysql/bin/mysqld[0x51cefa]
/usr/local/mysql/bin/mysqld(handle_slave_sql+0xaac)[0x51e03c]
/lib/libpthread.so.0(+0x68ca)[0x7f597933e8ca]
/lib/libc.so.6(clone+0x6d)[0x7f59785df92d]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (147bd9a5): insert into XXXXX (...) values (Null,8,IfNull(@SHARD_ID, Null),'XXXXX','XXXXX','XXXXX','',11,1,0,1,0,0,1,1,'2012-10-08 16:29:05','2010-09-13 18:34:24')
Connection ID (thread ID): 3
Status: NOT_KILLED

I use replicate-wild-ignore-table.

It crashes on a slave since I upgraded it from 5.5.17 -> 5.5.28.
Then I tried previous version : it crashes too on 5.5.27, 5.5.25a but it's ok on 5.5.24.

As soon as the SQL_THREAD begins, it crashed.
I tried START SLAVE SQL_THREAD UNTIL... and it seems it crashes very soon :

# at 107
#700101  1:00:00 server id 6000  end_log_pos 0  Rotate to log-bin.000680  pos: 54291846
# at 148
#121008 16:23:26 server id 6000  end_log_pos 0  Start: binlog v 4, server v 5.5.17-7.xxxxxxxxx-log created 121008 16:23:26
BINLOG '
3uFyUA9wFwAAZwAAAAAAAAAAAAQANS41LjE3LTcudHdlbmdhLWxvZwAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAVAAEGggAAAAICAgCAA==
'/*!*/;
# at 251
#121008 16:29:20 server id 101  end_log_pos 54291910    Query   thread_id=519342611     exec_time=0     error_code=0
SET TIMESTAMP=1349706560/*!*/;
SET @@session.pseudo_thread_id=519342611/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=0/*!*/;
SET @@session.auto_increment_increment=10, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=192/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN;
# at 315
#121008 16:29:20 server id 101  end_log_pos 54291938    Intvar
SET INSERT_ID=3853281/*!*/;
# at 343
#121008 16:29:20 server id 6000  end_log_pos 54291970   User_var
SET @`SHARD_ID`:=NULL/*!*/;
# at 375
[...]

START SLAVE SQL_THREAD UNTIL relay_log_file='xxxxx-relay-bin.000002',relay_log_pos=315;
No connection. Trying to reconnect...
Connection id:    3
Current database: mydb

Query OK, 0 rows affected (0.00 sec)

mysql> show slave status\G
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/tmp/mysql.sock' (2)
ERROR:
Can't connect to the server

Note : a relay log written by an IO_THREAD from 5.5.28 but executed by a 5.5.24 SQL_THREAD works.
[11 Oct 2012 12:21] Arnaud Gadal
I've just tried to disable my replicate-wild-ignore-table setting, and it works, no crash on 5.5.28.
Not a solution obviously, but Shane's guess seems to be right.
[12 Oct 2012 3:12] MySQL Verification Team
Duplicate of this, which is fixed in 5.5.29+
So we'll have to wait for that to be released.
Bug 14597605 - SLAVES CRASHES WITH USER VARIABLES AND REPLICATE-IGNORE-TABLE OPTIONS