[MDEV-30802] Assertion `index->is_btree() || index->is_ibuf()' failed in btr_search_guess_on_hash Created: 2023-03-07  Updated: 2023-09-19  Resolved: 2023-09-19

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.6.8, 10.8.3, 10.9.1, 10.8.8, 10.6, 10.9, 10.10, 10.11, 11.0, 11.1, 11.2, 11.3
Fix Version/s: 10.6.16, 10.10.7, 10.11.6, 11.0.4, 11.1.3

Type: Bug Priority: Blocker
Reporter: Matthias Leich Assignee: Thirunarayanan Balathandayuthapani
Resolution: Fixed Votes: 0
Labels: race, regression, rr-profile-analyzed

Issue Links:
Problem/Incident
is caused by MDEV-15250 UPSERT during ALTER-TABLE results in ... Closed

 Description    

origin/bb-10.8-thiru 6fe2492299485888814a6d1a7a797fd7540f4e06 2023-03-03T19:05:44+05:30
 
 
 
# 2023-03-03T21:51:59 [4183583] | [rr 4186224 936842]mysqld: /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/btr/btr0sea.cc:1060: bool btr_search_guess_on_hash(dict_index_t*, btr_search_t*, const dtuple_t*, ulint, ulint, btr_cur_t*, mtr_t*): Assertion `index->is_btree() || index->is_ibuf()' failed.
 
...
 
# 2023-03-03T21:51:59 [4183583] | Thread 3 (Thread 4186224.4186593):
 
# 2023-03-03T21:51:59 [4183583] | #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
# 2023-03-03T21:51:59 [4183583] | #1  0x00007f4ef5dd9859 in __GI_abort () at abort.c:79
 
# 2023-03-03T21:51:59 [4183583] | #2  0x00007f4ef5dd9729 in __assert_fail_base (fmt=0x7f4ef5f6f588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55a743b65420 "index->is_btree() || index->is_ibuf()", file=0x55a743b60c00 "/data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/btr/btr0sea.cc", line=1060, function=<optimized out>) at assert.c:92
 
# 2023-03-03T21:51:59 [4183583] | #3  0x00007f4ef5deaf36 in __GI___assert_fail (assertion=assertion@entry=0x55a743b65420 "index->is_btree() || index->is_ibuf()", file=file@entry=0x55a743b60c00 "/data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/btr/btr0sea.cc", line=line@entry=1060, function=function@entry=0x55a743b65380 "bool btr_search_guess_on_hash(dict_index_t*, btr_search_t*, const dtuple_t*, ulint, ulint, btr_cur_t*, mtr_t*)") at assert.c:101
 
# 2023-03-03T21:51:59 [4183583] | #4  0x000055a742d16237 in btr_search_guess_on_hash (index=0x6160031c9c08, info=info@entry=0x61a0006b95c0, tuple=tuple@entry=0x61900038f008, mode=mode@entry=4, latch_mode=<optimized out>, cursor=cursor@entry=0x7f4ed2572610, mtr=<optimized out>) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/include/dict0mem.h:1207
 
# 2023-03-03T21:51:59 [4183583] | #5  0x000055a742ce9016 in btr_cur_t::search_leaf (this=this@entry=0x7f4ed2572610, tuple=tuple@entry=0x61900038f008, mode=mode@entry=PAGE_CUR_LE, latch_mode=latch_mode@entry=BTR_PURGE_LEAF, mtr=mtr@entry=0x7f4ed2572af0) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/include/btr0cur.h:744
 
# 2023-03-03T21:51:59 [4183583] | #6  0x000055a742ad682e in btr_pcur_open (mtr=0x7f4ed2572af0, cursor=0x7f4ed2572610, latch_mode=BTR_PURGE_LEAF, mode=PAGE_CUR_LE, tuple=0x61900038f008) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/include/btr0pcur.h:431
 
# 2023-03-03T21:51:59 [4183583] | #7  row_search_index_entry (entry=entry@entry=0x61900038f008, mode=BTR_PURGE_LEAF, pcur=pcur@entry=0x7f4ed2572610, mtr=mtr@entry=0x7f4ed2572af0) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/row/row0row.cc:1281
 
# 2023-03-03T21:51:59 [4183583] | #8  0x000055a742ab9325 in row_purge_remove_sec_if_poss_leaf (node=node@entry=0x61a00000e508, index=index@entry=0x6160031c9c08, entry=entry@entry=0x61900038f008) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/include/dict0mem.h:1220
 
# 2023-03-03T21:51:59 [4183583] | #9  0x000055a742abe14b in row_purge_remove_sec_if_poss (entry=0x61900038f008, index=0x6160031c9c08, node=0x61a00000e508) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/row/row0purge.cc:571
 
# 2023-03-03T21:51:59 [4183583] | #10 row_purge_del_mark (node=node@entry=0x61a00000e508) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/row/row0purge.cc:619
 
# 2023-03-03T21:51:59 [4183583] | #11 0x000055a742abecbd in row_purge_record_func (node=node@entry=0x61a00000e508, undo_rec=undo_rec@entry=0x621000057ad8 "", thr=thr@entry=0x61600005a4c0, updated_extern=<optimized out>) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/row/row0purge.cc:1189
 
# 2023-03-03T21:51:59 [4183583] | #12 0x000055a742abf451 in row_purge (node=node@entry=0x61a00000e508, undo_rec=undo_rec@entry=0x621000057ad8 "", thr=thr@entry=0x61600005a4c0) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/row/row0purge.cc:1250
 
# 2023-03-03T21:51:59 [4183583] | #13 0x000055a742abfd6d in row_purge_step (thr=thr@entry=0x61600005a4c0) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/row/row0purge.cc:1313
 
# 2023-03-03T21:51:59 [4183583] | #14 0x000055a742975d56 in que_thr_step (thr=0x61600005a4c0) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/que/que0que.cc:597
 
# 2023-03-03T21:51:59 [4183583] | #15 que_run_threads_low (thr=thr@entry=0x61600005a4c0) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/que/que0que.cc:653
 
# 2023-03-03T21:51:59 [4183583] | #16 0x000055a7429760c4 in que_run_threads (thr=thr@entry=0x61600005a4c0) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/que/que0que.cc:673
 
# 2023-03-03T21:51:59 [4183583] | #17 0x000055a742b6ad20 in srv_task_execute () at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/srv/srv0srv.cc:1599
 
# 2023-03-03T21:51:59 [4183583] | #18 0x000055a742b6af13 in purge_worker_callback () at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/srv/srv0srv.cc:1843
 
# 2023-03-03T21:51:59 [4183583] | #19 0x000055a7430289c7 in tpool::task_group::execute (this=0x55a745115500 <purge_task_group>, t=t@entry=0x55a745115440 <purge_worker_task>) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/tpool/task_group.cc:55
 
# 2023-03-03T21:51:59 [4183583] | #20 0x000055a743028c3b in tpool::task::execute (this=0x55a745115440 <purge_worker_task>) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/tpool/task.cc:32
 
# 2023-03-03T21:51:59 [4183583] | #21 0x000055a74301fd44 in tpool::thread_pool_generic::worker_main (this=0x618000000880, thread_var=0x630000010400) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/tpool/tpool_generic.cc:576
 
 
 
RQG
 
=# git clone https://github.com/mleich1/rqg --branch <pick the right branch> RQG
 
#
 
# GIT_SHOW: HEAD -> master, origin/master, origin/HEAD 4eb4084904632fa859a9c4aebd04c434bc93ffa1 2023-03-03T12:47:43+01:00
 
# rqg.pl  : Version 4.2.1 (2022-12)
 
#
 
# $RQG_HOME/rqg.pl \
 
# --grammar=conf/mariadb/table_stress_innodb_nocopy1.yy \
 
# --gendata=conf/mariadb/table_stress.zz \
 
# --gendata_sql=conf/mariadb/table_stress.sql \
 
# --mysqld=--loose-innodb_lock_schedule_algorithm=fcfs \
 
# --mysqld=--loose-idle_write_transaction_timeout=0 \
 
# --mysqld=--loose-idle_transaction_timeout=0 \
 
# --mysqld=--loose-idle_readonly_transaction_timeout=0 \
 
# --mysqld=--connect_timeout=60 \
 
# --mysqld=--interactive_timeout=28800 \
 
# --mysqld=--slave_net_timeout=60 \
 
# --mysqld=--net_read_timeout=30 \
 
# --mysqld=--net_write_timeout=60 \
 
# --mysqld=--loose-table_lock_wait_timeout=50 \
 
# --mysqld=--wait_timeout=28800 \
 
# --mysqld=--lock-wait-timeout=86400 \
 
# --mysqld=--innodb-lock-wait-timeout=50 \
 
# --no_mask \
 
# --queries=10000000 \
 
# --seed=random \
 
# --reporters=Backtrace \
 
# --reporters=ErrorLog \
 
# --reporters=Deadlock \
 
# --validators=None \
 
# --mysqld=--log_output=none \
 
# --mysqld=--log_bin_trust_function_creators=1 \
 
# --mysqld=--loose-debug_assert_on_not_freed_memory=0 \
 
# --engine=InnoDB \
 
# --restart_timeout=240 \
 
# --mysqld=--plugin-load-add=file_key_management.so \
 
# --mysqld=--loose-file-key-management-filename=$RQG_HOME/conf/mariadb/encryption_keys.txt \
 
# --mysqld=--plugin-load-add=provider_lzo.so \
 
# --mysqld=--plugin-load-add=provider_bzip2.so \
 
# --mysqld=--plugin-load-add=provider_lzma.so \
 
# --mysqld=--plugin-load-add=provider_snappy.so \
 
# --mysqld=--plugin-load-add=provider_lz4.so \
 
# --mysqld=--loose-innodb_compression_level=1 \
 
# --duration=300 \
 
# --mysqld=--loose-innodb_fatal_semaphore_wait_threshold=300 \
 
# --mysqld=--innodb_file_per_table=0 \
 
# --mysqld=--loose-innodb_read_only_compressed=OFF \
 
# --mysqld=--loose-innodb-sync-debug \
 
# --mysqld=--innodb_stats_persistent=on \
 
# --mysqld=--innodb_adaptive_hash_index=on \
 
# --mysqld=--log-bin \
 
# --mysqld=--sync-binlog=1 \
 
# --mysqld=--loose-innodb_evict_tables_on_commit_debug=on \
 
# --mysqld=--loose-max-statement-time=30 \
 
# --threads=9 \
 
# --mysqld=--innodb-use-native-aio=0 \
 
# --mysqld=--loose-gdb \
 
# --mysqld=--loose-debug-gdb \
 
# --rr=Extended \
 
# --rr_options=--wait \
 
# --mysqld=--innodb_undo_log_truncate=OFF \
 
# --mysqld=--innodb_rollback_on_timeout=OFF \
 
# --mysqld=--innodb_page_size=32K \
 
# --mysqld=--innodb-buffer-pool-size=256M \
 
# <local settings>
 
 
 
pluto:/data/results/1677865194/TBR-1825$ _RR_TRACE_DIR=./1/rr/ rr replay --mark-stdio



 Comments   
Comment by Thirunarayanan Balathandayuthapani [ 2023-03-24 ]

Rollback marks the index as corrupted. At the same time, purge is working on the same index. It leads to assertion failure
`index->is_btree() || index->is_ibuf()`

Pasting stack trace:

Thread 3 received signal SIGABRT, Aborted.
 
__GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
50	../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
 
(rr) where
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#1  0x00007f4ef5dd9859 in __GI_abort () at abort.c:79
 
#2  0x00007f4ef5dd9729 in __assert_fail_base (fmt=0x7f4ef5f6f588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", 
    assertion=0x55a743b65420 "index->is_btree() || index->is_ibuf()", 
    file=0x55a743b60c00 "/data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/btr/btr0sea.cc", line=1060, function=<optimized out>)
 
    at assert.c:92
 
#3  0x00007f4ef5deaf36 in __GI___assert_fail (assertion=assertion@entry=0x55a743b65420 "index->is_btree() || index->is_ibuf()", 
    file=file@entry=0x55a743b60c00 "/data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/btr/btr0sea.cc", line=line@entry=1060, 
    function=function@entry=0x55a743b65380 "bool btr_search_guess_on_hash(dict_index_t*, btr_search_t*, const dtuple_t*, ulint, ulint, btr_cur_t*, mtr_t*)") at assert.c:101
 
#4  0x000055a742d16237 in btr_search_guess_on_hash (index=0x6160031c9c08, info=info@entry=0x61a0006b95c0, tuple=tuple@entry=0x61900038f008, 
    mode=mode@entry=4, latch_mode=<optimized out>, cursor=cursor@entry=0x7f4ed2572610, mtr=<optimized out>)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/include/dict0mem.h:1207
 
#5  0x000055a742ce9016 in btr_cur_t::search_leaf (this=this@entry=0x7f4ed2572610, tuple=tuple@entry=0x61900038f008, mode=mode@entry=PAGE_CUR_LE, 
    latch_mode=latch_mode@entry=BTR_PURGE_LEAF, mtr=mtr@entry=0x7f4ed2572af0)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/include/btr0cur.h:744
 
#6  0x000055a742ad682e in btr_pcur_open (mtr=0x7f4ed2572af0, cursor=0x7f4ed2572610, latch_mode=BTR_PURGE_LEAF, mode=PAGE_CUR_LE, 
    tuple=0x61900038f008) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/include/btr0pcur.h:431
 
#7  row_search_index_entry (entry=entry@entry=0x61900038f008, mode=BTR_PURGE_LEAF, pcur=pcur@entry=0x7f4ed2572610, mtr=mtr@entry=0x7f4ed2572af0)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/row/row0row.cc:1281
 
#8  0x000055a742ab9325 in row_purge_remove_sec_if_poss_leaf (node=node@entry=0x61a00000e508, index=index@entry=0x6160031c9c08, 
    entry=entry@entry=0x61900038f008) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/include/dict0mem.h:1220
 
#9  0x000055a742abe14b in row_purge_remove_sec_if_poss (entry=0x61900038f008, index=0x6160031c9c08, node=0x61a00000e508)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/row/row0purge.cc:571
 
#10 row_purge_del_mark (node=node@entry=0x61a00000e508) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/row/row0purge.cc:619
 
#11 0x000055a742abecbd in row_purge_record_func (node=node@entry=0x61a00000e508, undo_rec=undo_rec@entry=0x621000057ad8 "", 
    thr=thr@entry=0x61600005a4c0, updated_extern=<optimized out>)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/row/row0purge.cc:1189
 
#12 0x000055a742abf451 in row_purge (node=node@entry=0x61a00000e508, undo_rec=undo_rec@entry=0x621000057ad8 "", thr=thr@entry=0x61600005a4c0)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/row/row0purge.cc:1250
 
#13 0x000055a742abfd6d in row_purge_step (thr=thr@entry=0x61600005a4c0)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/row/row0purge.cc:1313
 
#14 0x000055a742975d56 in que_thr_step (thr=0x61600005a4c0) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/que/que0que.cc:597
 
#15 que_run_threads_low (thr=thr@entry=0x61600005a4c0) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/que/que0que.cc:653
 
#16 0x000055a7429760c4 in que_run_threads (thr=thr@entry=0x61600005a4c0)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/que/que0que.cc:673
 
#17 0x000055a742b6ad20 in srv_task_execute () at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/srv/srv0srv.cc:1599
 
#18 0x000055a742b6af13 in purge_worker_callback () at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/srv/srv0srv.cc:1843
 
--Type <RET> for more, q to quit, c to continue without paging--
 
#19 0x000055a7430289c7 in tpool::task_group::execute (this=0x55a745115500 <purge_task_group>, t=t@entry=0x55a745115440 <purge_worker_task>)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/tpool/task_group.cc:55
 
#20 0x000055a743028c3b in tpool::task::execute (this=0x55a745115440 <purge_worker_task>)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/tpool/task.cc:32
 
#21 0x000055a74301fd44 in tpool::thread_pool_generic::worker_main (this=0x618000000880, thread_var=0x630000010400)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/tpool/tpool_generic.cc:576
 
#22 0x000055a7430230e0 in std::__invoke_impl<void, void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> (__t=<optimized out>, __f=<optimized out>) at /usr/include/c++/9/bits/invoke.h:89
 
#23 std::__invoke<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> (
 
    __fn=<optimized out>) at /usr/include/c++/9/bits/invoke.h:95
 
#24 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=<optimized out>) at /usr/include/c++/9/thread:244
 
#25 std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> >::operator() (this=<optimized out>) at /usr/include/c++/9/thread:251
 
#26 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=<optimized out>) at /usr/include/c++/9/thread:195
 
#27 0x00007f4ef61e8de4 in ?? () from /lib/x86_64-linux-gnu/libstdc++.so.6
 
#28 0x00007f4ef6303609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#29 0x00007f4ef5ed6293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Alter table rollback marks the index as corrupted. Alter table does lock=shared. That's important because it marks the online status
as 0 always. So there is no need for purge to work on the indexes.

Thread 16 hit Hardware watchpoint 1: -location index->type
 
 
 
Old value = 18
 
New value = 2
 
0x000055a742a35357 in row_merge_drop_indexes (trx=0x7f4eea049140, table=table@entry=0x6180000dcd08, locked=<optimized out>, 
    alter_trx=0x7f4eea046540) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/row/row0merge.cc:4129
 
4129						index->type |= DICT_CORRUPT;
 
(rr) where
 
#0  0x000055a742a35357 in row_merge_drop_indexes (trx=0x7f4eea049140, table=table@entry=0x6180000dcd08, locked=<optimized out>, 
    alter_trx=0x7f4eea046540) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/row/row0merge.cc:4129
 
#1  0x000055a742710bd0 in innobase_rollback_sec_index (user_table=0x6180000dcd08, table=table@entry=0x619000919198, locked=<optimized out>, 
    trx=<optimized out>, alter_trx=<optimized out>)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/handler/handler0alter.cc:8904
 
#2  0x000055a74272ac81 in rollback_inplace_alter_table (ha_alter_info=ha_alter_info@entry=0x7f4ec125cdc0, table=<optimized out>, 
    prebuilt=0x621000309988) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/handler/handler0alter.cc:9041
 
#3  0x000055a742709c69 in ha_innobase::commit_inplace_alter_table (this=<optimized out>, altered_table=<optimized out>, 
    ha_alter_info=<optimized out>, commit=<optimized out>)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/handler/handler0alter.cc:11032
 
#4  0x000055a741d0e08f in handler::ha_commit_inplace_alter_table (this=0x61d0009344b8, altered_table=altered_table@entry=0x7f4ec125d4c0, 
    ha_alter_info=ha_alter_info@entry=0x7f4ec125cdc0, commit=commit@entry=false)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/sql/handler.cc:5268
 
#5  0x000055a7416ec492 in mysql_inplace_alter_table (thd=thd@entry=0x62b00020d218, table_list=<optimized out>, table=table@entry=0x619000919198, 
    altered_table=<optimized out>, ha_alter_info=<optimized out>, target_mdl_request=<optimized out>, ddl_log_state=<optimized out>, 
    trigger_param=<optimized out>, alter_ctx=<optimized out>, partial_alter=<optimized out>, start_alter_id=<optimized out>, 
    if_exists=<optimized out>) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/sql/sql_table.cc:7848
 
#6  0x000055a741724f00 in mysql_alter_table (thd=thd@entry=0x62b00020d218, new_db=new_db@entry=0x62b000211cf0, 
    new_name=new_name@entry=0x62b000212140, create_info=0x7f4ec125f800, table_list=<optimized out>, table_list@entry=0x629000e38498, 
    recreate_info=<optimized out>, alter_info=<optimized out>, order_num=<optimized out>, order=<optimized out>, ignore=<optimized out>, 
    if_exists=<optimized out>) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/sql/sql_table.cc:10782
 
#7  0x000055a7418b156b in Sql_cmd_alter_table::execute (this=<optimized out>, thd=0x62b00020d218)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/sql/structs.h:568
 
#8  0x000055a741439e60 in mysql_execute_command (thd=thd@entry=0x62b00020d218, 
    is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/sql/sql_parse.cc:5994
 
#9  0x000055a7413f0cbd in mysql_parse (thd=thd@entry=0x62b00020d218, rawbuf=<optimized out>, length=<optimized out>, 
    parser_state=parser_state@entry=0x7f4ec1261130) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/sql/sql_parse.cc:8019
 
#10 0x000055a74141f457 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x62b00020d218, 
    packet=packet@entry=0x6290028b9219 " ALTER TABLE t1 ADD UNIQUE KEY IF NOT EXISTS `Marvão_uidx2` ( col_string /*!100800 DESC */, col_text(9) /*!100800 ASC */ ), ALGORITHM = NOCOPY, LOCK = SHARED  /* E_R Thread5 QNO 6248 CON_ID 329 */ ", packet_length=packet_length@entry=198, 
    blocking=blocking@entry=true) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/sql/sql_class.h:1389
 
#11 0x000055a74142613e in do_command (thd=0x62b00020d218, blocking=blocking@entry=true)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/sql/sql_parse.cc:1407
 
#12 0x000055a74189a1f1 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x6080000035b8, put_in_cache=put_in_cache@entry=true)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/sql/sql_connect.cc:1416
 
#13 0x000055a74189ad3a in handle_one_connection (arg=0x6080000035b8) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/sql/sql_connect.cc:1318
 
#14 0x00007f4ef6303609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#15 0x00007f4ef5ed6293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

When index is being marked as corrupted, thread 3 does the following:

 
 
(rr) t 3
 
[Switching to thread 3 (Thread 4186224.4186593)]
 
#0  0x000055a742dba5fe in dfield_check_typed (field=0x61900038f040)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/data/data0data.cc:160
 
160	{
 
(rr) where
 
#0  0x000055a742dba5fe in dfield_check_typed (field=0x61900038f040)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/data/data0data.cc:160
 
#1  0x000055a742dbab00 in dtuple_check_typed (tuple=tuple@entry=0x61900038f008)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/data/data0data.cc:187
 
#2  0x000055a742ce840c in btr_cur_t::search_leaf (this=this@entry=0x7f4ed2572610, tuple=tuple@entry=0x61900038f008, mode=mode@entry=PAGE_CUR_LE, 
    latch_mode=latch_mode@entry=BTR_PURGE_LEAF, mtr=mtr@entry=0x7f4ed2572af0)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/btr/btr0cur.cc:950
 
#3  0x000055a742ad682e in btr_pcur_open (mtr=0x7f4ed2572af0, cursor=0x7f4ed2572610, latch_mode=BTR_PURGE_LEAF, mode=PAGE_CUR_LE, 
    tuple=0x61900038f008) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/include/btr0pcur.h:431
 
#4  row_search_index_entry (entry=entry@entry=0x61900038f008, mode=BTR_PURGE_LEAF, pcur=pcur@entry=0x7f4ed2572610, mtr=mtr@entry=0x7f4ed2572af0)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/row/row0row.cc:1281
 
#5  0x000055a742ab9325 in row_purge_remove_sec_if_poss_leaf (node=node@entry=0x61a00000e508, index=index@entry=0x6160031c9c08, 
    entry=entry@entry=0x61900038f008) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/include/dict0mem.h:1220
 
#6  0x000055a742abe14b in row_purge_remove_sec_if_poss (entry=0x61900038f008, index=0x6160031c9c08, node=0x61a00000e508)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/row/row0purge.cc:571
 
#7  row_purge_del_mark (node=node@entry=0x61a00000e508) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/row/row0purge.cc:619
 
#8  0x000055a742abecbd in row_purge_record_func (node=node@entry=0x61a00000e508, undo_rec=undo_rec@entry=0x621000057ad8 "", 
    thr=thr@entry=0x61600005a4c0, updated_extern=<optimized out>)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/row/row0purge.cc:1189
 
#9  0x000055a742abf451 in row_purge (node=node@entry=0x61a00000e508, undo_rec=undo_rec@entry=0x621000057ad8 "", thr=thr@entry=0x61600005a4c0)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/row/row0purge.cc:1250
 
#10 0x000055a742abfd6d in row_purge_step (thr=thr@entry=0x61600005a4c0)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/row/row0purge.cc:1313
 
#11 0x000055a742975d56 in que_thr_step (thr=0x61600005a4c0) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/que/que0que.cc:597
 
#12 que_run_threads_low (thr=thr@entry=0x61600005a4c0) at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/que/que0que.cc:653
 
#13 0x000055a7429760c4 in que_run_threads (thr=thr@entry=0x61600005a4c0)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/que/que0que.cc:673
 
#14 0x000055a742b6ad20 in srv_task_execute () at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/srv/srv0srv.cc:1599
 
#15 0x000055a742b6af13 in purge_worker_callback () at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/storage/innobase/srv/srv0srv.cc:1843
 
#16 0x000055a7430289c7 in tpool::task_group::execute (this=0x55a745115500 <purge_task_group>, t=t@entry=0x55a745115440 <purge_worker_task>)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/tpool/task_group.cc:55
 
#17 0x000055a743028c3b in tpool::task::execute (this=0x55a745115440 <purge_worker_task>)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/tpool/task.cc:32
 
#18 0x000055a74301fd44 in tpool::thread_pool_generic::worker_main (this=0x618000000880, thread_var=0x630000010400)
 
    at /data/Server/bb-10.8-thiru_fixing_MDEV-30183/tpool/tpool_generic.cc:576
 
#19 0x000055a7430230e0 in std::__invoke_impl<void, void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> (__t=<optimized out>, __f=<optimized out>) at /usr/include/c++/9/bits/invoke.h:89

Comment by Marko Mäkelä [ 2023-09-07 ]

As far as I understand, this is a race condition between rollback_inplace_alter_table() and the purge of history. I think that to fix this, at least the functions row_purge_remove_sec_if_poss() and row_purge_remove_clust_if_poss() (possibly also other functions that are invoked by purge) must do the following:

  1. Check if index->online_status != ONLINE_INDEX_COMPLETE (specifically, here index->online_status > ONLINE_INDEX_CREATION)
  2. If yes, acquire the index latch in the mini-transaction, and recheck.
  3. If needed, skip the operation. Else, continue with the operation.
  4. Let mtr_t::commit() release the index latch at the end.

We should have some similar code in DML code paths, at least rollback. Check those.

The reason for the race condition is that unlike other changes related to online native ALTER TABLE, the rollback is not guaranteed to be protected by MDL_EXCLUSIVE. In fact, common causes for the rollback is that a duplicate key was found, or the attempt to upgrade to MDL_EXCLUSIVE timed out.

Comment by Marko Mäkelä [ 2023-09-07 ]

In a discussion with thiru, we concluded that this only affects the rollback of creating secondary indexes when the table is not being rebuilt. If the table were being rebuilt, then any concurrent DML would not be able to access the rebuilt table until ha_innobase::commit_inplace_alter_table(commit=true) has finished.

We concluded that this needs to be fixed in row_purge_remove_sec_if_poss_leaf() and row_purge_remove_sec_if_poss_tree(). It turns out that the necessary logic was there before it was removed in MDEV-15250.

I am not sure if there is a bad impact of this bug on non-debug builds.

Comment by Marko Mäkelä [ 2023-09-15 ]

I did not remember that MDEV-15250 changed the logic so that all index->online_log for being-created secondary indexes will be preserved until ha_innobase::commit_alter_table() invokes row_log_apply() for one last time.

The purpose of purge is to implement deferred deletion, so that concurrent MVCC reads will be able to access the old data. In secondary indexes, we may have multiple entries pointing to the same primary key, corresponding to multiple versions of rows. While CREATE INDEX or ALTER TABLE…ADD INDEX is in progress, other transactions can’t access the not-yet-committed index. Therefore, row_log_apply() can apply all concurrently executed UPDATE and DELETE operations directly to the being-created index. In the case of ALTER TABLE…ADD INDEX…LOCK=SHARED, there will be no log to apply, but also no history to be purged, because the last version of the data will be used as the basis for creating the index.

The correct condition in purge would seem to be to check for dict_index_t::is_committed(). The flag can only be set in commit_cache_norebuild(), while that ALTER TABLE thread is holding both MDL_EXCLUSIVE on the table name and exclusive dict_sys.latch. Because purge is holding a shared MDL (ever since MDEV-16678 was implemented), it is safe to invoke dict_index_t::is_committed() without any additional locking.

Comment by Marko Mäkelä [ 2023-09-19 ]

thiru found out a nice way to reproduce the assertion failure with the existing test innodb.innodb-index-online:

diff --git a/storage/innobase/row/row0purge.cc b/storage/innobase/row/row0purge.cc
 
index ec717e1ded6..c13b1470ab6 100644
 
--- a/storage/innobase/row/row0purge.cc
 
+++ b/storage/innobase/row/row0purge.cc
 
@@ -447,6 +447,7 @@ row_purge_remove_sec_if_poss_leaf(
 
 	dict_index_t*	index,	/*!< in: index */
 
 	const dtuple_t*	entry)	/*!< in: index entry */
 
 {
 
+if (!index->is_committed()) sleep(5);
 
 	mtr_t			mtr;
 
 	btr_pcur_t		pcur;
 
 	bool			success	= true;

10.6 0f870914d410e8a34ea99b1e0ea7eb71094606f9 with the above patch

 
CURRENT_TEST: innodb.innodb-index-online
 
mysqltest: At line 339: query 'reap' failed: ER_LOCK_WAIT_TIMEOUT (1205): Lock wait timeout exceeded; try restarting transaction
 
…
 
mariadbd: /mariadb/10.6/storage/innobase/btr/btr0cur.cc:1011: dberr_t btr_cur_t::search_leaf(const dtuple_t*, page_cur_mode_t, btr_latch_mode, mtr_t*): Assertion `index()->is_btree() || index()->is_ibuf()' failed.

Generated at Thu Feb 08 10:19:00 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.