Bug #110872 Unable to create indexes concurrently on the same table
Submitted: 30 Apr 2023 2:06 Modified: 3 May 2023 22:58
Reporter: Mark Callaghan Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: DDL Severity:S3 (Non-critical)
Version:8.0 OS:Any
Assigned to: CPU Architecture:Any

[30 Apr 2023 2:06] Mark Callaghan
Description:
I am unable to create non-unique indexes concurrently on the same InnoDB table.

My proof that this doesn't happen concurrently is:
1) SHOW PROCESSLIST output
2) Creating 3 secondary indexes in separate client connections concurrently takes as long as creating them one at a time.

I don't know whether:
1) I am making a mistake
2) The docs aren't clear about
3) This is a bug

The docs at https://dev.mysql.com/doc/refman/8.0/en/alter-table.html state that it might be supported, however:
1) The docs aren't specific about which concurrent alters are supported, not the use of "Typically".
2) Assuming this is using ALGORITHM=INPLACE then the claim that the exclusive metadata lock is only taken briefly is not correct.

From the docs ...
INPLACE: Operations avoid copying table data but may rebuild the table in place. An exclusive metadata lock on the table may be taken briefly during preparation and execution phases of the operation. Typically, concurrent DML is supported.

From the repro script below, here is output that shows the time in seconds for each of the ways I tried to create the 3 secondary indexes.
* The first two are the fastest and create all 3 indexes in one statement as "alter table ... add index ..., add index ..., add index ..."
* the next two create the indexes one at a time and take ~106 seconds
* the last two create the indexes concurrently and also take ~106 seconds

67 seconds : create all without explicit inplace
66 seconds : create all with explicit inplace
106 seconds : create one at a time without explicit inplace
105 seconds : create one at a time with explicit inplace
106 seconds : create concurrent without explicit inplace
107 seconds : create concurrent with explicit inplace

Finally, if I run SHOW PROCESSLIST during the repro when 3 processes try to create the indexes concurrently I see this initially -- two of the processes are blocked on the table metadata lock.

Id      User    Host    db      Command Time    State   Info
5       event_scheduler localhost       NULL    Daemon  77295   Waiting on empty queue  NULL
7713    root    localhost       ib      Query   3       altering table  alter table pi1 add index pi1_marketsegment (price, customerid)
7714    root    localhost       ib      Query   3       Waiting for table metadata lock alter table pi1 add index pi1_registersegment (cashregisterid, price, customerid)
7715    root    localhost       ib      Query   3       Waiting for table metadata lock alter table pi1 add index pi1_pdc (price, dateandtime, customerid)

Then when the first create finishes, the lock is held by the next creator while the final one waits.

Id      User    Host    db      Command Time    State   Info
5       event_scheduler localhost       NULL    Daemon  77304   Waiting on empty queue  NULL
7714    root    localhost       ib      Query   12      altering table  alter table pi1 add index pi1_registersegment (cashregisterid, price, customerid)
7715    root    localhost       ib      Query   12      Waiting for table metadata lock alter table pi1 add index pi1_pdc (price, dateandtime, customerid)

How to repeat:
The reproduction case uses the insert benchmark client from:
https://github.com/mdcallag/mytools/blob/master/bench/ibench/iibench.py

Running the script below to insert 10M rows into the test table is sufficient to show the problem.

I ran "stat /path/to/pi1.ibd" before and after some of the index creation attempts and the files inode doesn't change. I assume this means that table copy isn't being done and INPLACE is done.

I repeated the test with two variations for my.cnf. The results are the same -- no concurrency, and the times (number of seconds) are similar.

One has:
innodb_ddl_threads=8
innodb_ddl_buffer_size=2G

The other has:
innodb_ddl_threads=1
innodb_ddl_buffer_size=2G

The table for the repro is here. It is created by iibench.py
Create Table: CREATE TABLE `pi1` (
  `transactionid` bigint NOT NULL AUTO_INCREMENT,
  `dateandtime` datetime DEFAULT NULL,
  `cashregisterid` int NOT NULL,
  `customerid` int NOT NULL,
  `productid` int NOT NULL,
  `price` float NOT NULL,
  `data` varchar(4000) DEFAULT NULL,
  PRIMARY KEY (`transactionid`)
) ENGINE=InnoDB AUTO_INCREMENT=5000001 DEFAULT CHARSET=latin1

The reproduction script tests and times a variety of ways to create the secondary indexes, so it is longer than required. The script is ...
---

# Path to "mysql" binary"
mysqlbin=$1
# User name for mysql login
my_user=$2
# password for mysql login
my_pw=$3
# name of database in mysql to use
my_db=$4
# number of rows to insert
nrows=$5

dbnodb="$mysqlbin -u${my_user} -p${my_pw}"
db="$mysqlbin -u${my_user} -p${my_pw} $my_db"

$dbnodb -e "create database ${my_db}"

python3 iibench.py --dbms=mysql --db_name=${my_db} --secs_per_report=1 --db_host=127.0.0.1 --db_user=${my_user} --db_password=${my_pw} --engine=innodb --engine_options= --unique_checks=1 --bulk_load=0 --max_rows=$nrows --table_name=pi1 --setup --num_secondary_indexes=0 --data_length_min=10 --data_length_max=20 --rows_per_commit=100 --inserts_per_second=0 --query_threads=0 --seed=1682702413 --dbopt=none >& o.load

function drop_all {
  start=$1
  msg="$2"
  stop=$( date +%s )
  echo $(( stop - start )) seconds : $msg
  $db -e "alter table pi1 drop index pi1_marketsegment"
  $db -e "alter table pi1 drop index pi1_registersegment"
  $db -e "alter table pi1 drop index pi1_pdc"
}

$db -e "alter table pi1 drop index pi1_marketsegment"
$db -e "alter table pi1 drop index pi1_registersegment"
$db -e "alter table pi1 drop index pi1_pdc"

msg="create all without explicit inplace"
start=$( date +%s )
time $db -e "alter table pi1 add index pi1_marketsegment (price, customerid), add index pi1_registersegment (cashregisterid, price, customerid), add index pi1_pdc (price, dateandtime, customerid)"
drop_all $start "$msg"

msg="create all with explicit inplace"
start=$( date +%s )
time $db -e "alter table pi1 add index pi1_marketsegment (price, customerid), add index pi1_registersegment (cashregisterid, price, customerid), add index pi1_pdc (price, dateandtime, customerid), algorithm=inplace"
drop_all $start "$msg"

msg="create one at a time without explicit inplace"
start=$( date +%s )
time $db -e "alter table pi1 add index pi1_marketsegment (price, customerid)"
time $db -e "alter table pi1 add index pi1_registersegment (cashregisterid, price, customerid)"
time $db -e "alter table pi1 add index pi1_pdc (price, dateandtime, customerid)"
drop_all $start "$msg"

msg="create one at a time with explicit inplace"
start=$( date +%s )
time $db -e "alter table pi1 add index pi1_marketsegment (price, customerid), algorithm=inplace"
time $db -e "alter table pi1 add index pi1_registersegment (cashregisterid, price, customerid), algorithm=inplace"
time $db -e "alter table pi1 add index pi1_pdc (price, dateandtime, customerid), algorithm=inplace"
drop_all $start "$msg"

while :; do $db -e "show processlist"; sleep 3; done >& o.spl.1 &
spid1=$!
msg="create concurrent without explicit inplace"
start=$( date +%s )
$db -e "alter table pi1 add index pi1_marketsegment (price, customerid)" &
j1=$!
$db -e "alter table pi1 add index pi1_registersegment (cashregisterid, price, customerid)" &
j2=$!
$db -e "alter table pi1 add index pi1_pdc (price, dateandtime, customerid)" &
j3=$!
wait $j1
wait $j2
wait $j3
kill $spid1
drop_all $start "$msg"

while :; do $db -e "show processlist"; sleep 3; done >& o.spl.2 &
spid2=$!
msg="create concurrent with explicit inplace"
start=$( date +%s )
$db -e "alter table pi1 add index pi1_marketsegment (price, customerid), algorithm=inplace" &
j1=$!
$db -e "alter table pi1 add index pi1_registersegment (cashregisterid, price, customerid), algorithm=inplace" &
j2=$!
$db -e "alter table pi1 add index pi1_pdc (price, dateandtime, customerid), algorithm=inplace" &
j3=$!
wait $j1
wait $j2
wait $j3
kill $spid2
drop_all $start "$msg"

Suggested fix:
Point out where I am wrong (very possible) or fix the docs the explain this isn't supported or fix a bug.
[30 Apr 2023 3:21] Mark Callaghan
A stack trace for one of the connections blocked on the table metadata lock ...

#0  0x00007fdbab297301 in __futex_abstimed_wait_cancelable64 () from /usr/local/fbcode/platform010/lib/libc.so.6
(gdb) where
#0  0x00007fdbab297301 in __futex_abstimed_wait_cancelable64 () from /usr/local/fbcode/platform010/lib/libc.so.6
#1  0x00007fdbab29a05d in pthread_cond_timedwait@@GLIBC_2.3.2 () from /usr/local/fbcode/platform010/lib/libc.so.6
#2  0x0000000001fec5af in native_cond_timedwait (cond=0x7fa6f6305480, mutex=0x7fa6f6305450, abstime=0x7fdb9ddf9750) at /data/users/mcallaghan/mysql-8.0.32/include/thr_cond.h:99
#3  my_cond_timedwait (cond=0x7fa6f6305480, mp=0x7fa6f6305450, abstime=0x7fdb9ddf9750) at /data/users/mcallaghan/mysql-8.0.32/include/thr_cond.h:148
#4  inline_mysql_cond_timedwait (that=0x7fa6f6305480, mutex=0x7fa6f6305450, abstime=0x7fdb9ddf9750, src_file=<optimized out>, src_line=1820)
    at /data/users/mcallaghan/mysql-8.0.32/include/mysql/psi/mysql_cond.h:242
#5  MDL_wait::timed_wait (this=0x7fa6f6305450, owner=0x7fa6f63050c0, abs_timeout=0x7fdb9ddf9750, set_status_on_timeout=true, wait_state_name=<optimized out>)
    at /data/users/mcallaghan/mysql-8.0.32/sql/mdl.cc:1819
#6  0x0000000001ff02c3 in MDL_context::acquire_lock (this=0x7fa6f6305450, mdl_request=0x7fa6f63115b8, lock_wait_timeout=<optimized out>) at /data/users/mcallaghan/mysql-8.0.32/sql/mdl.cc:3524
#7  0x0000000001ff1793 in MDL_context::acquire_locks (this=0x7fa6f63054a8, mdl_requests=<optimized out>, lock_wait_timeout=31536000) at /data/users/mcallaghan/mysql-8.0.32/sql/mdl.cc:3656
#8  0x00000000023ca276 in lock_table_names (thd=<optimized out>, tables_start=<optimized out>, tables_end=0x0, lock_wait_timeout=31536000, flags=0, schema_reqs=0x0)
    at /data/users/mcallaghan/mysql-8.0.32/sql/sql_base.cc:5487
#9  0x00000000023cd2e5 in open_tables (thd=<optimized out>, start=<optimized out>, counter=<optimized out>, flags=<optimized out>, prelocking_strategy=<optimized out>)
    at /data/users/mcallaghan/mysql-8.0.32/sql/sql_base.cc:5826
#10 0x000000000262265e in mysql_alter_table (thd=<optimized out>, new_db=0x7fa6f6311830 "ib", new_name=0x0, create_info=<optimized out>, table_list=<optimized out>, alter_info=0x7fdb9ddfcaa8)
    at /data/users/mcallaghan/mysql-8.0.32/sql/sql_table.cc:16313
#11 0x00000000023ba404 in Sql_cmd_alter_table::execute (this=<optimized out>, thd=0x7fa6f63050c0) at /data/users/mcallaghan/mysql-8.0.32/sql/sql_alter.cc:349
#12 0x0000000002549f4b in mysql_execute_command (thd=<optimized out>, first_level=false) at /data/users/mcallaghan/mysql-8.0.32/sql/sql_parse.cc:4688
#13 0x0000000002546814 in dispatch_sql_command (thd=0x7fa6f63050c0, parser_state=<optimized out>) at /data/users/mcallaghan/mysql-8.0.32/sql/sql_parse.cc:5322
#14 0x0000000002544390 in dispatch_command (thd=<optimized out>, com_data=0x7fdb9ddfec00, command=COM_QUERY) at /data/users/mcallaghan/mysql-8.0.32/sql/sql_parse.cc:2036
#15 0x0000000002545603 in do_command (thd=0x7fa6f63050c0) at /data/users/mcallaghan/mysql-8.0.32/sql/sql_parse.cc:1439
#16 0x00000000027670c4 in handle_connection (arg=<optimized out>) at /data/users/mcallaghan/mysql-8.0.32/sql/conn_handler/connection_handler_per_thread.cc:302
#17 0x0000000003b31f50 in pfs_spawn_thread (arg=0x3194add0) at /data/users/mcallaghan/mysql-8.0.32/storage/perfschema/pfs.cc:2986
#18 0x00007fdbab29ac0f in start_thread () from /usr/local/fbcode/platform010/lib/libc.so.6
#19 0x00007fdbab32d1dc in clone3 () from /usr/local/fbcode/platform010/lib/libc.so.6
[2 May 2023 13:20] MySQL Verification Team
Hi Mr. Callaghan,

Thank you for your bug report.

After several attempts we have been able to repeat the behaviour on 8.0.33.

Thank you very much on your report.

Verified as reported.
[3 May 2023 22:58] Mark Callaghan
Elsewhere, Sunny Bains mentioned that the current behavior is expected -- as in, any connection creating an index holds an exclusive table metadata lock. I don't doubt that, but hope the docs can be more clear about it.
[4 May 2023 11:32] MySQL Verification Team
Hi,

This could be both a documentation report and a new feature request.