Bug #102791 A deadlock occurs one innodb tables between unrelated rows
Submitted: 3 Mar 5:03 Modified: 4 Mar 16:02
Reporter: HULONG CUI Email Updates:
Status: Not a Bug Impact on me:
None 
Category:MySQL Server Severity:S3 (Non-critical)
Version:5.7.30 GA OS:Any
Assigned to: CPU Architecture:Any

[3 Mar 5:03] HULONG CUI
Description:
1)
I have 5.7.30-log MySQL Community Server (GPL)
and innodb table  have same data。table structure is as follows:

CREATE TABLE `process_context` (
  `id` bigint(19) unsigned NOT NULL AUTO_INCREMENT COMMENT 'id',
  `code` varchar(100) DEFAULT NULL COMMENT '编码',
  `create_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP COMMENT '创建时间',
  `update_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP COMMENT '最后更新时间',
  `creator` varchar(50) DEFAULT NULL,
  `last_updator` varchar(50) DEFAULT NULL,
  `OPTLOCK` bigint(10) DEFAULT '0',
  `SID` varchar(255) DEFAULT NULL,
  `KEY` varchar(255) DEFAULT NULL,
  `VALUE` varchar(2000) DEFAULT NULL,
  `SOURCE` varchar(255) DEFAULT NULL,
  PRIMARY KEY (`id`),
  KEY `idx_pc_sid` (`SID`)
) ENGINE=InnoDB AUTO_INCREMENT=293477010 DEFAULT CHARSET=utf8mb4 
####
2)
shell>show variables like '%lock%';
+-----------------------------------------+----------------------+
| Variable_name                           | Value                |
+-----------------------------------------+----------------------+
| innodb_autoinc_lock_mode                | 1                    |
| innodb_deadlock_detect                  | ON                   |
| innodb_lock_wait_timeout                | 5                    |
+-----------------------------------------+----------------------+
####

3)
------------------------
LATEST DETECTED DEADLOCK
------------------------
2021-03-03 11:53:37 0x7f2f6dc29700
*** (1) TRANSACTION:
TRANSACTION 688773626, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 5 lock struct(s), heap size 1136, 20 row lock(s), undo log entries 39
MySQL thread id 66549552, OS thread handle 139841679496960, query id 7298242270 10.8.81.195 usr_test updating
DELETE FROM `PROCESS_CONTEXT`
        WHERE ID = 193275447
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 36 page no 13097 n bits 144 index PRIMARY of table `test`.`process_context` trx id 688773626 lock_mode X locks rec but not gap waiting
Record lock, heap no 38 PHYSICAL RECORD: n_fields 13; compact format; info bits 0
 0: len 8; hex 000000000b852637; asc       &7;;
 1: len 6; hex 0000290dd9f8; asc   )   ;;
 2: len 7; hex 500000002c103a; asc P   , :;;
 3: SQL NULL;
 4: len 4; hex 603f0811; asc `?  ;;
 5: len 4; hex 603f0841; asc `? A;;
 6: SQL NULL;
 7: SQL NULL;
 8: len 8; hex 8000000000000000; asc         ;;
 9: len 30; hex 616931356537313830633061353434366630623662373333656130343238; asc ai15e7180c0a5446f0b6b733ea0428; (total 34 bytes);
 10: len 19; hex 73756250726f6365737356657273696f6e4964; asc subProcessVersionId;;
 11: len 4; hex 32343332; asc 2432;;
 12: len 4; hex 43414c4c; asc CALL;;

*** (2) TRANSACTION:
TRANSACTION 688773624, ACTIVE 0 sec starting index read, thread declared inside InnoDB 5000
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1136, 4 row lock(s), undo log entries 3
MySQL thread id 66563667, OS thread handle 139841681659648, query id 7298242377 10.8.81.195 usr_test updating
UPDATE `PROCESS_CONTEXT` SET
        `SID` = 'ai15e7180c0a5446f0b6b733ea0428ee13',
`KEY` = 'currentNodeId',
`VALUE` = '1683',
`SOURCE` = 'CALL',
`LAST_UPDATOR` = null,
`CODE` = null
        WHERE
        ID = 193274884
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 36 page no 13097 n bits 144 index PRIMARY of table `test`.`process_context` trx id 688773624 lock_mode X locks rec but not gap
Record lock, heap no 38 PHYSICAL RECORD: n_fields 13; compact format; info bits 0
 0: len 8; hex 000000000b852637; asc       &7;;
 1: len 6; hex 0000290dd9f8; asc   )   ;;
 2: len 7; hex 500000002c103a; asc P   , :;;
 3: SQL NULL;
 4: len 4; hex 603f0811; asc `?  ;;
 5: len 4; hex 603f0841; asc `? A;;
 6: SQL NULL;
 7: SQL NULL;
 8: len 8; hex 8000000000000000; asc         ;;
 9: len 30; hex 616931356537313830633061353434366630623662373333656130343238; asc ai15e7180c0a5446f0b6b733ea0428; (total 34 bytes);
 10: len 19; hex 73756250726f6365737356657273696f6e4964; asc subProcessVersionId;;
 11: len 4; hex 32343332; asc 2432;;
 12: len 4; hex 43414c4c; asc CALL;;

Record lock, heap no 39 PHYSICAL RECORD: n_fields 13; compact format; info bits 0
 0: len 8; hex 000000000b852638; asc       &8;;
 1: len 6; hex 0000290dd9f8; asc   )   ;;
 2: len 7; hex 500000002c1065; asc P   , e;;
 3: SQL NULL;
 4: len 4; hex 603f0811; asc `?  ;;
 5: len 4; hex 603f0841; asc `? A;;
 6: SQL NULL;
 7: SQL NULL;
 8: len 8; hex 8000000000000000; asc         ;;
 9: len 30; hex 616931356537313830633061353434366630623662373333656130343238; asc ai15e7180c0a5446f0b6b733ea0428; (total 34 bytes);
 10: len 14; hex 73756250726f636573734e616d65; asc subProcessName;;
 11: len 15; hex e6bba1e6848fe5baa6e8af84e4bbb7; asc                ;;
 12: len 4; hex 43414c4c; asc CALL;;

Record lock, heap no 73 PHYSICAL RECORD: n_fields 13; compact format; info bits 0
 0: len 8; hex 000000000b852639; asc       &9;;
 1: len 6; hex 0000290dd9f8; asc   )   ;;
 2: len 7; hex 500000002c109b; asc P   ,  ;;
 3: SQL NULL;
 4: len 4; hex 603f0811; asc `?  ;;
 5: len 4; hex 603f0841; asc `? A;;
 6: SQL NULL;
 7: SQL NULL;
 8: len 8; hex 8000000000000000; asc         ;;
 9: len 30; hex 616931356537313830633061353434366630623662373333656130343238; asc ai15e7180c0a5446f0b6b733ea0428; (total 34 bytes);
 10: len 12; hex 706172656e744e6f64654964; asc parentNodeId;;
 11: len 4; hex 31373138; asc 1718;;
 12: len 4; hex 43414c4c; asc CALL;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 36 page no 13074 n bits 144 index PRIMARY of table `test`.`process_context` trx id 688773624 lock_mode X locks rec but not gap waiting
Record lock, heap no 20 PHYSICAL RECORD: n_fields 13; compact format; info bits 32
 0: len 8; hex 000000000b852404; asc       $ ;;
 1: len 6; hex 0000290dd9fa; asc   )   ;;
 2: len 7; hex 520000006102fb; asc R   a  ;;
 3: SQL NULL;
 4: len 4; hex 603f0809; asc `?  ;;
 5: len 4; hex 603f0837; asc `? 7;;
 6: SQL NULL;
 7: SQL NULL;
 8: len 8; hex 8000000000000000; asc         ;;
 9: len 30; hex 616931356537313830633061353434366630623662373333656130343238; asc ai15e7180c0a5446f0b6b733ea0428; (total 34 bytes);
 10: len 13; hex 63757272656e744e6f64654964; asc currentNodeId;;
 11: len 3; hex 333332; asc 332;;
 12: len 4; hex 43414c4c; asc CALL;;

*** WE ROLL BACK TRANSACTION (2)

3)####Problem
SQL1: DELETE FROM `PROCESS_CONTEXT`  
      WHERE ID = 193275447
SQL2: UPDATE `PROCESS_CONTEXT` SET  `SID` = 'aaaaa',`KEY` = 'currentNodeId',`VALUE` = '1683', `SOURCE` = 'CALL',`LAST_UPDATOR` = null,`CODE` = null  
      WHERE         ID = 193274884
ID is primary key .
this is row record lock .
two sql not have same condition, but have  deallock.
I see that deadlocks should not occur between different rows。

How to repeat:
cant't replace
[3 Mar 15:57] MySQL Verification Team
Hi Mr. jacky,

Thank you for your bug report.

However, this is not a bug.

When you are using transactional database systems, with multiple connections running, getting a deadlock is a proof that MySQL with InnoDB storage engine, functions absolutely correctly.

Deadlocks happen when one thread is holding lock on row A , while asking for a lock on row B. In the same time another thread is holding a lock on the row B, while asking for a lock on the row A. Hence , a deadlock.

Standard defines that in these cases all involved transactions (and there can be N of those in a graph) should be immediately rolled back. It is then on the application developer to resubmit those transactions again.

Hence, not a bug.
[4 Mar 7:27] HULONG CUI
Understand the  deadlocks occur,but two session sql not have same condition.
  sql1: DELETE FROM `PROCESS_CONTEXT`    WHERE ID = 193275447
  sql2: UPDATE `PROCESS_CONTEXT` SET   ...      WHERE         ID = 193274884

why sql2 is RECORD LOCKS space id 36 page no 13097 n bits 144
[4 Mar 13:23] MySQL Verification Team
Hi Mr. jacky,

Conditions are not what is important. The relevant info is that both queries are accessing the same record. For the further diagnosis , you should look carefully at the EXPLAIN of the DMLs.
[4 Mar 16:02] HULONG CUI
1) explain DELETE FROM `PROCESS_CONTEXT`         WHERE ID = 193275447;
+----+-------------+-----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+
| id | select_type | table           | partitions | type  | possible_keys | key     | key_len | ref   | rows | filtered | Extra       |
+----+-------------+-----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+
|  1 | DELETE      | PROCESS_CONTEXT | NULL       | range | PRIMARY       | PRIMARY | 8       | const |    1 |   100.00 | Using where |
+----+-------------+-----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+

2)explain UPDATE `PROCESS_CONTEXT` SET          `SID` = 'ai15e7180c0a5446f0b6b733ea0428ee13', `KEY` = 'currentNodeId', `VALUE` = '1683', `SOURCE` = 'CALL', `LAST_UPDATOR` = null, `CODE` = null         WHERE         ID = 193274884;
+----+-------------+-----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+
| id | select_type | table           | partitions | type  | possible_keys | key     | key_len | ref   | rows | filtered | Extra       |
+----+-------------+-----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+
|  1 | UPDATE      | PROCESS_CONTEXT | NULL       | range | PRIMARY       | PRIMARY | 8       | const |    1 |   100.00 | Using where |
+----+-------------+-----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+
[4 Mar 16:02] HULONG CUI
1) explain DELETE FROM `PROCESS_CONTEXT`         WHERE ID = 193275447;
+----+-------------+-----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+
| id | select_type | table           | partitions | type  | possible_keys | key     | key_len | ref   | rows | filtered | Extra       |
+----+-------------+-----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+
|  1 | DELETE      | PROCESS_CONTEXT | NULL       | range | PRIMARY       | PRIMARY | 8       | const |    1 |   100.00 | Using where |
+----+-------------+-----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+

2)explain UPDATE `PROCESS_CONTEXT` SET          `SID` = 'ai15e7180c0a5446f0b6b733ea0428ee13', `KEY` = 'currentNodeId', `VALUE` = '1683', `SOURCE` = 'CALL', `LAST_UPDATOR` = null, `CODE` = null         WHERE         ID = 193274884;
+----+-------------+-----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+
| id | select_type | table           | partitions | type  | possible_keys | key     | key_len | ref   | rows | filtered | Extra       |
+----+-------------+-----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+
|  1 | UPDATE      | PROCESS_CONTEXT | NULL       | range | PRIMARY       | PRIMARY | 8       | const |    1 |   100.00 | Using where |
+----+-------------+-----------------+------------+-------+---------------+---------+---------+-------+------+----------+-------------+
[5 Mar 13:13] MySQL Verification Team
We're sorry, but the bug system is not the appropriate forum for asking help on using MySQL products. Your problem is not the result of a bug.

For details on getting support for MySQL products see http://www.mysql.com/support/
You can also check our forums (free) at http://forums.mysql.com/

Thank you for your interest in MySQL.