Details
-
Bug
-
Status: Stalled (View Workflow)
-
Major
-
Resolution: Unresolved
-
10.0(EOL), 10.1(EOL), 10.2(EOL), 10.3(EOL), 10.4(EOL), 10.5, 10.6
Description
In the third part of MDEV-25506, any DDL operations that will delete .ibd files will be rewritten. The design is such that MDL_EXCLUSIVE is supposed to prevent background access to tables that are about to be deleted. For the InnoDB internal tables that implement FULLTEXT INDEX, we tried to jump through some hoops to acquire MDL on the main table name. This will work for the #sql-backup table, but not for the #sql-alter table. (And MDEV-11415 was not really fixed for the internal tables related to fulltext indexes).
I observed the following crash:
CURRENT_TEST: innodb_fts.fulltext
|
mysqltest: At line 729: query 'CREATE FULLTEXT INDEX idx1 ON t1 (title,body)' failed with wrong errno <Unknown> (2013): 'Lost connection to server during query', instead of ER_DUP_ENTRY (1062)...
|
…
|
2021-06-03 14:41:15 0x7fcc1923c700 InnoDB: Assertion failure in file /mariadb/10.6/storage/innobase/dict/dict0dict.cc line 1893
|
InnoDB: Failing assertion: table->get_ref_count() == 0
|
The holder of the reference is about to release the reference as well as MDL_SHARED on test.t1:
#6 0x00005580aaac4ff5 in dict_sys_t::mutex_lock (this=<optimized out>) at /mariadb/10.6/storage/innobase/dict/dict0dict.cc:1064
|
#7 0x00005580aaac4b0a in dict_table_close (table=0x7fca877d0bc8, dict_locked=false, try_drop=false, thd=0x7fcb04001158, mdl=0x7fcb040286b0) at /mariadb/10.6/storage/innobase/dict/dict0dict.cc:325
|
#8 0x00005580aa98cf1d in purge_node_t::close_table (this=this@entry=0x5580ae1e9668) at /mariadb/10.6/storage/innobase/include/row0purge.h:229
|
#9 0x00005580aa98d422 in purge_node_t::end (this=0x5580ae1e9668) at /mariadb/10.6/storage/innobase/include/row0purge.h:259
|
#10 0x00005580aa9856a7 in row_purge_step (thr=thr@entry=0x5580ae1e9478) at /mariadb/10.6/storage/innobase/row/row0purge.cc:1335
|
But, the crashing thread is not holding MDL_EXCLUSIVE because it is executing a rollback. Hence, concurrent access from the purge thread was not blocked:
#5 0x00005580aaa1ad94 in ut_dbg_assertion_failed (expr=0x5580aaed071e "table->get_ref_count() == 0", file=<optimized out>, line=<optimized out>, line@entry=1893) at /mariadb/10.6/storage/innobase/ut/ut0dbg.cc:60
|
#6 0x00005580aaac91d9 in dict_sys_t::remove (this=0x5580ab5455c0 <dict_sys>, table=0x7fca877d0bc8, lru=false, keep=false) at /mariadb/10.6/storage/innobase/dict/dict0dict.cc:1893
|
#7 0x00005580aaaff4db in trx_t::commit (this=0x7fcc1a4f0290, deleted=std::vector of length 6, capacity 8 = {{m_file = 56, m_psi = 0x7fcc1bde0400}, {m_file = 55, m_psi = 0x7fcc1bde0140}, {m_file = 54, m_psi = 0x7fcc1bddfe80}, {m_file = 53, m_psi = 0x7fcc1bddfbc0}, {m_file = 52, m_psi = 0x7fcc1bddf900}, {m_file = 51, m_psi = 0x7fcc1bddf640}}) at /mariadb/10.6/storage/innobase/dict/drop.cc:241
|
#8 0x00005580aa839e15 in commit_unlock_and_unlink (trx=0x7fcc1a4f0290) at /mariadb/10.6/storage/innobase/handler/handler0alter.cc:6106
|
#9 rollback_inplace_alter_table (ha_alter_info=<optimized out>, ha_alter_info@entry=0x7fcc19238f80, table=0x7fca84b6e828, prebuilt=0x7fca877c4b88) at /mariadb/10.6/storage/innobase/handler/handler0alter.cc:8742
|
#10 0x00005580aa82eb64 in ha_innobase::commit_inplace_alter_table (this=0x7fca84c31420, altered_table=0x7fcc19238610, ha_alter_info=0x7fcc19238f80, commit=false) at /mariadb/10.6/storage/innobase/handler/handler0alter.cc:10771
|
#11 0x00005580aa307d8e in mysql_inplace_alter_table (thd=0x7fca84000d48, table_list=0x7fca84016a48, table=0x7fca84b6e828, altered_table=0x7fcc19238610, ha_alter_info=0x7fcc19238f80, target_mdl_request=<optimized out>, ddl_log_state=0x7fcc192385a0, trigger_param=0x7fcc19239c98, alter_ctx=0x7fcc19239040) at /mariadb/10.6/sql/sql_table.cc:7538
|
Purge was operating on the table FTS_0000000000000258_CONFIG, and it was holding MDL on test.t1 because table ID 0x258 belongs to that name.
Later, a different solution was implemented as part of that development: If a transaction would drop any FTS_ tables, using a new primitive purge_sys.stop_FTS() we will ensure that purge will not be running (on any table) until the transaction has been committed.
Could we fix fts_create_common_tables() so that it never invokes fts_drop_common_tables(), but simply empties the tables if they exist? That would remove the need to drop those common tables. (Note: this suggestion conflicts with the idea below.)
Even better would be to ensure that DDL operations will never write undo log to the FTS_ tables (extending what was implemented in MDEV-11415). We would still have to protect ALGORITHM=COPY and TRUNCATE TABLE operation by MDL (maybe by having ha_innobase::delete_table() and ha_innobase::truncate() acquire MDL on each to-be-dropped FTS_ table name), because purge may be processing undo log records that had been previously written for the old table.
Attachments
Issue Links
- relates to
-
-
- Closed
-
Activity
The reference count problem was worked around in MDEV-25506 part 3, and a race condition in the work-around was fixed in MDEV-25936.
There ought to be no correctness problem in the code. The unnecessary undo logging is merely a performance problem for now.
We now have an execution trace of this:
ssh plutorr replay /data/Results/1622894097/TBR-1069/dev/shm/vardir/1622894097/66/1/rr/latest-trace(rr) c…Thread 3 received signal SIGABRT, Aborted.[Switching to Thread 2548458.2552602]__GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:5050 ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.(rr) up 4#4 0x00005560994a4fac in trx_t::commit (this=0x7ff55accdfe8,deleted=std::vector of length 10, capacity 16 = {...})at /data/Server/bb-10.6-MDEV-25506_I/storage/innobase/dict/drop.cc:241241 dict_sys.remove(table);(rr) p table.n_ref_count$1 = {m_counter = {<std::__atomic_base<unsigned int>> = {static _S_alignment = 4, _M_i = 1}, <No data fields>}}(rr) watch -l table.n_ref_countHardware watchpoint 1: -location table.n_ref_count(rr) rcContinuing.…Continuing.[Switching to Thread 2548458.2561743]Thread 25 hit Hardware watchpoint 1: -location table.n_ref_countOld value ={m_counter = {<std::__atomic_base<unsigned int>> = {static _S_alignment = 4, _M_i = 1}, <No data fields>}}New value ={m_counter = {<std::__atomic_base<unsigned int>> = {static _S_alignment = 4, _M_i = 0}, <No data fields>}}0x0000556097aa32c8 in std::__atomic_base<unsigned int>::fetch_add (__m=std::memory_order_relaxed, __i=1, this=0x6180001b5750)at /usr/include/c++/9/bits/atomic_base.h:541541 { return __atomic_fetch_add(&_M_i, __i, int(__m)); }(rr) bt#0 0x0000556097aa32c8 in std::__atomic_base<unsigned int>::fetch_add (__m=std::memory_order_relaxed, __i=1, this=0x6180001b5750)at /usr/include/c++/9/bits/atomic_base.h:541#1 Atomic_counter<unsigned int>::add (this=0x6180001b5750, i=1)at /data/Server/bb-10.6-MDEV-25506_I/include/my_counter.h:27#2 0x0000556097aa16d6 in Atomic_counter<unsigned int>::operator++ (this=0x6180001b5750)at /data/Server/bb-10.6-MDEV-25506_I/include/my_counter.h:36#3 0x0000556098e4a418 in dict_table_t::acquire (this=0x6180001b5508)at /data/Server/bb-10.6-MDEV-25506_I/storage/innobase/include/dict0dict.ic:1145#4 0x00005560991bbb1a in row_purge_parse_undo_rec (node=0x61a00000abc8,undo_rec=0x621000052eb0 "", thr=0x61a00000ab20,updated_extern=0x7ff52fd9a820)at /data/Server/bb-10.6-MDEV-25506_I/storage/innobase/row/row0purge.cc:1101…(rr) f 3#3 0x0000556098e4a418 in dict_table_t::acquire (this=0x6180001b5508)at /data/Server/bb-10.6-MDEV-25506_I/storage/innobase/include/dict0dict.ic:11451145 n_ref_count++;(rr) p name$2 = {m_name = 0x604000068250 "test/FTS_", '0' <repeats 13 times>, "199_CONFIG",static part_suffix = "#P#"}(rr) thr a 3 bt…#12 0x000055609978f36e in safe_cond_wait (cond=0x7ff535b1e680, mp=0x610000000240, file=0x55609a785840 "/data/Server/bb-10.6-MDEV-25506_I/storage/innobase/fts/fts0opt.cc", line=2601) at /data/Server/bb-10.6-MDEV-25506_I/mysys/thr_mutex.c:492#13 0x000055609954e743 in fts_optimize_remove_table (table=0x618000113108) at /data/Server/bb-10.6-MDEV-25506_I/storage/innobase/fts/fts0opt.cc:2601#14 0x0000556098e1f9a7 in ha_innobase::delete_table (this=0x62b000145718, name=0x61b000168748 "./test/#sql-alter-26e2ea-35") at /data/Server/bb-10.6-MDEV-25506_I/storage/innobase/handler/ha_innodb.cc:13293#15 0x00005560984e5848 in hton_drop_table (hton=0x615000002118, path=0x61b000168748 "./test/#sql-alter-26e2ea-35") at /data/Server/bb-10.6-MDEV-25506_I/sql/handler.cc:576#16 0x000055609833d45e in THD::rm_temporary_table (this=0x62b00013b218, base=0x615000002118, path=0x61b000168748 "./test/#sql-alter-26e2ea-35") at /data/Server/bb-10.6-MDEV-25506_I/sql/temporary_tables.cc:703#17 0x0000556098340fa1 in THD::free_tmp_table_share (this=0x62b00013b218, share=0x61b000168198, delete_table=true) at /data/Server/bb-10.6-MDEV-25506_I/sql/temporary_tables.cc:1462#18 0x000055609833d16c in THD::drop_temporary_table (this=0x62b00013b218, table=0x619000433598, is_trans=0x0, delete_table=true) at /data/Server/bb-10.6-MDEV-25506_I/sql/temporary_tables.cc:669#19 0x0000556097fc8e28 in mysql_alter_table (thd=0x62b00013b218, new_db=0x62b00013fc28, new_name=0x62b000140040, create_info=0x7ff535b225d0, table_list=0x62b000142488, alter_info=0x7ff535b224a0, order_num=0, order=0x0, ignore=false, if_exists=false) at /data/Server/bb-10.6-MDEV-25506_I/sql/sql_table.cc:10739#20 0x00005560981519f5 in Sql_cmd_alter_table::execute (this=0x62b000142e90, thd=0x62b00013b218) at /data/Server/bb-10.6-MDEV-25506_I/sql/sql_alter.cc:550#21 0x0000556097d5a466 in mysql_execute_command (thd=0x62b00013b218) at /data/Server/bb-10.6-MDEV-25506_I/sql/sql_parse.cc:5983#22 0x0000556097d66933 in mysql_parse (thd=0x62b00013b218, rawbuf=0x62b000142238 "ALTER TABLE t3 ADD KEY IF NOT EXISTS `Marvão_idx3` ( col1, col2 ), ADD UNIQUE KEY `MarvãO_uidx3` ( col_string(9) ), ALGORITHM = COPY, LOCK = SHARED /* E_R Thread6 QNO 259 CON_ID 53 */", length=186, parser_state=0x7ff535b23b20) at /data/Server/bb-10.6-MDEV-25506_I/sql/sql_parse.cc:8016…(rr) thr 3[Switching to thread 3 (Thread 2548458.2552602)]#0 0x0000000070000002 in ?? ()(rr) f 14#14 0x0000556098e1f9a7 in ha_innobase::delete_table (this=0x62b000145718,name=0x61b000168748 "./test/#sql-alter-26e2ea-35")at /data/Server/bb-10.6-MDEV-25506_I/storage/innobase/handler/ha_innodb.cc:1329313293 fts_optimize_remove_table(table);(rr) p/x table.id$3 = 0x199Note: In purge, we cannot acquire MDL for the table name of table 0x199, because that main table name is test/#sql-alter-26e2ea-35. We could work this around by extending the SQL layer somehow.
A better fix is to not write undo log for any tables of that intermediate table, so that purge will have nothing to do there. In this ALGORITHM=COPY we are not dropping (and re-creating) the common tables, like in the originally reported ALGORITHM=INPLACE case, but the same problem remains: we are writing unnecessary undo log and hitting a race between purge and a DROP of an internal FTS_ table.