Navigating MySQL Isolation Levels and Deadlock Mysteries

Introduction

Prior to my journey with Hevodata, I had studied various isolation levels in MySQL mainly for interview preps. Those days, it was all in the books. Yet, at Hevodata, these aren’t just topics; they are daily hurdles.

I distinctly recall an on-call night, where MySQL froze for a distressing five minutes. The fallout? A service disruption in the US region of Hevodata, detailed here. With Hevodata’s deep reliance on MySQL, any hiccup in its function sets off a ripple effect.

The graph following this portrays how the average active sessions dropped to zero, indicating a lack of activity or responsiveness in the database. This cessation suggests that MySQL experienced a freeze or halt in its operations. Such behavior could be attributed to various causes, including system errors, resource exhaustion, or software bugs.

database load AAS

Finding the issue

Our deep dive into the MySQL error logs flagged a particularly bulky file.

mysql error log files

A closer peek revealed repetitive error patterns like:

2022-09-14T06:31:26.175857Z 494202 [Note] InnoDB: Transactions deadlock detected, dumping detailed information.
2022-09-14T06:31:26.175874Z 494202 [Note] InnoDB: 

*** (1) TRANSACTION:

TRANSACTION 35189549872, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s)
MySQL thread id 493231, OS thread handle 22606095234816, query id 10526067707 [MASKED_IP] root Searching rows for update
<query>
2022-09-14T06:31:26.175907Z 494202 [Note] InnoDB: *** (1) WAITING FOR THIS LOCK TO BE GRANTED:

RECORD LOCKS space id 1604 page no 126851 n bits 480 index <index> of table  <table_name> trx id 35189549872 lock_mode X waiting
Record lock, heap no 405 PHYSICAL RECORD: n_fields 4; compact format; info bits 32
 0: len 8; hex 8000000000001e71; asc        q;;
 1: len 8; hex 55504c4f41444544; asc UPLOADED;;
 2: len 4; hex 8000006a; asc    j;;
 3: len 8; hex 8000000014bc61a4; asc       a ;;

2022-09-14T06:31:26.176128Z 494202 [Note] InnoDB: 

*** (2) TRANSACTION:

TRANSACTION 35189549871, ACTIVE 0 sec updating or deleting
mysql tables in use 1, locked 1
15 lock struct(s), heap size 1136, 80 row lock(s), undo log entries 39
MySQL thread id 494202, OS thread handle 22579685799680, query id 10526067700 [MASKED_IP] root updating
<query>
2022-09-14T06:31:26.176206Z 494202 [Note] InnoDB: *** (2) HOLDS THE LOCK(S):

RECORD LOCKS space id 1604 page no 126851 n bits 480 index <index> of table  <table_name> trx id 35189549871 lock_mode X locks rec but not gap
Record lock, heap no 405 PHYSICAL RECORD: n_fields 4; compact format; info bits 32
 0: len 8; hex 8000000000001e71; asc        q;;
 1: len 8; hex 55504c4f41444544; asc UPLOADED;;
 2: len 4; hex 8000006a; asc    j;;
 3: len 8; hex 8000000014bc61a4; asc       a ;;

2022-09-14T06:31:26.176405Z 494202 [Note] InnoDB: *** (2) WAITING FOR THIS LOCK TO BE GRANTED:

RECORD LOCKS space id 1604 page no 126851 n bits 480 index <index> of table  <table_name> trx id 35189549871 lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 405 PHYSICAL RECORD: n_fields 4; compact format; info bits 32
 0: len 8; hex 8000000000001e71; asc        q;;
 1: len 8; hex 55504c4f41444544; asc UPLOADED;;
 2: len 4; hex 8000006a; asc    j;;
 3: len 8; hex 8000000014bc61a4; asc       a ;;

2022-09-14T06:31:26.176614Z 494202 [Note] InnoDB: *** WE ROLL BACK TRANSACTION (1)

What does it say?

This MySQL error log is detailing a deadlock situation that occurred within the InnoDB storage engine. Here’s a step-by-step breakdown:

Deadlock Detection:

This initial line indicates that InnoDB detected a deadlock, which is a situation where two or more transactions are waiting for locks in a circular manner, preventing each other from continuing.

Transaction 1 Details:

The transaction with the ID 35189549872 started reading an index but is currently in a waiting state.

• It has locked 1 MySQL table and is waiting for 3 lock structures.
• The MySQL thread associated with this transaction has an ID 493231.

Locks Transaction 1 is Waiting For:

• Transaction 1 is waiting for a lock (lock_mode X) on a record in a table (<table_name>) indexed by <index>.

Transaction 2 Details:

• The transaction with the ID 35189549871 is actively updating or deleting records.
• It has locked 1 MySQL table, holding 15 lock structures, with 80 row locks in total.
• The MySQL thread associated with this transaction has an ID 494202.

Locks Transaction 2 Holds:

• Transaction 2 currently holds a lock (lock_mode X locks rec but not gap) on the same record in the <table_name> table. This means it has an exclusive lock on a specific record, but not on the "gap" before the record, allowing for other records to be inserted before this one.

Locks Transaction 2 is Waiting For:

• Transaction 2 is also waiting for a different type of lock (lock_mode X locks gap before rec insert intention waiting) on the same record. This type of lock indicates that Transaction 2 intends to insert a new record before the current one, but it's waiting for the necessary lock to do so.

Resolution:

• To resolve the deadlock, InnoDB decided to roll back Transaction 1, allowing Transaction 2 to proceed. This is a common way database systems resolve deadlocks, by forcibly aborting one transaction to free up locks for others.

What was the cause?

We discovered that these deadlocks were emerging on a table with composite indexes, especially when multiple queries targeted the same index simultaneously.

Let’s consider a hypothetical table structured as follows:

|  row  |  city  | col1  |  col2  |  col3 |
|-------|--------|-------|--------|-------|
|   1   |  Goa   |  1    |   a    |   z   |
|   2   |  Gaya  |  1    |   a    |   z   |
|   3   |  Siwan |  1    |   b    |   z   |
|   4   |  Patna |  1    |   b    |   z   |

The index is on (col1, col3)

• Query 1:

update <table> set city = "mumbai" where col1 = 1, col2 = a and col3 = z

• Query 2:

update <table> set city = "mumbai" where col1 = 1, col2 = b and col3 = z

Under normal circumstances, the first query should lock rows 1 & 2, while the second one would lock rows 3 & 4.

However, here, query 1 tried to lock rows 3 & 4 (after taking lock on row 1 & 2), while query 2 was attempting to lock rows 1 & 2 (after taking lock on row 3 & 4). When both queries are executed simultaneously, the outcome is a deadlock.

This situation left us scratching our heads.

The baffling part was why Query 1 eyed rows 3 & 4 and vice-versa for Query 2. The answer lies in understanding MySQL’s transaction isolation level.

This level dictates how the changes in an ongoing transaction impact the data observed by other simultaneous transactions. For instance, if value x toggles from 1 to 2 to 3 in transaction T1, what should transaction T2 view for x while T1 is still underway?

MySQL offers four isolation levels:

1. Read Uncommitted:
   At the Uncommitted Read level, transactions have minimal isolation from one another, meaning there are no locks in place. This level permits “dirty reads”, where a transaction can view changes that another transaction has made but not yet committed.
2. Read Committed:
   The Read Committed level prevents dirty reads but allows for Non-repeatable reads. In this context, a single transaction should consistently retrieve identical data. However, due to changes by a concurrently committing transaction, non-repeatable reads might fetch different results.
3. Repeatable Read:
   The Repeatable Read level ensures the avoidance of non-repeatable reads. This level is MySQL’s default setting. It was this level that caused the problem in our scenario.
4. Serializable:
   Representing the highest form of isolation, the Serializable level fully segregates the impact of one transaction from any other.

| Isolation Level   | Dirty read | Non-repeatable read | Phantom Read |
|-------------------|------------|---------------------|--------------|
| READ UNCOMMITTED  | ✅         | ✅                  | ✅           |
| READ COMMITTED    | ❌         | ✅                  | ✅           |
| REPEATABLE READ   | ❌         | ❌                  | ✅           |
| SERIALIZABLE      | ❌         | ❌                  | ❌           |

As the isolation level increases in MySQL, the likelihood of encountering a deadlock also rises.

Since the default isolation level in MySQL is Repeatable Read, it avoids non-repeatable read using locks. In this case, the database server locks all rows examined (not just fetched) for the duration of the transaction.

In our scenario, since all four rows were fetched using the index, MySQL tried to lock all the rows to prevent non-repeatable reads.

Implementing a Fix

Considering our table’s write-intensive nature and the UI’s reading requirements, we deemed repeatable reads acceptable. We then scaled down the isolation level to READ COMMITTED. Using jdbi, the modification looked like:

jdbi.inTransaction(
        TransactionIsolationLevel.READ_COMMITTED,
        handle ->
            handle
                    .createUpdate(..)
)

source: link

After implementing this change, our production environment was thankfully devoid of any deadlocks.

deadlock_table

Additional References

• MySQL Bug Report