Skip to content

Commit 67920e9

Browse files
Added the global env condition and simplified the tests
Signed-off-by: Varun Deep Saini <[email protected]>
1 parent 4c82db3 commit 67920e9

File tree

6 files changed

+91
-185
lines changed

6 files changed

+91
-185
lines changed
Lines changed: 37 additions & 28 deletions
Original file line numberDiff line numberDiff line change
@@ -1,38 +1,47 @@
1-
CREATE TABLE t1 (
2-
id INT PRIMARY KEY,
3-
x INT
4-
) ENGINE=InnoDB;
5-
INSERT INTO t1 VALUES (1, 10), (2, 20);
6-
connect con1,localhost,root,,;
7-
connect con2,localhost,root,,;
1+
SET @saved_print_all_deadlocks = @@GLOBAL.innodb_print_all_deadlocks;
2+
SET GLOBAL innodb_print_all_deadlocks = ON;
3+
CREATE TABLE t (a INT PRIMARY KEY) ENGINE=InnoDB;
4+
INSERT INTO t VALUES (1), (2);
5+
connect con1,localhost,root,,;
6+
connect con2,localhost,root,,;
87
connection con1;
98
BEGIN;
10-
UPDATE t1 SET x = 100 WHERE id = 1;
9+
SELECT * FROM t WHERE a = 1 FOR UPDATE;
10+
a
11+
1
1112
connection con2;
1213
BEGIN;
13-
UPDATE t1 SET x = 200 WHERE id = 2;
14-
UPDATE t1 SET x = 201 WHERE id = 1;
14+
SELECT * FROM t WHERE a = 2 FOR UPDATE;
15+
a
16+
2
17+
SET DEBUG_SYNC = 'lock_wait_start SIGNAL con2_waiting';
18+
SELECT * FROM t WHERE a = 1 FOR UPDATE;
1519
connection con1;
16-
Per-session deadlock info is available
17-
Message contains TRANSACTION keyword
18-
ROLLBACK;
19-
connection con2;
20-
ROLLBACK;
21-
INSERT INTO t1 VALUES (3, 30), (4, 40);
22-
connection con1;
23-
BEGIN;
24-
UPDATE t1 SET x = 300 WHERE id = 3;
25-
connection con2;
26-
BEGIN;
27-
UPDATE t1 SET x = 400 WHERE id = 4;
28-
UPDATE t1 SET x = 401 WHERE id = 3;
29-
connection con1;
30-
Second deadlock shows new transaction info
31-
Second deadlock does not contain old info
20+
SET DEBUG_SYNC = 'now WAIT_FOR con2_waiting';
21+
SET debug_dbug = '+d,innodb_deadlock_victim_self';
22+
SELECT * FROM t WHERE a = 2 FOR UPDATE;
23+
ERROR 40001: Deadlock found when trying to get lock; try restarting transaction
24+
SHOW WARNINGS;
25+
Level Code Message
26+
Note 1213 TIMESTAMP 0x75be845156c0
27+
*** (1) TRANSACTION:
28+
TRANSACTION TRX_ID, ACTIVE 0 sec starting index read
29+
mysql tables in use 1, locked 1
30+
LOCK WAIT 3 lock struct(s), heap size 1144, 2 row lock(s)
31+
MariaDB thread id TID, OS thread handle 129461124159168, query id QID localhost root Statistics
32+
SELECT * FROM t WHERE a = 2 FOR UPDATE
33+
*** WAITING FOR THIS LOCK TO BE GRANTED:
34+
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
35+
Record lock,
36+
Error 1213 Deadlock found when trying to get lock; try restarting transaction
3237
ROLLBACK;
3338
connection con2;
39+
a
40+
1
3441
ROLLBACK;
42+
connection default;
3543
disconnect con1;
3644
disconnect con2;
37-
connection default;
38-
DROP TABLE t1;
45+
SET DEBUG_SYNC = 'RESET';
46+
DROP TABLE t;
47+
SET GLOBAL innodb_print_all_deadlocks = @saved_print_all_deadlocks;
Lines changed: 23 additions & 81 deletions
Original file line numberDiff line numberDiff line change
@@ -1,106 +1,48 @@
1-
#
2-
# Test per-session deadlock information via SHOW WARNINGS
3-
#
4-
51
--source include/have_innodb.inc
2+
--source include/have_debug.inc
3+
--source include/have_debug_sync.inc
64

7-
CREATE TABLE t1 (
8-
id INT PRIMARY KEY,
9-
x INT
10-
) ENGINE=InnoDB;
11-
12-
INSERT INTO t1 VALUES (1, 10), (2, 20);
13-
14-
--connect (con1,localhost,root,,)
15-
--connect (con2,localhost,root,,)
16-
17-
--connection con1
18-
BEGIN;
19-
UPDATE t1 SET x = 100 WHERE id = 1;
20-
21-
--connection con2
22-
BEGIN;
23-
UPDATE t1 SET x = 200 WHERE id = 2;
24-
--send UPDATE t1 SET x = 201 WHERE id = 1
25-
26-
--connection con1
27-
--disable_abort_on_error
285
--disable_query_log
29-
--disable_result_log
30-
UPDATE t1 SET x = 101 WHERE id = 2;
31-
--enable_result_log
6+
call mtr.add_suppression("Transactions deadlock detected");
327
--enable_query_log
33-
--enable_abort_on_error
34-
--let $errno= $mysql_errno
35-
if ($errno != 1213) {
36-
--echo Expected ER_LOCK_DEADLOCK (1213), got $errno
37-
--die
38-
}
39-
40-
--let $msg1= query_get_value(SHOW WARNINGS, Message, 1)
41-
--let $msg2= query_get_value(SHOW WARNINGS, Message, 2)
42-
--let $deadlock_info= `SELECT IF(LENGTH('$msg1') > LENGTH('$msg2'), '$msg1', '$msg2')`
438

44-
if (`SELECT LENGTH('$deadlock_info') > 100`) {
45-
--echo Per-session deadlock info is available
46-
}
9+
SET @saved_print_all_deadlocks = @@GLOBAL.innodb_print_all_deadlocks;
10+
SET GLOBAL innodb_print_all_deadlocks = ON;
4711

48-
if (`SELECT '$deadlock_info' LIKE '%TRANSACTION%'`) {
49-
--echo Message contains TRANSACTION keyword
50-
}
12+
CREATE TABLE t (a INT PRIMARY KEY) ENGINE=InnoDB;
13+
INSERT INTO t VALUES (1), (2);
5114

52-
ROLLBACK;
53-
54-
--connection con2
55-
--reap
56-
ROLLBACK;
57-
58-
# Second deadlock to verify info is cleared between transactions
59-
INSERT INTO t1 VALUES (3, 30), (4, 40);
15+
--connect(con1,localhost,root,,)
16+
--connect(con2,localhost,root,,)
6017

6118
--connection con1
6219
BEGIN;
63-
UPDATE t1 SET x = 300 WHERE id = 3;
20+
SELECT * FROM t WHERE a = 1 FOR UPDATE;
6421

6522
--connection con2
6623
BEGIN;
67-
UPDATE t1 SET x = 400 WHERE id = 4;
68-
--send UPDATE t1 SET x = 401 WHERE id = 3
24+
SELECT * FROM t WHERE a = 2 FOR UPDATE;
25+
SET DEBUG_SYNC = 'lock_wait_start SIGNAL con2_waiting';
26+
--send SELECT * FROM t WHERE a = 1 FOR UPDATE
6927

7028
--connection con1
71-
--disable_abort_on_error
72-
--disable_query_log
73-
--disable_result_log
74-
UPDATE t1 SET x = 301 WHERE id = 4;
75-
--enable_result_log
76-
--enable_query_log
77-
--enable_abort_on_error
78-
--let $errno= $mysql_errno
79-
if ($errno != 1213) {
80-
--echo Expected ER_LOCK_DEADLOCK (1213), got $errno
81-
--die
82-
}
83-
84-
--let $msg1= query_get_value(SHOW WARNINGS, Message, 1)
85-
--let $msg2= query_get_value(SHOW WARNINGS, Message, 2)
86-
--let $deadlock_info= `SELECT IF(LENGTH('$msg1') > LENGTH('$msg2'), '$msg1', '$msg2')`
87-
88-
if (`SELECT '$deadlock_info' LIKE '%id = 3%' OR '$deadlock_info' LIKE '%id = 4%'`) {
89-
--echo Second deadlock shows new transaction info
90-
}
29+
SET DEBUG_SYNC = 'now WAIT_FOR con2_waiting';
30+
SET debug_dbug = '+d,innodb_deadlock_victim_self';
31+
--error ER_LOCK_DEADLOCK
32+
SELECT * FROM t WHERE a = 2 FOR UPDATE;
9133

92-
if (`SELECT '$deadlock_info' NOT LIKE '%id = 1%'`) {
93-
--echo Second deadlock does not contain old info
94-
}
34+
--replace_regex /[0-9]{4}-[0-9]{2}-[0-9]{2} [0-9]{2}:[0-9]{2}:[0-9]{2}/TIMESTAMP/ /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/
35+
SHOW WARNINGS;
9536

9637
ROLLBACK;
9738

9839
--connection con2
9940
--reap
10041
ROLLBACK;
10142

43+
--connection default
10244
--disconnect con1
10345
--disconnect con2
104-
--connection default
105-
106-
DROP TABLE t1;
46+
SET DEBUG_SYNC = 'RESET';
47+
DROP TABLE t;
48+
SET GLOBAL innodb_print_all_deadlocks = @saved_print_all_deadlocks;

storage/innobase/handler/ha_innodb.cc

Lines changed: 1 addition & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -2104,17 +2104,8 @@ convert_error_code_to_mysql(
21042104
/* Since we rolled back the whole transaction, the
21052105
cached binlog must be emptied. */
21062106
innodb_transaction_abort(thd, true, error);
2107-
if (error == DB_DEADLOCK) {
2108-
trx_t* trx = thd_to_trx(thd);
2109-
if (trx && trx->lock.deadlock_info
2110-
&& trx->lock.deadlock_info_len > 0) {
2111-
push_warning_printf(thd,
2112-
Sql_condition::WARN_LEVEL_NOTE,
2113-
ER_LOCK_DEADLOCK,
2114-
"%s", trx->lock.deadlock_info);
2115-
}
2107+
if (error == DB_DEADLOCK)
21162108
return HA_ERR_LOCK_DEADLOCK;
2117-
}
21182109
return HA_ERR_RECORD_CHANGED;
21192110

21202111
case DB_LOCK_WAIT_TIMEOUT:

storage/innobase/include/trx0trx.h

Lines changed: 0 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -61,15 +61,6 @@ trx_set_detailed_error_from_file(
6161
trx_t* trx, /*!< in: transaction struct */
6262
FILE* file); /*!< in: file to read message from */
6363

64-
/** Set the deadlock information for a transaction from a file.
65-
@param trx transaction that was chosen as deadlock victim
66-
@param file file containing the deadlock information */
67-
void trx_set_deadlock_info_from_file(trx_t *trx, FILE *file);
68-
69-
/** Clear the deadlock information for a transaction.
70-
@param trx transaction */
71-
void trx_clear_deadlock_info(trx_t *trx);
72-
7364
/****************************************************************//**
7465
Retrieves the error_info field from a trx.
7566
@return the error info */
@@ -397,11 +388,6 @@ struct trx_lock_t
397388
/** number of lock_rec_set_nth_bit() calls since the start of transaction;
398389
protected by lock_sys.is_writer() or trx->mutex_is_owner(). */
399390
ulint set_nth_bit_calls;
400-
401-
/** Deadlock information for SHOW WARNINGS; protected by lock_sys.wait_mutex */
402-
char *deadlock_info;
403-
size_t deadlock_info_len;
404-
size_t deadlock_info_size;
405391
};
406392

407393
/** Logical first modification time of a table in a transaction */

storage/innobase/lock/lock0lock.cc

Lines changed: 30 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -7182,6 +7182,8 @@ and less modified rows. Bit 0 is used to prefer orig_trx in case of a tie.
71827182
static const char rollback_msg[]= "*** WE ROLL BACK TRANSACTION (%u)\n";
71837183
char buf[9 + sizeof rollback_msg];
71847184
trx_t *victim= nullptr;
7185+
char *deadlock_info= nullptr;
7186+
size_t deadlock_info_len= 0;
71857187

71867188
/* Here, lock elision does not make sense, because
71877189
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.
73047306
}
73057307
snprintf(buf, sizeof buf, rollback_msg, victim_pos);
73067308
print(buf);
7307-
trx_set_deadlock_info_from_file(victim, lock_latest_err_file);
7309+
7310+
if (srv_print_all_deadlocks)
7311+
{
7312+
rewind(lock_latest_err_file);
7313+
fseek(lock_latest_err_file, 0, SEEK_END);
7314+
long file_size= ftell(lock_latest_err_file);
7315+
if (file_size > 0)
7316+
{
7317+
deadlock_info= static_cast<char*>(ut_malloc_nokey(
7318+
static_cast<size_t>(file_size) + 1));
7319+
if (deadlock_info)
7320+
{
7321+
rewind(lock_latest_err_file);
7322+
deadlock_info_len= fread(deadlock_info, 1,
7323+
static_cast<size_t>(file_size),
7324+
lock_latest_err_file);
7325+
deadlock_info[deadlock_info_len]= '\0';
7326+
}
7327+
}
7328+
}
73087329
}
73097330

73107331
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.
73207341
func_exit:
73217342
if (current_trx)
73227343
lock_sys.wr_unlock();
7344+
7345+
if (deadlock_info && victim == trx && trx->mysql_thd)
7346+
{
7347+
push_warning_printf(trx->mysql_thd, Sql_condition::WARN_LEVEL_NOTE,
7348+
ER_LOCK_DEADLOCK, "%s", deadlock_info);
7349+
}
7350+
ut_free(deadlock_info);
7351+
73237352
return victim;
73247353
}
73257354
}

storage/innobase/trx/trx0trx.cc

Lines changed: 0 additions & 51 deletions
Original file line numberDiff line numberDiff line change
@@ -97,46 +97,6 @@ trx_set_detailed_error_from_file(
9797
os_file_read_string(file, trx->detailed_error, MAX_DETAILED_ERROR_LEN);
9898
}
9999

100-
/** Set the deadlock information for a transaction from a file.
101-
@param trx transaction that was chosen as deadlock victim
102-
@param file file containing the deadlock information */
103-
void trx_set_deadlock_info_from_file(trx_t *trx, FILE *file)
104-
{
105-
mysql_mutex_assert_owner(&lock_sys.wait_mutex);
106-
107-
rewind(file);
108-
fseek(file, 0, SEEK_END);
109-
long file_size = ftell(file);
110-
if (file_size <= 0) {
111-
return;
112-
}
113-
114-
size_t needed_size = static_cast<size_t>(file_size) + 1;
115-
116-
if (needed_size > trx->lock.deadlock_info_size) {
117-
ut_free(trx->lock.deadlock_info);
118-
trx->lock.deadlock_info = static_cast<char*>(
119-
ut_malloc_nokey(needed_size));
120-
trx->lock.deadlock_info_size = needed_size;
121-
}
122-
123-
rewind(file);
124-
size_t read_len = fread(trx->lock.deadlock_info, 1,
125-
static_cast<size_t>(file_size), file);
126-
trx->lock.deadlock_info[read_len] = '\0';
127-
trx->lock.deadlock_info_len = read_len;
128-
}
129-
130-
/** Clear the deadlock information for a transaction.
131-
@param trx transaction */
132-
void trx_clear_deadlock_info(trx_t *trx)
133-
{
134-
if (trx->lock.deadlock_info) {
135-
trx->lock.deadlock_info[0] = '\0';
136-
trx->lock.deadlock_info_len = 0;
137-
}
138-
}
139-
140100
/********************************************************************//**
141101
Initialize transaction object.
142102
@param trx trx to initialize */
@@ -232,10 +192,6 @@ struct TrxFactory {
232192
trx->detailed_error = reinterpret_cast<char*>(
233193
ut_zalloc_nokey(MAX_DETAILED_ERROR_LEN));
234194

235-
trx->lock.deadlock_info = nullptr;
236-
trx->lock.deadlock_info_len = 0;
237-
trx->lock.deadlock_info_size = 0;
238-
239195
trx->lock.lock_heap = mem_heap_create_typed(
240196
1024, MEM_HEAP_FOR_LOCK_HEAP);
241197
pthread_cond_init(&trx->lock.cond, nullptr);
@@ -282,11 +238,6 @@ struct TrxFactory {
282238

283239
ut_free(trx->detailed_error);
284240

285-
ut_free(trx->lock.deadlock_info);
286-
trx->lock.deadlock_info = nullptr;
287-
trx->lock.deadlock_info_len = 0;
288-
trx->lock.deadlock_info_size = 0;
289-
290241
trx->mutex_destroy();
291242

292243
trx->autoinc_locks.~small_vector();
@@ -445,7 +396,6 @@ void trx_t::free()
445396
trx_sys.deregister_trx(this);
446397
check_unique_secondary= true;
447398
check_foreigns= true;
448-
trx_clear_deadlock_info(this);
449399
assert_freed();
450400
trx_sys.rw_trx_hash.put_pins(this);
451401
mysql_thd= nullptr;
@@ -960,7 +910,6 @@ trx_start_low(
960910
ut_ad(trx->rsegs.m_noredo.rseg == NULL);
961911
ut_ad(trx_state_eq(trx, TRX_STATE_NOT_STARTED));
962912
ut_ad(UT_LIST_GET_LEN(trx->lock.trx_locks) == 0);
963-
trx_clear_deadlock_info(trx);
964913

965914
/* Check whether it is an AUTOCOMMIT SELECT */
966915
if (const THD* thd = trx->mysql_thd) {

0 commit comments

Comments
 (0)