Bug #52432 Crash in check_table_is_closed on an information_schema query
Submitted: 29 Mar 2010 11:25 Modified: 31 Jul 2010 16:48
Reporter: Philip Stoev Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Locking Severity:S2 (Serious)
Version:trunk-runtime-exp, next-mr-wl5136-stage OS:Any
Assigned to: Ingo Strüwing CPU Architecture:Any

[29 Mar 2010 11:25] Philip Stoev
Description:
When executing an RQG MDL/DDL workload, mysqld crashed as follows:

# 13:49:57 #2  0x000000000051b691 in handle_segfault (sig=11) at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/mysqld.cc:2753
# 13:49:57 #3  <signal handler called>
# 13:49:57 #4  0x00000000008a0897 in check_table_is_closed (name=0x7f9ebc06c048 "/1tb/vardir/threadpool1/current/tmp/#sql_322b_0", where=0xbad72d "delete")
# 13:49:57     at /1tb/bzr/mysql-next-mr-wl5136-stage/storage/myisam/mi_dbug.c:180
# 13:49:57 #5  0x00000000008a4b52 in mi_delete_table (name=0x7f9ebc06c048 "/1tb/vardir/threadpool1/current/tmp/#sql_322b_0")
# 13:49:57     at /1tb/bzr/mysql-next-mr-wl5136-stage/storage/myisam/mi_delete_table.c:31
# 13:49:57 #6  0x000000000088672f in ha_myisam::delete_table (this=0x7f9ebc08c390, name=0x7f9ebc06c048 "/1tb/vardir/threadpool1/current/tmp/#sql_322b_0")
# 13:49:57     at /1tb/bzr/mysql-next-mr-wl5136-stage/storage/myisam/ha_myisam.cc:1788
# 13:49:57 #7  0x000000000070b524 in handler::drop_table (this=0x7f9ebc08c390, name=0x7f9ebc06c048 "/1tb/vardir/threadpool1/current/tmp/#sql_322b_0")
# 13:49:57     at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/handler.cc:3069
# 13:49:57 #8  0x000000000070d731 in handler::ha_drop_table (this=0x7f9ebc08c390, name=0x7f9ebc06c048 "/1tb/vardir/threadpool1/current/tmp/#sql_322b_0")
# 13:49:57     at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/handler.cc:3354
# 13:49:57 #9  0x00000000005dc4e8 in free_tmp_table (thd=0x7f9ebc0de4b8, entry=0x7f9ebc06ab68) at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/sql_select.cc:10917
# 13:49:57 #10 0x0000000000561212 in close_thread_tables (thd=0x7f9ebc0de4b8) at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/sql_base.cc:1431
# 13:49:57 #11 0x00000000005615a2 in close_tables_for_reopen (thd=0x7f9ebc0de4b8, tables=0x7f9ec0a4e4e8, start_of_statement_svp=0x0)
# 13:49:57     at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/sql_base.cc:5505
# 13:49:57 #12 0x00000000006188ab in get_all_tables (thd=0x7f9ebc0de4b8, tables=0x7f9ebc0e5698, cond=0x7f9ebc05ac38)
# 13:49:57     at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/sql_show.cc:3560
# 13:49:57 #13 0x00000000006039a6 in get_schema_tables_result (join=0x7f9ebc0dbe48, executed_place=PROCESSED_BY_JOIN_EXEC)
# 13:49:57     at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/sql_show.cc:6644
# 13:49:57 #14 0x00000000005fb6d0 in JOIN::exec (this=0x7f9ebc0dbe48) at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/sql_select.cc:1829
# 13:49:57 #15 0x00000000005f82e8 in mysql_select (thd=0x7f9ebc0de4b8, rref_pointer_array=0x7f9ebc0e07a8, tables=0x7f9ebc0e5130, wild_num=0, fields=@0x7f9ebc0e06e0,
# 13:49:57     conds=0x7f9ebc09c208, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2684619520, result=0x7f9ebc0dac08, unit=0x7f9ebc0dffd8,
# 13:49:57     select_lex=0x7f9ebc0e05d8) at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/sql_select.cc:2506
# 13:49:57 #16 0x00000000005fd795 in handle_select (thd=0x7f9ebc0de4b8, lex=0x7f9ebc0dff38, result=0x7f9ebc0dac08, setup_tables_done_option=0)
# 13:49:57     at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/sql_select.cc:271
# 13:49:57 #17 0x00000000005a80c8 in execute_sqlcom_select (thd=0x7f9ebc0de4b8, all_tables=0x7f9ebc0e5130) at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/sql_parse.cc:4703
# 13:49:57 #18 0x00000000005a9d6a in mysql_execute_command (thd=0x7f9ebc0de4b8) at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/sql_parse.cc:2191
# 13:49:57 #19 0x00000000005b14e9 in mysql_parse (thd=0x7f9ebc0de4b8,
# 13:49:57     inBuf=0x7f9ebc0e1398 "SELECT CASE WHEN table_schema = 'information_schema' THEN 'INFORMATION_SCHEMA' ELSE table_schema END, table_name, CASE WHEN table_type = 'BASE TABLE' THEN 'table' WHEN table_type = 'VIEW' THEN 'view' "..., length=544, found_semicolon=0x7f9ec0a50cc0)
# 13:49:57     at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/sql_parse.cc:5735
# 13:49:57 #20 0x00000000005b2102 in dispatch_command (command=COM_QUERY, thd=0x7f9ebc0de4b8,
# 13:49:57     packet=0x7f9ebc03fd59 "SELECT CASE WHEN table_schema = 'information_schema' THEN 'INFORMATION_SCHEMA' ELSE table_schema END, table_name, CASE WHEN table_type = 'BASE TABLE' THEN 'table' WHEN table_type = 'VIEW' THEN 'view' "..., packet_length=544) at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/sql_parse.cc:1024
# 13:49:57 #21 0x00000000005b35a2 in do_command (thd=0x7f9ebc0de4b8) at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/sql_parse.cc:710
# 13:49:57 #22 0x0000000000680c20 in tp_process_event (my_thread_data=0x11b1fd0) at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/scheduler_thread_pool.cc:849
# 13:49:57 #23 0x00000000006810b3 in tp_group_low_level_wait_for_events (tp_group_low_level_cntx=0x1f82f98, my_tp_group=0x11b1e80, my_thread_data=0x11b1fd0,
# 13:49:57     next_events=0x7f9ec0a50f70, wait=true) at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/scheduler_poll.ic:425
# 13:49:57 #24 0x000000000068129e in handle_waiting_thread (my_tp_group=0x11b1e80, my_thread_data=0x11b1fd0, wait=true)
# 13:49:57     at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/scheduler_thread_pool.cc:1167
# 13:49:57 #25 0x00000000006813f7 in high_concurrency_algorithm (my_tp_group=0x11b1e80, my_thread_data=0x11b1fd0)
# 13:49:57     at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/scheduler_thread_pool.cc:1309
# 13:49:57 #26 0x00000000006815c2 in tp_worker_thread_main (arg=0x11b1fd0) at /1tb/bzr/mysql-next-mr-wl5136-stage/sql/scheduler_thread_pool.cc:1457
# 13:49:57 #27 0x000000315b0073da in start_thread () from /lib64/libpthread.so.0
# 13:49:57 #28 0x000000315a4e627d in clone () from /lib64/libc.so.6

How to repeat:
This has been observed more than once, so if is consistently repeatable, a test case will be provided. In the meantime, the core and the binary will be provided.
[29 Mar 2010 11:33] Philip Stoev
Location of crash:

(gdb) list
175     (void) fn_format(filename,name,"",MI_NAME_IEXT,4+16+32);
176     for (pos=myisam_open_list ; pos ; pos=pos->next)
177     {
178       MI_INFO *info=(MI_INFO*) pos->data;
179       MYISAM_SHARE *share=info->s;
180       if (!strcmp(share->unique_file_name,filename))
181       {
182         if (share->last_version)
183         {
184     fprintf(stderr,"Warning:  Table: %s is open on %s\n", name,where);
(gdb) print share
$1 = (MYISAM_SHARE *) 0x0

Source:

revision-id: mikael@mysql.com-20100318145400-vws1fr0ac9o81lwd
date: 2010-03-18 15:54:00 +0100
build-date: 2010-03-29 14:26:58 +0300
revno: 3054
branch-nick: mysql-next-mr-wl5136-stage

Core and binary:

http://mysql-systemqa.s3.amazonaws.com/var-bug52432.zip
[1 Apr 2010 16:33] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/104925

3009 Konstantin Osipov	2010-04-01
      A fix for Bug#52432 "Crash in check_table_is_closed on an 
      information_schema query"
[7 Jun 2010 12:06] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/110347

3041 Konstantin Osipov	2010-06-07
      A fix for Bug#52432 "Crash in check_table_is_closed on an 
      information_schema query.
      Porting a fix done for a feature tree by Ingo Struewing.
      No test case since the crash only occurs under a stress
      load.
     @ storage/myisam/mi_dbug.c
        Iterate over the list of MyISAM shares and access the MyISAM 
        share internals under a lock.
[7 Jun 2010 13:33] Konstantin Osipov
Queued in trunk-runtime.
[22 Jun 2010 13:07] Bugs System
Pushed into 5.5.5-m3 (revid:alik@sun.com-20100622130139-u05awgya93zvbsop) (version source revid:marko.makela@oracle.com-20100603095032-v5ptkkzt1bhz0m1d) (merge vers: 5.1.48) (pib:16)
[22 Jun 2010 13:09] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100622130623-r7yhm89fz9n5t9nb) (version source revid:alik@sun.com-20100622130528-187gd949sa9b6pa6) (pib:16)
[31 Jul 2010 16:48] Paul Dubois
Noted in 5.5.5 changelog.

The check_table_is_closed() debugging function did not protect access
to the MyISAM open tables list, with the result that server crashes
could occur during table drop or rename operations.