Crash in sql_cache.cc (mariadb 5.5.25)
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
MariaDB |
Fix Committed
|
High
|
Michael Widenius |
Bug Description
We've managed to reproduce a bug we hit in production some weeks ago. It occurs
in the query cache while doing selects from multiple connections.
Here's the full gdb traceback:
Program received signal SIGABRT, Aborted.
[Switching to Thread 0x7fffe92fe700 (LWP 29307)]
0x00007ffff61e9f55 in raise () from /lib64/libc.so.6
(gdb) bt full
#0 0x00007ffff61e9f55 in raise () from /lib64/libc.so.6
No symbol table info available.
#1 0x00007ffff61eb3d8 in abort () from /lib64/libc.so.6
No symbol table info available.
#2 0x00007ffff61e2f42 in ?? () from /lib64/libc.so.6
No symbol table info available.
#3 0x00007ffff61e2ff2 in __assert_fail () from /lib64/libc.so.6
No symbol table info available.
#4 0x00000000005bee14 in Query_cache:
at /var/tmp/
tot_length = 140737105610912
query = 0x5a3d8a "\211\330H\
tables_type = 0 '\000'
level = 2147483653, prev = 0x7fffe92fcda0}
#5 0x000000000060af7a in execute_
at /var/tmp/
lex = 0x7fffd401ca78
result = 0x7fffd4019ba0
res = false
#6 0x00000000006044da in mysql_execute_
res = 0
lex = 0x7fffd401ca78
level = 2147483652, prev = 0x7fffe92fd530}
up_result = 0
select_lex = 0x7fffd401d200
first_table = 0x7fffd4021b18
all_tables = 0x7fffd4021b18
unit = 0x7fffd401cb28
#7 0x00000000008db161 in mysql_open_cursor (thd=0x1f20010, result=
at /var/tmp/
save_result = 0x7fffd40226f8
lex = 0x7fffd401ca78
rc = 0
#8 0x0000000000623bd8 in Prepared_
at /var/tmp/
stmt_backup = {<ilink> = {_vptr.ilink = 0xcd3950, prev = 0x0, next = 0x0}, <Query_arena> = {_vptr.Query_arena = 0xcd3980, free_list = 0x7fffe92fd2f0,
str = 0xc60c8d "\311\303UH\
str = 0x7fffd4019958 "SELECT value_id, len FROM (SELECT value_id, LENGTH(data) len FROM events WHERE scope_id = 4 AND timestamp_id = 0 AND key_id = 395871952) tbl ORDER BY 2 DESC LIMIT 24", length = 165}, cs = 0x1491140}, base_query = {Ptr = 0x0, str_length = 0, Alloced_length = 0, extra_alloc = 0,
alloced = false, str_charset = 0x135f260}, db = 0x7fffe92fd3b0 "", db_length = 140737105613680, query_cache_
error = true
#9 0x0000000000622d90 in Prepared_
packet_
error = false
#10 0x0000000000620d98 in mysqld_stmt_execute (thd=0x1f20010, packet_
at /var/tmp/
packet = 0x1f2f98a ""
flags = 1
Ptr = 0x7fffd4000920 "SELECT value_id, len FROM (SELECT value_id, LENGTH(data) len FROM events WHERE scope_id = 4 AND timestamp_id = 0 AND key_id = 395871952) tbl ORDER BY 2 DESC LIMIT 24", str_length = 165, Alloced_length = 296, extra_alloc = 128, alloced = true, str_charset = 0x1491140}
packet_end = 0x1f2f9a8 ""
stmt = 0x7fffd4005e50
open_cursor = true
stmt_id = 1
level = 2147483651, prev = 0x7fffe92fd6c0}
#11 0x0000000000601a7c in dispatch_command (command=
at /var/tmp/
net = 0x1f20320
error = false
prev = 0x7fffe92fde30}
#12 0x0000000000600feb in do_command (thd=0x1f20010) at /var/tmp/
packet = 0x1f2f980 "\027\001"
net = 0x1f20320
command = COM_STMT_EXECUTE
#13 0x00000000006f44f0 in do_handle_
create_user = true
thd = 0x1f20010
#14 0x00000000006f3fc2 in handle_
thd = 0x1f20010
#15 0x00007ffff75a5f4a in start_thread () from /lib64/
No symbol table info available.
#16 0x00007ffff629afad in clone () from /lib64/libc.so.6
No symbol table info available.
>How-To-Repeat:
The query log shows these queries before sigabrt:ing (segfault from a non-debug build, at sql_cache.cc:1492):
CREATE TABLE IF NOT EXISTS events (scope_id INT(11) UNSIGNED NOT NULL,timestamp_id MEDIUMINT(11) UNSIGNED NOT NULL,key_id INT(11) UNSIGNED NOT NULL,value_id INT(11) UNSIGNED NOT NULL,data MEDIUMBLOB NOT NULL,PRIMARY KEY (scope_id, timestamp_id, key_id, value_id))
CREATE TABLE IF NOT EXISTS ids (id INT(11) UNSIGNED NOT NULL PRIMARY KEY,value VARCHAR(255) NOT NULL UNIQUE)
CREATE TABLE IF NOT EXISTS history (id INT(11) UNSIGNED NOT NULL AUTO_INCREMENT PRIMARY KEY,timestamp_id INT(11) NOT NULL,date TIMESTAMP DEFAULT CURRENT_TIMESTAMP)
SELECT timestamp_id FROM history ORDER BY id DESC LIMIT 1
SELECT value_id, len FROM (SELECT value_id, LENGTH(data) len FROM events WHERE scope_id = ? AND timestamp_id = ? AND key_id = ?) tbl ORDER BY 2 DESC LIMIT ?
SELECT value_id, len FROM (SELECT value_id, LENGTH(data) len FROM events WHERE scope_id = ? AND timestamp_id = ? AND key_id = ?) tbl ORDER BY 2 DESC LIMIT ?
SELECT value_id, len FROM (SELECT value_id, LENGTH(data) len FROM events WHERE scope_id = ? AND timestamp_id = ? AND key_id = ?) tbl ORDER BY 2 DESC LIMIT ?
The crash does not happen if we run it sequentially. We're using a ConnectionPool from libzdb (2.10.5), and it occurs every time. So far, we've reproduced this on linux 32 & 64 bit environments as well as Mac OS X Mountain Lion. Haven't tried MySQL 5.5 yet.
>Fix:
No fix as of yet (turn off query cache or don't run it in parallel)
Changed in maria: | |
status: | New → Fix Committed |
A couple of notes:
1. This is reproduced against an empty table as well :store_ query (this=0x1495ce0, thd=0x1f22000, tables_ used=0x7fffb800 7bb0) portage/ dev-db/ mariadb- 5.5.25/ work/mysql/ sql/sql_ cache.cc: 1386
__PRETTY_ FUNCTION_ _ = "void Query_cache: :store_ query(THD* , TABLE_LIST*)"
local_ tables = 32513 203\304\ 070[]ÐUH\ 211\345H\ 203\354\ 060H\211} \370\211u\ 364\211U\ 360\211M\ 354L\211E\ 340L\211M\ 330H\213E\ 370\213U\ 364\211\ 020H\213E\ 370\213U\ 360\211P\ 004H\213E\ 370\213U\ 354\211P\ bH\213E\ 370H\213U\ 340H\211P\ 020H\213E\ 370H\213U\ 330H\211P\ 030H\213E\ 370\306@ "
query_ length = 140737105905856
_db_stack_ frame_ = {func = 0xcdbd5a "mysql_ execute_ command" , portage/ dev-db/ mariadb- 5.5.25/ work/mysql/ sql/sql_ parse.cc" , level = 2147483653, prev = 0x7fffe9344da0} sqlcom_ select (thd=0x1f22000, all_tables= 0x7fffb8007bb0) portage/ dev-db/ mariadb- 5.5.25/ work/mysql/ sql/sql_ parse.cc: 4620 command (thd=0x1f22000) at /var/tmp/ portage/ dev-db/ mariadb- 5.5.25/ work/mysql/ sql/sql_ parse.cc: 2189
privileges_ requested = 1
_db_stack_ frame_ = {func = 0xce0003 "mysqld_ stmt_execute" , portage/ dev-db/ mariadb- 5.5.25/ work/mysql/ sql/sql_ prepare. cc", level = 2147483652, prev = 0x7fffe9345530}
__FUNCTION_ _ = "mysql_ execute_ command"
__PRETTY_ FUNCTION_ _ = "int mysql_execute_ command( THD*)"
have_table_ map_for_ update = false 0x7fffb8006348, pcursor= 0x7fffb80063a8) portage/ dev-db/ mariadb- 5.5.25/ work/mysql/ sql/sql_ cursor. cc:118
result_ materialize = 0x7fffb8003218 statement: :execute (this=0x7fffb80 06290, expanded_ query=0x7fffe93 45510, open_cursor=true) portage/ dev-db/ mariadb- 5.5.25/ work/mysql/ sql/sql_ prepare. cc:3869
2. The CREATE TABLE queries doesn't affect the outcome
3. We rewrote the query to not do a subselect, and it still crashes. Here's the gdb stracktrace:
0 0x00007ffff61e9f55 in raise () from /lib64/libc.so.6
No symbol table info available.
#1 0x00007ffff61eb3d8 in abort () from /lib64/libc.so.6
No symbol table info available.
#2 0x00007ffff61e2f42 in ?? () from /lib64/libc.so.6
No symbol table info available.
#3 0x00007ffff61e2ff2 in __assert_fail () from /lib64/libc.so.6
No symbol table info available.
#4 0x00000000005bee14 in Query_cache:
at /var/tmp/
tot_length = 140737105905824
query = 0x5a3d8a "\211\330H\
tables_type = 0 '\000'
file = 0xcdb6e0 "/var/tmp/
#5 0x000000000060af7a in execute_
at /var/tmp/
lex = 0x7fffb8006698
result = 0x7fffb8003218
res = false
#6 0x00000000006044da in mysql_execute_
res = 0
lex = 0x7fffb8006698
file = 0xcdf8d8 "/var/tmp/
up_result = 0
select_lex = 0x7fffb8006e20
first_table = 0x7fffb8007bb0
all_tables = 0x7fffb8007bb0
unit = 0x7fffb8006748
#7 0x00000000008db161 in mysql_open_cursor (thd=0x1f22000, result=
at /var/tmp/
save_result = 0x7fffb80084b8
lex = 0x7fffb8006698
rc = 0
#8 0x0000000000623bd8 in Prepared_
at /var/tmp/
stmt_backup = {<ilink> = {_vptr.ilink = 0xcd3950, prev = 0x0, next = 0x0}, <Query_arena> = {_vptr.Query_arena = 0xcd3980, free_list =
0x7fffe93452f0, mem_root = 0xc74389, is_backup_arena = ...