[MDEV-28886] Unexpected bogus locking errors upon partitioning operations Created: 2022-06-18  Updated: 2024-01-05

Status: Confirmed
Project: MariaDB Server
Component/s: Locking, Partitioning, Storage Engine - InnoDB
Affects Version/s: 10.5, 10.6, 10.7, 10.8, 10.9
Fix Version/s: 10.5, 10.6

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Marko Mäkelä
Resolution: Unresolved Votes: 0
Labels: None


 Description   

Contrary to its appearance, the test case is quite non-deterministic. It fails with different probability and with different errors depending on the version and build. Run with --repeat=N. Sometimes the first error causes further effects, some of which are shown below.

On 10.5 the issue appeared after this commit:

commit ea37b144094a0c2ebfc6774047fd473c1b2a8658
 
Author: Marko Mäkelä
 
Date:   Tue Dec 10 15:42:50 2019 +0200
 
 
 
    MDEV-16678 Prefer MDL to dict_sys.latch for innodb background tasks


--source include/have_innodb.inc
 
--source include/have_partition.inc
 
 
 
CREATE TABLE t (a INT, b INT) ENGINE=InnoDB PARTITION BY KEY(b) PARTITIONS 2;
 
INSERT INTO t VALUES (0,9),(1,8),(2,7),(3,6),(4,5),(5,4),(6,3),(7,2),(8,1),(9,0);
 
 
 
ALTER TABLE t NOWAIT REBUILD PARTITION p0;
 
ALTER TABLE t NOWAIT TRUNCATE PARTITION p0;
 
DROP TABLE t;

10.5 debug builds usually fail for me like this:

10.5 674842be

 
ALTER TABLE t NOWAIT REBUILD PARTITION p0;
 
ALTER TABLE t NOWAIT TRUNCATE PARTITION p0;
 
mysqltest: At line 8: query 'ALTER TABLE t NOWAIT TRUNCATE PARTITION p0' failed: 1205: Lock wait timeout exceeded; try restarting transaction

10.6 more often fails on the first ALTER already:

10.6 0e4cf497

 
ALTER TABLE t NOWAIT REBUILD PARTITION p0;
 
mysqltest: At line 7: query 'ALTER TABLE t NOWAIT REBUILD PARTITION p0' failed: ER_LOCK_WAIT_TIMEOUT (1205): Lock wait timeout exceeded; try restarting transaction
 
ALTER TABLE t NOWAIT TRUNCATE PARTITION p0;
 
DROP TABLE t;

or on both:

CREATE TABLE t (a INT, b INT) ENGINE=InnoDB PARTITION BY KEY(b) PARTITIONS 2;
 
INSERT INTO t VALUES (0,9),(1,8),(2,7),(3,6),(4,5),(5,4),(6,3),(7,2),(8,1),(9,0);
 
ALTER TABLE t NOWAIT REBUILD PARTITION p0;
 
mysqltest: At line 7: query 'ALTER TABLE t NOWAIT REBUILD PARTITION p0' failed: ER_LOCK_WAIT_TIMEOUT (1205): Lock wait timeout exceeded; try restarting transaction
 
ALTER TABLE t NOWAIT TRUNCATE PARTITION p0;
 
mysqltest: At line 8: query 'ALTER TABLE t NOWAIT TRUNCATE PARTITION p0' failed: ER_LOCK_WAIT_TIMEOUT (1205): Lock wait timeout exceeded; try restarting transaction
 
DROP TABLE t;

10.8 adds more variety. It must be coming from the per-partition options, but for now I will consider it all side-effects of the same problem:

10.8 cb19e211

 
ALTER TABLE t NOWAIT REBUILD PARTITION p0;
 
mysqltest: At line 7: query 'ALTER TABLE t NOWAIT REBUILD PARTITION p0' failed: ER_LOCK_WAIT_TIMEOUT (1205): Lock wait timeout exceeded; try restarting transaction
 
ALTER TABLE t NOWAIT TRUNCATE PARTITION p0;
 
mysqltest: At line 8: query 'ALTER TABLE t NOWAIT TRUNCATE PARTITION p0' failed: ER_GET_ERRNO (1030): Got error 140 "Wrong create options" from storage engine InnoDB
 
SHOW WARNINGS;
 
Level	Code	Message
 
Warning	140	InnoDB: invalid PAGE_COMPRESSION_LEVEL = 11936128518282651045. Valid values are [1, 2, 3, 4, 5, 6, 7, 8, 9]
 
Error	1030	Got error 140 "Wrong create options" from storage engine InnoDB
 
DROP TABLE t;

10.8 cb19e211 ASAN

 
==1726155==ERROR: AddressSanitizer: heap-use-after-free on address 0x61d0000b75bc at pc 0x557d30ea37c3 bp 0x7f3d25931800 sp 0x7f3d259317f8
 
READ of size 4 at 0x61d0000b75bc thread T11
 
    #0 0x557d30ea37c2 in create_table_info_t::check_table_options() /data/src/10.8/storage/innobase/handler/ha_innodb.cc:11249
 
    #1 0x557d30ef07ad in create_table_info_t::prepare_create_table(char const*, bool) /data/src/10.8/storage/innobase/handler/ha_innodb.cc:12020
 
    #2 0x557d30ef07ad in ha_innobase::create(char const*, TABLE*, HA_CREATE_INFO*, bool, trx_t*) /data/src/10.8/storage/innobase/handler/ha_innodb.cc:13194
 
    #3 0x557d30edfaaf in ha_innobase::truncate() /data/src/10.8/storage/innobase/handler/ha_innodb.cc:13962
 
    #4 0x557d30c91ab1 in ha_partition::truncate_partition(Alter_info*, bool*) /data/src/10.8/sql/ha_partition.cc:4918
 
    #5 0x557d301e2060 in Sql_cmd_alter_table_truncate_partition::execute(THD*) /data/src/10.8/sql/sql_partition_admin.cc:958
 
    #6 0x557d2fe07c07 in mysql_execute_command(THD*, bool) /data/src/10.8/sql/sql_parse.cc:5988
 
    #7 0x557d2fe14c0a in mysql_parse(THD*, char*, unsigned int, Parser_state*) /data/src/10.8/sql/sql_parse.cc:8027
 
    #8 0x557d2fe1a274 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /data/src/10.8/sql/sql_parse.cc:1894
 
    #9 0x557d2fe1fc75 in do_command(THD*, bool) /data/src/10.8/sql/sql_parse.cc:1407
 
    #10 0x557d301da83d in do_handle_one_connection(CONNECT*, bool) /data/src/10.8/sql/sql_connect.cc:1418
 
    #11 0x557d301dad7c in handle_one_connection /data/src/10.8/sql/sql_connect.cc:1312
 
    #12 0x557d30cb3a6b in pfs_spawn_thread /data/src/10.8/storage/perfschema/pfs.cc:2201
 
    #13 0x7f3d344faea6 in start_thread nptl/pthread_create.c:477
 
    #14 0x7f3d340f9dee in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xfddee)
 
 
 
0x61d0000b75bc is located 828 bytes inside of 2064-byte region [0x61d0000b7280,0x61d0000b7a90)
 
freed by thread T11 here:
 
    #0 0x7f3d34a00b6f in __interceptor_free ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:123
 
    #1 0x557d315a3454 in root_free /data/src/10.8/mysys/my_alloc.c:78
 
    #2 0x557d315a3454 in free_root /data/src/10.8/mysys/my_alloc.c:501
 
    #3 0x557d301240e9 in closefrm(TABLE*) /data/src/10.8/sql/table.cc:4540
 
    #4 0x557d30402a1f in intern_close_table /data/src/10.8/sql/table_cache.cc:220
 
    #5 0x557d30402a1f in tc_remove_table /data/src/10.8/sql/table_cache.cc:258
 
    #6 0x557d2fe2e505 in handle_alter_part_error /data/src/10.8/sql/sql_partition.cc:7073
 
    #7 0x557d2fe4c5be in fast_alter_partition_table(THD*, TABLE*, Alter_info*, Alter_table_ctx*, HA_CREATE_INFO*, TABLE_LIST*) /data/src/10.8/sql/sql_partition.cc:7773
 
    #8 0x557d30091285 in mysql_alter_table(THD*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool, bool) /data/src/10.8/sql/sql_table.cc:10408
 
    #9 0x557d301eca63 in Sql_cmd_alter_table::execute(THD*) /data/src/10.8/sql/sql_alter.cc:547
 
    #10 0x557d2fe07c07 in mysql_execute_command(THD*, bool) /data/src/10.8/sql/sql_parse.cc:5988
 
    #11 0x557d2fe14c0a in mysql_parse(THD*, char*, unsigned int, Parser_state*) /data/src/10.8/sql/sql_parse.cc:8027
 
    #12 0x557d2fe1a274 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /data/src/10.8/sql/sql_parse.cc:1894
 
    #13 0x557d2fe1fc75 in do_command(THD*, bool) /data/src/10.8/sql/sql_parse.cc:1407
 
    #14 0x557d301da83d in do_handle_one_connection(CONNECT*, bool) /data/src/10.8/sql/sql_connect.cc:1418
 
    #15 0x557d301dad7c in handle_one_connection /data/src/10.8/sql/sql_connect.cc:1312
 
    #16 0x557d30cb3a6b in pfs_spawn_thread /data/src/10.8/storage/perfschema/pfs.cc:2201
 
    #17 0x7f3d344faea6 in start_thread nptl/pthread_create.c:477
 
 
 
previously allocated by thread T11 here:
 
    #0 0x7f3d34a00e8f in __interceptor_malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:145
 
    #1 0x557d315b5968 in my_malloc /data/src/10.8/mysys/my_malloc.c:90
 
    #2 0x557d315a2b45 in alloc_root /data/src/10.8/mysys/my_alloc.c:332
 
    #3 0x557d2fe3eb33 in Sql_alloc::operator new(unsigned long) /data/src/10.8/sql/sql_alloc.h:28
 
    #4 0x557d2fe3eb33 in mysql_unpack_partition(THD*, char*, unsigned int, TABLE*, bool, handlerton*, bool*) /data/src/10.8/sql/sql_partition.cc:4428
 
    #5 0x557d30147545 in open_table_from_share(THD*, TABLE_SHARE*, st_mysql_const_lex_string const*, unsigned int, unsigned int, unsigned int, TABLE*, bool, List<String>*) /data/src/10.8/sql/table.cc:4312
 
    #6 0x557d2fc8d0c5 in open_table(THD*, TABLE_LIST*, Open_table_context*) /data/src/10.8/sql/sql_base.cc:2016
 
    #7 0x557d2fc963c1 in open_and_process_table /data/src/10.8/sql/sql_base.cc:3826
 
    #8 0x557d2fc963c1 in open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) /data/src/10.8/sql/sql_base.cc:4309
 
    #9 0x557d2fc9802e in open_and_lock_tables(THD*, DDL_options_st const&, TABLE_LIST*, bool, unsigned int, Prelocking_strategy*) /data/src/10.8/sql/sql_base.cc:5282
 
    #10 0x557d2fd4fd7a in open_and_lock_tables(THD*, TABLE_LIST*, bool, unsigned int) /data/src/10.8/sql/sql_base.h:509
 
    #11 0x557d2fd4fd7a in mysql_insert(THD*, TABLE_LIST*, List<Item>&, List<List<Item> >&, List<Item>&, List<Item>&, enum_duplicates, bool, select_result*) /data/src/10.8/sql/sql_insert.cc:758
 
    #12 0x557d2fe093dd in mysql_execute_command(THD*, bool) /data/src/10.8/sql/sql_parse.cc:4562
 
    #13 0x557d2fe14c0a in mysql_parse(THD*, char*, unsigned int, Parser_state*) /data/src/10.8/sql/sql_parse.cc:8027
 
    #14 0x557d2fe1a274 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /data/src/10.8/sql/sql_parse.cc:1894
 
    #15 0x557d2fe1fc75 in do_command(THD*, bool) /data/src/10.8/sql/sql_parse.cc:1407
 
    #16 0x557d301da83d in do_handle_one_connection(CONNECT*, bool) /data/src/10.8/sql/sql_connect.cc:1418
 
    #17 0x557d301dad7c in handle_one_connection /data/src/10.8/sql/sql_connect.cc:1312
 
    #18 0x557d30cb3a6b in pfs_spawn_thread /data/src/10.8/storage/perfschema/pfs.cc:2201
 
    #19 0x7f3d344faea6 in start_thread nptl/pthread_create.c:477
 
 
 
Thread T11 created by T0 here:
 
    #0 0x7f3d349ac2a2 in __interceptor_pthread_create ../../../../src/libsanitizer/asan/asan_interceptors.cpp:214
 
    #1 0x557d30cb3ce9 in my_thread_create /data/src/10.8/storage/perfschema/my_thread.h:52
 
    #2 0x557d30cb3ce9 in pfs_spawn_thread_v1 /data/src/10.8/storage/perfschema/pfs.cc:2252
 
    #3 0x557d2fae56ad in inline_mysql_thread_create /data/src/10.8/include/mysql/psi/mysql_thread.h:1139
 
    #4 0x557d2fae56ad in create_thread_to_handle_connection(CONNECT*) /data/src/10.8/sql/mysqld.cc:6014
 
    #5 0x557d2faf1447 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /data/src/10.8/sql/mysqld.cc:6135
 
    #6 0x557d2faf1fbf in handle_connections_sockets() /data/src/10.8/sql/mysqld.cc:6259
 
    #7 0x557d2faf38d0 in mysqld_main(int, char**) /data/src/10.8/sql/mysqld.cc:5909
 
    #8 0x7f3d34022d09 in __libc_start_main ../csu/libc-start.c:308
 
 
 
SUMMARY: AddressSanitizer: heap-use-after-free /data/src/10.8/storage/innobase/handler/ha_innodb.cc:11249 in create_table_info_t::check_table_options()
 
Shadow bytes around the buggy address:
 
  0x0c3a8000ee60: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3a8000ee70: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3a8000ee80: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3a8000ee90: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3a8000eea0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
=>0x0c3a8000eeb0: fd fd fd fd fd fd fd[fd]fd fd fd fd fd fd fd fd
 
  0x0c3a8000eec0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3a8000eed0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3a8000eee0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3a8000eef0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3a8000ef00: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
Shadow byte legend (one shadow byte represents 8 application bytes):
 
  Addressable:           00
 
  Partially addressable: 01 02 03 04 05 06 07 
  Heap left redzone:       fa
 
  Freed heap region:       fd
 
  Stack left redzone:      f1
 
  Stack mid redzone:       f2
 
  Stack right redzone:     f3
 
  Stack after return:      f5
 
  Stack use after scope:   f8
 
  Global redzone:          f9
 
  Global init order:       f6
 
  Poisoned by user:        f7
 
  Container overflow:      fc
 
  Array cookie:            ac
 
  Intra object redzone:    bb
 
  ASan internal:           fe
 
  Left alloca redzone:     ca
 
  Right alloca redzone:    cb
 
  Shadow gap:              cc
 
==1726155==ABORTING
 
220619  1:48:36 [ERROR] mysqld got signal 6 ;
 
This could be because you hit a bug. It is also possible that this binary
 
or one of the libraries it was linked against is corrupt, improperly built,
 
or misconfigured. This error can also be caused by malfunctioning hardware.
 
 
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
 
 
We will try our best to scrape up some info that will hopefully help
 
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.
 
 
 
Server version: 10.8.4-MariaDB-log
 
key_buffer_size=1048576
 
read_buffer_size=131072
 
max_used_connections=1
 
max_threads=153
 
thread_count=1
 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63773 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x62b00017a218
 
Attempting backtrace. You can use the following information to find out
 
where mysqld died. If you see no messages after this, something went
 
terribly wrong...
 
stack_bottom = 0x7f3d25934990 thread_stack 0x5fc00
 
sanitizer_common/sanitizer_common_interceptors.inc:4101(__interceptor_backtrace.part.0)[0x7f3d3499adf1]
 
mysys/stacktrace.c:213(my_print_stacktrace)[0x557d315be436]
 
sql/signal_handler.cc:223(handle_fatal_signal)[0x557d3056af44]
 
sigaction.c:0(__restore_rt)[0x7f3d34506140]
 
linux/raise.c:51(__GI_raise)[0x7f3d34037ce1]
 
stdlib/abort.c:81(__GI_abort)[0x7f3d34021537]
 
sanitizer_common/sanitizer_posix_libcdep.cpp:149(__sanitizer::Abort())[0x7f3d34a1c11b]
 
sanitizer_common/sanitizer_termination.cpp:59(__sanitizer::Die())[0x7f3d34a26ce8]
 
asan/asan_report.cpp:186(__asan::ScopedInErrorReport::~ScopedInErrorReport())[0x7f3d34a0944c]
 
asan/asan_report.cpp:474(__asan::ReportGenericError(unsigned long, unsigned long, unsigned long, unsigned long, bool, unsigned long, unsigned int, bool))[0x7f3d34a08d47]
 
asan/asan_rtl.cpp:119(__asan_report_load4)[0x7f3d34a098a8]
 
handler/ha_innodb.cc:11314(create_table_info_t::check_table_options())[0x557d30ea37c3]
 
handler/ha_innodb.cc:12020(create_table_info_t::prepare_create_table(char const*, bool))[0x557d30ef07ae]
 
handler/ha_innodb.cc:13965(ha_innobase::truncate())[0x557d30edfab0]
 
sql/ha_partition.cc:4920(ha_partition::truncate_partition(Alter_info*, bool*))[0x557d30c91ab2]
 
sql/sql_partition_admin.cc:958(Sql_cmd_alter_table_truncate_partition::execute(THD*))[0x557d301e2061]
 
sql/sql_parse.cc:5988(mysql_execute_command(THD*, bool))[0x557d2fe07c08]
 
sql/sql_parse.cc:8044(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x557d2fe14c0b]
 
sql/sql_parse.cc:1896(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x557d2fe1a275]
 
sql/sql_parse.cc:1409(do_command(THD*, bool))[0x557d2fe1fc76]
 
sql/sql_connect.cc:1418(do_handle_one_connection(CONNECT*, bool))[0x557d301da83e]
 
sql/sql_connect.cc:1312(handle_one_connection)[0x557d301dad7d]
 
perfschema/pfs.cc:2204(pfs_spawn_thread)[0x557d30cb3a6c]
 
nptl/pthread_create.c:478(start_thread)[0x7f3d344faea7]
 
x86_64/clone.S:97(__GI___clone)[0x7f3d340f9def]
 
 
 
Trying to get some variables.
 
Some pointers may be invalid and cause the dump to abort.
 
Query (0x6290000b9238): ALTER TABLE t NOWAIT TRUNCATE PARTITION p0
 
 
 
Connection ID (thread ID): 4
 
Status: NOT_KILLED
 
 
 
Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from_having=on,not_null_range_scan=off
 
 
 
The manual page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/ contains
 
information that should help you find out what is causing the crash.
 
Writing a core file...
 
Working directory at /dev/shm/var_auto_oY1f/mysqld.1/data
 
Resource Limits:
 
Limit                     Soft Limit           Hard Limit           Units     
Max cpu time              unlimited            unlimited            seconds   
Max file size             unlimited            unlimited            bytes     
Max data size             unlimited            unlimited            bytes     
Max stack size            8388608              unlimited            bytes     
Max core file size        unlimited            unlimited            bytes     
Max resident set          unlimited            unlimited            bytes     
Max processes             385885               385885               processes 
Max open files            1024                 1024                 files     
Max locked memory         12659513344          12659513344          bytes     
Max address space         unlimited            unlimited            bytes     
Max file locks            unlimited            unlimited            locks     
Max pending signals       385885               385885               signals   
Max msgqueue size         819200               819200               bytes     
Max nice priority         0                    0                    
Max realtime priority     0                    0                    
Max realtime timeout      unlimited            unlimited            us        
Core pattern: core



 Comments   
Comment by Marko Mäkelä [ 2024-01-05 ]

I can easily reproduce this with ./mtr --rr. The conflicting MDL is being held by a thread that is saving InnoDB persistent statistics.

10.11 bdf65893ddb2ce0552a20e53e2358350521d2d35

 
#10 0x000065321d360eff in syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
 
#11 0x000055cc01d997fb in binary_semaphore::wait (this=0x6d4e4d885690) at /mariadb/11/storage/innobase/log/log0sync.cc:127
 
#12 0x000055cc01d99d56 in group_commit_lock::acquire (this=0x55cc03737040 <flush_lock>, num=68762, callback=0x0) at /mariadb/11/storage/innobase/log/log0sync.cc:273
 
#13 0x000055cc01d674be in log_write_up_to (lsn=68762, durable=true, callback=0x0) at /mariadb/11/storage/innobase/log/log0log.cc:960
 
#14 0x000055cc01f1472c in trx_flush_log_if_needed (lsn=68762, trx=0x55c66a768680) at /mariadb/11/storage/innobase/trx/trx0trx.cc:1264
 
#15 0x000055cc01f167f4 in trx_t::commit_in_memory (mtr=0x6d4e4d883e10, this=0x55c66a768680) at /mariadb/11/storage/innobase/trx/trx0trx.cc:1480
 
#16 trx_t::commit_low (this=0x55c66a768680, mtr=0x6d4e4d883e10) at /mariadb/11/storage/innobase/trx/trx0trx.cc:1584
 
#17 0x000055cc01f16989 in trx_t::commit_persist (this=0x55c66a768680) at /mariadb/11/storage/innobase/trx/trx0trx.cc:1598
 
#18 0x000055cc01f16a9d in trx_t::commit (this=0x55c66a768680) at /mariadb/11/storage/innobase/trx/trx0trx.cc:1607
 
#19 0x000055cc02010aeb in dict_stats_save (table_orig=0x33eb2803c350, only_for_index=0x0) at /mariadb/11/storage/innobase/dict/dict0stats.cc:3461
 
#20 0x000055cc020127be in dict_stats_update (table=0x33eb2803c350, stats_upd_option=DICT_STATS_RECALC_PERSISTENT) at /mariadb/11/storage/innobase/dict/dict0stats.cc:4100
 
#21 0x000055cc0201888b in dict_stats_process_entry_from_recalc_pool (thd=0x615354001168) at /mariadb/11/storage/innobase/dict/dict0stats_bg.cc:348

Note that in mtr, a questionable change was made in MDEV-4750 to set the non-default parameter innodb_stats_persistent=OFF. I reverted that change in 10.6. In earlier versions this change is masking MDEV-15020.

Also note that the purge of InnoDB transaction history may acquire metadata locks at any time. Even if we added STATS_PERSISTENT=0 to the CREATE TABLE statement, the history after the row-level-logged INSERT would be processed, as noted in MDEV-12288.

I am reassigning this to serg for determining the correct course of action. I do not know why NOWAIT was implemented in the first place and what its intended purpose is.

Comment by Sergei Golubchik [ 2024-01-05 ]

NOWAIT was implemented in MDEV-11379, it was part of AliSQL, and the intended purpose apparently was to set lock wait timeout to 0 for the duration of the statement.

If InnoDB background tasks take MDLs then the locking error while unexpected is clearly not "bogus" and the server behaves as intended.

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