Bug #46473 Assertion in reference_table_share on concurrent SELECT on system tables

• Submitted: 30 Jul 2009 10:57
• Modified: 29 Sep 2009 9:26
• Reporter: Philip Stoev
• Status: Can't repeat
• Category: MySQL Server: Locking
• Severity: S2 (Serious)
• Version: 5.4
• OS: Any
• Assigned to: Magne Mæhre
• CPU Architecture: Any
• Tags: locking, performance_schema, regression

[30 Jul 2009 10:57] Philip Stoev

Description:
When executing SELECTs against the mysql database and normal data in 2 threads, mysqld asserted as follows in the logging-to-table mechanism :

# 13:10:47 #5  0x000000315a434a43 in abort () from /lib64/libc.so.6
# 13:10:47 #6  0x000000315a42bec9 in __assert_fail () from /lib64/libc.so.6
# 13:10:47 #7  0x00000000006ca8f6 in reference_table_share (share=0x1fd75b0) at sql_base.cc:707
# 13:10:47 #8  0x00000000006d6b28 in open_table (thd=0x7f30f8cb15c8, table_list=0x7f30f5571e10, mem_root=0x7f30f8cb3e88, action=0x7f30f5571d4c, flags=0)
# 13:10:47     at sql_base.cc:2714
# 13:10:47 #9  0x00000000006d72ae in open_ltable (thd=0x7f30f8cb15c8, table_list=0x7f30f5571e10, lock_type=TL_WRITE_CONCURRENT_INSERT, lock_flags=27)
# 13:10:47     at sql_base.cc:4126
# 13:10:47 #10 0x00000000006d7576 in open_performance_schema_table (thd=0x7f30f8cb15c8, one_table=0x7f30f5571e10, backup=0x7f30f5572390) at sql_base.cc:8132
# 13:10:47 #11 0x000000000075d425 in Log_to_csv_event_handler::log_general (this=0x7f30f813af70, thd=0x7f30f8cb15c8, event_time=1248948645,
# 13:10:47     user_host=0x7f30f55724c0 "root[root] @ localhost [127.0.0.1]", user_host_len=34, thread_id=7, command_type=0xb51fad "Query", command_type_len=5,
# 13:10:47     sql_text=0x22a1c40 "SELECT * FROM `mysql` . `func`", sql_text_len=30, client_cs=0x104d820) at log.cc:474
# 13:10:47 #12 0x000000000075a0d4 in LOGGER::general_log_write (this=0x105f3c0, thd=0x7f30f8cb15c8, command=COM_QUERY,
# 13:10:47     query=0x22a1c40 "SELECT * FROM `mysql` . `func`", query_length=30) at log.cc:2075
# 13:10:47 #13 0x000000000075a184 in general_log_write (thd=0x7f30f8cb15c8, command=COM_QUERY, query=0x22a1c40 "SELECT * FROM `mysql` . `func`", query_length=30)
# 13:10:47     at log.cc:6162
# 13:10:47 #14 0x00000000006854e2 in dispatch_command (command=COM_QUERY, thd=0x7f30f8cb15c8, packet=0x7f30f8cbbf29 "SELECT * FROM `mysql` . `func`", packet_length=30)
# 13:10:47     at sql_parse.cc:1055
# 13:10:47 #15 0x0000000000686a61 in do_command (thd=0x7f30f8cb15c8) at sql_parse.cc:743
# 13:10:47 #16 0x0000000000673b5f in handle_one_connection (arg=0x7f30f8cb15c8) at sql_connect.cc:1158
# 13:10:47 #17 0x000000315b0073da in start_thread () from /lib64/libpthread.so.0
# 13:10:47 #18 0x000000315a4e627d in clone () from /lib64/libc.so.6

Here is a backtrace that does not involve logging to table

# 13:13:58 #5  0x000000315a434a43 in abort () from /lib64/libc.so.6
# 13:13:58 #6  0x000000315a42bec9 in __assert_fail () from /lib64/libc.so.6
# 13:13:58 #7  0x00000000006ca8f6 in reference_table_share (share=0x7f3874c3e8b0) at sql_base.cc:707
# 13:13:58 #8  0x00000000006d6a68 in open_table (thd=0x7f3874ca6bd8, table_list=0x7f3874d30078, mem_root=0x7f386f5545d0, action=0x7f386f55464c, flags=2)
# 13:13:58     at sql_base.cc:2693
# 13:13:58 #9  0x00000000006d7b0b in open_tables (thd=0x7f3874ca6bd8, start=0x7f386f5546b0, counter=0x7f386f5546ec, flags=2) at sql_base.cc:3763
# 13:13:58 #10 0x00000000006d81f6 in open_normal_and_derived_tables (thd=0x7f3874ca6bd8, tables=0x7f3874d30078, flags=2) at sql_base.cc:4276
# 13:13:58 #11 0x00000000008151a6 in get_all_tables (thd=0x7f3874ca6bd8, tables=0x1856308, cond=0x0) at sql_show.cc:3499
# 13:13:58 #12 0x000000000080046b in get_schema_tables_result (join=0x7f3874cc90f0, executed_place=PROCESSED_BY_JOIN_EXEC) at sql_show.cc:6512
# 13:13:58 #13 0x000000000071e5bc in JOIN::exec (this=0x7f3874cc90f0) at sql_select.cc:2408
# 13:13:58 #14 0x000000000071ad9e in mysql_select (thd=0x7f3874ca6bd8, rref_pointer_array=0x7f3874ca8b98, tables=0x1856308, wild_num=1, fields=@0x7f3874ca8ab8,
# 13:13:58     conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2684635648, result=0x1857890, unit=0x7f3874ca8548,
# 13:13:58     select_lex=0x7f3874ca89b0) at sql_select.cc:3091
# 13:13:58 #15 0x0000000000720636 in handle_select (thd=0x7f3874ca6bd8, lex=0x7f3874ca84a8, result=0x1857890, setup_tables_done_option=0) at sql_select.cc:306
# 13:13:58 #16 0x000000000067a77b in execute_sqlcom_select (thd=0x7f3874ca6bd8, all_tables=0x1856308) at sql_parse.cc:4927
# 13:13:58 #17 0x000000000067bffa in mysql_execute_command (thd=0x7f3874ca6bd8) at sql_parse.cc:2112
# 13:13:58 #18 0x0000000000684940 in mysql_parse (thd=0x7f3874ca6bd8, inBuf=0x1856080 "SELECT * FROM `information_schema` . `PARTITIONS`", length=49,
# 13:13:58     found_semicolon=0x7f386f556f10) at sql_parse.cc:5942
# 13:13:58 #19 0x000000000068555b in dispatch_command (command=COM_QUERY, thd=0x7f3874ca6bd8,
# 13:13:58     packet=0x7f3874cb1539 "SELECT * FROM `information_schema` . `PARTITIONS`", packet_length=49) at sql_parse.cc:1061
# 13:13:58 #20 0x0000000000686a61 in do_command (thd=0x7f3874ca6bd8) at sql_parse.cc:743
# 13:13:58 #21 0x0000000000673b5f in handle_one_connection (arg=0x7f3874ca6bd8) at sql_connect.cc:1158
# 13:13:58 #22 0x000000315b0073da in start_thread () from /lib64/libpthread.so.0
# 13:13:58 #23 0x000000315a4e627d in clone () from /lib64/libc.so.6

This issue is not repeatable on 5.1 

How to repeat:
RQG grammar:

query:
        SELECT * FROM _database . _table;

To reproduce, please clone a fresh copy of test-extra-6.0 and then run:

cd mysql-test/gentest

perl runall.pl \
--basedir=/path/to/mysql/tree
--grammar=/path/to/grammar
--threads=2

And you should observe the crash within a few seconds.

[29 Sep 2009 9:26] Magne Mæhre

This bug is no longer reproducible in neither 5.4 nor later code trees.
(i.e it's been fixed as part of a patch for another bug)