[MDEV-27672] Assertion `!table->fts->in_queue' failed in fts_optimize_remove_table Created: 2022-01-28  Updated: 2022-03-11  Resolved: 2022-03-11

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.8.1
Fix Version/s: 10.6.8, 10.7.4, 10.8.3

Type: Bug Priority: Major
Reporter: Matthias Leich Assignee: Thirunarayanan Balathandayuthapani
Resolution: Fixed Votes: 0
Labels: rr-profile-analyzed

Attachments: File TBR-1110.cc     File TBR-1110_better.yy     File mdev-27672.patch    

 Description   

origin/HEAD, origin/10.8, 10.8 0c5d1342ae6b5ab3256848be7a83e5c3b1f21566 2022-01-27T21:25:07+02:00
The tree contains the patch for MDEV-19555.
 
mysqld: /data/Server/10.8C/storage/innobase/fts/fts0opt.cc:2615: void fts_optimize_remove_table(dict_table_t*): Assertion `!table->fts->in_queue' failed.
...
# 2022-01-28T18:22:57 [2406543] | Query (0x629000d89238): ALTER TABLE t3 ADD UNIQUE INDEX IF NOT EXISTS `uidx1` ( col_string ASC ), ADD UNIQUE INDEX IF NOT EXISTS `uIdx1` ( col_string ASC ) 
# 2022-01-28T18:22:57 [2406543] |Status: NOT_KILLED
 
(rr) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x000036845bff6859 in __GI_abort () at abort.c:79
#2  0x000036845bff6729 in __assert_fail_base (fmt=0x36845c18c588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55f08b4c7de0 "!table->fts->in_queue", file=0x55f08b4c5e40 "/data/Server/10.8C/storage/innobase/fts/fts0opt.cc", line=2615, 
    function=<optimized out>) at assert.c:92
#3  0x000036845c007f36 in __GI___assert_fail (assertion=0x55f08b4c7de0 "!table->fts->in_queue", file=0x55f08b4c5e40 "/data/Server/10.8C/storage/innobase/fts/fts0opt.cc", line=2615, function=0x55f08b4c7e20 "void fts_optimize_remove_table(dict_table_t*)")
    at assert.c:101
#4  0x000055f08a448bfb in fts_optimize_remove_table (table=0x618000301508) at /data/Server/10.8C/storage/innobase/fts/fts0opt.cc:2615
#5  0x000055f089dc2b6e in rollback_inplace_alter_table (ha_alter_info=0x6b7e501e9c40, table=0x619000418298, prebuilt=0x621000277588) at /data/Server/10.8C/storage/innobase/handler/handler0alter.cc:8735
#6  0x000055f089d9d424 in ha_innobase::commit_inplace_alter_table (this=0x61d00005dcb8, altered_table=0x6b7e501ea340, ha_alter_info=0x6b7e501e9c40, commit=false) at /data/Server/10.8C/storage/innobase/handler/handler0alter.cc:10843
#7  0x000055f089457f8c in handler::ha_commit_inplace_alter_table (this=0x61d00005dcb8, altered_table=0x6b7e501ea340, ha_alter_info=0x6b7e501e9c40, commit=false) at /data/Server/10.8C/sql/handler.cc:5195
#8  0x000055f088ebfda9 in mysql_inplace_alter_table (thd=0x62b0001ce218, table_list=0x629000d89458, table=0x619000418298, altered_table=0x6b7e501ea340, ha_alter_info=0x6b7e501e9c40, target_mdl_request=0x6b7e501e9d40, ddl_log_state=0x6b7e501e9a60, 
    trigger_param=0x6b7e501ea760, alter_ctx=0x6b7e501eb1a0, partial_alter=@0x6b7e501e97d0: false, start_alter_id=@0x6b7e501e9800: 0, if_exists=false) at /data/Server/10.8C/sql/sql_table.cc:7829
#9  0x000055f088ed41f8 in mysql_alter_table (thd=0x62b0001ce218, new_db=0x62b0001d2cc0, new_name=0x62b0001d30d8, create_info=0x6b7e501ec650, table_list=0x629000d89458, alter_info=0x6b7e501ec520, order_num=0, order=0x0, ignore=false, if_exists=false)
    at /data/Server/10.8C/sql/sql_table.cc:10675
#10 0x000055f089061462 in Sql_cmd_alter_table::execute (this=0x629000d89db0, thd=0x62b0001ce218) at /data/Server/10.8C/sql/sql_alter.cc:547
#11 0x000055f088c2c5c7 in mysql_execute_command (thd=0x62b0001ce218, is_called_from_prepared_stmt=false) at /data/Server/10.8C/sql/sql_parse.cc:5988
#12 0x000055f088c38a05 in mysql_parse (thd=0x62b0001ce218, rawbuf=0x629000d89238 "ALTER TABLE t3 ADD UNIQUE INDEX IF NOT EXISTS `uidx1` ( col_string ASC ), ADD UNIQUE INDEX IF NOT EXISTS `uIdx1` ( col_string ASC ) /* E_R Thread1 QNO 807 CON_ID 17 */", length=167, 
    parser_state=0x6b7e501edb20) at /data/Server/10.8C/sql/sql_parse.cc:8027
#13 0x000055f088c10dea in dispatch_command (command=COM_QUERY, thd=0x62b0001ce218, 
    packet=0x629000d7f219 "ALTER TABLE t3 ADD UNIQUE INDEX IF NOT EXISTS `uidx1` ( col_string ASC ), ADD UNIQUE INDEX IF NOT EXISTS `uIdx1` ( col_string ASC ) /* E_R Thread1 QNO 807 CON_ID 17 */ ", packet_length=168, blocking=true)
    at /data/Server/10.8C/sql/sql_parse.cc:1894
#14 0x000055f088c0e1c2 in do_command (thd=0x62b0001ce218, blocking=true) at /data/Server/10.8C/sql/sql_parse.cc:1402
#15 0x000055f0890471de in do_handle_one_connection (connect=0x608000003138, put_in_cache=true) at /data/Server/10.8C/sql/sql_connect.cc:1418
#16 0x000055f089046a6a in handle_one_connection (arg=0x608000003138) at /data/Server/10.8C/sql/sql_connect.cc:1312
#17 0x00004162530ef609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#18 0x000036845c0f3293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
(rr)
 
Per my bookkeeping of RQG runs we have this problem in 10.7 and 10.6 too.
 
pluto:/data/results/1643393487/TBR-1110/dev/shm/rqg/1643393487/26/1/rr
 
RQG
====
# git clone https://github.com/mleich1/rqg --branch experimental RQG
#
# GIT_SHOW: HEAD -> experimental, origin/experimental 91dc9c0f18cbab8725687895c86e1b2bc71ed185 2022-01-25T20:16:46+01:00
# rqg.pl  : Version 4.0.4 (2021-12)
#
# $RQG_HOME/rqg.pl \
# --duration=300 \
# --queries=10000000 \
# --no_mask \
# --seed=random \
# --grammar=TBR-1110_better.yy \
# --gendata_sql=conf/mariadb/table_stress.sql \
# --gendata=conf/mariadb/table_stress.zz \
# --rpl_mode=none \
# --max_gd_duration=1800 \
# --engine=InnoDB \
# --mysqld=--innodb_use_native_aio=0 \
# --mysqld=--innodb-lock-wait-timeout=50 \
# --mysqld=--loose-idle_readonly_transaction_timeout=0 \
# --mysqld=--loose-idle_write_transaction_timeout=0 \
# --mysqld=--innodb_adaptive_hash_index=on \
# --mysqld=--net_write_timeout=60 \
# --mysqld=--innodb-buffer-pool-size=5M \
# --mysqld=--innodb_stats_persistent=off \
# --mysqld=--log-output=none \
# --mysqld=--log-bin \
# --mysqld=--plugin-load-add=file_key_management.so \
# --mysqld=--loose-idle_transaction_timeout=0 \
# --mysqld=--lock-wait-timeout=86400 \
# --mysqld=--loose-innodb_read_only_compressed=OFF \
# --mysqld=--loose-debug_assert_on_not_freed_memory=0 \
# --mysqld=--slave_net_timeout=60 \
# --mysqld=--net_read_timeout=30 \
# --mysqld=--file-key-management-filename=$RQG_HOME/conf/mariadb/encryption_keys.txt \
# --mysqld=--sync-binlog=1 \
# --mysqld=--loose-max-statement-time=30 \
# --mysqld=--innodb_page_size=4K \
# --mysqld=--connect_timeout=60 \
# --mysqld=--loose-table_lock_wait_timeout=50 \
# --mysqld=--loose_innodb_lock_schedule_algorithm=fcfs \
# --mysqld=--log_bin_trust_function_creators=1 \
# --mysqld=--wait_timeout=28800 \
# --mysqld=--interactive_timeout=28800 \
# --reporters=Backtrace,Deadlock1,ErrorLog \
# --validators=None \
# --threads=2 \
# --rr=Extended \
# --rr_options=--chaos --wait \
# --vardir_type=fast \
# --no_mask \
# <some local settings>
 
Search pattern
[ 'TBR-1110', 'mysqld: .{1,250}fts0opt.cc:.{1,10}: void fts_optimize_remove_table\(dict_table_t\*\): Assertion \`\!table->fts->in_queue\' failed..+RESULT: The RQG run ended with status STATUS_SERVER_CRASHED' ],



 Comments   
Comment by Thirunarayanan Balathandayuthapani [ 2022-01-31 ]

MDEV-27672

  • During rollback of DDL, InnoDB tries to remove the table from fts_optimize_wq
    even when there was no fts index added. Problem should exist from 10.6 onwards.

The following alter does add only the unique index, and the table has only FTS_DOC_ID_INDEX.

ALTER TABLE t3 ADD UNIQUE INDEX IF NOT EXISTS `uidx1` ( col_string ASC ), ADD UNIQUE INDEX IF NOT EXISTS `uIdx1` ( col_string ASC ) /* E_R Thread1 QNO 807 CON_ID 17 */

Comment by Thirunarayanan Balathandayuthapani [ 2022-03-08 ]

mdev-27672.patch

Attached patch avoid un-necessary removal of fts table from fts_optimize_wq queue during rollback_inplace_alter_table().

Generated at Thu Feb 08 09:54:42 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.