Comment 28 for bug 758788

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:

#6 0x000000000092708b in row_prebuilt_free (prebuilt=0x7f67d8019608, dict_locked=0) at row/row0mysql.c:798
        lock = 0x7f67cc01d2f8
        i = 8
#7 0x00000000008b695c in ha_innobase::close (this=0x7f67d800edf0) at handler/ha_innodb.cc:4571
        _db_func_ = 0xbd9308 "closefrm"
        _db_file_ = 0xbd8e17 "table.cc"
        dbug_violation_helper = {_entered = true}
        thd = 0x2742b60
        _db_level_ = 10
        _db_framep_ = 0x7f67e80008c0
#8 0x00000000006cd55b in closefrm (table=0x7f67d8009ad0, free_share=true) at table.cc:1999
        _db_func_ = 0xbd597d "intern_close_table"
        _db_file_ = 0xbd5741 "sql_base.cc"
        dbug_violation_helper = {_entered = true}
        error = 0
        _db_level_ = 9
        _db_framep_ = 0x7f67e80009d0
#9 0x00000000006b3ac5 in intern_close_table (table=0x7f67d8009ad0) at sql_base.cc:789
        _db_func_ = 0xbd59b0 "free_cache_entry"
        _db_file_ = 0xbd5741 "sql_base.cc"
        dbug_violation_helper = {_entered = true}
        _db_level_ = 8
        _db_framep_ = 0x7f6828083328
#10 0x00000000006b3b7c in free_cache_entry (table=0x7f67d8009ad0) at sql_base.cc:811
        _db_func_ = 0xc72c57 "my_hash_delete"
        _db_file_ = 0xc72bd0 "hash.c"
        dbug_violation_helper = {_entered = true}
        __PRETTY_FUNCTION__ = "void free_cache_entry(TABLE*)"
        _db_level_ = 7
        _db_framep_ = 0x7f67f8e80c30
#11 0x0000000000a5fe4b in my_hash_delete (hash=0x10bc060, record=0x7f67d8009ad0 "\220\243") at hash.c:549
        blength = 16
        pos2 = 6
        pos_hashnr = 1386574718
        lastpos_hashnr = 1948990622
        idx = 4294967295
        empty_index = 9
        data = 0x1bd85f0
        lastpos = 0x1bd8690
        gpos = 0x1bd85f0
        pos = 0x1bd8650
        pos3 = 0x1bd8650
        empty = 0x1bd8680
        _db_func_ = 0xbd59f5 "close_cached_tables"
        _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_refresh=true, wait_for_placeholders=false) at sql_base.cc:876
        _db_func_ = 0xb82151 "mysql_execute_command"
        _db_file_ = 0xb81b40 "sql_parse.cc"
        dbug_violation_helper = {_entered = true}
        __PRETTY_FUNCTION__ = "bool close_cached_tables(THD*, TABLE_LIST*, bool, bool, bool)"
        result = false
        _db_level_ = 5
        _db_framep_ = 0x810681
#13 0x0000000000675478 in reload_acl_and_cache (thd=0x2742b60, options=4, tables=0x0, write_to_binlog=0x7f6828083f9c) at sql_parse.cc:7366
        result = false
        tmp_write_to_binlog = 1
        __PRETTY_FUNCTION__ = "bool reload_acl_and_cache(THD*, ulong, TABLE_LIST*, int*)"
#14 0x000000000066d0e1 in mysql_execute_command (thd=0x2742b60) at sql_parse.cc:4299
        write_to_binlog = 1
        up_result = 0
        select_lex = 0x2744dd0
        unit = 0x27449a8
        _db_func_ = 0xb82d19 "mysql_parse"
        _db_file_ = 0xb81b40 "sql_parse.cc"
        __PRETTY_FUNCTION__ = "int mysql_execute_command(THD*)"
        have_table_map_for_update = false
        _db_level_ = 4
        _db_framep_ = 0x2742b60
        lex = 0x27448f8
        first_table = 0x0
        dbug_violation_helper = {_entered = true}
        res = 0
        need_start_waiting = false
        all_tables = 0x0
#15 0x0000000000672e98 in mysql_parse (thd=0x2742b60, rawbuf=0x7f67e8004ae0 "FLUSH TABLES", length=12, found_semicolon=0x7f6828084c20) at sql_parse.cc:6350
        lex = 0x27448f8
        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}}
        err = false
        _db_func_ = 0xb81d41 "dispatch_command"
        _db_file_ = 0xb81b40 "sql_parse.cc"
        tp = {tv_sec = 140085324956732, tv_nsec = 140085324956736}
        end_cpu_nsecs = 0
        __PRETTY_FUNCTION__ = "void mysql_parse(THD*, char*, uint, const char**)"
        _db_level_ = 3
        _db_framep_ = 0x7f6828084430
        end_time = {tv_sec = 140085324956744, tv_usec = 2143201131185}
        start_usecs = 0
        cputime_error = 0
        dbug_violation_helper = {_entered = true}
        end_time_error = 0
        start_time = {tv_sec = 41171480, tv_usec = 140085324956719}
        end_usecs = 0
        start_time_error = 0
        start_cpu_nsecs = 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"
        dbug_violation_helper = {_entered = true}
        __PRETTY_FUNCTION__ = "bool dispatch_command(enum_server_command, THD*, char*, uint)"
        error = false
        _db_level_ = 2
        _db_framep_ = 0x7f6828084d50
#17 0x000000000066388f in do_command (thd=0x2742b60) at sql_parse.cc:908
        return_value = false
        packet = 0x27458e0 "\003FLUSH TABLES"
        command = COM_QUERY
        _db_func_ = 0xc79554 "?func"
        _db_file_ = 0xc7955a "?file"
        _db_level_ = 1
        _db_framep_ = 0x6615fe
        dbug_violation_helper = {_entered = true}
        __PRETTY_FUNCTION__ = "bool do_command(THD*)"
        packet_length = 13
        net = 0x2742cc8
#18 0x000000000066198f in handle_one_connection (arg=0x2742b60) at sql_connect.cc:2099
        net = 0x2742cc8
        create_user = true
        thd = 0x2742b60
#19 0x000000391b007851 in start_thread () from /lib64/libpthread.so.0
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.