[MDEV-33798] ROW base optimistic deadlock with concurrent writes on same table row and multi domain - Jira

XML

Word

Printable

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Fixed
Affects Version/s: 10.11.7
Fix Version/s: 10.6.18, 10.11.8, 11.0.6, 11.1.5, 11.2.4, 11.4.2
Component/s: Replication
Labels:
None

Description

Following Brandon advice to open a ticket after Zulip (the initial conversation was done via DM, but an official Zulip topic has been created for this since with more details (e.g. variables, show slave status, etc): link)

Issue:
Replication sql thread stopped in optimistic but ok in conservative

Context:
Concurrent writes on 2 tables with same name but different DB

Workaround
Moving to conservative fixed the replication sql thread regular stop

select * from api_check;

+----+---------------------+

| id | last_check |

+----+---------------------+

| 1 | 2024-03-29 09:49:10 |

+----+---------------------+

1 row in set (0.001 sec)

MariaDB [mixr_user]> show create table api_check;

+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+

| Table | Create Table |

+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+

| api_check | CREATE TABLE api_check (

id tinyint(3) unsigned NOT NULL,

last_check datetime NOT NULL DEFAULT '0000-00-00 00:00:00',

PRIMARY KEY (id)

) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci |

+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+

1 row in set (0.000 sec)

Processlist:

| 3455587 | system user | | wpmixrgen | Slave_worker | 20 | Update_rows_log_event::find_row(-1) on table api_check | update api_check set last_check = '2024-03-29 00:34:28' where id = 1 | 0.000 |

| 3455588 | system user | | mixr_user | Slave_worker | 20 | Update_rows_log_event::find_row(-1) on table api_check | update api_check set last_check = '2024-03-29 00:34:27' where id = 1 | 0.000 |

No views in the middle

MariaDB [wpmixrgen]> show full tables like 'api_check';

+---------------------------------+------------+

| Tables_in_wpmixrgen (api_check) | Table_type |

+---------------------------------+------------+

| api_check                       | BASE TABLE |

+---------------------------------+------------+

1 row in set (0.002 sec)

Database changed

MariaDB [mixr_user]> show full tables like 'api_check';

+---------------------------------+------------+

| Tables_in_mixr_user (api_check) | Table_type |

+---------------------------------+------------+

| api_check                       | BASE TABLE |

+---------------------------------+------------+

1 row in set (0.001 sec)

Bonus:
Stop all slaves could stale when in such deadlock

| 3460647 | root | 10.48.0.1:55828 | NULL | Killed | 186 | Killing slave | stop all slaves

Metadata lock state:

+-----------+----------------------+---------------+---------------------+--------------+----------------+

| THREAD_ID | LOCK_MODE | LOCK_DURATION | LOCK_TYPE | TABLE_SCHEMA | TABLE_NAME |

+-----------+----------------------+---------------+---------------------+--------------+----------------+

| 3470443 | MDL_BACKUP_TRANS_DML | NULL | Backup lock | | |

| 3470438 | MDL_BACKUP_TRANS_DML | NULL | Backup lock | | |

| 3470445 | MDL_SHARED_WRITE | NULL | Table metadata lock | mixr_user | api_check |

| 3470438 | MDL_SHARED_WRITE | NULL | Table metadata lock | mixr_user | api_check |

| 3470442 | MDL_SHARED_WRITE | NULL | Table metadata lock | wpmixrgen | api_check |

| 3470443 | MDL_SHARED_WRITE | NULL | Table metadata lock | wpmixrgen | api_check |

| 3470442 | MDL_SHARED_WRITE | NULL | Table metadata lock | mysql | gtid_slave_pos |

| 3470445 | MDL_SHARED_WRITE | NULL | Table metadata lock | mysql | gtid_slave_pos |

| 3470444 | MDL_SHARED_WRITE | NULL | Table metadata lock | mysql | gtid_slave_pos |

| 3470444 | MDL_SHARED_WRITE | NULL | Table metadata lock | wpmixrgen | schedule_log |

+-----------+----------------------+---------------+---------------------+--------------+----------------+

10 rows in set (0.001 sec)

INNODB_TRX:

trx_id: 2669046603

trx_state: LOCK WAIT

trx_started: 2024-03-29 15:48:18

trx_requested_lock_id: 2669046603:27938:3:2

trx_wait_started: 2024-03-29 15:48:18

trx_weight: 2

trx_mysql_thread_id: 3470443

trx_query: update api_check set last_check = '2024-03-29 04:44:09' where id = 1

trx_operation_state: starting index read

trx_tables_in_use: 1

trx_tables_locked: 1

trx_lock_structs: 2

trx_lock_memory_bytes: 1128

trx_rows_locked: 1

trx_rows_modified: 0

trx_concurrency_tickets: 0

trx_isolation_level: REPEATABLE READ

trx_unique_checks: 1

trx_foreign_key_checks: 1

trx_last_foreign_key_error: NULL

trx_is_read_only: 0

trx_autocommit_non_locking: 0

---

trx_id: 2669046602

                 trx_state: LOCK WAIT

               trx_started: 2024-03-29 15:48:18

     trx_requested_lock_id: 2669046602:27887:3:2

          trx_wait_started: 2024-03-29 15:48:18

                trx_weight: 2

       trx_mysql_thread_id: 3470438

                 trx_query: update `api_check` set `last_check` = '2024-03-29 04:44:13' where `id` = 1

       trx_operation_state: starting index read

         trx_tables_in_use: 1

         trx_tables_locked: 1

          trx_lock_structs: 2

     trx_lock_memory_bytes: 1128

           trx_rows_locked: 1

         trx_rows_modified: 0

   trx_concurrency_tickets: 0

       trx_isolation_level: REPEATABLE READ

         trx_unique_checks: 1

    trx_foreign_key_checks: 1

trx_last_foreign_key_error: NULL

          trx_is_read_only: 0

trx_autocommit_non_locking: 0

InnoDB Status:

MariaDB [information_schema]> show engine innodb status\G

*************************** 1. row ***************************

  Type: InnoDB

  Name:

Status:

=====================================

2024-03-29 15:51:38 0x7f696c107640 INNODB MONITOR OUTPUT

=====================================

Per second averages calculated from the last 1 seconds

-----------------

BACKGROUND THREAD

-----------------

srv_master_thread loops: 2 srv_active, 0 srv_shutdown, 3704919 srv_idle

srv_master_thread log flush and writes: 3704803

----------

SEMAPHORES

----------

------------

TRANSACTIONS

------------

Trx id counter 2669046610

Purge done for trx's n:o < 2669046590 undo n:o < 0 state: running

History list length 2

LIST OF TRANSACTIONS FOR EACH SESSION:

---TRANSACTION 2669046609, ACTIVE 50 sec starting index read

mysql tables in use 1, locked 1

LOCK WAIT 2 lock struct(s), heap size 1128, 1 row lock(s)

MariaDB thread id 3470438, OS thread handle 140090653918784, query id 380459332 Update_rows_log_event::find_row(-1) on table `api_check`

update `api_check` set `last_check` = '2024-03-29 04:44:13' where `id` = 1

------- TRX HAS BEEN WAITING 49554452 ns FOR THIS LOCK TO BE GRANTED:

RECORD LOCKS space id 27887 page no 3 n bits 8 index PRIMARY of table `mixr_user`.`api_check` trx id 2669046609 lock_mode X locks rec but not gap waiting

Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0

 0: len 1; hex 01; asc  ;;

 1: len 6; hex 00009f166b2e; asc     k.;;

 2: len 7; hex 350000c0030110; asc 5      ;;

 3: len 5; hex 99b2fa4b0e; asc    K ;;

------------------

---TRANSACTION (0x7f6aa4544380), not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION (0x7f6aa4543880), not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION (0x7f6aa4542d80), not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION 2669046575, ACTIVE (PREPARED) 550 sec

3 lock struct(s), heap size 1128, 1 row lock(s), undo log entries 2

MariaDB thread id 3470442, OS thread handle 140090649925184, query id 380457775 Waiting for prior transaction to commit

---TRANSACTION 2669046608, ACTIVE 50 sec starting index read

mysql tables in use 1, locked 1

LOCK WAIT 2 lock struct(s), heap size 1128, 1 row lock(s)

MariaDB thread id 3470443, OS thread handle 140090649310784, query id 380459331 Update_rows_log_event::find_row(-1) on table `api_check`

update `api_check` set `last_check` = '2024-03-29 04:44:09' where `id` = 1

------- TRX HAS BEEN WAITING 49554452 ns FOR THIS LOCK TO BE GRANTED:

RECORD LOCKS space id 27938 page no 3 n bits 8 index PRIMARY of table `wpmixrgen`.`api_check` trx id 2669046608 lock_mode X locks rec but not gap waiting

Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0

 0: len 1; hex 01; asc  ;;

 1: len 6; hex 00009f166b2f; asc     k/;;

 2: len 7; hex 360000c0020110; asc 6      ;;

 3: len 5; hex 99b2fa4b0d; asc    K ;;

------------------

---TRANSACTION 2669046585, ACTIVE (PREPARED) 550 sec

2 lock struct(s), heap size 1128, 0 row lock(s), undo log entries 2

MariaDB thread id 3470444, OS thread handle 140090649003584, query id 380457783 Waiting for prior transaction to commit

---TRANSACTION 2669046574, ACTIVE (PREPARED) 550 sec

3 lock struct(s), heap size 1128, 1 row lock(s), undo log entries 2

MariaDB thread id 3470445, OS thread handle 140090648389184, query id 380457773 Waiting for prior transaction to commit

---TRANSACTION (0x7f6aa453f680), not started

0 lock struct(s), heap size 1128, 0 row lock(s)

---TRANSACTION (0x7f6aa453eb80), not started

0 lock struct(s), heap size 1128, 0 row lock(s)

--------

FILE I/O

--------

Pending flushes (fsync): 0

73352 OS file reads, 300770765 OS file writes, 2527252 OS fsyncs

0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s

---

LOG

---

Log sequence number 3210682942432

Log flushed up to   3210682942432

Pages flushed up to 3210682942432

Last checkpoint at  3210682942408

----------------------

BUFFER POOL AND MEMORY

----------------------

Total large memory allocated 3808428032

Dictionary memory allocated 23218440

Buffer pool size   228160

Free buffers       129541

Database pages     98619

Old database pages 36423

Modified db pages  0

Percent of dirty pages(LRU & free pages): 0.000

Max dirty pages percent: 40.000

Pending reads 0

Pending writes: LRU 0, flush list 0

Pages made young 170619, not young 32960930

0.00 youngs/s, 0.00 non-youngs/s

Pages read 72866, created 30503592, written 115666167

0.00 reads/s, 0.00 creates/s, 0.00 writes/s

Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000

Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s

LRU len: 98619, unzip_LRU len: 0

I/O sum[0]:cur[0], unzip sum[0]:cur[0]

--------------

ROW OPERATIONS

--------------

0 read views open inside InnoDB

state: sleeping

----------------------------

END OF INNODB MONITOR OUTPUT

============================

1 row in set (0.001 sec)

Attachments

Issue Links

duplicates

MDEV-21953 deadlock between BACKUP STAGE BLOCK_COMMIT and parallel replication

Closed

MDEV-31840 Parallel replication undetected deadlocks with outside transaction

Open

Activity

People

Assignee:: Kristian Nielsen

Reporter:: VAROQUI Stephane

Votes:: 0 Vote for this issue

Watchers:: 6 Start watching this issue

Dates

Created:: 2024-03-29 15:42

Updated:: 2024-06-12 09:42

Resolved:: 2024-06-12 09:42

Git Integration

Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.