Assertion `trx->lock.wait_lock == lock' failed in lock_sys_t::cancel

origin/bb-10.6-MDEV-20605-cur-pos-fix ac48095d5ba1c408cdc77d095985b2f20e46c82f 2022-01-21T21:00:54+03:00

Per Vladislav his modifications for MDEV-20605 cannot be the reason for the bad effect.

mysqld: /data/Server/bb-10.6-MDEV-20605-cur-pos-fix/storage/innobase/lock/lock0lock.cc:5744: static dberr_t lock_sys_t::cancel(trx_t*, ib_lock_t*) [with bool check_victim = false]: Assertion `trx->lock.wait_lock == lock' failed.

# 2022-01-31T20:06:20 [219582] | Query (0x62b000237238): UPDATE t1 SET col1 = 2702 LIMIT 2 

# 2022-01-31T20:06:20 [219582] | Status: NOT_KILLED

(rr) bt

#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50

#1  0x000013540ba13859 in __GI_abort () at abort.c:79

#2  0x000013540ba13729 in __assert_fail_base (fmt=0x13540bba9588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55a9db267a60 "trx->lock.wait_lock == lock", 

    file=0x55a9db25d680 "/data/Server/bb-10.6-MDEV-20605-cur-pos-fix/storage/innobase/lock/lock0lock.cc", line=5744, function=<optimized out>) at assert.c:92

#3  0x000013540ba24f36 in __GI___assert_fail (assertion=0x55a9db267a60 "trx->lock.wait_lock == lock", file=0x55a9db25d680 "/data/Server/bb-10.6-MDEV-20605-cur-pos-fix/storage/innobase/lock/lock0lock.cc", line=5744, 

    function=0x55a9db2679e0 "static dberr_t lock_sys_t::cancel(trx_t*, ib_lock_t*) [with bool check_victim = false]") at assert.c:101

#4  0x000055a9d9f2543a in lock_sys_t::cancel<false> (trx=0x7ffa5799fe88, lock=0x7ffa579a01c8) at /data/Server/bb-10.6-MDEV-20605-cur-pos-fix/storage/innobase/lock/lock0lock.cc:5744

#5  0x000055a9d9efd1e2 in lock_wait (thr=0x621000899db8) at /data/Server/bb-10.6-MDEV-20605-cur-pos-fix/storage/innobase/lock/lock0lock.cc:1918

#6  0x000055a9da10c759 in row_mysql_handle_errors (new_err=0x7ffa4d83c4c0, trx=0x7ffa5799fe88, thr=0x621000899db8, savept=0x0) at /data/Server/bb-10.6-MDEV-20605-cur-pos-fix/storage/innobase/row/row0mysql.cc:686

#7  0x000055a9da192e2c in row_search_mvcc (buf=0x61a00028c2b8 "\377", mode=PAGE_CUR_G, prebuilt=0x621000899588, match_mode=0, direction=0) at /data/Server/bb-10.6-MDEV-20605-cur-pos-fix/storage/innobase/row/row0sel.cc:5826

#8  0x000055a9d9d8b7d9 in ha_innobase::index_read (this=0x61d0000f1eb8, buf=0x61a00028c2b8 "\377", key_ptr=0x0, key_len=0, find_flag=HA_READ_AFTER_KEY) at /data/Server/bb-10.6-MDEV-20605-cur-pos-fix/storage/innobase/handler/ha_innodb.cc:9015

#9  0x000055a9d9d8e156 in ha_innobase::index_first (this=0x61d0000f1eb8, buf=0x61a00028c2b8 "\377") at /data/Server/bb-10.6-MDEV-20605-cur-pos-fix/storage/innobase/handler/ha_innodb.cc:9376

#10 0x000055a9d9d8e394 in ha_innobase::rnd_next (this=0x61d0000f1eb8, buf=0x61a00028c2b8 "\377") at /data/Server/bb-10.6-MDEV-20605-cur-pos-fix/storage/innobase/handler/ha_innodb.cc:9469

#11 0x000055a9d94936d0 in handler::ha_rnd_next (this=0x61d0000f1eb8, buf=0x61a00028c2b8 "\377") at /data/Server/bb-10.6-MDEV-20605-cur-pos-fix/sql/handler.cc:3397

#12 0x000055a9d989cfc5 in rr_sequential (info=0x7ffa4d83dac0) at /data/Server/bb-10.6-MDEV-20605-cur-pos-fix/sql/records.cc:519

#13 0x000055a9d8b22cf6 in READ_RECORD::read_record (this=0x7ffa4d83dac0) at /data/Server/bb-10.6-MDEV-20605-cur-pos-fix/sql/records.h:81

#14 0x000055a9d8f98334 in mysql_update (thd=0x62b000230218, table_list=0x62b000237398, fields=..., values=..., conds=0x0, order_num=0, order=0x0, limit=2, ignore=false, found_return=0x7ffa4d83e2f0, updated_return=0x7ffa4d83e310)

    at /data/Server/bb-10.6-MDEV-20605-cur-pos-fix/sql/sql_update.cc:1005

#15 0x000055a9d8cb91e4 in mysql_execute_command (thd=0x62b000230218, is_called_from_prepared_stmt=false) at /data/Server/bb-10.6-MDEV-20605-cur-pos-fix/sql/sql_parse.cc:4407

#16 0x000055a9d8cd1628 in mysql_parse (thd=0x62b000230218, rawbuf=0x62b000237238 "UPDATE t1 SET col1 = 2702 LIMIT 2  /* E_R Thread24 QNO 409 CON_ID 38 */", length=71, parser_state=0x7ffa4d83eb20) at /data/Server/bb-10.6-MDEV-20605-cur-pos-fix/sql/sql_parse.cc:8029

#17 0x000055a9d8ca99cd in dispatch_command (command=COM_QUERY, thd=0x62b000230218, packet=0x629000e3d219 " UPDATE t1 SET col1 = 2702 LIMIT 2  /* E_R Thread24 QNO 409 CON_ID 38 */ ", packet_length=73, blocking=true)

    at /data/Server/bb-10.6-MDEV-20605-cur-pos-fix/sql/sql_parse.cc:1896

#18 0x000055a9d8ca6da5 in do_command (thd=0x62b000230218, blocking=true) at /data/Server/bb-10.6-MDEV-20605-cur-pos-fix/sql/sql_parse.cc:1404

#19 0x000055a9d90a72d4 in do_handle_one_connection (connect=0x608000003bb8, put_in_cache=true) at /data/Server/bb-10.6-MDEV-20605-cur-pos-fix/sql/sql_connect.cc:1418

#20 0x000055a9d90a6b60 in handle_one_connection (arg=0x608000003bb8) at /data/Server/bb-10.6-MDEV-20605-cur-pos-fix/sql/sql_connect.cc:1312

#21 0x0000470645dd1609 in start_thread (arg=<optimized out>) at pthread_create.c:477

#22 0x000013540bb10293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

(rr)

pluto:/data/results/1643649542/TBR-1342/dev/shm/rqg/1643649542/10/1/rr

RQG

===

# git clone https://github.com/mleich1/rqg --branch experimental RQG

#

# GIT_SHOW: HEAD -> experimental, origin/experimental 067340e8ec78c25880ccd2e67dd62ad134edc531 2022-01-31T17:10:39+01:00

# rqg.pl  : Version 4.0.4 (2021-12)

#

# $RQG_HOME/rqg.pl \

# --grammar=conf/mariadb/table_stress_innodb.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=Deadlock1 \

# --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 \

# --mysqld=--plugin-load-add=provider_snappy \

# --mysqld=--plugin-load-add=provider_lz4 \

# --duration=300 \

# --mysqld=--loose-innodb_fatal_semaphore_wait_threshold=300 \

# --mysqld=--loose-innodb_read_only_compressed=OFF \

# --mysqld=--innodb_stats_persistent=on \

# --mysqld=--innodb_adaptive_hash_index=off \

# --mysqld=--log-bin \

# --mysqld=--sync-binlog=1 \

# --mysqld=--loose-innodb_evict_tables_on_commit_debug=off \

# --mysqld=--loose-max-statement-time=30 \

# --threads=33 \

# --mysqld=--innodb-use-native-aio=0 \

# --mysqld=--loose-gdb \

# --mysqld=--loose-debug-gdb \

# --rr=Extended \

# --rr_options=--chaos --wait \

# --mysqld=--innodb_rollback_on_timeout=OFF \

# --vardir_type=fast \

# --mysqld=--innodb_page_size=4K \

# --mysqld=--innodb-buffer-pool-size=5M \

# --no_mask \

# <local settings>