Bug #66781 Debug assertion failure in query cache code on sysbench oltp test
Submitted: 12 Sep 2012 9:02 Modified: 18 Jan 2013 13:19
Reporter: Alexey Kopytov Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Query Cache Severity:S3 (Non-critical)
Version:5.1.65, 5.5.27, 5.5.29, 5.7.0 OS:Any
Assigned to: CPU Architecture:Any

[12 Sep 2012 9:02] Alexey Kopytov
Description:
Debug builds of both MySQL 5.1 and 5.5 crash with an assertion failure in the query cache code when started with --debug on the sysbench OLTP load. Though the assertions and backtraces are different. Tested on debug builds of 5.1.65 and 5.5.27 from the launchpad branches.

5.1.65 backtrace:

ssertion failed: (thd->net.query_cache_query == 0), function unknown function, file sql_cache.cc, line 1505.

Program received signal SIGABRT, Aborted.
[Switching to process 6542 thread 0x2703]
0x00007fff81198ce2 in __pthread_kill ()
(gdb) bt
#0  0x00007fff81198ce2 in __pthread_kill ()
#1  0x00007fff8673d7d2 in pthread_kill ()
#2  0x00007fff8672ea7a in abort ()
#3  0x00007fff867615de in __assert_rtn ()
#4  0x00000001003b7923 in Query_cache::send_result_to_client (this=0x10092fbc0, thd=0x10e827a28, sql=0x10112c638 "SELECT c from sbtest where id=2507", query_length=34) at sql_cache.cc:1505
#5  0x0000000100261c0d in Prepared_statement::execute (this=0x10d1dd388, expanded_query=0x10f2b0dd0, open_cursor=false) at sql_prepare.cc:3649
#6  0x000000010026204d in Prepared_statement::execute_loop (this=0x10d1dd388, expanded_query=0x10f2b0dd0, open_cursor=false, packet=0x10e82a632 "", packet_end=0x10e82a638 "") at sql_prepare.cc:3333
#7  0x0000000100262879 in mysqld_stmt_execute (thd=0x10e827a28, packet_arg=0x10e82a629 "\001", packet_length=15) at sql_prepare.cc:2506
#8  0x0000000100180a36 in dispatch_command (command=COM_STMT_EXECUTE, thd=0x10e827a28, packet=0x10e82a629 "\001", packet_length=15) at sql_parse.cc:1234
#9  0x000000010018283b in do_command (thd=0x10e827a28) at sql_parse.cc:893
#10 0x0000000100166263 in handle_one_connection (arg=0x10e827a28) at sql_connect.cc:1454
#11 0x00007fff8673b8bf in _pthread_start ()
#12 0x00007fff8673eb75 in thread_start ()

5.5.27 backtrace:

Assertion failed: (0), function end_of_result, file /Users/kaa/src/launchpad/mysql-5.5/sql/sql_cache.cc, line 1037.

Program received signal SIGABRT, Aborted.
[Switching to process 6603 thread 0x2a03]
0x00007fff81198ce2 in __pthread_kill ()
(gdb) bt
#0  0x00007fff81198ce2 in __pthread_kill ()
#1  0x00007fff8673d7d2 in pthread_kill ()
#2  0x00007fff8672ea7a in abort ()
#3  0x00007fff867615de in __assert_rtn ()
#4  0x000000010025ea7d in Query_cache::end_of_result (this=0x100d29460, thd=0x101923800) at sql_cache.cc:1037
#5  0x00000001002caaf6 in dispatch_command (command=COM_STMT_EXECUTE, thd=0x101923800, packet=0x10192ec01 "", packet_length=17) at sql_parse.cc:1406
#6  0x00000001002cb1a1 in do_command (thd=0x101923800) at sql_parse.cc:773
#7  0x000000010040ba73 in do_handle_one_connection (thd_arg=0x101923800) at sql_connect.cc:840
#8  0x000000010040bb73 in handle_one_connection (arg=0x101923800) at sql_connect.cc:759
#9  0x00007fff8673b8bf in _pthread_start ()
#10 0x00007fff8673eb75 in thread_start ()

Sometimes it crashes almost immediately, sometimes it takes a while. At one of the test runs on 5.5.27 the server didn't crash but instead sysbench failed with the following error:

"
ALERT: MySQL error: 

FATAL: Error fetching result: `pA?`
Done.

Note: net_clear() skipped 176 bytes from file: socket (5)
"

In both cases the server was started with --debug --query_cache_size=32M --query_cache_type=1. I could not reproduce it with the --debug option removed.

sysbench command line (for 0.4):

sysbench --test=oltp  --oltp-table-size=5000 --num-threads=4 run

How to repeat:
Use the above sysbench command line on a debug server started with --debug.
[15 Sep 2012 7:41] Sveta Smirnova
Thank you for the report.

Verified as described.
[18 Jan 2013 13:19] Paul DuBois
Noted in 5.7.1 changelog.

If one thread was rebuilding a result for the query cache, other
threads in the middle of using the previous result could fail to
discard the old result properly. For debug builds, this raised an
assertion.