A little more info on one of the 5.1 assertions that I can reproduce nearly at will:
InnoDB: Assertion failure in thread 140323328083712 in file lock/lock0lock.c line 3799
InnoDB: Failing assertion: (table->locks).count > 0
What seems to be happening is that a FLUSH TABLES is closing an innodb dict table that still has locks on it. This is causing a dict table handle count to get decremented down to 0 yet a transaction still has an IX lock on the table.
Along comes the dictionary trimmer and sees the table with no open handles, so, it removes it from the cache. Later on, when the transaction is cleaning up, it tries to remove the (now invalid) table from its lock list and all kinds of interesting things can happen...
I hacked in an assertion in row_prebuilt_free just before it decrements the table handle count to assert if there is a matching trx to table lock in the table lock list and it fires with the following bt full:
If I do not assert here but just log the prebuilt->table and prebuilt->trx, the real assertion mentioned above will be triggered and the prebuilt table transaction ans lock list pointers will all match the ones discovered/logged here.
A little more info on one of the 5.1 assertions that I can reproduce nearly at will: >locks) .count > 0
InnoDB: Assertion failure in thread 140323328083712 in file lock/lock0lock.c line 3799
InnoDB: Failing assertion: (table-
What seems to be happening is that a FLUSH TABLES is closing an innodb dict table that still has locks on it. This is causing a dict table handle count to get decremented down to 0 yet a transaction still has an IX lock on the table.
Along comes the dictionary trimmer and sees the table with no open handles, so, it removes it from the cache. Later on, when the transaction is cleaning up, it tries to remove the (now invalid) table from its lock list and all kinds of interesting things can happen...
I hacked in an assertion in row_prebuilt_free just before it decrements the table handle count to assert if there is a matching trx to table lock in the table lock list and it fires with the following bt full:
#6 0x000000000092708b in row_prebuilt_free (prebuilt= 0x7f67d8019608, dict_locked=0) at row/row0mysql.c:798 0edf0) at handler/ ha_innodb. cc:4571
dbug_violation _helper = {_entered = true} 0x7f67d8009ad0, free_share=true) at table.cc:1999 close_table"
dbug_violation _helper = {_entered = true} 0x7f67d8009ad0) at sql_base.cc:789
dbug_violation _helper = {_entered = true} 0x7f67d8009ad0) at sql_base.cc:811
dbug_violation _helper = {_entered = true}
__PRETTY_ FUNCTION_ _ = "void free_cache_ entry(TABLE* )" 0x7f67d8009ad0 "\220\243") at hash.c:549
lastpos_ hashnr = 1948990622 cached_ tables" refresh= true, wait_for_ placeholders= false) at sql_base.cc:876 execute_ command"
dbug_violation _helper = {_entered = true}
__PRETTY_ FUNCTION_ _ = "bool close_cached_ tables( THD*, TABLE_LIST*, bool, bool, bool)" acl_and_ cache (thd=0x2742b60, options=4, tables=0x0, write_to_ binlog= 0x7f6828083f9c) at sql_parse.cc:7366
tmp_write_ to_binlog = 1
__PRETTY_ FUNCTION_ _ = "bool reload_ acl_and_ cache(THD* , ulong, TABLE_LIST*, int*)" command (thd=0x2742b60) at sql_parse.cc:4299
write_ to_binlog = 1
__PRETTY_ FUNCTION_ _ = "int mysql_execute_ command( THD*)"
have_table_ map_for_ update = false
dbug_violation _helper = {_entered = true}
need_start_ waiting = false 0x7f67e8004ae0 "FLUSH TABLES", length=12, found_semicolon =0x7f6828084c20 ) at sql_parse.cc:6350
parser_ state = {m_lip = {m_thd = 0x2742b60, yylineno = 1, yytoklen = 0, yylval = 0x7f6828082b30, m_ptr = 0x7f67e8004aed "\004", m_tok_start = 0x7f67e8004aed "\004", m_tok_end = 0x7f67e8004aed "\004", m_end_of_query = 0x7f67e8004aec "",
m_ tok_start_ prev = 0x7f67e8004aec "", m_buf = 0x7f67e8004ae0 "FLUSH TABLES", m_buf_length = 12, m_echo = true, m_echo_saved = 127, m_cpp_buf = 0x7f67e8004b68 "FLUSH TABLES", m_cpp_ptr = 0x7f67e8004b74 "", m_cpp_tok_start = 0x7f67e8004b74 "",
m_ cpp_tok_ start_prev = 0x7f67e8004b74 "", m_cpp_tok_end = 0x7f67e8004b74 "", m_body_utf8 = 0x0, m_body_utf8_ptr = 0xb81c12 "query", m_cpp_utf8_ processed_ ptr = 0x0, next_state = MY_LEX_END, found_semicolon = 0x0, tok_bitmap = 60 '<',
ignore_ space = false, stmt_prepare_mode = false, in_comment = NO_COMMENT, in_comment_saved = 10988444, m_cpp_text_start = 0x7f68280843a0 "", m_cpp_text_end = 0xa7c801 "H\211E\370H\203}", <incomplete sequence \370>, m_underscore_cs = 0x0}, m_yacc = {
yacc_ yyss = 0x0, yacc_yyvs = 0x0}}
end_cpu_ nsecs = 0
__PRETTY_ FUNCTION_ _ = "void mysql_parse(THD*, char*, uint, const char**)"
cputime_ error = 0
dbug_violation _helper = {_entered = true}
end_time_ error = 0
start_ time_error = 0
start_ cpu_nsecs = 0
dbug_violation _helper = {_entered = true}
__PRETTY_ FUNCTION_ _ = "bool dispatch_ command( enum_server_ command, THD*, char*, uint)"
return_ value = false
dbug_violation _helper = {_entered = true}
__PRETTY_ FUNCTION_ _ = "bool do_command(THD*)"
packet_ length = 13 one_connection (arg=0x2742b60) at sql_connect.cc:2099 libpthread. so.0
lock = 0x7f67cc01d2f8
i = 8
#7 0x00000000008b695c in ha_innobase::close (this=0x7f67d80
_db_func_ = 0xbd9308 "closefrm"
_db_file_ = 0xbd8e17 "table.cc"
thd = 0x2742b60
_db_level_ = 10
_db_framep_ = 0x7f67e80008c0
#8 0x00000000006cd55b in closefrm (table=
_db_func_ = 0xbd597d "intern_
_db_file_ = 0xbd5741 "sql_base.cc"
error = 0
_db_level_ = 9
_db_framep_ = 0x7f67e80009d0
#9 0x00000000006b3ac5 in intern_close_table (table=
_db_func_ = 0xbd59b0 "free_cache_entry"
_db_file_ = 0xbd5741 "sql_base.cc"
_db_level_ = 8
_db_framep_ = 0x7f6828083328
#10 0x00000000006b3b7c in free_cache_entry (table=
_db_func_ = 0xc72c57 "my_hash_delete"
_db_file_ = 0xc72bd0 "hash.c"
_db_level_ = 7
_db_framep_ = 0x7f67f8e80c30
#11 0x0000000000a5fe4b in my_hash_delete (hash=0x10bc060, record=
blength = 16
pos2 = 6
pos_hashnr = 1386574718
idx = 4294967295
empty_index = 9
data = 0x1bd85f0
lastpos = 0x1bd8690
gpos = 0x1bd85f0
pos = 0x1bd8650
pos3 = 0x1bd8650
empty = 0x1bd8680
_db_func_ = 0xbd59f5 "close_
_db_file_ = 0xbd5741 "sql_base.cc"
_db_level_ = 6
_db_framep_ = 0xa7ab9c
#12 0x00000000006b3de9 in close_cached_tables (thd=0x2742b60, tables=0x0, have_lock=false, wait_for_
_db_func_ = 0xb82151 "mysql_
_db_file_ = 0xb81b40 "sql_parse.cc"
result = false
_db_level_ = 5
_db_framep_ = 0x810681
#13 0x0000000000675478 in reload_
result = false
#14 0x000000000066d0e1 in mysql_execute_
up_result = 0
select_lex = 0x2744dd0
unit = 0x27449a8
_db_func_ = 0xb82d19 "mysql_parse"
_db_file_ = 0xb81b40 "sql_parse.cc"
_db_level_ = 4
_db_framep_ = 0x2742b60
lex = 0x27448f8
first_table = 0x0
res = 0
all_tables = 0x0
#15 0x0000000000672e98 in mysql_parse (thd=0x2742b60, rawbuf=
lex = 0x27448f8
err = false
_db_func_ = 0xb81d41 "dispatch_command"
_db_file_ = 0xb81b40 "sql_parse.cc"
tp = {tv_sec = 140085324956732, tv_nsec = 140085324956736}
_db_level_ = 3
_db_framep_ = 0x7f6828084430
end_time = {tv_sec = 140085324956744, tv_usec = 2143201131185}
start_usecs = 0
start_time = {tv_sec = 41171480, tv_usec = 140085324956719}
end_usecs = 0
#16 0x0000000000664aca in dispatch_command (command=COM_QUERY, thd=0x2742b60, packet=0x27458e1 "FLUSH TABLES", packet_length=12) at sql_parse.cc:1319
packet_end = 0x7f67e8004aec ""
end_of_stmt = 0x0
net = 0x2742cc8
_db_func_ = 0xb81ca8 "do_command"
_db_file_ = 0xb81b40 "sql_parse.cc"
error = false
_db_level_ = 2
_db_framep_ = 0x7f6828084d50
#17 0x000000000066388f in do_command (thd=0x2742b60) at sql_parse.cc:908
packet = 0x27458e0 "\003FLUSH TABLES"
command = COM_QUERY
_db_func_ = 0xc79554 "?func"
_db_file_ = 0xc7955a "?file"
_db_level_ = 1
_db_framep_ = 0x6615fe
net = 0x2742cc8
#18 0x000000000066198f in handle_
net = 0x2742cc8
create_user = true
thd = 0x2742b60
#19 0x000000391b007851 in start_thread () from /lib64/
No symbol table info available.
#20 0x000000391a8e811d in clone () from /lib64/libc.so.6
If I do not assert here but just log the prebuilt->table and prebuilt->trx, the real assertion mentioned above will be triggered and the prebuilt table transaction ans lock list pointers will all match the ones discovered/logged here.