[MDEV-26902] Auxilary fts table evicts during DDL Created: 2021-10-25  Updated: 2021-10-26  Resolved: 2021-10-26

Status: Closed
Project: MariaDB Server
Component/s: Full-text Search, Storage Engine - InnoDB
Affects Version/s: 10.2, 10.3, 10.4, 10.5, 10.6, 10.7
Fix Version/s: 10.2.41, 10.3.32, 10.4.22, 10.5.13, 10.6.5, 10.7.1

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

Attachments: File TBR-1203.zz     File TBR-1203_micro.yy    

 Description   

origin/10.6 1193a793c40b806c6f1f007bbd87f4d9a73e686d 2021-10-25T10:55:04+03:00
mysqld: /data/Server/10.6H/storage/innobase/include/sux_lock.h:77: void sux_lock<ssux>::free() [with ssux = ssux_lock_impl<false>]: Assertion `!writer.load(std::memory_order_relaxed)' failed.
 
(rr) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007f32c4ae0859 in __GI_abort () at abort.c:79
#2  0x00007f32c4ae0729 in __assert_fail_base (fmt=0x7f32c4c76588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x5629e1eb8020 "!writer.load(std::memory_order_relaxed)", file=0x5629e1eb7980 "/data/Server/10.6H/storage/innobase/include/sux_lock.h", line=77, 
    function=<optimized out>) at assert.c:92
#3  0x00007f32c4af1f36 in __GI___assert_fail (assertion=0x5629e1eb8020 "!writer.load(std::memory_order_relaxed)", file=0x5629e1eb7980 "/data/Server/10.6H/storage/innobase/include/sux_lock.h", line=77, 
    function=0x5629e1eb8080 "void sux_lock<ssux>::free() [with ssux = ssux_lock_impl<false>]") at assert.c:101
#4  0x00005629e08bd21e in sux_lock<ssux_lock_impl<false> >::free (this=0x616001959878) at /data/Server/10.6H/storage/innobase/include/sux_lock.h:77
#5  0x00005629e0e16b73 in dict_index_remove_from_cache_low (table=0x6180000c4508, index=0x616001959708, lru_evict=1) at /data/Server/10.6H/storage/innobase/dict/dict0dict.cc:2130
#6  0x00005629e0e13f62 in dict_sys_t::remove (this=0x5629e3085fc0 <dict_sys>, table=0x6180000c4508, lru=true, keep=false) at /data/Server/10.6H/storage/innobase/dict/dict0dict.cc:1850
#7  0x00005629e0e10528 in dict_sys_t::evict_table_LRU (this=0x5629e3085fc0 <dict_sys>, half=false) at /data/Server/10.6H/storage/innobase/dict/dict0dict.cc:1322
#8  0x00005629e0c21ef2 in srv_master_do_idle_tasks (counter_time=1619227655250) at /data/Server/10.6H/storage/innobase/srv/srv0srv.cc:1605
#9  0x00005629e0c225db in srv_master_callback () at /data/Server/10.6H/storage/innobase/srv/srv0srv.cc:1663
#10 0x00005629e0fd2d0e in tpool::thread_pool_generic::timer_generic::run (this=0x6120000034c0) at /data/Server/10.6H/tpool/tpool_generic.cc:313
#11 0x00005629e0fd2ff0 in tpool::thread_pool_generic::timer_generic::execute (arg=0x6120000034c0) at /data/Server/10.6H/tpool/tpool_generic.cc:332
#12 0x00005629e0fe2a77 in tpool::task::execute (this=0x612000003500) at /data/Server/10.6H/tpool/task.cc:37
#13 0x00005629e0fcf1c1 in tpool::thread_pool_generic::worker_main (this=0x618000000880, thread_var=0x63000001f700) at /data/Server/10.6H/tpool/tpool_generic.cc:549
#14 0x00005629e0fe1bab in std::__invoke_impl<void, void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> (__f=
    @0x6040000060e8: (void (tpool::thread_pool_generic::*)(class tpool::thread_pool_generic * const, struct tpool::worker_data *)) 0x5629e0fcefde <tpool::thread_pool_generic::worker_main(tpool::worker_data*)>, __t=@0x6040000060e0: 0x618000000880)
    at /usr/include/c++/9/bits/invoke.h:73
#15 0x00005629e0fe1956 in std::__invoke<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> (__fn=
    @0x6040000060e8: (void (tpool::thread_pool_generic::*)(class tpool::thread_pool_generic * const, struct tpool::worker_data *)) 0x5629e0fcefde <tpool::thread_pool_generic::worker_main(tpool::worker_data*)>) at /usr/include/c++/9/bits/invoke.h:95
#16 0x00005629e0fe17e7 in std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> >::_M_invoke<0ul, 1ul, 2ul> (this=0x6040000060d8) at /usr/include/c++/9/thread:244
#17 0x00005629e0fe1731 in std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> >::operator() (this=0x6040000060d8) at /usr/include/c++/9/thread:251
#18 0x00005629e0fe1696 in std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> > >::_M_run (this=0x6040000060d0) at /usr/include/c++/9/thread:195
#19 0x00007f32c4860de4 in ?? () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#20 0x00007e9a20d61609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#21 0x00007f32c4bdd293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
(rr)
sdp:/data/Results/1635179648/tmp/dev/shm/vardir/1635179648/72/1/rr
Archive: sdp:/data/Results/1635179648/000205.tar.xz
 
RQG
---
git clone https://github.com/mleich1/rqg --branch experimental RQG
       origin/experimental 346d06939a990a69913e644b47dd007bd215f402 2021-10-25T18:07:32+02:00
 
# $RQG_HOME/rqg.pl \
# --duration=300 \
# --queries=10000000 \
# --no_mask \
# --seed=random \
# --short_column_names \
# --max_gd_duration=1200 \
# --rpl_mode=none \
# --gendata=TBR-1203.zz \
# --engine=InnoDB \
# --mysqld=--loose-idle_transaction_timeout=0 \
# --mysqld=--innodb_adaptive_hash_index=on \
# --mysqld=--log_bin_trust_function_creators=1 \
# --mysqld=--loose-debug_assert_on_not_freed_memory=0 \
# --mysqld=--sync-binlog=1 \
# --mysqld=--interactive_timeout=28800 \
# --mysqld=--slave_net_timeout=60 \
# --mysqld=--lock-wait-timeout=86400 \
# --mysqld=--loose-idle_write_transaction_timeout=0 \
# --mysqld=--innodb_page_size=16K \
# --mysqld=--loose-table_lock_wait_timeout=50 \
# --mysqld=--loose_innodb_lock_schedule_algorithm=fcfs \
# --mysqld=--plugin-load-add=file_key_management.so \
# --mysqld=--innodb-lock-wait-timeout=50 \
# --mysqld=--net_write_timeout=60 \
# --mysqld=--wait_timeout=28800 \
# --mysqld=--log-output=none \
# --mysqld=--connect_timeout=60 \
# --mysqld=--loose-innodb_fatal_semaphore_wait_threshold=300 \
# --mysqld=--innodb_stats_persistent=off \
# --mysqld=--loose-idle_readonly_transaction_timeout=0 \
# --mysqld=--net_read_timeout=30 \
# --mysqld=--file-key-management-filename=$RQG_HOME/conf/mariadb/encryption_keys.txt \
# --mysqld=--innodb-buffer-pool-size=256M \
# --mysqld=--log-bin \
# --mysqld=--loose_innodb_use_native_aio=0 \
# --reporters=Backtrace,Deadlock1,ErrorLog \
# --validators=None \
# --grammar=TBR-1203_micro.yy \
# --threads=3 \
# --grammar=/data/Results/1635179648/c00000.yy \
# --workdir=<local settings> \
# --vardir=<local settings> \
# --mtr-build-thread=<local settings> \
# --basedir1=<local settings> \
# --script_debug=_nix_ \
# --rr=Extended \
# --rr_options=--chaos \
# --wait



 Comments   
Comment by Thirunarayanan Balathandayuthapani [ 2021-10-26 ]

InnoDB should release the auxiliary table after bulk load finish.

diff --git a/storage/innobase/row/row0ftsort.cc b/storage/innobase/row/row0ftsort.cc
index 96b7953a6b1..6bf22efda9a 100644
--- a/storage/innobase/row/row0ftsort.cc
+++ b/storage/innobase/row/row0ftsort.cc
@@ -1766,8 +1766,6 @@ row_fts_merge_insert(
        }
 
 exit:
-       aux_table->release();
-
        fts_sql_commit(trx);
 
        trx->op_info = "";
@@ -1777,6 +1775,8 @@ row_fts_merge_insert(
        error = ins_ctx.btr_bulk->finish(error);
        UT_DELETE(ins_ctx.btr_bulk);
 
+       aux_table->release();
+
        trx->free();
 
        mem_heap_free(heap);

MDEV-25702 releases the table little early. It should be fixed in 10.2+

Comment by Marko Mäkelä [ 2021-10-26 ]

The 10.2-based fix looks OK to me.

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