Bug #69426 Crash Under Load
Submitted: 7 Jun 2013 12:57 Modified: 7 Jun 2013 17:42
Reporter: Will Fong Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: General Severity:S2 (Serious)
Version:5.5.29 OS:Linux
Assigned to: CPU Architecture:Any

[7 Jun 2013 12:57] Will Fong
Description:
Hello,

We experienced two crashes that seem very similar to these two bug reports, however in version 5.5: 

http://bugs.mysql.com/bug.php?id=51054

http://bugs.mysql.com/bug.php?id=39022

Stack trace attached:

130604 15:22:34  InnoDB: Rollback of non-prepared transactions completed
130604 15:22:36 [Note] Starting crash recovery...
130604 15:22:36  InnoDB: Starting recovery for XA transactions...
130604 15:22:36  InnoDB: Transaction 1CA3FF25F in prepared state after recovery
130604 15:22:36  InnoDB: Transaction contains changes to 7 rows
130604 15:22:36  InnoDB: 1 transactions in prepared state after recovery
130604 15:22:36 [Note] Found 1 prepared transaction(s) in InnoDB
130604 15:22:36 [Note] Crash recovery finished.
130604 15:22:36 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
130604 15:22:36 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
130604 15:22:36 [Note] Server socket created on IP: '0.0.0.0'.
130604 15:22:36 [Note] Event Scheduler: Loaded 0 events
130604 15:22:36 [Note] /usr/libexec/mysqld: ready for connections.
Version: '5.5.29-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server (GPL) by Remi
130604 15:22:39 [Warning] Timeout waiting for reply of binlog (file: mysql-bin.000770, pos: 2236), semi-sync up to file , position 0.
130604 15:22:39 [Note] Semi-sync replication switched OFF.
130604 15:24:04 [Note] Start semi-sync binlog_dump to slave (server_id: 660), pos(mysql-bin.000769, 484922910)
130604 15:24:04 [Note] Semi-sync replication switched ON with slave (server_id: 660) at (mysql-bin.000770, 327065)
130604 15:24:10 [ERROR] /usr/libexec/mysqld: Sort aborted: Server shutdown in progress
...
130604 15:26:39 [ERROR] /usr/libexec/mysqld: Sort aborted: Server shutdown in progress
 len 224; hex 88f9113cbf2b0000286e606fb92b000080cbd240b92b0000000000000000000000000000000000000000000000000000030000000000000003000000000000000100000000000000000000000000000000000000000000000300000000000000000000000000000000000000000000000000000000000000000000000000000001000000000000008344510700000000eee293a4bf2b00000200000000000000010000000000000080cbd240b92b0000000000000000000060e1117700000000020000000000000018dea79000000000e8e293a4bf2b00001000000000000000; asc    < +  (n`o +     @ +                                                                                                                   DQ          +                     @ +          `  w                         +          ;
TRANSACTION 1CA452879, ACTIVE 14 sec fetching rows, thread declared inside InnoDB 444
mysql tables in use 2, locked 0
MySQL thread id 16451, OS thread handle 0x2bbed74fe940, query id 661188 16-38.idc.bm-sms.co.jp 192.168.16.38 db_kp_user Sending data
select count(distinct trncarepla0_.care_plan_support_progress_info_internal_id) as col_0_0_ from db_kp.trn_care_plan_support_progress_info trncarepla0_ inner join db_kp.led_user leduser1_ on trncarepla0_.user_internal_id=leduser1_.user_internal_id where leduser1_.user_internal_id=2403785 and trncarepla0_.ones_company_plant_internal_id=15979
130604 15:26:39  InnoDB: Assertion failure in thread 48098656119104 in file btr0pcur.c line 250
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.5/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
06:26:39 UTC - 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=33554432
read_buffer_size=2097152
max_used_connections=1001
max_threads=1000
thread_count=713
connection_count=713
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 10284166 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x2bbf64792960
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 = 2bbed74fe098 thread_stack 0x30000
/usr/libexec/mysqld(my_print_stacktrace+0x2e)[0x7b12fe]
/usr/libexec/mysqld(handle_fatal_signal+0x3e2)[0x67d7d2]
/lib64/libpthread.so.0[0x3d2a40eca0]
/lib64/libc.so.6(gsignal+0x35)[0x3d29c302c5]
/lib64/libc.so.6(abort+0x110)[0x3d29c31d70]
/usr/libexec/mysqld[0x889cdf]
/usr/libexec/mysqld[0x83f4f7]
/usr/libexec/mysqld[0x843470]
/usr/libexec/mysqld[0x820abc]
/usr/libexec/mysqld(_ZN7handler21read_multi_range_nextEPP18st_key_multi_range+0x29)[0x67e0e9]
/usr/libexec/mysqld(_ZN18QUICK_RANGE_SELECT8get_nextEv+0x16b)[0x744e2b]
/usr/libexec/mysqld(_ZN26QUICK_ROR_INTERSECT_SELECT8get_nextEv+0x12c)[0x74538c]
/usr/libexec/mysqld[0x7575f9]
/usr/libexec/mysqld(_Z10sub_selectP4JOINP13st_join_tableb+0x5f)[0x59acff]
/usr/libexec/mysqld[0x5a0bb8]
/usr/libexec/mysqld(_ZN4JOIN4execEv+0x1230)[0x5b0f80]
/usr/libexec/mysqld(_Z12mysql_selectP3THDPPP4ItemP10TABLE_LISTjR4ListIS1_ES2_jP8st_orderSB_S2_SB_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x1c9)[0x5b2349]
/usr/libexec/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0x16f)[0x5b2c5f]
/usr/libexec/mysqld[0x5741dd]
/usr/libexec/mysqld(_Z21mysql_execute_commandP3THD+0x41d1)[0x578901]
/usr/libexec/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x10a)[0x57a7ba]
/usr/libexec/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x14ed)[0x57c4cd]
/usr/libexec/mysqld(_Z10do_commandP3THD+0xc2)[0x57c822]
/usr/libexec/mysqld(_Z24do_handle_one_connectionP3THD+0xf2)[0x610442]
/usr/libexec/mysqld(handle_one_connection+0x53)[0x610533]
/usr/libexec/mysqld(pfs_spawn_thread+0x5a)[0x7d5f3a]
/lib64/libpthread.so.0[0x3d2a40683d]
/lib64/libc.so.6(clone+0x6d)[0x3d29cd503d]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (96280250): select count(distinct trncarepla0_.care_plan_support_progress_info_internal_id) as col_0_0_ from db_kp.trn_care_plan_support_progress_info trncarepla0_ inner join db_kp.led_user leduser1_ on trncarepla0_.user_internal_id=leduser1_.user_internal_id where leduser1_.user_internal_id=2403785 and trncarepla0_.ones_company_plant_internal_id=15979
Connection ID (thread ID): 16451
Status: KILL_CONNECTION

Thanks,
-will

How to repeat:
Unable to repeat. 

Suggested fix:
I believe the answers are in the previous two tickets:

http://bugs.mysql.com/bug.php?id=51054

http://bugs.mysql.com/bug.php?id=39022
[7 Jun 2013 17:42] MySQL Verification Team
This is a known bug. See http://bugs.mysql.com/bug.php?id=68051