From 77ce06ab261c2f417240d52bbf2431e7a2c8f93c Mon Sep 17 00:00:00 2001 From: Varun Deep Saini Date: Mon, 22 Dec 2025 20:21:01 +0530 Subject: [PATCH 1/7] Include deadlock detail information in SHOW WARNINGS after deadlock detection error --- .../innodb/r/deadlock_session_info.result | 38 +++++++ .../suite/innodb/t/deadlock_session_info.test | 106 ++++++++++++++++++ storage/innobase/handler/ha_innodb.cc | 14 ++- storage/innobase/include/trx0trx.h | 15 +++ storage/innobase/lock/lock0lock.cc | 1 + storage/innobase/trx/trx0trx.cc | 51 +++++++++ 6 files changed, 223 insertions(+), 2 deletions(-) create mode 100644 mysql-test/suite/innodb/r/deadlock_session_info.result create mode 100644 mysql-test/suite/innodb/t/deadlock_session_info.test diff --git a/mysql-test/suite/innodb/r/deadlock_session_info.result b/mysql-test/suite/innodb/r/deadlock_session_info.result new file mode 100644 index 0000000000000..506ea5a53c623 --- /dev/null +++ b/mysql-test/suite/innodb/r/deadlock_session_info.result @@ -0,0 +1,38 @@ +CREATE TABLE t1 ( +id INT PRIMARY KEY, +x INT +) ENGINE=InnoDB; +INSERT INTO t1 VALUES (1, 10), (2, 20); +connect con1,localhost,root,,; +connect con2,localhost,root,,; +connection con1; +BEGIN; +UPDATE t1 SET x = 100 WHERE id = 1; +connection con2; +BEGIN; +UPDATE t1 SET x = 200 WHERE id = 2; +UPDATE t1 SET x = 201 WHERE id = 1; +connection con1; +Per-session deadlock info is available +Message contains TRANSACTION keyword +ROLLBACK; +connection con2; +ROLLBACK; +INSERT INTO t1 VALUES (3, 30), (4, 40); +connection con1; +BEGIN; +UPDATE t1 SET x = 300 WHERE id = 3; +connection con2; +BEGIN; +UPDATE t1 SET x = 400 WHERE id = 4; +UPDATE t1 SET x = 401 WHERE id = 3; +connection con1; +Second deadlock shows new transaction info +Second deadlock does not contain old info +ROLLBACK; +connection con2; +ROLLBACK; +disconnect con1; +disconnect con2; +connection default; +DROP TABLE t1; diff --git a/mysql-test/suite/innodb/t/deadlock_session_info.test b/mysql-test/suite/innodb/t/deadlock_session_info.test new file mode 100644 index 0000000000000..bb729db6da493 --- /dev/null +++ b/mysql-test/suite/innodb/t/deadlock_session_info.test @@ -0,0 +1,106 @@ +# +# Test per-session deadlock information via SHOW WARNINGS +# + +--source include/have_innodb.inc + +CREATE TABLE t1 ( + id INT PRIMARY KEY, + x INT +) ENGINE=InnoDB; + +INSERT INTO t1 VALUES (1, 10), (2, 20); + +--connect (con1,localhost,root,,) +--connect (con2,localhost,root,,) + +--connection con1 +BEGIN; +UPDATE t1 SET x = 100 WHERE id = 1; + +--connection con2 +BEGIN; +UPDATE t1 SET x = 200 WHERE id = 2; +--send UPDATE t1 SET x = 201 WHERE id = 1 + +--connection con1 +--disable_abort_on_error +--disable_query_log +--disable_result_log +UPDATE t1 SET x = 101 WHERE id = 2; +--enable_result_log +--enable_query_log +--enable_abort_on_error +--let $errno= $mysql_errno +if ($errno != 1213) { + --echo Expected ER_LOCK_DEADLOCK (1213), got $errno + --die +} + +--let $msg1= query_get_value(SHOW WARNINGS, Message, 1) +--let $msg2= query_get_value(SHOW WARNINGS, Message, 2) +--let $deadlock_info= `SELECT IF(LENGTH('$msg1') > LENGTH('$msg2'), '$msg1', '$msg2')` + +if (`SELECT LENGTH('$deadlock_info') > 100`) { + --echo Per-session deadlock info is available +} + +if (`SELECT '$deadlock_info' LIKE '%TRANSACTION%'`) { + --echo Message contains TRANSACTION keyword +} + +ROLLBACK; + +--connection con2 +--reap +ROLLBACK; + +# Second deadlock to verify info is cleared between transactions +INSERT INTO t1 VALUES (3, 30), (4, 40); + +--connection con1 +BEGIN; +UPDATE t1 SET x = 300 WHERE id = 3; + +--connection con2 +BEGIN; +UPDATE t1 SET x = 400 WHERE id = 4; +--send UPDATE t1 SET x = 401 WHERE id = 3 + +--connection con1 +--disable_abort_on_error +--disable_query_log +--disable_result_log +UPDATE t1 SET x = 301 WHERE id = 4; +--enable_result_log +--enable_query_log +--enable_abort_on_error +--let $errno= $mysql_errno +if ($errno != 1213) { + --echo Expected ER_LOCK_DEADLOCK (1213), got $errno + --die +} + +--let $msg1= query_get_value(SHOW WARNINGS, Message, 1) +--let $msg2= query_get_value(SHOW WARNINGS, Message, 2) +--let $deadlock_info= `SELECT IF(LENGTH('$msg1') > LENGTH('$msg2'), '$msg1', '$msg2')` + +if (`SELECT '$deadlock_info' LIKE '%id = 3%' OR '$deadlock_info' LIKE '%id = 4%'`) { + --echo Second deadlock shows new transaction info +} + +if (`SELECT '$deadlock_info' NOT LIKE '%id = 1%'`) { + --echo Second deadlock does not contain old info +} + +ROLLBACK; + +--connection con2 +--reap +ROLLBACK; + +--disconnect con1 +--disconnect con2 +--connection default + +DROP TABLE t1; diff --git a/storage/innobase/handler/ha_innodb.cc b/storage/innobase/handler/ha_innodb.cc index eacde4912b89e..64cb0007f3552 100644 --- a/storage/innobase/handler/ha_innodb.cc +++ b/storage/innobase/handler/ha_innodb.cc @@ -2104,8 +2104,18 @@ convert_error_code_to_mysql( /* Since we rolled back the whole transaction, the cached binlog must be emptied. */ innodb_transaction_abort(thd, true, error); - return error == DB_DEADLOCK - ? HA_ERR_LOCK_DEADLOCK : HA_ERR_RECORD_CHANGED; + if (error == DB_DEADLOCK) { + trx_t* trx = thd_to_trx(thd); + if (trx && trx->lock.deadlock_info + && trx->lock.deadlock_info_len > 0) { + push_warning_printf(thd, + Sql_condition::WARN_LEVEL_NOTE, + ER_LOCK_DEADLOCK, + "%s", trx->lock.deadlock_info); + } + return HA_ERR_LOCK_DEADLOCK; + } + return HA_ERR_RECORD_CHANGED; case DB_LOCK_WAIT_TIMEOUT: /* Starting from 5.0.13, we let MySQL just roll back the diff --git a/storage/innobase/include/trx0trx.h b/storage/innobase/include/trx0trx.h index 266d3be7a3dd4..6499d214a9b9f 100644 --- a/storage/innobase/include/trx0trx.h +++ b/storage/innobase/include/trx0trx.h @@ -60,6 +60,16 @@ trx_set_detailed_error_from_file( /*=============================*/ trx_t* trx, /*!< in: transaction struct */ FILE* file); /*!< in: file to read message from */ + +/** Set the deadlock information for a transaction from a file. +@param trx transaction that was chosen as deadlock victim +@param file file containing the deadlock information */ +void trx_set_deadlock_info_from_file(trx_t *trx, FILE *file); + +/** Clear the deadlock information for a transaction. +@param trx transaction */ +void trx_clear_deadlock_info(trx_t *trx); + /****************************************************************//** Retrieves the error_info field from a trx. @return the error info */ @@ -387,6 +397,11 @@ struct trx_lock_t /** number of lock_rec_set_nth_bit() calls since the start of transaction; protected by lock_sys.is_writer() or trx->mutex_is_owner(). */ ulint set_nth_bit_calls; + + /** Deadlock information for SHOW WARNINGS; protected by lock_sys.wait_mutex */ + char *deadlock_info; + size_t deadlock_info_len; + size_t deadlock_info_size; }; /** Logical first modification time of a table in a transaction */ diff --git a/storage/innobase/lock/lock0lock.cc b/storage/innobase/lock/lock0lock.cc index 91af7afe14530..3996f73b67dfd 100644 --- a/storage/innobase/lock/lock0lock.cc +++ b/storage/innobase/lock/lock0lock.cc @@ -7304,6 +7304,7 @@ and less modified rows. Bit 0 is used to prefer orig_trx in case of a tie. } snprintf(buf, sizeof buf, rollback_msg, victim_pos); print(buf); + trx_set_deadlock_info_from_file(victim, lock_latest_err_file); } DBUG_EXECUTE_IF("innodb_deadlock_victim_self", victim= trx;); diff --git a/storage/innobase/trx/trx0trx.cc b/storage/innobase/trx/trx0trx.cc index 987e719d4e9f7..71cca9993c9c9 100644 --- a/storage/innobase/trx/trx0trx.cc +++ b/storage/innobase/trx/trx0trx.cc @@ -97,6 +97,46 @@ trx_set_detailed_error_from_file( os_file_read_string(file, trx->detailed_error, MAX_DETAILED_ERROR_LEN); } +/** Set the deadlock information for a transaction from a file. +@param trx transaction that was chosen as deadlock victim +@param file file containing the deadlock information */ +void trx_set_deadlock_info_from_file(trx_t *trx, FILE *file) +{ + mysql_mutex_assert_owner(&lock_sys.wait_mutex); + + rewind(file); + fseek(file, 0, SEEK_END); + long file_size = ftell(file); + if (file_size <= 0) { + return; + } + + size_t needed_size = static_cast(file_size) + 1; + + if (needed_size > trx->lock.deadlock_info_size) { + ut_free(trx->lock.deadlock_info); + trx->lock.deadlock_info = static_cast( + ut_malloc_nokey(needed_size)); + trx->lock.deadlock_info_size = needed_size; + } + + rewind(file); + size_t read_len = fread(trx->lock.deadlock_info, 1, + static_cast(file_size), file); + trx->lock.deadlock_info[read_len] = '\0'; + trx->lock.deadlock_info_len = read_len; +} + +/** Clear the deadlock information for a transaction. +@param trx transaction */ +void trx_clear_deadlock_info(trx_t *trx) +{ + if (trx->lock.deadlock_info) { + trx->lock.deadlock_info[0] = '\0'; + trx->lock.deadlock_info_len = 0; + } +} + /********************************************************************//** Initialize transaction object. @param trx trx to initialize */ @@ -192,6 +232,10 @@ struct TrxFactory { trx->detailed_error = reinterpret_cast( ut_zalloc_nokey(MAX_DETAILED_ERROR_LEN)); + trx->lock.deadlock_info = nullptr; + trx->lock.deadlock_info_len = 0; + trx->lock.deadlock_info_size = 0; + trx->lock.lock_heap = mem_heap_create_typed( 1024, MEM_HEAP_FOR_LOCK_HEAP); pthread_cond_init(&trx->lock.cond, nullptr); @@ -238,6 +282,11 @@ struct TrxFactory { ut_free(trx->detailed_error); + ut_free(trx->lock.deadlock_info); + trx->lock.deadlock_info = nullptr; + trx->lock.deadlock_info_len = 0; + trx->lock.deadlock_info_size = 0; + trx->mutex_destroy(); trx->autoinc_locks.~small_vector(); @@ -396,6 +445,7 @@ void trx_t::free() trx_sys.deregister_trx(this); check_unique_secondary= true; check_foreigns= true; + trx_clear_deadlock_info(this); assert_freed(); trx_sys.rw_trx_hash.put_pins(this); mysql_thd= nullptr; @@ -910,6 +960,7 @@ trx_start_low( ut_ad(trx->rsegs.m_noredo.rseg == NULL); ut_ad(trx_state_eq(trx, TRX_STATE_NOT_STARTED)); ut_ad(UT_LIST_GET_LEN(trx->lock.trx_locks) == 0); + trx_clear_deadlock_info(trx); /* Check whether it is an AUTOCOMMIT SELECT */ if (const THD* thd = trx->mysql_thd) { From 19592c624902ba7e5df5c8919b2c4bf45e5ba388 Mon Sep 17 00:00:00 2001 From: Varun Deep Saini Date: Tue, 23 Dec 2025 01:09:17 +0530 Subject: [PATCH 2/7] Added the global env condition and simplified the tests Signed-off-by: Varun Deep Saini --- .../innodb/r/deadlock_session_info.result | 65 ++++++----- .../suite/innodb/t/deadlock_session_info.test | 104 ++++-------------- storage/innobase/handler/ha_innodb.cc | 11 +- storage/innobase/include/trx0trx.h | 14 --- storage/innobase/lock/lock0lock.cc | 31 +++++- storage/innobase/trx/trx0trx.cc | 51 --------- 6 files changed, 91 insertions(+), 185 deletions(-) diff --git a/mysql-test/suite/innodb/r/deadlock_session_info.result b/mysql-test/suite/innodb/r/deadlock_session_info.result index 506ea5a53c623..7cf94dba34d78 100644 --- a/mysql-test/suite/innodb/r/deadlock_session_info.result +++ b/mysql-test/suite/innodb/r/deadlock_session_info.result @@ -1,38 +1,47 @@ -CREATE TABLE t1 ( -id INT PRIMARY KEY, -x INT -) ENGINE=InnoDB; -INSERT INTO t1 VALUES (1, 10), (2, 20); -connect con1,localhost,root,,; -connect con2,localhost,root,,; +SET @saved_print_all_deadlocks = @@GLOBAL.innodb_print_all_deadlocks; +SET GLOBAL innodb_print_all_deadlocks = ON; +CREATE TABLE t (a INT PRIMARY KEY) ENGINE=InnoDB; +INSERT INTO t VALUES (1), (2); +connect con1,localhost,root,,; +connect con2,localhost,root,,; connection con1; BEGIN; -UPDATE t1 SET x = 100 WHERE id = 1; +SELECT * FROM t WHERE a = 1 FOR UPDATE; +a +1 connection con2; BEGIN; -UPDATE t1 SET x = 200 WHERE id = 2; -UPDATE t1 SET x = 201 WHERE id = 1; +SELECT * FROM t WHERE a = 2 FOR UPDATE; +a +2 +SET DEBUG_SYNC = 'lock_wait_start SIGNAL con2_waiting'; +SELECT * FROM t WHERE a = 1 FOR UPDATE; connection con1; -Per-session deadlock info is available -Message contains TRANSACTION keyword -ROLLBACK; -connection con2; -ROLLBACK; -INSERT INTO t1 VALUES (3, 30), (4, 40); -connection con1; -BEGIN; -UPDATE t1 SET x = 300 WHERE id = 3; -connection con2; -BEGIN; -UPDATE t1 SET x = 400 WHERE id = 4; -UPDATE t1 SET x = 401 WHERE id = 3; -connection con1; -Second deadlock shows new transaction info -Second deadlock does not contain old info +SET DEBUG_SYNC = 'now WAIT_FOR con2_waiting'; +SET debug_dbug = '+d,innodb_deadlock_victim_self'; +SELECT * FROM t WHERE a = 2 FOR UPDATE; +ERROR 40001: Deadlock found when trying to get lock; try restarting transaction +SHOW WARNINGS; +Level Code Message +Note 1213 TIMESTAMP 0xTHD +*** (1) TRANSACTION: +TRANSACTION TRX_ID, ACTIVE 0 sec starting index read +mysql tables in use 1, locked 1 +LOCK WAIT 3 lock struct(s), heap size 1144, 2 row lock(s) +MariaDB thread id TID, OS thread handle TID, query id QID localhost root Statistics +SELECT * FROM t WHERE a = 2 FOR UPDATE +*** WAITING FOR THIS LOCK TO BE GRANTED: +RECORD LOCKS space id 8 page no 3 n bits 320 index PRIMARY of table `test`.`t` trx id TRX_ID lock_mode X locks rec but not gap waiting +Record lock, +Error 1213 Deadlock found when trying to get lock; try restarting transaction ROLLBACK; connection con2; +a +1 ROLLBACK; +connection default; disconnect con1; disconnect con2; -connection default; -DROP TABLE t1; +SET DEBUG_SYNC = 'RESET'; +DROP TABLE t; +SET GLOBAL innodb_print_all_deadlocks = @saved_print_all_deadlocks; diff --git a/mysql-test/suite/innodb/t/deadlock_session_info.test b/mysql-test/suite/innodb/t/deadlock_session_info.test index bb729db6da493..a1f7a6b18bfa6 100644 --- a/mysql-test/suite/innodb/t/deadlock_session_info.test +++ b/mysql-test/suite/innodb/t/deadlock_session_info.test @@ -1,97 +1,38 @@ -# -# Test per-session deadlock information via SHOW WARNINGS -# - --source include/have_innodb.inc +--source include/have_debug.inc +--source include/have_debug_sync.inc -CREATE TABLE t1 ( - id INT PRIMARY KEY, - x INT -) ENGINE=InnoDB; - -INSERT INTO t1 VALUES (1, 10), (2, 20); - ---connect (con1,localhost,root,,) ---connect (con2,localhost,root,,) - ---connection con1 -BEGIN; -UPDATE t1 SET x = 100 WHERE id = 1; - ---connection con2 -BEGIN; -UPDATE t1 SET x = 200 WHERE id = 2; ---send UPDATE t1 SET x = 201 WHERE id = 1 - ---connection con1 ---disable_abort_on_error --disable_query_log ---disable_result_log -UPDATE t1 SET x = 101 WHERE id = 2; ---enable_result_log +call mtr.add_suppression("Transactions deadlock detected"); --enable_query_log ---enable_abort_on_error ---let $errno= $mysql_errno -if ($errno != 1213) { - --echo Expected ER_LOCK_DEADLOCK (1213), got $errno - --die -} - ---let $msg1= query_get_value(SHOW WARNINGS, Message, 1) ---let $msg2= query_get_value(SHOW WARNINGS, Message, 2) ---let $deadlock_info= `SELECT IF(LENGTH('$msg1') > LENGTH('$msg2'), '$msg1', '$msg2')` -if (`SELECT LENGTH('$deadlock_info') > 100`) { - --echo Per-session deadlock info is available -} +SET @saved_print_all_deadlocks = @@GLOBAL.innodb_print_all_deadlocks; +SET GLOBAL innodb_print_all_deadlocks = ON; -if (`SELECT '$deadlock_info' LIKE '%TRANSACTION%'`) { - --echo Message contains TRANSACTION keyword -} +CREATE TABLE t (a INT PRIMARY KEY) ENGINE=InnoDB; +INSERT INTO t VALUES (1), (2); -ROLLBACK; - ---connection con2 ---reap -ROLLBACK; - -# Second deadlock to verify info is cleared between transactions -INSERT INTO t1 VALUES (3, 30), (4, 40); +--connect(con1,localhost,root,,) +--connect(con2,localhost,root,,) --connection con1 BEGIN; -UPDATE t1 SET x = 300 WHERE id = 3; +SELECT * FROM t WHERE a = 1 FOR UPDATE; --connection con2 BEGIN; -UPDATE t1 SET x = 400 WHERE id = 4; ---send UPDATE t1 SET x = 401 WHERE id = 3 +SELECT * FROM t WHERE a = 2 FOR UPDATE; +SET DEBUG_SYNC = 'lock_wait_start SIGNAL con2_waiting'; +--send SELECT * FROM t WHERE a = 1 FOR UPDATE --connection con1 ---disable_abort_on_error ---disable_query_log ---disable_result_log -UPDATE t1 SET x = 301 WHERE id = 4; ---enable_result_log ---enable_query_log ---enable_abort_on_error ---let $errno= $mysql_errno -if ($errno != 1213) { - --echo Expected ER_LOCK_DEADLOCK (1213), got $errno - --die -} - ---let $msg1= query_get_value(SHOW WARNINGS, Message, 1) ---let $msg2= query_get_value(SHOW WARNINGS, Message, 2) ---let $deadlock_info= `SELECT IF(LENGTH('$msg1') > LENGTH('$msg2'), '$msg1', '$msg2')` - -if (`SELECT '$deadlock_info' LIKE '%id = 3%' OR '$deadlock_info' LIKE '%id = 4%'`) { - --echo Second deadlock shows new transaction info -} +SET DEBUG_SYNC = 'now WAIT_FOR con2_waiting'; +SET debug_dbug = '+d,innodb_deadlock_victim_self'; +--error ER_LOCK_DEADLOCK +SELECT * FROM t WHERE a = 2 FOR UPDATE; -if (`SELECT '$deadlock_info' NOT LIKE '%id = 1%'`) { - --echo Second deadlock does not contain old info -} +--replace_regex /[0-9]{4}-[0-9]{2}-[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2}/TIMESTAMP/ /0x[0-9a-f]+/0xTHD/ /OS thread handle [0-9]+/OS thread handle TID/ /thread id [0-9]+/thread id TID/ /query id [0-9]+/query id QID/ /trx id [0-9]+/trx id TRX_ID/ /TRANSACTION [0-9]+/TRANSACTION TRX_ID/ +SHOW WARNINGS; ROLLBACK; @@ -99,8 +40,9 @@ ROLLBACK; --reap ROLLBACK; +--connection default --disconnect con1 --disconnect con2 ---connection default - -DROP TABLE t1; +SET DEBUG_SYNC = 'RESET'; +DROP TABLE t; +SET GLOBAL innodb_print_all_deadlocks = @saved_print_all_deadlocks; diff --git a/storage/innobase/handler/ha_innodb.cc b/storage/innobase/handler/ha_innodb.cc index 64cb0007f3552..99840be7fb125 100644 --- a/storage/innobase/handler/ha_innodb.cc +++ b/storage/innobase/handler/ha_innodb.cc @@ -2104,17 +2104,8 @@ convert_error_code_to_mysql( /* Since we rolled back the whole transaction, the cached binlog must be emptied. */ innodb_transaction_abort(thd, true, error); - if (error == DB_DEADLOCK) { - trx_t* trx = thd_to_trx(thd); - if (trx && trx->lock.deadlock_info - && trx->lock.deadlock_info_len > 0) { - push_warning_printf(thd, - Sql_condition::WARN_LEVEL_NOTE, - ER_LOCK_DEADLOCK, - "%s", trx->lock.deadlock_info); - } + if (error == DB_DEADLOCK) return HA_ERR_LOCK_DEADLOCK; - } return HA_ERR_RECORD_CHANGED; case DB_LOCK_WAIT_TIMEOUT: diff --git a/storage/innobase/include/trx0trx.h b/storage/innobase/include/trx0trx.h index 6499d214a9b9f..f5f805e0d2c66 100644 --- a/storage/innobase/include/trx0trx.h +++ b/storage/innobase/include/trx0trx.h @@ -61,15 +61,6 @@ trx_set_detailed_error_from_file( trx_t* trx, /*!< in: transaction struct */ FILE* file); /*!< in: file to read message from */ -/** Set the deadlock information for a transaction from a file. -@param trx transaction that was chosen as deadlock victim -@param file file containing the deadlock information */ -void trx_set_deadlock_info_from_file(trx_t *trx, FILE *file); - -/** Clear the deadlock information for a transaction. -@param trx transaction */ -void trx_clear_deadlock_info(trx_t *trx); - /****************************************************************//** Retrieves the error_info field from a trx. @return the error info */ @@ -397,11 +388,6 @@ struct trx_lock_t /** number of lock_rec_set_nth_bit() calls since the start of transaction; protected by lock_sys.is_writer() or trx->mutex_is_owner(). */ ulint set_nth_bit_calls; - - /** Deadlock information for SHOW WARNINGS; protected by lock_sys.wait_mutex */ - char *deadlock_info; - size_t deadlock_info_len; - size_t deadlock_info_size; }; /** Logical first modification time of a table in a transaction */ diff --git a/storage/innobase/lock/lock0lock.cc b/storage/innobase/lock/lock0lock.cc index 3996f73b67dfd..12cc32b0eff47 100644 --- a/storage/innobase/lock/lock0lock.cc +++ b/storage/innobase/lock/lock0lock.cc @@ -7182,6 +7182,8 @@ and less modified rows. Bit 0 is used to prefer orig_trx in case of a tie. static const char rollback_msg[]= "*** WE ROLL BACK TRANSACTION (%u)\n"; char buf[9 + sizeof rollback_msg]; trx_t *victim= nullptr; + char *deadlock_info= nullptr; + size_t deadlock_info_len= 0; /* Here, lock elision does not make sense, because for the output we are going to invoke system calls, @@ -7304,7 +7306,26 @@ and less modified rows. Bit 0 is used to prefer orig_trx in case of a tie. } snprintf(buf, sizeof buf, rollback_msg, victim_pos); print(buf); - trx_set_deadlock_info_from_file(victim, lock_latest_err_file); + + if (srv_print_all_deadlocks) + { + rewind(lock_latest_err_file); + fseek(lock_latest_err_file, 0, SEEK_END); + long file_size= ftell(lock_latest_err_file); + if (file_size > 0) + { + deadlock_info= static_cast(ut_malloc_nokey( + static_cast(file_size) + 1)); + if (deadlock_info) + { + rewind(lock_latest_err_file); + deadlock_info_len= fread(deadlock_info, 1, + static_cast(file_size), + lock_latest_err_file); + deadlock_info[deadlock_info_len]= '\0'; + } + } + } } DBUG_EXECUTE_IF("innodb_deadlock_victim_self", victim= trx;); @@ -7320,6 +7341,14 @@ and less modified rows. Bit 0 is used to prefer orig_trx in case of a tie. func_exit: if (current_trx) lock_sys.wr_unlock(); + + if (deadlock_info && victim == trx && trx->mysql_thd) + { + push_warning_printf(trx->mysql_thd, Sql_condition::WARN_LEVEL_NOTE, + ER_LOCK_DEADLOCK, "%s", deadlock_info); + } + ut_free(deadlock_info); + return victim; } } diff --git a/storage/innobase/trx/trx0trx.cc b/storage/innobase/trx/trx0trx.cc index 71cca9993c9c9..987e719d4e9f7 100644 --- a/storage/innobase/trx/trx0trx.cc +++ b/storage/innobase/trx/trx0trx.cc @@ -97,46 +97,6 @@ trx_set_detailed_error_from_file( os_file_read_string(file, trx->detailed_error, MAX_DETAILED_ERROR_LEN); } -/** Set the deadlock information for a transaction from a file. -@param trx transaction that was chosen as deadlock victim -@param file file containing the deadlock information */ -void trx_set_deadlock_info_from_file(trx_t *trx, FILE *file) -{ - mysql_mutex_assert_owner(&lock_sys.wait_mutex); - - rewind(file); - fseek(file, 0, SEEK_END); - long file_size = ftell(file); - if (file_size <= 0) { - return; - } - - size_t needed_size = static_cast(file_size) + 1; - - if (needed_size > trx->lock.deadlock_info_size) { - ut_free(trx->lock.deadlock_info); - trx->lock.deadlock_info = static_cast( - ut_malloc_nokey(needed_size)); - trx->lock.deadlock_info_size = needed_size; - } - - rewind(file); - size_t read_len = fread(trx->lock.deadlock_info, 1, - static_cast(file_size), file); - trx->lock.deadlock_info[read_len] = '\0'; - trx->lock.deadlock_info_len = read_len; -} - -/** Clear the deadlock information for a transaction. -@param trx transaction */ -void trx_clear_deadlock_info(trx_t *trx) -{ - if (trx->lock.deadlock_info) { - trx->lock.deadlock_info[0] = '\0'; - trx->lock.deadlock_info_len = 0; - } -} - /********************************************************************//** Initialize transaction object. @param trx trx to initialize */ @@ -232,10 +192,6 @@ struct TrxFactory { trx->detailed_error = reinterpret_cast( ut_zalloc_nokey(MAX_DETAILED_ERROR_LEN)); - trx->lock.deadlock_info = nullptr; - trx->lock.deadlock_info_len = 0; - trx->lock.deadlock_info_size = 0; - trx->lock.lock_heap = mem_heap_create_typed( 1024, MEM_HEAP_FOR_LOCK_HEAP); pthread_cond_init(&trx->lock.cond, nullptr); @@ -282,11 +238,6 @@ struct TrxFactory { ut_free(trx->detailed_error); - ut_free(trx->lock.deadlock_info); - trx->lock.deadlock_info = nullptr; - trx->lock.deadlock_info_len = 0; - trx->lock.deadlock_info_size = 0; - trx->mutex_destroy(); trx->autoinc_locks.~small_vector(); @@ -445,7 +396,6 @@ void trx_t::free() trx_sys.deregister_trx(this); check_unique_secondary= true; check_foreigns= true; - trx_clear_deadlock_info(this); assert_freed(); trx_sys.rw_trx_hash.put_pins(this); mysql_thd= nullptr; @@ -960,7 +910,6 @@ trx_start_low( ut_ad(trx->rsegs.m_noredo.rseg == NULL); ut_ad(trx_state_eq(trx, TRX_STATE_NOT_STARTED)); ut_ad(UT_LIST_GET_LEN(trx->lock.trx_locks) == 0); - trx_clear_deadlock_info(trx); /* Check whether it is an AUTOCOMMIT SELECT */ if (const THD* thd = trx->mysql_thd) { From 0cf376fb582cbf1438e9964659124343649b349d Mon Sep 17 00:00:00 2001 From: Varun Deep Saini Date: Wed, 24 Dec 2025 10:22:37 +0530 Subject: [PATCH 3/7] Resolved comments --- .../suite/innodb/r/deadlock_session_info.result | 4 ++-- .../suite/innodb/t/deadlock_session_info.test | 2 +- storage/innobase/handler/ha_innodb.cc | 5 ++--- storage/innobase/lock/lock0lock.cc | 17 +++++++++-------- 4 files changed, 14 insertions(+), 14 deletions(-) diff --git a/mysql-test/suite/innodb/r/deadlock_session_info.result b/mysql-test/suite/innodb/r/deadlock_session_info.result index 7cf94dba34d78..c30c1a9d962e6 100644 --- a/mysql-test/suite/innodb/r/deadlock_session_info.result +++ b/mysql-test/suite/innodb/r/deadlock_session_info.result @@ -31,8 +31,8 @@ LOCK WAIT 3 lock struct(s), heap size 1144, 2 row lock(s) MariaDB thread id TID, OS thread handle TID, query id QID localhost root Statistics SELECT * FROM t WHERE a = 2 FOR UPDATE *** WAITING FOR THIS LOCK TO BE GRANTED: -RECORD LOCKS space id 8 page no 3 n bits 320 index PRIMARY of table `test`.`t` trx id TRX_ID lock_mode X locks rec but not gap waiting -Record lock, +RECORD LOCKS space id ID page no 3 n bits 320 index PRIMARY of table `test`.`t` trx id TRX_ID lock_mode X locks rec but not gap waiting + Error 1213 Deadlock found when trying to get lock; try restarting transaction ROLLBACK; connection con2; diff --git a/mysql-test/suite/innodb/t/deadlock_session_info.test b/mysql-test/suite/innodb/t/deadlock_session_info.test index a1f7a6b18bfa6..0421cbb3065f0 100644 --- a/mysql-test/suite/innodb/t/deadlock_session_info.test +++ b/mysql-test/suite/innodb/t/deadlock_session_info.test @@ -31,7 +31,7 @@ SET debug_dbug = '+d,innodb_deadlock_victim_self'; --error ER_LOCK_DEADLOCK SELECT * FROM t WHERE a = 2 FOR UPDATE; ---replace_regex /[0-9]{4}-[0-9]{2}-[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2}/TIMESTAMP/ /0x[0-9a-f]+/0xTHD/ /OS thread handle [0-9]+/OS thread handle TID/ /thread id [0-9]+/thread id TID/ /query id [0-9]+/query id QID/ /trx id [0-9]+/trx id TRX_ID/ /TRANSACTION [0-9]+/TRANSACTION TRX_ID/ +--replace_regex /[0-9]{4}-[0-9]{2}-[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2}/TIMESTAMP/ /0x[0-9a-f]+/0xTHD/ /OS thread handle [0-9]+/OS thread handle TID/ /thread id [0-9]+/thread id TID/ /query id [0-9]+/query id QID/ /trx id [0-9]+/trx id TRX_ID/ /TRANSACTION [0-9]+/TRANSACTION TRX_ID/ /space id [0-9]+/space id ID/ /Rec.*// SHOW WARNINGS; ROLLBACK; diff --git a/storage/innobase/handler/ha_innodb.cc b/storage/innobase/handler/ha_innodb.cc index 99840be7fb125..eacde4912b89e 100644 --- a/storage/innobase/handler/ha_innodb.cc +++ b/storage/innobase/handler/ha_innodb.cc @@ -2104,9 +2104,8 @@ convert_error_code_to_mysql( /* Since we rolled back the whole transaction, the cached binlog must be emptied. */ innodb_transaction_abort(thd, true, error); - if (error == DB_DEADLOCK) - return HA_ERR_LOCK_DEADLOCK; - return HA_ERR_RECORD_CHANGED; + return error == DB_DEADLOCK + ? HA_ERR_LOCK_DEADLOCK : HA_ERR_RECORD_CHANGED; case DB_LOCK_WAIT_TIMEOUT: /* Starting from 5.0.13, we let MySQL just roll back the diff --git a/storage/innobase/lock/lock0lock.cc b/storage/innobase/lock/lock0lock.cc index 12cc32b0eff47..720a09242d132 100644 --- a/storage/innobase/lock/lock0lock.cc +++ b/storage/innobase/lock/lock0lock.cc @@ -7309,18 +7309,16 @@ and less modified rows. Bit 0 is used to prefer orig_trx in case of a tie. if (srv_print_all_deadlocks) { - rewind(lock_latest_err_file); - fseek(lock_latest_err_file, 0, SEEK_END); - long file_size= ftell(lock_latest_err_file); - if (file_size > 0) + long len= ftell(lock_latest_err_file); + if (len > 0) { deadlock_info= static_cast(ut_malloc_nokey( - static_cast(file_size) + 1)); + static_cast(len) + 1)); if (deadlock_info) { rewind(lock_latest_err_file); deadlock_info_len= fread(deadlock_info, 1, - static_cast(file_size), + static_cast(len), lock_latest_err_file); deadlock_info[deadlock_info_len]= '\0'; } @@ -7344,8 +7342,11 @@ and less modified rows. Bit 0 is used to prefer orig_trx in case of a tie. if (deadlock_info && victim == trx && trx->mysql_thd) { - push_warning_printf(trx->mysql_thd, Sql_condition::WARN_LEVEL_NOTE, - ER_LOCK_DEADLOCK, "%s", deadlock_info); + while (deadlock_info_len > 0 && deadlock_info[deadlock_info_len - 1] == '\n') + deadlock_info[--deadlock_info_len]= '\0'; + if (deadlock_info_len > 0) + push_warning(trx->mysql_thd, Sql_condition::WARN_LEVEL_NOTE, + ER_LOCK_DEADLOCK, deadlock_info); } ut_free(deadlock_info); From 948f9a8ff3638d6d694b4c6f657c63c6f82c870c Mon Sep 17 00:00:00 2001 From: Varun Deep Saini Date: Wed, 24 Dec 2025 10:35:31 +0530 Subject: [PATCH 4/7] remove non functional changes --- storage/innobase/include/trx0trx.h | 1 - 1 file changed, 1 deletion(-) diff --git a/storage/innobase/include/trx0trx.h b/storage/innobase/include/trx0trx.h index f5f805e0d2c66..266d3be7a3dd4 100644 --- a/storage/innobase/include/trx0trx.h +++ b/storage/innobase/include/trx0trx.h @@ -60,7 +60,6 @@ trx_set_detailed_error_from_file( /*=============================*/ trx_t* trx, /*!< in: transaction struct */ FILE* file); /*!< in: file to read message from */ - /****************************************************************//** Retrieves the error_info field from a trx. @return the error info */ From 1eadd6b6517ad2ab07f8d04c90decc87cda9f904 Mon Sep 17 00:00:00 2001 From: Varun Deep Saini Date: Thu, 25 Dec 2025 00:18:05 +0530 Subject: [PATCH 5/7] Updated tests --- .../suite/innodb/r/autoinc_debug.result | 70 +++++++++++++++++++ .../innodb/r/deadlock_session_info.result | 47 ------------- mysql-test/suite/innodb/t/autoinc_debug.test | 9 +++ .../suite/innodb/t/deadlock_session_info.test | 48 ------------- storage/innobase/lock/lock0lock.cc | 13 ++-- 5 files changed, 84 insertions(+), 103 deletions(-) delete mode 100644 mysql-test/suite/innodb/r/deadlock_session_info.result delete mode 100644 mysql-test/suite/innodb/t/deadlock_session_info.test diff --git a/mysql-test/suite/innodb/r/autoinc_debug.result b/mysql-test/suite/innodb/r/autoinc_debug.result index 585dafeec9d5b..4eb6d402a9d0a 100644 --- a/mysql-test/suite/innodb/r/autoinc_debug.result +++ b/mysql-test/suite/innodb/r/autoinc_debug.result @@ -108,6 +108,8 @@ SET DEBUG_SYNC='RESET'; # # MDEV-33593: Auto increment deadlock error causes ASSERT in subsequent save point # +SET @saved_print_all_deadlocks = @@GLOBAL.innodb_print_all_deadlocks; +SET GLOBAL innodb_print_all_deadlocks = ON; CREATE TABLE t1(col1 INT PRIMARY KEY AUTO_INCREMENT, col2 INT) ENGINE=InnoDB; CREATE TABLE t2(col1 INT PRIMARY KEY) ENGINE=InnoDB; INSERT INTO t1(col2) values(100); @@ -133,6 +135,73 @@ SET DEBUG_SYNC='now WAIT_FOR t3_waiting'; SET debug_dbug = '+d,innodb_deadlock_victim_self'; INSERT INTO t1(col2) VALUES(200); ERROR HY000: Failed to read auto-increment value from storage engine +# Verify deadlock info is available in session warnings (MDEV-34686) +SHOW WARNINGS; +Level Code Message +Note 1213 TIMESTAMP 0xTHD +*** (1) TRANSACTION: +TRANSACTION 59, ACTIVE 0 sec inserting +mysql tables in use 2, locked 2 +LOCK WAIT 5 lock struct(s), heap size 1144, 3 row lock(s) +MariaDB thread id 3, OS thread handle TID, query id 57 localhost root Sending data +INSERT INTO t1(col2) SELECT col2 from t1 +*** WAITING FOR THIS LOCK TO BE GRANTED: +RECORD LOCKS space id 10 page no 3 n bits 320 index PRIMARY of table `test`.`t1` trx id 59 lock_mode X insert intention waiting +Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0 + 0: len 8; hex 73757072656d756d; asc supremum;; + +*** CONFLICTING WITH: +RECORD LOCKS space id 10 page no 3 n bits 320 index PRIMARY of table `test`.`t1` trx id 58 lock_mode X +Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0 + 0: len 8; hex 73757072656d756d; asc supremum;; + +RECORD LOCKS space id 10 page no 3 n bits 320 index PRIMARY of table `test`.`t1` trx id 59 lock mode S +Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0 + 0: len 8; hex 73757072656d756d; asc supremum;; + +Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0 + 0: len 4; hex 80000001; asc ;; + 1: len 6; hex 000000000037; asc 7;; + 2: len 7; hex 91000000320110; asc 2 ;; + 3: len 4; hex 80000064; asc d;; + + +*** (2) TRANSACTION: +TRANSACTION 58, ACTIVE 0 sec inserting +mysql tables in use 1, locked 1 +LOCK WAIT 4 lock struct(s), heap size 1144, 2 row lock(s) +MariaDB thread id 7, OS thread handle TID, query id 54 localhost root Update +INSERT INTO t2 values(100) +*** WAITING FOR THIS LOCK TO BE GRANTED: +RECORD LOCKS space id 11 page no 3 n bits 320 index PRIMARY of table `test`.`t2` trx id 58 lock mode S locks rec but not gap waiting +Record lock, heap no 2 PHYSICAL RECORD: n_fields 3; compact format; info bits 0 + 0: len 4; hex 80000064; asc d;; + 1: len 6; hex 000000000039; asc 9;; + 2: len 7; hex 92000000320110; asc 2 ;; + +*** CONFLICTING WITH: +RECORD LOCKS space id 11 page no 3 n bits 320 index PRIMARY of table `test`.`t2` trx id 57 lock_mode X locks rec but not gap +Record lock, heap no 2 PHYSICAL RECORD: n_fields 3; compact format; info bits 0 + 0: len 4; hex 80000064; asc d;; + 1: len 6; hex 000000000039; asc 9;; + 2: len 7; hex 92000000320110; asc 2 ;; + + +*** (3) TRANSACTION: +TRANSACTION 57, ACTIVE 0 sec setting auto-inc lock +mysql tables in use 1, locked 1 +LOCK WAIT 3 lock struct(s), heap size 1144, 1 row lock(s), undo log entries 1 +MariaDB thread id 6, OS thread handle TID, query id 61 localhost root Update +INSERT INTO t1(col2) VALUES(200) +*** WAITING FOR THIS LOCK TO BE GRANTED: +TABLE LOCK table `test`.`t1` trx id 57 lock mode AUTO-INC waiting +*** CONFLICTING WITH: +TABLE LOCK table `test`.`t1` trx id 58 lock mode IX +TABLE LOCK table `test`.`t1` trx id 59 lock mode IS +TABLE LOCK table `test`.`t1` trx id 59 lock mode AUTO-INC +TABLE LOCK table `test`.`t1` trx id 59 lock mode IX +*** WE ROLL BACK TRANSACTION (1) +Error 1467 Failed to read auto-increment value from storage engine # The transaction should have been rolled back SELECT * FROM t1; col1 col2 @@ -159,6 +228,7 @@ col1 100 DROP TABLE t2; SET DEBUG_SYNC='RESET'; +SET GLOBAL innodb_print_all_deadlocks = @saved_print_all_deadlocks; # # End of 10.5 tests # diff --git a/mysql-test/suite/innodb/r/deadlock_session_info.result b/mysql-test/suite/innodb/r/deadlock_session_info.result deleted file mode 100644 index c30c1a9d962e6..0000000000000 --- a/mysql-test/suite/innodb/r/deadlock_session_info.result +++ /dev/null @@ -1,47 +0,0 @@ -SET @saved_print_all_deadlocks = @@GLOBAL.innodb_print_all_deadlocks; -SET GLOBAL innodb_print_all_deadlocks = ON; -CREATE TABLE t (a INT PRIMARY KEY) ENGINE=InnoDB; -INSERT INTO t VALUES (1), (2); -connect con1,localhost,root,,; -connect con2,localhost,root,,; -connection con1; -BEGIN; -SELECT * FROM t WHERE a = 1 FOR UPDATE; -a -1 -connection con2; -BEGIN; -SELECT * FROM t WHERE a = 2 FOR UPDATE; -a -2 -SET DEBUG_SYNC = 'lock_wait_start SIGNAL con2_waiting'; -SELECT * FROM t WHERE a = 1 FOR UPDATE; -connection con1; -SET DEBUG_SYNC = 'now WAIT_FOR con2_waiting'; -SET debug_dbug = '+d,innodb_deadlock_victim_self'; -SELECT * FROM t WHERE a = 2 FOR UPDATE; -ERROR 40001: Deadlock found when trying to get lock; try restarting transaction -SHOW WARNINGS; -Level Code Message -Note 1213 TIMESTAMP 0xTHD -*** (1) TRANSACTION: -TRANSACTION TRX_ID, ACTIVE 0 sec starting index read -mysql tables in use 1, locked 1 -LOCK WAIT 3 lock struct(s), heap size 1144, 2 row lock(s) -MariaDB thread id TID, OS thread handle TID, query id QID localhost root Statistics -SELECT * FROM t WHERE a = 2 FOR UPDATE -*** WAITING FOR THIS LOCK TO BE GRANTED: -RECORD LOCKS space id ID page no 3 n bits 320 index PRIMARY of table `test`.`t` trx id TRX_ID lock_mode X locks rec but not gap waiting - -Error 1213 Deadlock found when trying to get lock; try restarting transaction -ROLLBACK; -connection con2; -a -1 -ROLLBACK; -connection default; -disconnect con1; -disconnect con2; -SET DEBUG_SYNC = 'RESET'; -DROP TABLE t; -SET GLOBAL innodb_print_all_deadlocks = @saved_print_all_deadlocks; diff --git a/mysql-test/suite/innodb/t/autoinc_debug.test b/mysql-test/suite/innodb/t/autoinc_debug.test index f62cfd8afce09..f11d5475173f8 100644 --- a/mysql-test/suite/innodb/t/autoinc_debug.test +++ b/mysql-test/suite/innodb/t/autoinc_debug.test @@ -5,6 +5,7 @@ --disable_query_log call mtr.add_suppression("InnoDB: Transaction was aborted due to "); +call mtr.add_suppression("Transactions deadlock detected"); --enable_query_log # Two parallel connection with autoinc column after restart. @@ -101,6 +102,9 @@ SET DEBUG_SYNC='RESET'; --echo # MDEV-33593: Auto increment deadlock error causes ASSERT in subsequent save point --echo # +SET @saved_print_all_deadlocks = @@GLOBAL.innodb_print_all_deadlocks; +SET GLOBAL innodb_print_all_deadlocks = ON; + CREATE TABLE t1(col1 INT PRIMARY KEY AUTO_INCREMENT, col2 INT) ENGINE=InnoDB; CREATE TABLE t2(col1 INT PRIMARY KEY) ENGINE=InnoDB; INSERT INTO t1(col2) values(100); @@ -131,6 +135,10 @@ SET debug_dbug = '+d,innodb_deadlock_victim_self'; --error ER_AUTOINC_READ_FAILED INSERT INTO t1(col2) VALUES(200); +--echo # Verify deadlock info is available in session warnings (MDEV-34686) +--replace_regex /[0-9]{4}-[0-9]{2}-[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2}/TIMESTAMP/ /0x[0-9a-f]+/0xTHD/ /OS thread handle [0-9]+/OS thread handle TID/ /::1 // +SHOW WARNINGS; + --echo # The transaction should have been rolled back SELECT * FROM t1; SELECT * FROM t2; @@ -158,6 +166,7 @@ SELECT * FROM t2; DROP TABLE t2; SET DEBUG_SYNC='RESET'; +SET GLOBAL innodb_print_all_deadlocks = @saved_print_all_deadlocks; --echo # --echo # End of 10.5 tests diff --git a/mysql-test/suite/innodb/t/deadlock_session_info.test b/mysql-test/suite/innodb/t/deadlock_session_info.test deleted file mode 100644 index 0421cbb3065f0..0000000000000 --- a/mysql-test/suite/innodb/t/deadlock_session_info.test +++ /dev/null @@ -1,48 +0,0 @@ ---source include/have_innodb.inc ---source include/have_debug.inc ---source include/have_debug_sync.inc - ---disable_query_log -call mtr.add_suppression("Transactions deadlock detected"); ---enable_query_log - -SET @saved_print_all_deadlocks = @@GLOBAL.innodb_print_all_deadlocks; -SET GLOBAL innodb_print_all_deadlocks = ON; - -CREATE TABLE t (a INT PRIMARY KEY) ENGINE=InnoDB; -INSERT INTO t VALUES (1), (2); - ---connect(con1,localhost,root,,) ---connect(con2,localhost,root,,) - ---connection con1 -BEGIN; -SELECT * FROM t WHERE a = 1 FOR UPDATE; - ---connection con2 -BEGIN; -SELECT * FROM t WHERE a = 2 FOR UPDATE; -SET DEBUG_SYNC = 'lock_wait_start SIGNAL con2_waiting'; ---send SELECT * FROM t WHERE a = 1 FOR UPDATE - ---connection con1 -SET DEBUG_SYNC = 'now WAIT_FOR con2_waiting'; -SET debug_dbug = '+d,innodb_deadlock_victim_self'; ---error ER_LOCK_DEADLOCK -SELECT * FROM t WHERE a = 2 FOR UPDATE; - ---replace_regex /[0-9]{4}-[0-9]{2}-[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2}/TIMESTAMP/ /0x[0-9a-f]+/0xTHD/ /OS thread handle [0-9]+/OS thread handle TID/ /thread id [0-9]+/thread id TID/ /query id [0-9]+/query id QID/ /trx id [0-9]+/trx id TRX_ID/ /TRANSACTION [0-9]+/TRANSACTION TRX_ID/ /space id [0-9]+/space id ID/ /Rec.*// -SHOW WARNINGS; - -ROLLBACK; - ---connection con2 ---reap -ROLLBACK; - ---connection default ---disconnect con1 ---disconnect con2 -SET DEBUG_SYNC = 'RESET'; -DROP TABLE t; -SET GLOBAL innodb_print_all_deadlocks = @saved_print_all_deadlocks; diff --git a/storage/innobase/lock/lock0lock.cc b/storage/innobase/lock/lock0lock.cc index 720a09242d132..465e641707a03 100644 --- a/storage/innobase/lock/lock0lock.cc +++ b/storage/innobase/lock/lock0lock.cc @@ -7320,6 +7320,8 @@ and less modified rows. Bit 0 is used to prefer orig_trx in case of a tie. deadlock_info_len= fread(deadlock_info, 1, static_cast(len), lock_latest_err_file); + if (deadlock_info_len && deadlock_info[deadlock_info_len - 1] == '\n') + --deadlock_info_len; deadlock_info[deadlock_info_len]= '\0'; } } @@ -7340,14 +7342,9 @@ and less modified rows. Bit 0 is used to prefer orig_trx in case of a tie. if (current_trx) lock_sys.wr_unlock(); - if (deadlock_info && victim == trx && trx->mysql_thd) - { - while (deadlock_info_len > 0 && deadlock_info[deadlock_info_len - 1] == '\n') - deadlock_info[--deadlock_info_len]= '\0'; - if (deadlock_info_len > 0) - push_warning(trx->mysql_thd, Sql_condition::WARN_LEVEL_NOTE, - ER_LOCK_DEADLOCK, deadlock_info); - } + if (deadlock_info && current_trx && victim == trx && trx->mysql_thd) + push_warning(trx->mysql_thd, Sql_condition::WARN_LEVEL_NOTE, + ER_LOCK_DEADLOCK, deadlock_info); ut_free(deadlock_info); return victim; From 8d4c835b6571badc2d4e1d6b559fb440b05cf6ed Mon Sep 17 00:00:00 2001 From: Varun Deep Saini Date: Thu, 25 Dec 2025 01:49:17 +0530 Subject: [PATCH 6/7] resolved comments --- storage/innobase/lock/lock0lock.cc | 31 +++++++++++++++--------------- 1 file changed, 15 insertions(+), 16 deletions(-) diff --git a/storage/innobase/lock/lock0lock.cc b/storage/innobase/lock/lock0lock.cc index 465e641707a03..2fc3f0ee3fcc3 100644 --- a/storage/innobase/lock/lock0lock.cc +++ b/storage/innobase/lock/lock0lock.cc @@ -7183,7 +7183,6 @@ and less modified rows. Bit 0 is used to prefer orig_trx in case of a tie. char buf[9 + sizeof rollback_msg]; trx_t *victim= nullptr; char *deadlock_info= nullptr; - size_t deadlock_info_len= 0; /* Here, lock elision does not make sense, because for the output we are going to invoke system calls, @@ -7310,22 +7309,22 @@ and less modified rows. Bit 0 is used to prefer orig_trx in case of a tie. if (srv_print_all_deadlocks) { long len= ftell(lock_latest_err_file); - if (len > 0) - { - deadlock_info= static_cast(ut_malloc_nokey( - static_cast(len) + 1)); - if (deadlock_info) - { - rewind(lock_latest_err_file); - deadlock_info_len= fread(deadlock_info, 1, - static_cast(len), - lock_latest_err_file); - if (deadlock_info_len && deadlock_info[deadlock_info_len - 1] == '\n') - --deadlock_info_len; - deadlock_info[deadlock_info_len]= '\0'; - } - } + if (len <= 0) + goto captured; + deadlock_info= static_cast(ut_malloc_nokey( + static_cast(len) + 1)); + if (!deadlock_info) + goto captured; + rewind(lock_latest_err_file); + size_t deadlock_info_len= fread(deadlock_info, 1, + static_cast(len), + lock_latest_err_file); + ut_ad(deadlock_info_len <= static_cast(len)); + if (deadlock_info[deadlock_info_len - 1] == '\n') + --deadlock_info_len; + deadlock_info[deadlock_info_len]= '\0'; } + captured:; } DBUG_EXECUTE_IF("innodb_deadlock_victim_self", victim= trx;); From b940c6c7340e8ab12bdcab7066d4af9bf52725d8 Mon Sep 17 00:00:00 2001 From: Varun Deep Saini Date: Fri, 26 Dec 2025 23:39:06 +0530 Subject: [PATCH 7/7] refactoring --- .../suite/innodb/r/autoinc_debug.result | 64 ++++--------------- mysql-test/suite/innodb/t/autoinc_debug.test | 2 +- storage/innobase/lock/lock0lock.cc | 40 ++++++------ 3 files changed, 33 insertions(+), 73 deletions(-) diff --git a/mysql-test/suite/innodb/r/autoinc_debug.result b/mysql-test/suite/innodb/r/autoinc_debug.result index 4eb6d402a9d0a..0b80a69c9dd6e 100644 --- a/mysql-test/suite/innodb/r/autoinc_debug.result +++ b/mysql-test/suite/innodb/r/autoinc_debug.result @@ -140,66 +140,30 @@ SHOW WARNINGS; Level Code Message Note 1213 TIMESTAMP 0xTHD *** (1) TRANSACTION: -TRANSACTION 59, ACTIVE 0 sec inserting +TRANSACTION TRX_ID, ACTIVE N sec inserting mysql tables in use 2, locked 2 -LOCK WAIT 5 lock struct(s), heap size 1144, 3 row lock(s) -MariaDB thread id 3, OS thread handle TID, query id 57 localhost root Sending data +LOCK WAIT N lock struct(s), heap size N, N row lock(s) +MariaDB thread id TID, OS thread handle TID, query id QID localhost root Sending data INSERT INTO t1(col2) SELECT col2 from t1 *** WAITING FOR THIS LOCK TO BE GRANTED: -RECORD LOCKS space id 10 page no 3 n bits 320 index PRIMARY of table `test`.`t1` trx id 59 lock_mode X insert intention waiting -Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0 - 0: len 8; hex 73757072656d756d; asc supremum;; - -*** CONFLICTING WITH: -RECORD LOCKS space id 10 page no 3 n bits 320 index PRIMARY of table `test`.`t1` trx id 58 lock_mode X -Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0 - 0: len 8; hex 73757072656d756d; asc supremum;; - -RECORD LOCKS space id 10 page no 3 n bits 320 index PRIMARY of table `test`.`t1` trx id 59 lock mode S -Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0 - 0: len 8; hex 73757072656d756d; asc supremum;; - -Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0 - 0: len 4; hex 80000001; asc ;; - 1: len 6; hex 000000000037; asc 7;; - 2: len 7; hex 91000000320110; asc 2 ;; - 3: len 4; hex 80000064; asc d;; - - -*** (2) TRANSACTION: -TRANSACTION 58, ACTIVE 0 sec inserting -mysql tables in use 1, locked 1 -LOCK WAIT 4 lock struct(s), heap size 1144, 2 row lock(s) -MariaDB thread id 7, OS thread handle TID, query id 54 localhost root Update -INSERT INTO t2 values(100) -*** WAITING FOR THIS LOCK TO BE GRANTED: -RECORD LOCKS space id 11 page no 3 n bits 320 index PRIMARY of table `test`.`t2` trx id 58 lock mode S locks rec but not gap waiting -Record lock, heap no 2 PHYSICAL RECORD: n_fields 3; compact format; info bits 0 - 0: len 4; hex 80000064; asc d;; - 1: len 6; hex 000000000039; asc 9;; - 2: len 7; hex 92000000320110; asc 2 ;; - -*** CONFLICTING WITH: -RECORD LOCKS space id 11 page no 3 n bits 320 index PRIMARY of table `test`.`t2` trx id 57 lock_mode X locks rec but not gap -Record lock, heap no 2 PHYSICAL RECORD: n_fields 3; compact format; info bits 0 - 0: len 4; hex 80000064; asc d;; - 1: len 6; hex 000000000039; asc 9;; - 2: len 7; hex 92000000320110; asc 2 ;; +RECORD LOCKS space id ID page no N n bits N index PRIMARY of table `test`.`t1` trx id TRX_ID lock_mode X insert intention waiting +Record lock, heap no 1 PHYSICAL RECORD: n_fields N; compact format; info bits N + 0: len 8; hex HEX; asc DATA;; *** (3) TRANSACTION: -TRANSACTION 57, ACTIVE 0 sec setting auto-inc lock +TRANSACTION TRX_ID, ACTIVE N sec setting auto-inc lock mysql tables in use 1, locked 1 -LOCK WAIT 3 lock struct(s), heap size 1144, 1 row lock(s), undo log entries 1 -MariaDB thread id 6, OS thread handle TID, query id 61 localhost root Update +LOCK WAIT N lock struct(s), heap size N, N row lock(s), undo log entries N +MariaDB thread id TID, OS thread handle TID, query id QID localhost root Update INSERT INTO t1(col2) VALUES(200) *** WAITING FOR THIS LOCK TO BE GRANTED: -TABLE LOCK table `test`.`t1` trx id 57 lock mode AUTO-INC waiting +TABLE LOCK table `test`.`t1` trx id TRX_ID lock mode AUTO-INC waiting *** CONFLICTING WITH: -TABLE LOCK table `test`.`t1` trx id 58 lock mode IX -TABLE LOCK table `test`.`t1` trx id 59 lock mode IS -TABLE LOCK table `test`.`t1` trx id 59 lock mode AUTO-INC -TABLE LOCK table `test`.`t1` trx id 59 lock mode IX +TABLE LOCK table `test`.`t1` trx id TRX_ID lock mode IX +TABLE LOCK table `test`.`t1` trx id TRX_ID lock mode IS +TABLE LOCK table `test`.`t1` trx id TRX_ID lock mode AUTO-INC +TABLE LOCK table `test`.`t1` trx id TRX_ID lock mode IX *** WE ROLL BACK TRANSACTION (1) Error 1467 Failed to read auto-increment value from storage engine # The transaction should have been rolled back diff --git a/mysql-test/suite/innodb/t/autoinc_debug.test b/mysql-test/suite/innodb/t/autoinc_debug.test index f11d5475173f8..5d40686b6b9e8 100644 --- a/mysql-test/suite/innodb/t/autoinc_debug.test +++ b/mysql-test/suite/innodb/t/autoinc_debug.test @@ -136,7 +136,7 @@ SET debug_dbug = '+d,innodb_deadlock_victim_self'; INSERT INTO t1(col2) VALUES(200); --echo # Verify deadlock info is available in session warnings (MDEV-34686) ---replace_regex /[0-9]{4}-[0-9]{2}-[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2}/TIMESTAMP/ /0x[0-9a-f]+/0xTHD/ /OS thread handle [0-9]+/OS thread handle TID/ /::1 // +--replace_regex /[0-9]{4}-[0-9]{2}-[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2}/TIMESTAMP/ /0x[0-9a-f]+/0xTHD/ /OS thread handle [0-9]+/OS thread handle TID/ /::1 // /127\.0\.0\.1 // /localhost::[0-9]* // /thread id [0-9]+/thread id TID/ /query id [0-9]+/query id QID/ /trx id [0-9]+/trx id TRX_ID/ /TRANSACTION [0-9]+/TRANSACTION TRX_ID/ /space id [0-9]+/space id ID/ /page no [0-9]+/page no N/ /n bits [0-9]+/n bits N/ /n_fields [0-9]+/n_fields N/ /info bits [0-9]+/info bits N/ /ACTIVE [0-9]+ sec/ACTIVE N sec/ /heap size [0-9]+/heap size N/ /[0-9]+ lock struct\(s\)/N lock struct(s)/ /[0-9]+ row lock\(s\)/N row lock(s)/ /undo log entries [0-9]+/undo log entries N/ /hex [0-9a-f]+; asc .*;;/hex HEX; asc DATA;;/ SHOW WARNINGS; --echo # The transaction should have been rolled back diff --git a/storage/innobase/lock/lock0lock.cc b/storage/innobase/lock/lock0lock.cc index 2fc3f0ee3fcc3..6356ad54acdb4 100644 --- a/storage/innobase/lock/lock0lock.cc +++ b/storage/innobase/lock/lock0lock.cc @@ -7305,36 +7305,32 @@ and less modified rows. Bit 0 is used to prefer orig_trx in case of a tie. } snprintf(buf, sizeof buf, rollback_msg, victim_pos); print(buf); - - if (srv_print_all_deadlocks) - { - long len= ftell(lock_latest_err_file); - if (len <= 0) - goto captured; - deadlock_info= static_cast(ut_malloc_nokey( - static_cast(len) + 1)); - if (!deadlock_info) - goto captured; - rewind(lock_latest_err_file); - size_t deadlock_info_len= fread(deadlock_info, 1, - static_cast(len), - lock_latest_err_file); - ut_ad(deadlock_info_len <= static_cast(len)); - if (deadlock_info[deadlock_info_len - 1] == '\n') - --deadlock_info_len; - deadlock_info[deadlock_info_len]= '\0'; - } - captured:; } DBUG_EXECUTE_IF("innodb_deadlock_victim_self", victim= trx;); ut_ad(victim->state == TRX_STATE_ACTIVE); - /* victim->lock.was_chosen_as_deadlock_victim must always be set before - releasing waiting locks and resetting trx->lock.wait_lock */ victim->lock.was_chosen_as_deadlock_victim= true; DEBUG_SYNC_C("deadlock_report_before_lock_releasing"); lock_cancel_waiting_and_release(victim->lock.wait_lock); + + if (!srv_print_all_deadlocks) + goto func_exit; + long len= ftell(lock_latest_err_file); + if (len <= 0) + goto func_exit; + deadlock_info= static_cast(ut_malloc_nokey( + static_cast(len) + 1)); + if (!deadlock_info) + goto func_exit; + rewind(lock_latest_err_file); + size_t deadlock_info_len= fread(deadlock_info, 1, + static_cast(len), + lock_latest_err_file); + ut_ad(deadlock_info_len <= static_cast(len)); + if (deadlock_info[deadlock_info_len - 1] == '\n') + --deadlock_info_len; + deadlock_info[deadlock_info_len]= '\0'; } func_exit: