| Bug #49730 | During Fast Index creation mysql client is locked | ||
|---|---|---|---|
| Submitted: | 16 Dec 2009 6:09 | Modified: | 26 Jan 2011 13:51 |
| Reporter: | Vadim TKACHENKO | Email Updates: | |
| Status: | Duplicate | Impact on me: | |
| Category: | MySQL Server: Locking | Severity: | S2 (Serious) |
| Version: | 5.1.47 + plugin 1.0.8, 5.5.5, 5.6.99 | OS: | Any |
| Assigned to: | Assigned Account | CPU Architecture: | Any |
| Tags: | fast alter table | ||
[16 Dec 2009 6:09]
Vadim TKACHENKO
[16 Dec 2009 8:22]
Sveta Smirnova
Thank you for the report. I can not repeat described behavior with dummy data. Please provide output of SHOW CREATE TABLE pages3
[16 Dec 2009 14:19]
Vadim TKACHENKO
Sveta, Schema is CREATE TABLE `pages3` ( `id` int(10) unsigned NOT NULL, `page` varchar(2000) NOT NULL, `crchash` int(10) unsigned NOT NULL, PRIMARY KEY (`id`), KEY `crchash` (`crchash`) ) ENGINE=InnoDB DEFAULT CHARSET=latin1 KEY_BLOCK_SIZE=8 Parameters are: innodb_buffer_pool_size=12G innodb_log_file_size=256M innodb_flush_log_at_trx_commit=2 innodb_flush_method=O_DIRECT ignore-builtin-innodb plugin-load=innodb=ha_innodb_plugin.so plugin_dir=/data/vol1/engines/mysql-5.1.41/mysql-5.1.41-linux-x86_64-glibc23/lib/plugin innodb_file_per_table=1 innodb_file_format=Barracuda
[18 Dec 2009 16:03]
Sveta Smirnova
Thank you for the feedback. I still can not repeat described behavior, although I can prove InnoDB Plugin locks LOCK_open while alters table and InnoDB does not. Could you please attach gdb in locking time, then run `bt` and `bt full` commands and send us output, so we can see where it is locked?
[19 Dec 2009 6:05]
Vadim TKACHENKO
Sveta,
Make sure you have big amount of data so ALTER TABLE ADD KEY runs long enough.
Here is bt for relevant threads
Thread 4 (Thread 0x49478940 (LWP 11198)):
#0 0x00000000008e106d in adler32 (adler=196091,
buf=0x2aac9b1d0d62 "%D1%82%D1%80%D0%BE%D0%BD%D0%BD%D0%B0%D1%8F_%D0%BF%D1%80%D0%BE%D0%BC%D1%8B%D1%88%D0%BB%D0%B5%D0%BD%D0%BD%D0%BE%D1%81%D1%82%D1%8C/[???,\2011\004:?M%D0%9A%D0%B0%D1%82%D0%B5%D0%B3%D0%BE%D1%80%D0%B8%D1%8F:%D0%AD"..., len=10798) at adler32.c:101
#1 0x00002aaaab2e1f61 in buf_zip_decompress (block=0x2aaab4525c40, check=<value optimized out>) at buf/buf0buf.c:1826
#2 0x00002aaaab2e56fe in buf_page_get_gen (space=6, zip_size=16384, offset=107754, rw_latch=1, guess=0x0, mode=10,
file=0x2aaaab3b5a0b "./include/btr0btr.ic", line=53, mtr=0x49474350) at buf/buf0buf.c:2234
#3 0x00002aaaab2d9fb7 in btr_pcur_move_to_next_page (cursor=0x494747f0, mtr=0x49474350) at ./include/btr0btr.ic:53
#4 0x00002aaaab378f83 in row_merge_read_clustered_index (trx=0x2f84f450, table=0x2f80df40, old_table=0x19ea4080,
new_table=0x19ea4080, index=0x2f890440, files=0x2f87e310, n_index=1, block=0x2aadcd708000) at ./include/btr0pcur.ic:350
#5 0x00002aaaab37a012 in row_merge_build_indexes (trx=0x2f84f450, old_table=0x19ea4080, new_table=0x19ea4080, indexes=0x2f7de120,
n_indexes=1, table=0x2f80df40) at row/row0merge.c:2480
#6 0x00002aaaab328bfc in ha_innodb::add_index (this=0x2f819d10, table=0x2f80df40, key_info=0x2f88f8c0,
num_of_keys=<value optimized out>) at handler/handler0alter.cc:798
#7 0x00000000006e9010 in mysql_alter_table (thd=0x2aadd006cf70, new_db=0x2f88e858 "wikistat", new_name=0x2f88e4f0 "pages0",
create_info=0x494770b0, table_list=0x2f88e528, alter_info=0x49477190, order_num=0, order=0x0, ignore=false)
---Type <return> to continue, or q <return> to quit---
at sql_table.cc:7202
#8 0x00000000005f084a in mysql_execute_command (thd=0x2aadd006cf70) at sql_parse.cc:2898
#9 0x00000000005f59be in mysql_parse (thd=0x2aadd006cf70, inBuf=0x2f88e430 "alter table pages0 add key (crchash,id)", length=39,
found_semicolon=0x49478060) at sql_parse.cc:5970
#10 0x00000000005f68ae in dispatch_command (command=COM_QUERY, thd=0x2aadd006cf70,
packet=0x2aadd00c8751 "alter table pages0 add key (crchash,id)", packet_length=<value optimized out>) at sql_parse.cc:1231
#11 0x00000000005f7176 in do_command (thd=0x2aadd006cf70) at sql_parse.cc:872
#12 0x00000000005e9ad6 in handle_one_connection (arg=<value optimized out>) at sql_connect.cc:1127
#13 0x00000037e82064a7 in start_thread () from /lib64/libpthread.so.0
#14 0x00000037e7ad3c2d in clone () from /lib64/libc.so.6
Thread 3 (Thread 0x494b9940 (LWP 11200)):
#0 0x00000037e820ab99 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1 0x0000000000621606 in wait_for_condition (thd=0x2aadd00cc760, mutex=0xcdd760, cond=0xcddd60) at sql_base.cc:2169
#2 0x000000000062ad3a in open_table (thd=0x2aadd00cc760, table_list=0x494b8ac0, mem_root=0x494b8320, refresh=0x494b837f, flags=0)
at sql_base.cc:2834
#3 0x000000000062bb29 in open_tables (thd=0x2aadd00cc760, start=0x494b83c8, counter=0x494b83dc, flags=0) at sql_base.cc:4581
#4 0x000000000062bc9e in open_normal_and_derived_tables (thd=0xcddd64, tables=0x494b8ac0, flags=4294967295) at sql_base.cc:5036
#5 0x00000000006fe182 in mysqld_list_fields (thd=0xcddd64, table_list=0x80, wild=0x2f7e04b8 "") at sql_show.cc:895
#6 0x00000000005f666a in dispatch_command (command=<value optimized out>, thd=0x2aadd00cc760, packet=0x2aadd00cf028 "",
packet_length=804458463) at sql_parse.cc:1340
#7 0x00000000005f7176 in do_command (thd=0x2aadd00cc760) at sql_parse.cc:872
#8 0x00000000005e9ad6 in handle_one_connection (arg=<value optimized out>) at sql_connect.cc:1127
#9 0x00000037e82064a7 in start_thread () from /lib64/libpthread.so.0
#10 0x00000037e7ad3c2d in clone () from /lib64/libc.so.6
( I have different table there, but the lock is the same)
[21 Dec 2009 14:30]
Sveta Smirnova
Thank you for the report.
Verified as described.
To easily repeat modify sources as follow:
=== modified file 'sql/sql_table.cc'
--- sql/sql_table.cc 2009-11-27 13:34:39 +0000
+++ sql/sql_table.cc 2009-12-21 14:10:24 +0000
@@ -7297,6 +7297,7 @@
my_free(new_table,MYF(0));
}
VOID(pthread_mutex_lock(&LOCK_open));
+ sleep(120);
if (error)
{
VOID(quick_rm_table(new_db_type, new_db, tmp_name, FN_IS_TMP));
Then start server and run following queries:
create database db1;
use db1;
create table t1(f1 int unsigned not null auto_increment, f2 varchar(2000), f3 int(10) unsigned NOT NULL, PRIMARY KEY(f1)) engine=innodb ROW_FORMAT=COMPRESSED DEFAULT CHARSET=latin1 KEY_BLOCK_SIZE=8;
--disable_query_log
let $i=400;
while ($i)
{
--eval set @str=repeat(md5($i), 62);
--eval insert into t1(f2,f3) values(@str,$i);
--eval insert into t1(f2,f3) values(@str,$i);
--eval insert into t1(f2,f3) values(@str,$i);
dec $i;
}
--enable_query_log
select now();
alter table t1 add key(f3, f1);
(I use MTR to create data, but this should be not matter,
option file contains:
--innodb_flush_log_at_trx_commit=2 --innodb_flush_method=O_DIRECT --ignore-builtin-innodb --innodb_file_per_table=1 --innodb_file_format=Barracuda --ignore-builtin-innodb --plugin-load=innodb=ha_innodb_plugin.so --plugin-dir=/Users/apple/bzr/mysql-5.1/storage/innodb_plugin/.libs
)
Then in another terminal open new connection, run SHOW PROCESSLIST until you see row like:
| 3 | root | localhost | db1 | Query | 1 | manage keys | alter table t2 add key(f3, f1)
Then issue
USE db1
In third terminal you can see SHOW PROCESSLIST output like in the initial reply:
mysql> show processlist;
+----+------+-----------+------+------------+------+----------------+--------------------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+------+-----------+------+------------+------+----------------+--------------------------------+
| 2 | root | localhost | db1 | Query | 57 | manage keys | alter table t1 add key(f3, f1) |
| 3 | root | localhost | db1 | Field List | 53 | Opening tables | |
| 4 | root | localhost | NULL | Query | 0 | NULL | show processlist |
+----+------+-----------+------+------------+------+----------------+--------------------------------+
3 rows in set (0.00 sec)
[1 Jun 2010 7:11]
MySQL Verification Team
to repeat:
thread 1:
---------
set old_alter_table=0;
drop table if exists t1;
create table t1(id int not null auto_increment primary key,a char(255) character set latin1)engine=innodb;
insert into t1(a) values ('a'),('b'),('c'),('d'),('e'),('f');
insert into t1(a) select t1.a from t1,t1 a,t1 b,t1 c,t1 d,t1 f,t1 g;
alter table t1 add index(a);
thread 2:
---------
select * from t1 limit 10;
thread 3:
---------
show processlist;
+---------+------+-------------------+-----------------------------+
| Command | Time | State | Info |
+---------+------+-------------------+-----------------------------+
| Query | 5 | manage keys | alter table t1 add index(a) |
| Query | 3 | Waiting for table | select * from t1 limit 10 |
| Query | 0 | NULL | show processlist |
+---------+------+-------------------+-----------------------------+
[1 Jun 2010 7:16]
MySQL Verification Team
stack traces in a readable format for the above test: Stack Traces: mysql> select * from t1 limit 10; ntdll.dll!_ZwWaitForMultipleObjects@20 kernel32.dll!_WaitForMultipleObjectsEx@20 kernel32.dll!_WaitForMultipleObjects@16 mysqld.exe!pthread_cond_timedwait mysqld.exe!pthread_cond_wait mysqld.exe!wait_for_condition mysqld.exe!open_table mysqld.exe!open_tables mysqld.exe!open_and_lock_tables_derived mysqld.exe!execute_sqlcom_select mysqld.exe!mysql_execute_command mysqld.exe!mysql_parse mysqld.exe!dispatch_command mysqld.exe!do_command mysqld.exe!handle_one_connection mysqld.exe!pthread_start mysqld.exe!_callthreadstart mysql> alter table t1 add index(a); ntdll.dll!_NtWriteFile kernel32.dll!_WriteFile ha_innodb_plugin.dll!os_file_write ha_innodb_plugin.dll!row_merge_write ha_innodb_plugin.dll!row_merge_write_rec ha_innodb_plugin.dll!row_merge_blocks ha_innodb_plugin.dll!row_merge ha_innodb_plugin.dll!row_merge_sort ha_innodb_plugin.dll!row_merge_build_indexes ha_innodb_plugin.dll!ha_innodb::add_index mysqld.exe!mysql_alter_table mysqld.exe!mysql_execute_command mysqld.exe!mysql_parse mysqld.exe!dispatch_command mysqld.exe!do_command mysqld.exe!handle_one_connection mysqld.exe!pthread_start mysqld.exe!_callthreadstart
[3 Jun 2010 15:56]
Konstantin Osipov
Is it repeatable in 5.5? Values are low/low for 5.5.
[3 Jun 2010 18:12]
Sveta Smirnova
Yes, this is repeatable with next-mr and mysql-trunk-bugfixing.
[9 Nov 2010 13:06]
Jon Olav Hauglid
See also bug#42230
[2 Dec 2010 11:48]
Jon Olav Hauglid
Setting the bug to patch pending as it is fixed by the patch submitted (but not yet reviewed) for bug#42230.
[26 Jan 2011 13:51]
Jon Olav Hauglid
Closing as a duplicate of Bug#42230
