MDEV-16335: Include deadlock detail information in SHOW WARNINGS

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,37 @@ 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 TRX_ID, ACTIVE N sec inserting
+mysql tables in use 2, locked 2
+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 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 TRX_ID, ACTIVE N sec setting auto-inc lock
+mysql tables in use 1, locked 1
+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 TRX_ID lock mode AUTO-INC waiting
+*** CONFLICTING WITH:
+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
 SELECT * FROM t1;
 col1	col2
@@ -159,6 +192,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
 #

mysql-test/suite/innodb/r/deadlock_report.result

@@ -0,0 +1,37 @@
+call mtr.add_suppression("InnoDB: Transaction was aborted due to ");
+call mtr.add_suppression("Transactions deadlock detected");
+SET @save = @@GLOBAL.innodb_print_all_deadlocks;
+SET GLOBAL innodb_print_all_deadlocks = ON;
+CREATE TABLE t1 (id INT PRIMARY KEY) ENGINE=InnoDB;
+CREATE TABLE t2 (a INT) ENGINE=InnoDB;
+INSERT INTO t1 VALUES (1), (2);
+INSERT INTO t2 VALUES (1),(2),(3),(4),(5),(6),(7),(8),(9),(10);
+connect con1, localhost, root,,;
+connect con2, localhost, root,,;
+connection con2;
+BEGIN;
+UPDATE t2 SET a = a + 1;
+SELECT * FROM t1 WHERE id = 2 FOR UPDATE;
+id
+2
+connection con1;
+BEGIN;
+SELECT * FROM t1 WHERE id = 1 FOR UPDATE;
+id
+1
+connection con2;
+SELECT * FROM t1 WHERE id = 1 FOR UPDATE;
+connection default;
+connection con1;
+SELECT * FROM t1 WHERE id = 2 FOR UPDATE;
+ERROR 40001: Deadlock found when trying to get lock; try restarting transaction
+connection con2;
+id
+1
+COMMIT;
+disconnect con1;
+disconnect con2;
+connection default;
+DROP TABLE t1, t2;
+SET GLOBAL innodb_print_all_deadlocks = @save;
+# End of 10.5 tests

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 // /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
 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

mysql-test/suite/innodb/t/deadlock_report.test

@@ -0,0 +1,64 @@
+--source include/have_innodb.inc
+--source include/not_embedded.inc
+
+# MDEV-34686: Deadlock info available in session warnings
+# Verify deadlock info appears in SHOW WARNINGS when innodb_print_all_deadlocks=ON
+
+call mtr.add_suppression("InnoDB: Transaction was aborted due to ");
+call mtr.add_suppression("Transactions deadlock detected");
+
+SET @save = @@GLOBAL.innodb_print_all_deadlocks;
+SET GLOBAL innodb_print_all_deadlocks = ON;
+
+CREATE TABLE t1 (id INT PRIMARY KEY) ENGINE=InnoDB;
+# Table to increase transaction weight (locks + undo records)
+CREATE TABLE t2 (a INT) ENGINE=InnoDB;
+INSERT INTO t1 VALUES (1), (2);
+INSERT INTO t2 VALUES (1),(2),(3),(4),(5),(6),(7),(8),(9),(10);
+
+--connect(con1, localhost, root,,)
+--connect(con2, localhost, root,,)
+
+# con2: increase weight so con1 will be chosen as deadlock victim
+--connection con2
+BEGIN;
+UPDATE t2 SET a = a + 1;
+SELECT * FROM t1 WHERE id = 2 FOR UPDATE;
+
+# con1: minimal weight
+--connection con1
+BEGIN;
+SELECT * FROM t1 WHERE id = 1 FOR UPDATE;
+
+# con2 waits for row 1
+--connection con2
+--send SELECT * FROM t1 WHERE id = 1 FOR UPDATE
+
+# Wait for con2 to enter lock wait
+--connection default
+let $wait_condition=
+  SELECT COUNT(*) >= 2 FROM information_schema.innodb_locks;
+--source include/wait_condition.inc
+
+# con1 triggers deadlock - will be victim due to lower weight
+--connection con1
+--error ER_LOCK_DEADLOCK
+SELECT * FROM t1 WHERE id = 2 FOR UPDATE;
+
+# Deadlock info must appear as Note
+--let $level = query_get_value(SHOW WARNINGS, Level, 1)
+if (`SELECT '$level' != 'Note'`) {
+  --die First warning should be Note with deadlock info
+}
+
+--connection con2
+--reap
+COMMIT;
+
+--disconnect con1
+--disconnect con2
+--connection default
+DROP TABLE t1, t2;
+SET GLOBAL innodb_print_all_deadlocks = @save;
+
+--echo # End of 10.5 tests

storage/innobase/lock/lock0lock.cc

@@ -7182,6 +7182,7 @@ 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;
 
     /* Here, lock elision does not make sense, because
     for the output we are going to invoke system calls,
@@ -7309,16 +7310,40 @@ and less modified rows. Bit 0 is used to prefer orig_trx in case of a tie.
       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<true>(victim->lock.wait_lock);
+
+      if (!srv_print_all_deadlocks || !current_trx || victim != trx ||
+          !trx->mysql_thd)
+        goto func_exit;
+      fflush(lock_latest_err_file);
+      long len= ftell(lock_latest_err_file);
+      if (len <= 0)
+        goto func_exit;
+      deadlock_info= static_cast<char*>(ut_malloc_nokey(
+        static_cast<size_t>(len) + 1));
+      if (!deadlock_info)
+        goto func_exit;
+      rewind(lock_latest_err_file);
+      size_t deadlock_info_len= fread(deadlock_info, 1,
+                                      static_cast<size_t>(len),
+                                      lock_latest_err_file);
+      ut_ad(deadlock_info_len <= static_cast<size_t>(len));
+      if (deadlock_info_len && deadlock_info[deadlock_info_len - 1] == '\n')
+        --deadlock_info_len;
+      deadlock_info[deadlock_info_len]= '\0';
     }
 
 func_exit:
     if (current_trx)
       lock_sys.wr_unlock();
+
+    if (deadlock_info)
+      push_warning(trx->mysql_thd, Sql_condition::WARN_LEVEL_NOTE,
+                   ER_LOCK_DEADLOCK, deadlock_info);
+    ut_free(deadlock_info);
+
     return victim;
   }
 }