Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-2410

LP:925377 - Querying myisam table metadata while 'alter table..enable keys' is running may corrupt the table

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: None
    • Component/s: None
    • Labels:

      Description

      In MariaDB 5.3.3 tables are reported as corrupted in the server log when metadata queries like "show table status like 'tablename'" or "select ..from information_schemna where table_schema = 'dbname'
      AND a.table_name LIKE 'tablename'" are run while indexes are getting rebuilt with "alter table tablename enable keys".

      I can consistently replicate the problem in MariaDB 5.3.3 (mariadb-5.3.3-rc-Linux-x86_64.tar.gz) running on RHEL 5.7 and RHEL 6.1.

      An error like

      [ERROR] mysqld: Table './dbname/tablename' is marked as crashed and should be repaired

      gets logged in the server log just as the metadata query is getting submitted. The query remains in a "Waiting for table" state and will return only after the "alter table enable keys" query ends.
      Running "check table" or "repair table" after "alter table enable keys" won't report any problems.

      Use this script to reproduce the problem:

      #!/bin/sh

      HOST=localhost
      PORT=3306
      USER=
      PASSWORD=
      DATABASE=test
      MYSQL_CLIENT=/usr/bin/mysql
      TABLE=reproducer
      DATAFILE=reproducer.txt

      function generate_file {
      echo "Generating data file $DATAFILE.."
      for i in

      {1..100000}


      do
      echo "$i,line number $i" >> $DATAFILE
      done
      }

      function run_cmd {
      echo "Running -> '$1'"
      $MYSQL_CLIENT --host=$HOST --user=$USER --password=$PASSWORD --database=$DATABASE --exec="$1"
      }

      generate_file

      run_cmd "drop table if exists $TABLE"
      run_cmd "create table $TABLE (id int, sometext varchar(100), primary key (id), index(sometext)) ENGINE=myisam"
      run_cmd "alter table $TABLE disable keys"
      run_cmd "load data local infile '$DATAFILE' into table $TABLE fields terminated by ','"

      run_cmd "alter table $TABLE enable keys" &
      sleep 1
      run_cmd "show table status like '$TABLE'"

        Gliffy Diagrams

          Attachments

            Activity

            Hide
            elenst Elena Stepanova added a comment -

            Re: Querying myisam table metadata while 'alter table..enable keys' is running may corrupt the table
            Debug version of the server aborts with the assertion failure.
            It is reproducible on 5.1, 5.2, 5.3 with the provided test, although the sleep time might require adjusting. MTR version of the test case is below.

            mi_open.c:64: test_if_reopen: Assertion `strcmp(share->unique_file_name,filename) || share->last_version' failed.

            #8 0xb759a014 in __assert_fail () from /lib/libc.so.6
            #9 0x0855573f in test_if_reopen (filename=0x8fbdb3e0 "/home/elenst/5.3.3-release/data/test/reproducer.MYI") at mi_open.c:63
            #10 0x085558f4 in mi_open (name=0x9f3d310 "./test/reproducer", mode=2, open_flags=82) at mi_open.c:112
            #11 0x08517b5c in ha_myisam::open (this=0xa049140, name=0x9f3d310 "./test/reproducer", mode=2, test_if_locked=18) at ha_myisam.cc:720
            #12 0x08433f7a in handler::ha_open (this=0xa049140, table_arg=0xa048a10, name=0x9f3d310 "./test/reproducer", mode=2, test_if_locked=18)
            at handler.cc:2189
            #13 0x0834860c in open_table_from_share (thd=0x9f9d768, share=0x9f3d060, alias=0xa03da10 "reproducer", db_stat=39, prgflag=44, ha_open_flags=16,
            outparam=0xa048a10, is_create_table=false) at table.cc:2369
            #14 0x0833629b in open_unireg_entry (thd=0x9f9d768, entry=0xa048a10, table_list=0xa03da20, alias=0xa03da10 "reproducer", cache_key=0x8fbdc241 "test",
            cache_key_length=16, mem_root=0x8fbdc440, flags=0) at sql_base.cc:4102
            #15 0x08333d95 in open_table (thd=0x9f9d768, table_list=0xa03da20, mem_root=0x8fbdc440, refresh=0x8fbdc487, flags=2) at sql_base.cc:2974
            #16 0x08337655 in open_tables (thd=0x9f9d768, start=0x8fbdc4f4, counter=0x8fbdc4dc, flags=2) at sql_base.cc:4796
            #17 0x083384fe in open_normal_and_derived_tables (thd=0x9f9d768, tables=0xa03da20, flags=2, dt_phases=34) at sql_base.cc:5266
            #18 0x08475961 in fill_schema_table_by_open (thd=0x9f9d768, is_show_fields_or_keys=false, table=0xa03b460, schema_table=0x8b161f8,
            orig_db_name=0x8fbdcfe8, orig_table_name=0xa039470, open_tables_state_backup=0x8fbdcf58) at sql_show.cc:3580
            #19 0x084767aa in get_all_tables (thd=0x9f9d768, tables=0xa038470, cond=0x0) at sql_show.cc:4032
            #20 0x08480e09 in get_schema_tables_result (join=0xa042428, executed_place=PROCESSED_BY_JOIN_EXEC) at sql_show.cc:6800
            #21 0x08356b7a in JOIN::exec (this=0xa042428) at sql_select.cc:2186
            #22 0x083591ad in mysql_select (thd=0x9f9d768, rref_pointer_array=0x9f9f2f4, tables=0xa038470, wild_num=0, fields=..., conds=0x0, og_num=0,
            order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2684635648, result=0xa0392f0, unit=0x9f9eed8, select_lex=0x9f9f1b8)
            at sql_select.cc:2931
            #23 0x08350ec7 in handle_select (thd=0x9f9d768, lex=0x9f9ee7c, result=0xa0392f0, setup_tables_done_option=0) at sql_select.cc:284
            #24 0x082ec31d in execute_sqlcom_select (thd=0x9f9d768, all_tables=0xa038470) at sql_parse.cc:5151
            #25 0x082e36f9 in mysql_execute_command (thd=0x9f9d768) at sql_parse.cc:2284
            #26 0x082ee958 in mysql_parse (thd=0x9f9d768, rawbuf=0xa0374a8 "show table status like 'reproducer'", length=35, found_semicolon=0x8fbde234)
            at sql_parse.cc:6152
            #27 0x082e1339 in dispatch_command (command=COM_QUERY, thd=0x9f9d768, packet=0xa02f449 "show table status like 'reproducer'", packet_length=35)
            at sql_parse.cc:1228
            #28 0x082e07e3 in do_command (thd=0x9f9d768) at sql_parse.cc:923
            #29 0x082dd769 in handle_one_connection (arg=0x9f9d768) at sql_connect.cc:1193
            #30 0xb7828b25 in start_thread () from /lib/libpthread.so.0

            Query (0x945dc08): SHOW TABLE STATUS LIKE 'bug925377'
            Connection ID (thread ID): 2
            Status: NOT_KILLED
            Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on

            bzr version-info
            revision-id: igor@askmonty.org-20120203204917-q2jyemhc1kyqseq5
            date: 2012-02-03 12:49:17 -0800
            build-date: 2012-02-08 05:25:34 +0400
            revno: 3411
            branch-nick: maria-5.3

            1. MTR test case:

            --connect(con1,localhost,root,,)
            --perl
            open( DATA, ">bug925377.txt" )

            die "Couldn't open file bug925377.txt for writing: $!";
            foreach my $i ( 1..100000 )
            {
            print DATA "$i,line number $i\n";
            }
            close( DATA );
            EOF
            --disable_warnings
            DROP TABLE IF EXISTS bug925377;
            --enable_warnings
            CREATE TABLE bug925377 (
            id INT PRIMARY KEY,
            a VARCHAR(100),
            INDEX(a)
            ) ENGINE=MyISAM;
            ALTER TABLE bug925377 DISABLE KEYS;
            LOAD DATA LOCAL INFILE 'bug925377.txt'
            INTO TABLE bug925377
            FIELDS TERMINATED BY ',';
            --send
            ALTER TABLE bug925377 ENABLE KEYS;
            --connection default
            #--sleep 2
            --let $wait_timeout=10
            --let $show_statement= SHOW PROCESSLIST
            --let $field= State
            --let $condition= = 'Repair by sorting'
            --source include/wait_show_condition.inc
            #SHOW PROCESSLIST;
            SHOW TABLE STATUS LIKE 'bug925377';
            --connection con1
            --reap
            DROP TABLE bug925377;
            1. End of test
            Show
            elenst Elena Stepanova added a comment - Re: Querying myisam table metadata while 'alter table..enable keys' is running may corrupt the table Debug version of the server aborts with the assertion failure. It is reproducible on 5.1, 5.2, 5.3 with the provided test, although the sleep time might require adjusting. MTR version of the test case is below. mi_open.c:64: test_if_reopen: Assertion `strcmp(share->unique_file_name,filename) || share->last_version' failed. #8 0xb759a014 in __assert_fail () from /lib/libc.so.6 #9 0x0855573f in test_if_reopen (filename=0x8fbdb3e0 "/home/elenst/5.3.3-release/data/test/reproducer.MYI") at mi_open.c:63 #10 0x085558f4 in mi_open (name=0x9f3d310 "./test/reproducer", mode=2, open_flags=82) at mi_open.c:112 #11 0x08517b5c in ha_myisam::open (this=0xa049140, name=0x9f3d310 "./test/reproducer", mode=2, test_if_locked=18) at ha_myisam.cc:720 #12 0x08433f7a in handler::ha_open (this=0xa049140, table_arg=0xa048a10, name=0x9f3d310 "./test/reproducer", mode=2, test_if_locked=18) at handler.cc:2189 #13 0x0834860c in open_table_from_share (thd=0x9f9d768, share=0x9f3d060, alias=0xa03da10 "reproducer", db_stat=39, prgflag=44, ha_open_flags=16, outparam=0xa048a10, is_create_table=false) at table.cc:2369 #14 0x0833629b in open_unireg_entry (thd=0x9f9d768, entry=0xa048a10, table_list=0xa03da20, alias=0xa03da10 "reproducer", cache_key=0x8fbdc241 "test", cache_key_length=16, mem_root=0x8fbdc440, flags=0) at sql_base.cc:4102 #15 0x08333d95 in open_table (thd=0x9f9d768, table_list=0xa03da20, mem_root=0x8fbdc440, refresh=0x8fbdc487, flags=2) at sql_base.cc:2974 #16 0x08337655 in open_tables (thd=0x9f9d768, start=0x8fbdc4f4, counter=0x8fbdc4dc, flags=2) at sql_base.cc:4796 #17 0x083384fe in open_normal_and_derived_tables (thd=0x9f9d768, tables=0xa03da20, flags=2, dt_phases=34) at sql_base.cc:5266 #18 0x08475961 in fill_schema_table_by_open (thd=0x9f9d768, is_show_fields_or_keys=false, table=0xa03b460, schema_table=0x8b161f8, orig_db_name=0x8fbdcfe8, orig_table_name=0xa039470, open_tables_state_backup=0x8fbdcf58) at sql_show.cc:3580 #19 0x084767aa in get_all_tables (thd=0x9f9d768, tables=0xa038470, cond=0x0) at sql_show.cc:4032 #20 0x08480e09 in get_schema_tables_result (join=0xa042428, executed_place=PROCESSED_BY_JOIN_EXEC) at sql_show.cc:6800 #21 0x08356b7a in JOIN::exec (this=0xa042428) at sql_select.cc:2186 #22 0x083591ad in mysql_select (thd=0x9f9d768, rref_pointer_array=0x9f9f2f4, tables=0xa038470, wild_num=0, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2684635648, result=0xa0392f0, unit=0x9f9eed8, select_lex=0x9f9f1b8) at sql_select.cc:2931 #23 0x08350ec7 in handle_select (thd=0x9f9d768, lex=0x9f9ee7c, result=0xa0392f0, setup_tables_done_option=0) at sql_select.cc:284 #24 0x082ec31d in execute_sqlcom_select (thd=0x9f9d768, all_tables=0xa038470) at sql_parse.cc:5151 #25 0x082e36f9 in mysql_execute_command (thd=0x9f9d768) at sql_parse.cc:2284 #26 0x082ee958 in mysql_parse (thd=0x9f9d768, rawbuf=0xa0374a8 "show table status like 'reproducer'", length=35, found_semicolon=0x8fbde234) at sql_parse.cc:6152 #27 0x082e1339 in dispatch_command (command=COM_QUERY, thd=0x9f9d768, packet=0xa02f449 "show table status like 'reproducer'", packet_length=35) at sql_parse.cc:1228 #28 0x082e07e3 in do_command (thd=0x9f9d768) at sql_parse.cc:923 #29 0x082dd769 in handle_one_connection (arg=0x9f9d768) at sql_connect.cc:1193 #30 0xb7828b25 in start_thread () from /lib/libpthread.so.0 Query (0x945dc08): SHOW TABLE STATUS LIKE 'bug925377' Connection ID (thread ID): 2 Status: NOT_KILLED Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on bzr version-info revision-id: igor@askmonty.org-20120203204917-q2jyemhc1kyqseq5 date: 2012-02-03 12:49:17 -0800 build-date: 2012-02-08 05:25:34 +0400 revno: 3411 branch-nick: maria-5.3 MTR test case: --connect(con1,localhost,root,,) --perl open( DATA, ">bug925377.txt" ) die "Couldn't open file bug925377.txt for writing: $!"; foreach my $i ( 1..100000 ) { print DATA "$i,line number $i\n"; } close( DATA ); EOF --disable_warnings DROP TABLE IF EXISTS bug925377; --enable_warnings CREATE TABLE bug925377 ( id INT PRIMARY KEY, a VARCHAR(100), INDEX(a) ) ENGINE=MyISAM; ALTER TABLE bug925377 DISABLE KEYS; LOAD DATA LOCAL INFILE 'bug925377.txt' INTO TABLE bug925377 FIELDS TERMINATED BY ','; --send ALTER TABLE bug925377 ENABLE KEYS; --connection default #--sleep 2 --let $wait_timeout=10 --let $show_statement= SHOW PROCESSLIST --let $field= State --let $condition= = 'Repair by sorting' --source include/wait_show_condition.inc #SHOW PROCESSLIST; SHOW TABLE STATUS LIKE 'bug925377'; --connection con1 --reap DROP TABLE bug925377; End of test
            Hide
            monty Michael Widenius added a comment -

            Re: Querying myisam table metadata while 'alter table..enable keys' is running may corrupt the table
            This happens because SHOW commands ignores that table is in FLUSH and tells handler to open a table anyway (which MyISAM can't handle).
            Fixed by introducing a new flag in 5.3 when opening a table for status read only.

            Show
            monty Michael Widenius added a comment - Re: Querying myisam table metadata while 'alter table..enable keys' is running may corrupt the table This happens because SHOW commands ignores that table is in FLUSH and tells handler to open a table anyway (which MyISAM can't handle). Fixed by introducing a new flag in 5.3 when opening a table for status read only.
            Hide
            ratzpo Rasmus Johansson added a comment -

            This bug appears to be present still on 5.3.6 - possibly not during ENABLE|DISABLE keys but immediately before drop. see my.cnf below and Ruby script for test case.

            [mysqld]
            basedir=/home/revin/Downloads/mariadb-5.3.6-Linux-x86_64/
            datadir=/var/lib/mysql
            socket=/var/lib/mysql/mysql.sock
            user=revin

            1. Disabling symbolic-links is recommended to prevent assorted security risks
              symbolic-links=0

            collation_server = utf8_unicode_ci
            character_set_server = utf8
            skip-external-locking
            #fast_index_creation = false

            1. 10MB ramdisk - can be ignored
              tmpdir = /tmpfs

            key_buffer = 276M
            innodb_buffer_pool_size = 276M
            max_allowed_packet = 16M
            thread_stack = 256K
            thread_cache_size = 128
            thread_concurrency = 8
            max_connections = 512
            table_cache = 2048
            myisam-recover = BACKUP
            query_cache_limit = 1M
            query_cache_size = 128M
            expire_logs_days = 10
            max_binlog_size = 100M

            [mysqld_safe]
            log-error=/var/log/mysqld.log
            pid-file=/var/run/mysqld/mysqld.pid
            myisam_crash.rb
            LPexportBug925377_myisam_crash.rb

            Show
            ratzpo Rasmus Johansson added a comment - This bug appears to be present still on 5.3.6 - possibly not during ENABLE|DISABLE keys but immediately before drop. see my.cnf below and Ruby script for test case. [mysqld] basedir=/home/revin/Downloads/mariadb-5.3.6-Linux-x86_64/ datadir=/var/lib/mysql socket=/var/lib/mysql/mysql.sock user=revin Disabling symbolic-links is recommended to prevent assorted security risks symbolic-links=0 collation_server = utf8_unicode_ci character_set_server = utf8 skip-external-locking #fast_index_creation = false 10MB ramdisk - can be ignored tmpdir = /tmpfs key_buffer = 276M innodb_buffer_pool_size = 276M max_allowed_packet = 16M thread_stack = 256K thread_cache_size = 128 thread_concurrency = 8 max_connections = 512 table_cache = 2048 myisam-recover = BACKUP query_cache_limit = 1M query_cache_size = 128M expire_logs_days = 10 max_binlog_size = 100M [mysqld_safe] log-error=/var/log/mysqld.log pid-file=/var/run/mysqld/mysqld.pid myisam_crash.rb LPexportBug925377_myisam_crash.rb
            Hide
            ratzpo Rasmus Johansson added a comment -

            Re: Querying myisam table metadata while 'alter table..enable keys' is running may corrupt the table
            This bug appears to be present still on 5.3.6 - possibly not during ENABLE|DISABLE keys but immediately before drop. see my.cnf below and Ruby script for test case.

            [mysqld]
            basedir=/home/revin/Downloads/mariadb-5.3.6-Linux-x86_64/
            datadir=/var/lib/mysql
            socket=/var/lib/mysql/mysql.sock
            user=revin

            1. Disabling symbolic-links is recommended to prevent assorted security risks
              symbolic-links=0

            collation_server = utf8_unicode_ci
            character_set_server = utf8
            skip-external-locking
            #fast_index_creation = false

            1. 10MB ramdisk - can be ignored
              tmpdir = /tmpfs

            key_buffer = 276M
            innodb_buffer_pool_size = 276M
            max_allowed_packet = 16M
            thread_stack = 256K
            thread_cache_size = 128
            thread_concurrency = 8
            max_connections = 512
            table_cache = 2048
            myisam-recover = BACKUP
            query_cache_limit = 1M
            query_cache_size = 128M
            expire_logs_days = 10
            max_binlog_size = 100M

            [mysqld_safe]
            log-error=/var/log/mysqld.log
            pid-file=/var/run/mysqld/mysqld.pid

            Show
            ratzpo Rasmus Johansson added a comment - Re: Querying myisam table metadata while 'alter table..enable keys' is running may corrupt the table This bug appears to be present still on 5.3.6 - possibly not during ENABLE|DISABLE keys but immediately before drop. see my.cnf below and Ruby script for test case. [mysqld] basedir=/home/revin/Downloads/mariadb-5.3.6-Linux-x86_64/ datadir=/var/lib/mysql socket=/var/lib/mysql/mysql.sock user=revin Disabling symbolic-links is recommended to prevent assorted security risks symbolic-links=0 collation_server = utf8_unicode_ci character_set_server = utf8 skip-external-locking #fast_index_creation = false 10MB ramdisk - can be ignored tmpdir = /tmpfs key_buffer = 276M innodb_buffer_pool_size = 276M max_allowed_packet = 16M thread_stack = 256K thread_cache_size = 128 thread_concurrency = 8 max_connections = 512 table_cache = 2048 myisam-recover = BACKUP query_cache_limit = 1M query_cache_size = 128M expire_logs_days = 10 max_binlog_size = 100M [mysqld_safe] log-error=/var/log/mysqld.log pid-file=/var/run/mysqld/mysqld.pid
            Hide
            jasonparrott Jason Parrott added a comment -

            Re: Querying myisam table metadata while 'alter table..enable keys' is running may corrupt the table
            I can confirm that Jervin's reproducer works and produces this error message:

            120426 11:32:39 [ERROR] mysqld: Table './test/customer46' is marked as crashed and should be repaired

            Elena, would you rather I open a new bug report?

            Show
            jasonparrott Jason Parrott added a comment - Re: Querying myisam table metadata while 'alter table..enable keys' is running may corrupt the table I can confirm that Jervin's reproducer works and produces this error message: 120426 11:32:39 [ERROR] mysqld: Table './test/customer46' is marked as crashed and should be repaired Elena, would you rather I open a new bug report?
            Hide
            elenst Elena Stepanova added a comment -

            Re: Querying myisam table metadata while 'alter table..enable keys' is running may corrupt the table
            Hi Jervin, Jason,

            Yes, if it's not too much trouble, please do open a new bug report.

            Show
            elenst Elena Stepanova added a comment - Re: Querying myisam table metadata while 'alter table..enable keys' is running may corrupt the table Hi Jervin, Jason, Yes, if it's not too much trouble, please do open a new bug report.
            Hide
            jasonparrott Jason Parrott added a comment -

            Re: Querying myisam table metadata while 'alter table..enable keys' is running may corrupt the table
            No problem - opened bug #989055 and attached Jervin's code.

            Show
            jasonparrott Jason Parrott added a comment - Re: Querying myisam table metadata while 'alter table..enable keys' is running may corrupt the table No problem - opened bug #989055 and attached Jervin's code.
            Hide
            ratzpo Rasmus Johansson added a comment -

            Launchpad bug id: 925377

            Show
            ratzpo Rasmus Johansson added a comment - Launchpad bug id: 925377

              People

              • Assignee:
                monty Michael Widenius
                Reporter:
                andreilaki Andrei Laki
              • Votes:
                0 Vote for this issue
                Watchers:
                0 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: