Details
Major Description
origin/bb-10.6-MDEV-32050-rerebase bf0f43d51340d2b7e0cb1681c63605536556f385 2023-10-19T15:48:57+03:00
It is in the moment unknown if the problems are
- caused by the
MDEV-32050modifications - in 10.6 and other main versions too.
Scenario:
1. Start the DB server with lock-wait-timeout=15 and generate some initial data
2. 33 sessions run concurrent some DDL/DML mix
3. During 2. is ongoing PROCESSLISTS with content like
# 2023-10-19T19:11:06 [407978] DBServer_e::MySQL::MySQLd::server_is_operable: server[1] ID -- COMMAND -- TIME -- STATE -- INFO -- RQG_guess
|
# 2023-10-19T19:11:06 [407978] DBServer_e::MySQL::MySQLd::server_is_operable: server[1] -->20 -- Query -- 459 -- Waiting for table metadata lock -- CREATE OR REPLACE ALGORITHM = MERGE VIEW view_2 AS SELECT /* QUERY_ID: 6818048 */ /* RESULTSET_SAME_DATA_IN_EVERY_ROW */ 9 AS `col_int_key`
|
# 2023-10-19T19:11:06 [407978] FROM view_1
|
# 2023-10-19T19:11:06 [407978] /* E_R Thread10 QNO 759 CON_ID 20 */ <--suspicious
|
# 2023-10-19T19:11:06 [407978] DBServer_e::MySQL::MySQLd::server_is_operable: server[1] -->21 -- Query -- 368 -- Waiting for table metadata lock -- ALTER ALGORITHM = TEMPTABLE VIEW view_1 AS SELECT /* QUERY_ID: 5899008 */ /* RESULTSET_SAME_DATA_IN_EVERY_ROW */ 2 AS `col_int_key`
|
# 2023-10-19T19:11:06 [407978] FROM view_2
|
# 2023-10-19T19:11:06 [407978] WHERE func_2 ( `col_int_key` ) < 7 /* E_R Thread6 QNO 840 CON_ID 21 */ <--suspicious
|
# 2023-10-19T19:11:06 [407978] DBServer_e::MySQL::MySQLd::server_is_operable: server[1] -->23 -- Query -- 461 -- Waiting for table metadata lock -- CREATE OR REPLACE ALGORITHM = UNDEFINED VIEW view_2 AS SELECT /* QUERY_ID: 10715136 */ /* RESULTSET_SAME_DATA_IN_EVERY_ROW */ func_1 ( `col_int_key` ) AS `col_int_key`
|
# 2023-10-19T19:11:06 [407978] FROM view_1
|
# 2023-10-19T19:11:06 [407978] /* E_R Thread5 QNO 714 CON_ID 23 */ <--suspicious
|
# 2023-10-19T19:11:06 [407978] DBServer_e::MySQL::MySQLd::server_is_operable: server[1] -->26 -- Query -- 399 -- Waiting for table metadata lock -- CREATE OR REPLACE ALGORITHM = UNDEFINED VIEW view_2 AS SELECT /* QUERY_ID: 2509824 */ /* RESULTSET_SAME_DATA_IN_EVERY_ROW */ 7 AS `col_int_key`
|
# 2023-10-19T19:11:06 [407978] FROM view_1
|
# 2023-10-19T19:11:06 [407978] /* E_R Thread24 QNO 684 CON_ID 26 */ <--suspicious
|
# 2023-10-19T19:11:06 [407978] DBServer_e::MySQL::MySQLd::server_is_operable: server[1] -->27 -- Query -- 459 -- Waiting for table metadata lock -- CREATE OR REPLACE ALGORITHM = UNDEFINED VIEW view_2 AS SELECT /* QUERY_ID: 15198720 */ /* RESULTSET_SAME_DATA_IN_EVERY_ROW */ 6 AS `col_int_key`
|
# 2023-10-19T19:11:06 [407978] FROM view_1
|
# 2023-10-19T19:11:06 [407978] /* E_R Thread22 QNO 686 CON_ID 27 */ <--suspicious
|
# 2023-10-19T19:11:06 [407978] DBServer_e::MySQL::MySQLd::server_is_operable: server[1] -->28 -- Query -- 413 -- Waiting for table metadata lock -- CREATE OR REPLACE ALGORITHM = MERGE VIEW view_2 AS SELECT /* QUERY_ID: 2850048 */ /* RESULTSET_SAME_DATA_IN_EVERY_ROW */ func_1 ( 3 ) AS `col_int_key`
|
# 2023-10-19T19:11:06 [407978] FROM view_1
|
# 2023-10-19T19:11:06 [407978] WHERE 5 < 6 /* E_R Thread20 QNO 625 CON_ID 28 */ <--suspicious
|
# 2023-10-19T19:11:06 [407978] DBServer_e::MySQL::MySQLd::server_is_operable: server[1] -->30 -- Query -- 460 -- Waiting for table metadata lock -- CREATE OR REPLACE ALGORITHM = UNDEFINED VIEW view_1 AS SELECT /* QUERY_ID: 8853504 */ /* RESULTSET_SAME_DATA_IN_EVERY_ROW */ func_2 ( `col_int_key` ) AS `col_int_key`
|
# 2023-10-19T19:11:06 [407978] FROM view_2
|
# 2023-10-19T19:11:06 [407978] /* E_R Thread27 QNO 672 CON_ID 30 */ <--suspicious
|
# 2023-10-19T19:11:06 [407978] DBServer_e::MySQL::MySQLd::server_is_operable: server[1] -->31 -- Query -- 459 -- Waiting for table metadata lock -- CREATE OR REPLACE ALGORITHM = UNDEFINED VIEW view_1 AS SELECT /* QUERY_ID: 4352256 */ /* RESULTSET_SAME_DATA_IN_EVERY_ROW */ func_2 ( 3 ) AS `col_int_key`
|
# 2023-10-19T19:11:06 [407978] FROM view_2
|
# 2023-10-19T19:11:06 [407978] /* E_R Thread12 QNO 703 CON_ID 31 */ <--suspicious
|
# 2023-10-19T19:11:06 [407978] DBServer_e::MySQL::MySQLd::server_is_operable: server[1] -->34 -- Query -- 429 -- Waiting for table metadata lock -- CREATE OR REPLACE ALGORITHM = UNDEFINED VIEW view_2 AS SELECT /* QUERY_ID: 13853184 */ /* RESULTSET_SAME_DATA_IN_EVERY_ROW */ func_2 ( `col_int_key` ) AS `col_int_key`
|
# 2023-10-19T19:11:06 [407978] FROM view_1
|
# 2023-10-19T19:11:06 [407978] WHERE 4 <> func_2 ( 2 ) /* E_R Thread29 QNO 750 CON_ID 34 */ <--suspicious
|
# 2023-10-19T19:11:06 [407978] DBServer_e::MySQL::MySQLd::server_is_operable: server[1] -->38 -- Query -- 430 -- Waiting for table metadata lock -- CREATE OR REPLACE ALGORITHM = TEMPTABLE VIEW view_1 AS SELECT /* QUERY_ID: 7958784 */ /* RESULTSET_SAME_DATA_IN_EVERY_ROW */ func_1 ( 2 ) AS `col_int_key`
|
# 2023-10-19T19:11:06 [407978] FROM view_2
|
# 2023-10-19T19:11:06 [407978] /* E_R Thread32 QNO 658 CON_ID 38 */ <--suspicious
|
# 2023-10-19T19:11:06 [407978] DBServer_e::MySQL::MySQLd::server_is_operable: server[1] Content of processlist ---------- end
|
were observed. IMHO the DB server should have killed all these queries because of exceeding lock-wait-timeout=15 and release their locks.
I had also the hope that some automatic deadlock detection would kicked in and reduced the number of threads waiting for MDL lock.
4. RQG reacts with running 'SHOW ENGINE INNODB STATUS' and sending SIGABRT
to the server process.
pluto:/data/results/1697741072/LWT_VIOLATION$ _RR_TRACE_DIR=./1/rr/ rr replay --mark-stdio
RQG
|
===
|
# git clone https://github.com/mleich1/rqg --branch <pick the right branch> RQG
|
#
|
# GIT_SHOW: HEAD -> master, origin/master, origin/HEAD 4f27e561407069c72ce0eaee4cfc27c1cdd5d26c 2023-10-17T20:57:24+02:00
|
# rqg.pl : Version 4.4.0 (2023-08)
|
#
|
# $RQG_HOME/rqg.pl \
|
# --grammar=conf/runtime/metadata_stability.yy \
|
# --gendata=conf/runtime/metadata_stability.zz \
|
# --filter=conf/mariadb/no_flush_no_lock.ff \
|
# --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 \
|
# --no_mask \
|
# --queries=10000000 \
|
# --seed=random \
|
# --reporters=None \
|
# --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=--lock-wait-timeout=15 \
|
# --mysqld=--innodb-lock-wait-timeout=10 \
|
# --mysqld=--sql_mode=traditional \
|
# --mysqld=--innodb_file_per_table=1 \
|
# --mysqld=--loose-innodb_read_only_compressed=OFF \
|
# --mysqld=--innodb_stats_persistent=on \
|
# --mysqld=--innodb_adaptive_hash_index=on \
|
# --mysqld=--innodb_random_read_ahead=OFF \
|
# --mysqld=--log-bin \
|
# --mysqld=--sync-binlog=1 \
|
# --mysqld=--loose-innodb_evict_tables_on_commit_debug=on \
|
# --threads=33 \
|
# --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=--loose_innodb_change_buffering=deletes \
|
# --mysqld=--innodb_rollback_on_timeout=OFF \
|
# --mysqld=--innodb_page_size=8K \
|
# --mysqld=--innodb-buffer-pool-size=8M \
|
# <local settings>
|