Details
-
Bug
-
Status: Open (View Workflow)
-
Major
-
Resolution: Unresolved
-
11.4.9
-
None
-
None
-
None
-
Tested in docker with docker.mariadb.com/enterprise-server:11.4 "Id": "sha256:10ac6005da8c1d277ab496cdcaa376ffb486764b7e198e398165462f1e4d15ef"
Description
Running the HammerDB TPC-C benchmark with 32 clients (no stored procedures) and doing ALTER TABLE tpcc.order_line DROP PRIMARY KEY at the same time causes the alter query to never stop. The query remains stuck at Update_rows_log_event::find_row() and never proceeds from that, even once the benchmark stops. While this is happening, CPU usage is at 100%. Killing the query does stop it so it's not permanently stuck.
If there's no concurrent updates on the table, the ALTER completes quickly.
While the alter is ongoing, the progress reporting sends out nonsensical values:
Stage: 3 of 4 'After apply log event' 1.65e+04% of stage done
|
Stage: 3 of 4 'After apply log event' 1.11e+04% of stage done
|
Stage: 3 of 4 'After apply log event' 102% of stage done
|
Stage: 3 of 4 'After apply log event' 6.26e+03% of stage done
|
Stage: 3 of 4 'After apply log event' 2.73e+03% of stage done
|
Stage: 4 of 4 'After apply log event' 1.56e+04% of stage done
|
Stage: 4 of 4 'After apply log event' 1.64e+04% of stage done
|
There are no other client connections at the same time.
MariaDB [tpcc]> show processlist;
|
+-----+---------+-----------------+------+-------------+-------+---------------------------------------------------------------+----------------------------------------------+----------+
|
| Id | User | Host | db | Command | Time | State | Info | Progress |
|
+-----+---------+-----------------+------+-------------+-------+---------------------------------------------------------------+----------------------------------------------+----------+
|
| 4 | maxuser | localhost:40510 | NULL | Binlog Dump | 13237 | Master has sent all binlog to slave; waiting for more updates | NULL | 0.000 |
|
| 5 | maxuser | localhost:40514 | NULL | Binlog Dump | 13237 | Master has sent all binlog to slave; waiting for more updates | NULL | 0.000 |
|
| 7 | maxuser | localhost:40520 | NULL | Binlog Dump | 13236 | Master has sent all binlog to slave; waiting for more updates | NULL | 0.000 |
|
| 108 | maxuser | localhost:50372 | tpcc | Query | 1477 | Update_rows_log_event::find_row() | alter table tpcc.order_line drop primary key | 100.000 |
|
| 183 | maxuser | localhost:42854 | NULL | Sleep | 2 | | NULL | 0.000 |
|
| 184 | maxuser | localhost:33074 | tpcc | Query | 0 | starting | show processlist | 0.000 |
|
+-----+---------+-----------------+------+-------------+-------+---------------------------------------------------------------+----------------------------------------------+----------+
|
6 rows in set (0.000 sec)
|
The schema is the one that's created automatically by HammerDB:
MariaDB [tpcc]> show create table order_line\G
|
*************************** 1. row ***************************
|
Table: order_line
|
Create Table: CREATE TABLE `order_line` (
|
`ol_w_id` int(11) NOT NULL,
|
`ol_d_id` int(11) NOT NULL,
|
`ol_o_id` int(11) NOT NULL,
|
`ol_number` int(11) NOT NULL,
|
`ol_i_id` int(11) DEFAULT NULL,
|
`ol_delivery_d` datetime DEFAULT NULL,
|
`ol_amount` int(11) DEFAULT NULL,
|
`ol_supply_w_id` int(11) DEFAULT NULL,
|
`ol_quantity` int(11) DEFAULT NULL,
|
`ol_dist_info` char(24) CHARACTER SET latin1 COLLATE latin1_bin DEFAULT NULL
|
) ENGINE=InnoDB DEFAULT CHARSET=latin1 COLLATE=latin1_swedish_ci
|
1 row in set (0.000 sec)
|
Here's one stacktrace:
[Switching to thread 12 (LWP 3544396)]
|
#0 0x0000556601f73cf1 in buf_page_optimistic_fix(buf_block_t*, page_id_t) ()
|
#0 0x0000556601f73cf1 in buf_page_optimistic_fix(buf_block_t*, page_id_t) ()
|
#1 0x000055660177e36a in btr_pcur_optimistic_latch_leaves(btr_pcur_t*, btr_latch_mode*, mtr_t*) ()
|
#2 0x0000556601f6daef in btr_pcur_t::restore_position(btr_latch_mode, mtr_t*) ()
|
#3 0x0000556601ef0446 in sel_restore_position_for_mysql(bool*, btr_latch_mode, btr_pcur_t*, bool, mtr_t*) [clone .constprop.0] ()
|
#4 0x0000556601ef7072 in row_search_mvcc(unsigned char*, page_cur_mode_t, row_prebuilt_t*, unsigned long, unsigned long) ()
|
#5 0x0000556601e2ef40 in ha_innobase::rnd_next(unsigned char*) ()
|
#6 0x0000556601b2c10f in handler::ha_rnd_next(unsigned char*) ()
|
#7 0x0000556601c7e392 in Rows_log_event::find_row(rpl_group_info*) ()
|
#8 0x0000556601c7e81f in Update_rows_log_event::do_exec_row(rpl_group_info*) ()
|
#9 0x0000556601c7244f in Rows_log_event::do_apply_event(rpl_group_info*) ()
|
#10 0x0000556601c6af5d in Log_event::apply_event(rpl_group_info*) ()
|
#11 0x000055660194cd34 in online_alter_read_from_binlog(THD*, rpl_group_info*, Cache_flip_event_log*, unsigned long long*) ()
|
#12 0x00005566019635ff in copy_data_between_tables(THD*, TABLE*, TABLE*, bool, unsigned int, st_order*, unsigned long long*, unsigned long long*, Alter_info*, Alter_table_ctx*, bool, unsigned long long) [clone .constprop.0] ()
|
#13 0x00005566019691cb in mysql_alter_table(THD*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, Table_specification_st*, TABLE_LIST*, Recreate_info*, Alter_info*, unsigned int, st_order*, bool, bool) ()
|
#14 0x00005566019d6182 in Sql_cmd_alter_table::execute(THD*) ()
|
#15 0x00005566018a0fa6 in mysql_execute_command(THD*, bool) ()
|
#16 0x00005566018a2171 in mysql_parse(THD*, char*, unsigned int, Parser_state*) ()
|
#17 0x00005566018a4805 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) ()
|
#18 0x00005566018a663d in do_command(THD*, bool) ()
|
#19 0x0000556601aab817 in tp_callback(TP_connection*) ()
|
#20 0x0000556601cc4c2d in worker_main(void*) ()
|
#21 0x0000556601d6b199 in pfs_spawn_thread ()
|
#22 0x00007f01ade8b2ea in start_thread () from target:/lib64/libc.so.6
|
#23 0x00007f01adf0f5e4 in clone () from target:/lib64/libc.so.6
|
I've attached a flamegraph of a perf recording.
Attachments
Issue Links
- relates to
-
MDEV-14479 Do not acquire InnoDB record locks when covering table locks exist
-
- Closed
-
-
MDEV-16329 Engine-independent online ALTER TABLE
-
- Closed
-
-
MDEV-20546 INSERT SELECT randomly blocks in Copy to temp table
-
- Open
-
-
MDEV-24813 Locking full table scan fails to use table-level locking
-
- In Review
-
-
MDEV-37832 The IF operator implicitly sets SHARED LOCK
-
- Closed
-