[MDEV-2410] LP:925377 - Querying myisam table metadata while 'alter table..enable keys' is running may corrupt the table Created: 2012-02-02  Updated: 2015-02-02  Resolved: 2012-10-04

Status: Closed
Project: MariaDB Server
Component/s: None
Affects Version/s: None
Fix Version/s: None

Type: Bug Priority: Major
Reporter: Andrei Laki (Inactive) Assignee: Michael Widenius
Resolution: Fixed Votes: 0
Labels: Launchpad

Attachments: XML File LPexportBug925377.xml     File LPexportBug925377_myisam_crash.rb    

 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'"

 Comments   
Comment by Elena Stepanova [ 2012-02-08 ]

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
Comment by Michael Widenius [ 2012-02-28 ]

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.

Comment by Rasmus Johansson (Inactive) [ 2012-04-25 ]

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

Comment by Rasmus Johansson (Inactive) [ 2012-04-25 ]

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

Comment by Jason Parrott (Inactive) [ 2012-04-26 ]

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?

Comment by Elena Stepanova [ 2012-04-26 ]

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.

Comment by Jason Parrott (Inactive) [ 2012-04-26 ]

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.

Comment by Rasmus Johansson (Inactive) [ 2012-04-26 ]

Launchpad bug id: 925377

Generated at Thu Feb 08 06:41:39 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.