InnoDB: Failing assertion: state == TRX_STATE_NOT_STARTED || (relaxed && thd_get_error_number(trx->mysql_thd))

origin/10.6 4030a9fb2eb699361c58d71878e97b282647319a 2022-02-18T15:13:56+02:00

2022-02-21 14:52:54 0x722c77164700  InnoDB: Assertion failure in file /data/Server/10.6H/storage/innobase/include/trx0trx.inl line 65

InnoDB: Failing assertion: state == TRX_STATE_NOT_STARTED || (relaxed && thd_get_error_number(trx->mysql_thd))

...

than comes the usual stuff like

# 2022-02-21T14:58:29 [2457874] | [rr 2458829 79175]/data/Server_bin/10.6H_asan/bin/mysqld(+0x27b9c55)[0x55a58b437c55]

# 2022-02-21T14:58:29 [2457874] | [rr 2458829 79204]/data/Server_bin/10.6H_asan/bin/mysqld(_ZN7handler15ha_rename_tableEPKcS1_+0x183)[0x55a58ab30487]

# 2022-02-21T14:58:29 [2457874] | [rr 2458829 79311]/data/Server_bin/10.6H_asan/bin/mysqld(_Z18mysql_rename_tableP10handlertonPK25st_mysql_const_lex_stringS3_S3_S3_P34st_mysql_const_unsigned_lex_stringj+0x6d0)[0x55a58a59b85f]

# 2022-02-21T14:58:29 [2457874] | [rr 2458829 79653]/data/Server_bin/10.6H_asan/bin/mysqld(_Z17mysql_alter_tableP3THDPK25st_mysql_const_lex_stringS3_P14HA_CREATE_INFOP10TABLE_LISTP10Alter_infojP8st_orderbb+0x7e74)[0x55a58a5c128e]

# 2022-02-21T14:58:29 [2457874] | [rr 2458829 79718]/data/Server_bin/10.6H_asan/bin/mysqld(_ZN19Sql_cmd_alter_table7executeEP3THD+0x15b8)[0x55a58a74cb8c]

# 2022-02-21T14:58:29 [2457874] | [rr 2458829 79759]/data/Server_bin/10.6H_asan/bin/mysqld(_Z21mysql_execute_commandP3THDb+0x122e6)[0x55a58a350536]

# 2022-02-21T14:58:29 [2457874] | [rr 2458829 79811]/data/Server_bin/10.6H_asan/bin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x448)[0x55a58a35c91e]

# 2022-02-21T14:58:29 [2457874] | [rr 2458829 79924]/data/Server_bin/10.6H_asan/bin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcjb+0x20aa)[0x55a58a334cc3]

# 2022-02-21T14:58:29 [2457874] | [rr 2458829 80340]/data/Server_bin/10.6H_asan/bin/mysqld(_Z10do_commandP3THDb+0x1081)[0x55a58a33209b]

# 2022-02-21T14:58:29 [2457874] | [rr 2458829 80706]/data/Server_bin/10.6H_asan/bin/mysqld(_Z24do_handle_one_connectionP7CONNECTb+0x592)[0x55a58a732fc2]

# 2022-02-21T14:58:29 [2457874] | [rr 2458829 81294]/data/Server_bin/10.6H_asan/bin/mysqld(handle_one_connection+0x4f)[0x55a58a73284e]

# 2022-02-21T14:58:29 [2457874] | [rr 2501253 85630]

# 2022-02-21T14:58:29 [2457874] | =================================================================

# 2022-02-21T14:58:29 [2457874] | [rr 2501253 85634][rr 2501253 85637]==2501253==ERROR: LeakSanitizer: detected memory leaks

...

and than some surprise

# 2022-02-21T14:58:29 [2457874] | [rr 2458829 87650]2022-02-21 14:57:55 0 [ERROR] [FATAL] InnoDB: innodb_fatal_semaphore_wait_threshold was exceeded for dict_sys.latch. Please refer to https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/

(rr) bt

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

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

#2  0x000055a58b90b6ab in ut_dbg_assertion_failed (expr=0x55a58c8f4260 "state == TRX_STATE_NOT_STARTED || (relaxed && thd_get_error_number(trx->mysql_thd))", 

    file=0x55a58c8f40e0 "/data/Server/10.6H/storage/innobase/include/trx0trx.inl", line=65) at /data/Server/10.6H/storage/innobase/ut/ut0dbg.cc:60

#3  0x000055a58b57f33c in trx_state_eq (trx=0x16fa1299c028, state=TRX_STATE_ACTIVE, relaxed=false) at /data/Server/10.6H/storage/innobase/include/trx0trx.inl:65

#4  0x000055a58b5b26b0 in rw_trx_hash_t::validate_element (trx=0x16fa1299c028) at /data/Server/10.6H/storage/innobase/include/trx0sys.h:510

#5  0x000055a58b8f01ee in rw_trx_hash_t::insert (this=0x55a58d9bac80 <trx_sys+33152>, trx=0x16fa1299c028) at /data/Server/10.6H/storage/innobase/include/trx0sys.h:671

#6  0x000055a58b8f03e9 in trx_sys_t::register_rw (this=0x55a58d9b2b00 <trx_sys>, trx=0x16fa1299c028) at /data/Server/10.6H/storage/innobase/include/trx0sys.h:1102

#7  0x000055a58b8eea86 in trx_set_rw_mode (trx=0x16fa1299c028) at /data/Server/10.6H/storage/innobase/trx/trx0trx.cc:2154

#8  0x000055a58b59ac5a in lock_table (table=0x618000000d08, mode=LOCK_X, thr=0x61a000502f08) at /data/Server/10.6H/storage/innobase/lock/lock0lock.cc:3561

#9  0x000055a58b59bf67 in lock_table_for_trx (table=0x618000000d08, trx=0x16fa1299c028, mode=LOCK_X) at /data/Server/10.6H/storage/innobase/lock/lock0lock.cc:3722

#10 0x000055a58b437c55 in ha_innobase::rename_table (this=0x62b000113d70, from=0x722c7715dd00 "./test/#sql-alter-2584cd-11", to=0x722c7715df40 "./test/t1")

    at /data/Server/10.6H/storage/innobase/handler/ha_innodb.cc:14127

#11 0x000055a58ab30487 in handler::ha_rename_table (this=0x62b000113d70, from=0x722c7715dd00 "./test/#sql-alter-2584cd-11", to=0x722c7715df40 "./test/t1") at /data/Server/10.6H/sql/handler.cc:5304

#12 0x000055a58a59b85f in mysql_rename_table (base=0x615000002d98, old_db=0x722c771601f0, old_name=0x722c77160220, new_db=0x722c771601f0, new_name=0x722c77160210, id=0x722c77160240, flags=1)

    at /data/Server/10.6H/sql/sql_table.cc:4994

#13 0x000055a58a5c128e in mysql_alter_table (thd=0x62b00010a218, new_db=0x62b00010ec18, new_name=0x62b00010f030, create_info=0x722c77161650, table_list=0x62b0001113f0, alter_info=0x722c77161520, order_num=0, order=0x0, 

    ignore=false, if_exists=false) at /data/Server/10.6H/sql/sql_table.cc:10622

#14 0x000055a58a74cb8c in Sql_cmd_alter_table::execute (this=0x62b000111c40, thd=0x62b00010a218) at /data/Server/10.6H/sql/sql_alter.cc:542

#15 0x000055a58a350536 in mysql_execute_command (thd=0x62b00010a218, is_called_from_prepared_stmt=false) at /data/Server/10.6H/sql/sql_parse.cc:5996

#16 0x000055a58a35c91e in mysql_parse (thd=0x62b00010a218, rawbuf=0x62b000111238 "ALTER TABLE t1 MODIFY COLUMN col_text TEXT, LOCK = EXCLUSIVE, ALGORITHM = COPY /* E_R Thread1 QNO 31 CON_ID 17 */", length=113, 

    parser_state=0x722c77162b20) at /data/Server/10.6H/sql/sql_parse.cc:8029

#17 0x000055a58a334cc3 in dispatch_command (command=COM_QUERY, thd=0x62b00010a218, 

    packet=0x629000bfe219 "ALTER TABLE t1 MODIFY COLUMN col_text TEXT, LOCK = EXCLUSIVE, ALGORITHM = COPY /* E_R Thread1 QNO 31 CON_ID 17 */ ", packet_length=114, blocking=true)

    at /data/Server/10.6H/sql/sql_parse.cc:1896

#18 0x000055a58a33209b in do_command (thd=0x62b00010a218, blocking=true) at /data/Server/10.6H/sql/sql_parse.cc:1404

#19 0x000055a58a732fc2 in do_handle_one_connection (connect=0x608000003238, put_in_cache=true) at /data/Server/10.6H/sql/sql_connect.cc:1418

#20 0x000055a58a73284e in handle_one_connection (arg=0x608000003238) at /data/Server/10.6H/sql/sql_connect.cc:1312

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

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

(rr) quit

RQG

===

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

#

# GIT_SHOW: HEAD -> experimental, origin/experimental 21c04af5b9431827c8d4d6b24477b6a2937c6805 2022-02-21T12:45:32+01:00

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

#

# $RQG_HOME/rqg.pl \

# --duration=300 \

# --queries=10000000 \

# --no_mask \

# --seed=random \

# --engine=InnoDB \

# --rpl_mode=none \

# --max_gd_duration=1200 \

# --gendata_sql=conf/mariadb/table_stress.sql \

# --gendata=conf/mariadb/table_stress.zz \

# --mysqld=--loose-idle_write_transaction_timeout=0 \

# --mysqld=--plugin-load-add=file_key_management.so \

# --mysqld=--log-bin \

# --mysqld=--lock-wait-timeout=86400 \

# --mysqld=--loose-idle_readonly_transaction_timeout=0 \

# --mysqld=--log_bin_trust_function_creators=1 \

# --mysqld=--slave_net_timeout=60 \

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

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

# --mysqld=--loose-table_lock_wait_timeout=50 \

# --mysqld=--loose-plugin-load-add=provider_lz4.so \

# --mysqld=--net_read_timeout=30 \

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

# --mysqld=--loose-idle_transaction_timeout=0 \

# --mysqld=--interactive_timeout=28800 \

# --mysqld=--innodb_rollback_on_timeout=ON \    # <==================

# --mysqld=--log-output=none \

# --mysqld=--connect_timeout=60 \

# --mysqld=--file-key-management-filename=$RQG_HOME/conf/mariadb/encryption_keys.txt \

# --mysqld=--loose-debug_assert_on_not_freed_memory=0 \

# --mysqld=--loose_innodb_lock_schedule_algorithm=fcfs \

# --mysqld=--net_write_timeout=60 \

# --mysqld=--wait_timeout=28800 \

# --mysqld=--innodb-lock-wait-timeout=50 \

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

# --reporters=Backtrace,Deadlock1,ErrorLog \

# --validators=None \

# --grammar=TBR-1371-min.yy \

# --threads=2 \

# <local settings>

pluto:/data/results/1645455155/TBR-1371/dev/shm/rqg/1645455155/23/1/rr