|
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::store_query (this=0x1495ce0, thd=0x1f20010, tables_used=0x7fffd4021b18)
at /var/tmp/portage/dev-db/mariadb-5.5.25/work/mysql/sql/sql_cache.cc:1386
tot_length = 140737105610912
_PRETTY_FUNCTION_ = "void Query_cache::store_query(THD*, TABLE_LIST*)"
local_tables = 1
query = 0x5a3d8a "\211\330H\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 = 140737105610944
tables_type = 0 '\000'
db_stack_frame =
{func = 0xcdbd5a "mysql_execute_command", file = 0xcdb6e0 "/var/tmp/portage/dev-db/mariadb-5.5.25/work/mysql/sql/sql_parse.cc",
level = 2147483653, prev = 0x7fffe92fcda0}
#5 0x000000000060af7a in execute_sqlcom_select (thd=0x1f20010, all_tables=0x7fffd4021b18)
at /var/tmp/portage/dev-db/mariadb-5.5.25/work/mysql/sql/sql_parse.cc:4620
lex = 0x7fffd401ca78
result = 0x7fffd4019ba0
res = false
#6 0x00000000006044da in mysql_execute_command (thd=0x1f20010) at /var/tmp/portage/dev-db/mariadb-5.5.25/work/mysql/sql/sql_parse.cc:2189
privileges_requested = 1
res = 0
lex = 0x7fffd401ca78
db_stack_frame =
{func = 0xce0003 "mysqld_stmt_execute", file = 0xcdf8d8 "/var/tmp/portage/dev-db/mariadb-5.5.25/work/mysql/sql/sql_prepare.cc",
level = 2147483652, prev = 0x7fffe92fd530}
_FUNCTION_ = "mysql_execute_command"
up_result = 0
_PRETTY_FUNCTION_ = "int mysql_execute_command(THD*)"
select_lex = 0x7fffd401d200
first_table = 0x7fffd4021b18
all_tables = 0x7fffd4021b18
unit = 0x7fffd401cb28
have_table_map_for_update = false
#7 0x00000000008db161 in mysql_open_cursor (thd=0x1f20010, result=0x7fffd4005f08, pcursor=0x7fffd4005f68)
at /var/tmp/portage/dev-db/mariadb-5.5.25/work/mysql/sql/sql_cursor.cc:118
save_result = 0x7fffd40226f8
result_materialize = 0x7fffd4019ba0
lex = 0x7fffd401ca78
rc = 0
#8 0x0000000000623bd8 in Prepared_statement::execute (this=0x7fffd4005e50, expanded_query=0x7fffe92fd510, open_cursor=true)
at /var/tmp/portage/dev-db/mariadb-5.5.25/work/mysql/sql/sql_prepare.cc:3869
stmt_backup = {<ilink> = {_vptr.ilink = 0xcd3950, prev = 0x0, next = 0x0}, <Query_arena> = {_vptr.Query_arena = 0xcd3980, free_list = 0x7fffe92fd2f0,
mem_root = 0xc74389, is_backup_arena = false, is_reprepared = false, state = 32767}, id = 0, mark_used_columns = MARK_COLUMNS_READ, name =
{
str = 0xc60c8d "\311\303UH\211\345H\203\354PH\211}
\310H\211u\300\211U\274H\215E\320H\211\301\272
{", length = 8610247264}
, lex = 0x1f222e8,
query_string = {string =
{
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_is_applicable = -98 '\236'}
old_stmt_arena = 0x1f20028
saved_cur_db_name_buf = "\220W\000\324\377\177\000\000\260\323/\351\377\177\000\000@\324/\351\377\177\000\000E\331a\000\000\000\000\000\360\323/\351\377\177\000\000\020\325/\351\377\177\000\000\250\371\362\001\000\000\000\000\250\371\362\001\000\000\000\000\212\371\362\001\000\000\000\000P^\000\324\377\177", '\000' <repeats 23 times>, "\177\000\000`\362\065\001\000\000\000\000\003\000\316\000\000\000\000\000\330\370\315\000\000\000\000\000\004\000\000\200\377\177\000\000\060\325/\351\377\177\000\000\003\000\316\000\000\000\000\000\260\323/\351\377\177\000\000\310!\002\324\377\177\000\000\370&\002\324\377\177\000\000\330&\002\324\377\177\000\000\020\000\362\001\000\000\000\000\370&\002\324\377\177\000\000[I"
saved_cur_db_name =
{str = 0x7fffe92fd360 "\220W", length = 202}
cur_db_changed = false
_PRETTY_FUNCTION_ = "bool Prepared_statement::execute(String*, bool)"
error = true
stmt_db_name =
{str = 0x7fffd401dd70 "juliette", length = 8}
#9 0x0000000000622d90 in Prepared_statement::execute_loop (this=0x7fffd4005e50, expanded_query=0x7fffe92fd510, open_cursor=true, packet=0x1f2f98a "",
packet_end=0x1f2f9a8 "") at /var/tmp/portage/dev-db/mariadb-5.5.25/work/mysql/sql/sql_prepare.cc:3545
MAX_REPREPARE_ATTEMPTS = 3
_PRETTY_FUNCTION_ = "bool Prepared_statement::execute_loop(String*, bool, uchar*, uchar*)"
reprepare_observer =
{m_invalidated = false}
error = false
reprepare_attempt = 0
need_set_parameters = false
#10 0x0000000000620d98 in mysqld_stmt_execute (thd=0x1f20010, packet_arg=0x1f2f981 "\001", packet_length=39)
at /var/tmp/portage/dev-db/mariadb-5.5.25/work/mysql/sql/sql_prepare.cc:2656
packet = 0x1f2f98a ""
flags = 1
expanded_query =
{
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
save_protocol = 0x1f205d8
db_stack_frame =
{func = 0xcdb899 "dispatch_command", file = 0xcdb6e0 "/var/tmp/portage/dev-db/mariadb-5.5.25/work/mysql/sql/sql_parse.cc",
level = 2147483651, prev = 0x7fffe92fd6c0}
#11 0x0000000000601a7c in dispatch_command (command=COM_STMT_EXECUTE, thd=0x1f20010, packet=0x1f2f981 "\001", packet_length=39)
at /var/tmp/portage/dev-db/mariadb-5.5.25/work/mysql/sql/sql_parse.cc:1009
net = 0x1f20320
_PRETTY_FUNCTION_ = "bool dispatch_command(enum_server_command, THD*, char*, uint)"
_FUNCTION_ = "dispatch_command"
error = false
db_stack_frame =
{func = 0xcdb7e4 "do_command", file = 0xcdb6e0 "/var/tmp/portage/dev-db/mariadb-5.5.25/work/mysql/sql/sql_parse.cc", level = 2147483650,
prev = 0x7fffe92fde30}
#12 0x0000000000600feb in do_command (thd=0x1f20010) at /var/tmp/portage/dev-db/mariadb-5.5.25/work/mysql/sql/sql_parse.cc:794
return_value = false
packet = 0x1f2f980 "\027\001"
packet_length = 40
net = 0x1f20320
command = COM_STMT_EXECUTE
_PRETTY_FUNCTION_ = "bool do_command(THD*)"
db_stack_frame =
{func = 0xeccf05 "?func", file = 0xeccf0b "?file", level = 2147483649, prev = 0x0}
#13 0x00000000006f44f0 in do_handle_one_connection (thd_arg=0x1f20010) at /var/tmp/portage/dev-db/mariadb-5.5.25/work/mysql/sql/sql_connect.cc:1253
create_user = true
thd = 0x1f20010
#14 0x00000000006f3fc2 in handle_one_connection (arg=0x1f20010) at /var/tmp/portage/dev-db/mariadb-5.5.25/work/mysql/sql/sql_connect.cc:1168
thd = 0x1f20010
#15 0x00007ffff75a5f4a in start_thread () from /lib64/libpthread.so.0
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)
|
LPexportBug1039277.xml