Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Incomplete
-
10.5.16
Description
hello, we have recently upgraded from mariadb 10.1 to mariadb 10.5 and have been seeing some unexplained locking occuring which we have not been able to identify.
environment
MariaDB [dev]> \s
|
--------------
|
mysql Ver 15.1 Distrib 10.5.16-MariaDB, for debian-linux-gnu (x86_64) using readline 5.2 |
|
Connection id: 997 |
Current database: dev
|
Current user: root@localhost |
SSL: Cipher in use is TLS_AES_256_GCM_SHA384
|
Current pager: stdout
|
Using outfile: '' |
Using delimiter: ;
|
Server: MariaDB
|
Server version: 10.5.16-MariaDB-1:10.5.16+maria~bionic-log mariadb.org binary distribution |
Protocol version: 10 |
Connection: Localhost via UNIX socket
|
Server characterset: latin1
|
Db characterset: latin1
|
Client characterset: utf8
|
Conn. characterset: utf8
|
UNIX socket: /var/run/mysqld/mysqld.sock
|
Uptime: 41 days 22 hours 34 min 44 sec |
|
Threads: 4 Questions: 9486 Slow queries: 0 Opens: 256 Open tables: 250 Queries per second avg: 0.002 |
output of* show engine innodb status*
Spin rounds per wait: 28.59 RW-shared, 45.00 RW-excl, 0.00 RW-sx |
2------------ |
3TRANSACTIONS
|
4------------ |
5Trx id counter 104227 |
6Purge done for trx's n:o < 104066 undo n:o < 0 state: running |
7History list length 96 |
8LIST OF TRANSACTIONS FOR EACH SESSION:
|
9---TRANSACTION 422141812912496, not started |
100 lock struct(s), heap size 1128, 0 row lock(s) |
11---TRANSACTION 422141812950800, ACTIVE 17091 sec starting index read |
12mysql tables in use 2, locked 0 |
130 lock struct(s), heap size 1128, 0 row lock(s) |
14MySQL thread id 16485, OS thread handle 140659917436672, query id 74379 localhost dev Sending data |
15SELECT `account`.`id`, `account`.`status`, `account`.`status_message`, `something_summary`.`id_something`, SUM(owed_sum) AS `owed_sum`, SUM(paid_sum) AS `paid_sum`, SUM(pending_sum) AS `pending_sum` FROM `account`
|
16 INNER JOIN `something_summary` ON something_summary.id_account = account.id |
17 INNER JOIN `partner` ON partner.id = something_summary.id_partner WHERE (`account`.created_on >= '2021-12-01 00:00:00') AND (`account`.created_on < '2021-12-31 23:59:59') AND (account.status_message != "Submitted in error by partner") AND (partner.id = '1212') GROUP BY `account`.`id` |
18Trx read view will not see trx with id >= 104227, sees < 104208 |
19---TRANSACTION 422141812946544, ACTIVE 18258 sec starting index read |
20mysql tables in use 2, locked 0 |
210 lock struct(s), heap size 1128, 0 row lock(s) |
22MySQL thread id 16409, OS thread handle 140666827491072, query id 73613 localhost dev Sending data |
23SELECT `account`.`id`, `account`.`status`, `account`.`status_message`, `something_summary`.`id_something`, SUM(owed_sum) AS `owed_sum`, SUM(paid_sum) AS `paid_sum`, SUM(pending_sum) AS `pending_sum` FROM `account`
|
24 INNER JOIN `something_summary` ON something_summary.id_account = account.id |
25 INNER JOIN `partner` ON partner.id = something_summary.id_partner WHERE (`account`.created_on >= '2021-12-01 00:00:00') AND (`account`.created_on < '2021-12-31 23:59:59') AND (account.status_message != "Submitted in error by partner") AND (partner.id = '1212') GROUP BY `account`.`id` |
26Trx read view will not see trx with id >= 104227, sees < 104208 |
27---TRANSACTION 422141812942288, ACTIVE 18285 sec starting index read |
28mysql tables in use 2, locked 0 |
290 lock struct(s), heap size 1128, 0 row lock(s) |
30MySQL thread id 16403, OS thread handle 140659916515072, query id 73587 localhost dev Sending data |
31SELECT `account`.`id`, `account`.`status`, `account`.`status_message`, `something_summary`.`id_something`, SUM(owed_sum) AS `owed_sum`, SUM(paid_sum) AS `paid_sum`, SUM(pending_sum) AS `pending_sum` FROM `account`
|
32 INNER JOIN `something_summary` ON something_summary.id_account = account.id |
33 INNER JOIN `partner` ON partner.id = something_summary.id_partner WHERE (`account`.created_on >= '2021-12-01 00:00:00') AND (`account`.created_on < '2021-12-31 23:59:59') AND (account.status_message != "Submitted in error by partner") AND (partner.id = '1212') GROUP BY `account`.`id` |
34Trx read view will not see trx with id >= 104227, sees < 104208 |
35---TRANSACTION 104220, ACTIVE 18446744073708026459 sec inserting |
36mysql tables in use 1, locked 1 |
371 lock struct(s), heap size 1128, 0 row lock(s), undo log entries 1 |
38MySQL thread id 16061, OS thread handle 140666826262272, query id 71685 localhost dev Update |
39INSERT INTO `something_pending` (`id_account`, `id_something`, `id_partner`, `date`, `amount`, `last_updated`, `created_on`, `owner`) VALUES ('7641771', '53730175', '206917', '2022-10-06', '100', NOW(), NOW(), 'someuser') |
40---TRANSACTION 104208, ACTIVE 18446744073708248571 sec updating or deleting |
41mysql tables in use 1, locked 1 |
422 lock struct(s), heap size 1128, 1 row lock(s), undo log entries 1 |
43MySQL thread id 6241, OS thread handle 140659918972672, query id 39141 localhost dev Updating |
44UPDATE `account_transaction` SET `owner` = 'someuser', `processor` = 'someprocessor', `status` = 'success', `string_account_number` = '42712291121901', `id_lender` = '1303', `paid_on` = CURDATE(), `lender` = SOME BANK SERVICES', `reason` = '', `last_updated` = '2022-07-26 00:00:00', `check_number` = '44556677' WHERE (id = '67764108') |
45---TRANSACTION 422141812908240, not started |
460 lock struct(s), heap size 1128, 0 row lock(s) |
Attachments
Issue Links
- relates to
-
MDEV-27800 upgrade from MariaDB 10.2 to 10.5.13 results in [ERROR] InnoDB: corrupted TRX_NO
-
- Closed
-
Activity
we have made the suggested change and are seeing locks
| InnoDB | |
|
=====================================
|
2022-09-26 13:02:59 0x7f1445fa0700 INNODB MONITOR OUTPUT |
=====================================
|
Per second averages calculated from the last 18446744073706361222 seconds |
-----------------
|
BACKGROUND THREAD
|
-----------------
|
srv_master_thread loops: 29 srv_active, 0 srv_shutdown, 1757 srv_idle |
srv_master_thread log flush and writes: 1775 |
----------
|
SEMAPHORES
|
----------
|
OS WAIT ARRAY INFO: reservation count 79 |
--Thread 139724550096640 has waited at buf0buf.cc line 2581 for 6515.00 seconds the semaphore: |
S-lock on RW-latch at 0x7f13f40d7e78 created in file buf0buf.cc line 1046 |
a writer (thread id 0) has reserved it in mode exclusive |
number of readers 0, waiters flag 1, lock_word: 0 |
Last time write locked in file buf0rea.cc line 120 |
OS WAIT ARRAY INFO: signal count 64 |
RW-shared spins 119, rounds 2489, OS waits 43 |
RW-excl spins 3, rounds 90, OS waits 3 |
RW-sx spins 0, rounds 0, OS waits 0 |
Spin rounds per wait: 20.92 RW-shared, 30.00 RW-excl, 0.00 RW-sx |
------------
|
TRANSACTIONS
|
------------
|
Trx id counter 99731 |
Purge done for trx's n:o < 99725 undo n:o < 0 state: running |
History list length 11 |
LIST OF TRANSACTIONS FOR EACH SESSION:
|
---TRANSACTION 421199550197968, not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION 99730, ACTIVE 6142 sec starting index read |
mysql tables in use 1, locked 1 |
LOCK WAIT 2 lock struct(s), heap size 1128, 1 row lock(s) |
MySQL thread id 693, OS thread handle 139724550403840, query id 8855 localhost dev Updating |
UPDATE `account_transaction` SET `bank_account_number` = '121212121212', `bank_routing_number` = '12121212', `bank_account_type` = 'Checking' WHERE (`account_transaction`.`id` = 12121212) |
------- TRX HAS BEEN WAITING 6142 SEC FOR THIS LOCK TO BE GRANTED: |
RECORD LOCKS space id 356 page no 529847 n bits 200 index PRIMARY of table `dev`.`account_transaction` trx id 99730 lock_mode X locks rec but not gap waiting |
Record lock, heap no 127 PHYSICAL RECORD: n_fields 37; compact format; info bits 0 |
0: len 4; hex 041d237b; asc #{;; |
1: len 6; hex 000000018591; asc ;; |
2: len 7; hex 65000200241aae; asc e $ ;; |
3: len 3; hex 0b9bbd; asc ;; |
4: len 4; hex 00000000; asc ;; |
5: len 1; hex 01; asc ;; |
6: len 5; hex 8000008a00; asc ;; |
7: len 1; hex 01; asc ;; |
8: SQL NULL; |
9: len 0; hex ; asc ;; |
10: len 3; hex 000000; asc ;; |
11: len 0; hex ; asc ;; |
12: len 0; hex ; asc ;; |
13: len 0; hex ; asc ;; |
14: len 1; hex 01; asc ;; |
15: len 0; hex ; asc ;; |
16: len 0; hex ; asc ;; |
17: SQL NULL; |
18: len 0; hex ; asc ;; |
19: SQL NULL; |
20: len 0; hex ; asc ;; |
21: len 3; hex 8fcd26; asc &;; |
22: len 3; hex 800000; asc ;; |
23: len 5; hex 99adf4b398; asc ;; |
24: len 5; hex 3030303233; asc 00023;; |
25: len 30; hex 53706563696669656420736f75726365206b6579206e6f7420666f756e64; asc Specified source key not found; (total 31 bytes); |
26: len 1; hex 04; asc ;; |
27: len 1; hex 80; asc ;; |
28: len 1; hex 00; asc ;; |
29: len 5; hex 8000000032; asc 2;; |
30: len 1; hex 00; asc ;; |
31: len 5; hex 99ad7aa60b; asc z ;; |
32: len 3; hex 005bcb; asc [ ;; |
33: len 5; hex 99ad7aa60b; asc z ;; |
34: len 3; hex 005bcb; asc [ ;; |
35: len 1; hex 80; asc ;; |
36: len 1; hex 80; asc ;; |
|
------------------
|
---TRANSACTION 99729, ACTIVE 6515 sec updating or deleting |
mysql tables in use 1, locked 1 |
2 lock struct(s), heap size 1128, 1 row lock(s), undo log entries 1 |
MySQL thread id 539, OS thread handle 139724550096640, query id 7881 localhost dev Updating |
UPDATE `account_transaction` SET `status` = 'failure', `failure_date` = NOW(), `failure_description` = 'Specified source key not found.', `failure_code` = '0000' WHERE (id = 12121212) |
--------
|
FILE I/O
|
--------
|
Pending flushes (fsync) log: 0; buffer pool: 0 |
43732 OS file reads, 281 OS file writes, 463 OS fsyncs |
-0.00 reads/s, 10922 avg bytes/read, -0.00 writes/s, -0.00 fsyncs/s |
-------------------------------------
|
INSERT BUFFER AND ADAPTIVE HASH INDEX
|
-------------------------------------
|
Ibuf: size 1, free list len 48011, seg size 48013, 0 merges |
merged operations:
|
insert 0, delete mark 0, delete 0 |
discarded operations:
|
insert 0, delete mark 0, delete 0 |
-0.00 hash searches/s, -0.00 non-hash searches/s |
---
|
LOG
|
---
|
Log sequence number 197107157970 |
Log flushed up to 197107157672 |
Pages flushed up to 197105764376 |
Last checkpoint at 197105764364 |
0 pending log flushes, 0 pending chkp writes |
280 log i/o's done, 11.00 log i/o's/second |
----------------------
|
BUFFER POOL AND MEMORY
|
----------------------
|
Total large memory allocated 6459228160 |
Dictionary memory allocated 38736792 |
Buffer pool size 387120 |
Free buffers 343337 |
Database pages 43783 |
Old database pages 16182 |
Modified db pages 866 |
Percent of dirty pages(LRU & free pages): 0.224 |
Max dirty pages percent: 90.000 |
Pending reads 2 |
Pending writes: LRU 0, flush list 0 |
Pages made young 8, not young 0 |
-0.00 youngs/s, -0.00 non-youngs/s |
Pages read 43527, created 254, written 0 |
-0.00 reads/s, -0.00 creates/s, -0.00 writes/s |
Buffer pool hit rate 993 / 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: 43783, unzip_LRU len: 0 |
I/O sum[0]:cur[16], unzip sum[0]:cur[0] |
--------------
|
ROW OPERATIONS
|
--------------
|
0 read views open inside InnoDB |
Process ID=0, Main thread ID=0, state: sleeping |
Number of rows inserted 130, updated 82, deleted 50, read 16125838 |
-0.00 inserts/s, -0.00 updates/s, -0.00 deletes/s, -0.00 reads/s |
Number of system rows inserted 0, updated 0, deleted 0, read 0 |
-0.00 inserts/s, -0.00 updates/s, -0.00 deletes/s, -0.00 reads/s |
----------------------------
|
END OF INNODB MONITOR OUTPUT
|
table schema
MariaDB [dev]> describe account_transaction;
|
+---------------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+------+-----+---------+----------------+
|
| Field | Type | Null | Key | Default | Extra |
|
+---------------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+------+-----+---------+----------------+
|
| id | int(11) unsigned | NO | PRI | NULL | auto_increment | |
| id_account | mediumint(8) unsigned | NO | MUL | NULL | | |
| id_account_payment | int(10) unsigned | NO | MUL | NULL | | |
| type | enum('debit','special_debit','nsf_fee','cancel_fee','refund','loan_payment','over_phone_loan_payment','single_loan_payment','accelerated_loan_payment','enrollment_fee','credit','fee_loan_payment','charged_off','charged_off_credit','collection','positive_balance_adjustment','negative_balance_adjustment','stop_payment_fee') | YES | MUL | NULL | | |
| amount | decimal(10,2) | NO | | NULL | | |
| owner | enum('smart','debtwave','msb') | NO | MUL | smart | | |
| processor | varchar(20) | YES | MUL | NULL | | |
| id_ach | varchar(32) | NO | MUL | NULL | | |
| id_lender | mediumint(8) unsigned | NO | | NULL | | |
| lender | varchar(32) | NO | | NULL | | |
| bank_account_number | varchar(32) | NO | | NULL | | |
| bank_routing_number | varchar(32) | NO | | NULL | | |
| bank_account_type | enum('Checking','Savings','Money Market','Other','Corporate','Corporate Savings') | NO | | NULL | | |
| gtb_payment_desc | varchar(64) | NO | | NULL | | |
| loan_account_number | varchar(32) | NO | | NULL | | |
| id_account_check_statuses | int(11) | YES | MUL | NULL | | |
| check_number | varchar(32) | NO | MUL | NULL | | |
| cleared_date | date | YES | | NULL | |
|
| reason | text | NO | | NULL | |
|
| scheduled_on | date | NO | MUL | NULL | |
|
| paid_on | date | NO | MUL | NULL | |
|
| failure_date | datetime | NO | | NULL | |
|
| failure_code | char(5) | NO | | NULL | | |
| failure_description | text | NO | | NULL | |
|
| status | enum('pending','canceled','success','failure','processing') | NO | | NULL | | |
| processed_externally | tinyint(1) | NO | | 0 | | |
| on_hold | tinyint(3) unsigned | NO | | NULL | | |
| fee | decimal(10,2) | NO | | NULL | | |
| recollection | tinyint(3) unsigned | NO | | 0 | | |
| created_on | datetime | NO | | NULL | |
|
| created_on_by | mediumint(8) unsigned | NO | | NULL | | |
| last_updated | datetime | NO | | NULL | |
|
| last_updated_by | mediumint(8) unsigned | NO | | NULL | | |
| auto_updated | tinyint(1) | NO | | 0 | | |
| force_check | tinyint(1) | NO | | 0 | | |
+---------------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+------+-----+---------+----------------+
|
35 rows in set (0.002 sec) |
|
MariaDB [dev]>
|
|
MariaDB [dev]> show variables like '%isolation%'; |
+---------------+-----------------+
|
| Variable_name | Value |
|
+---------------+-----------------+
|
| tx_isolation | REPEATABLE-READ |
|
+---------------+-----------------+
|
1 row in set (0.002 sec) |
|
MariaDB [dev]>
|
MariaDB [dev]> explain UPDATE `account_transaction` SET `status` = 'failure', `failure_date` = NOW(), `failure_description` = 'Specified source key not found.', `failure_code` = '0000' WHERE (id = 12121212) |
-> ;
|
+------+-------------+---------------------+-------+---------------+---------+---------+------+------+-------------+
|
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
|
+------+-------------+---------------------+-------+---------------+---------+---------+------+------+-------------+
|
| 1 | SIMPLE | account_transaction | range | PRIMARY | PRIMARY | 4 | NULL | 1 | Using where | |
+------+-------------+---------------------+-------+---------------+---------+---------+------+------+-------------+
|
1 row in set (0.001 sec) |
|
MariaDB [dev]>
|
more details
MariaDB [(none)]> show full processlist \G
|
*************************** 1. row *************************** |
Id: 1010 |
User: dev
|
Host: localhost
|
db: dev
|
Command: Query
|
Time: 14212 |
State: Sending data
|
Info: SELECT `commission`.`id`, `commission`.`id_account`, `commission`.`id_partner`, `commission`.`id_partner_link`, IFNULL((
|
SELECT SUM(ct1.amount)
|
FROM commission_transaction ct1
|
WHERE ct1.status = "success" |
AND ct1.type = "payment" |
AND ct1.id_commission = commission.id), 0) - |
IFNULL((
|
SELECT SUM(ct2.amount)
|
FROM commission_transaction ct2
|
WHERE ct2.status = "success" |
AND ct2.type = "chargeback" |
AND ct2.id_commission = commission.id), 0) AS `PaidSum`, IFNULL(( |
SELECT SUM(ct3.amount)
|
FROM commission_transaction ct3
|
WHERE ct3.status = "pending" |
AND ct3.type = "payment" |
AND ct3.id_commission = commission.id), 0) - |
IFNULL((
|
SELECT SUM(ct4.amount)
|
FROM commission_transaction ct4
|
WHERE ct4.status = "pending" |
AND ct4.type = "chargeback" |
AND ct4.id_commission = commission.id), 0) AS `PendingSum`, IFNULL(( |
SELECT SUM(cs1.amount)
|
FROM commission_structure cs1
|
WHERE cs1.disable = 0 |
AND cs1.id_commission = commission.id), 0) AS `CommissionOwed` FROM `commission` WHERE (commission.id_account = '121212') |
Progress: 0.000 |
*************************** 2. row *************************** |
Id: 1083 |
User: root
|
Host: localhost
|
db: NULL
|
Command: Query
|
Time: 0 |
State: starting
|
Info: show full processlist
|
Progress: 0.000 |
2 rows in set (0.000 sec) |
|
MariaDB [(none)]> show engine innodb status \G
|
*************************** 1. row *************************** |
Type: InnoDB
|
Name:
|
Status:
|
=====================================
|
2022-09-13 08:44:05 0x7f59541c5700 INNODB MONITOR OUTPUT |
=====================================
|
Per second averages calculated from the last 71 seconds |
-----------------
|
BACKGROUND THREAD
|
-----------------
|
srv_master_thread loops: 0 srv_active, 0 srv_shutdown, 62093 srv_idle |
srv_master_thread log flush and writes: 62060 |
----------
|
SEMAPHORES
|
----------
|
OS WAIT ARRAY INFO: reservation count 19 |
--Thread 140021828638464 has waited at row0sel.cc line 4719 for 14172.00 seconds the semaphore: |
S-lock on RW-latch at 0x7f593407c078 created in file buf0buf.cc line 1046 |
a writer (thread id 140014612133632) has reserved it in mode exclusive |
number of readers 0, waiters flag 1, lock_word: 0 |
Last time write locked in file mtr0mtr.inl line 146 |
--Thread 140014612133632 has waited at buf0buf.cc line 2581 for 14172.00 seconds the semaphore: |
S-lock on RW-latch at 0x7f5934082078 created in file buf0buf.cc line 1046 |
a writer (thread id 0) has reserved it in mode exclusive |
number of readers 0, waiters flag 1, lock_word: 0 |
Last time write locked in file buf0rea.cc line 120 |
OS WAIT ARRAY INFO: signal count 8 |
RW-shared spins 3, rounds 30, OS waits 1 |
RW-excl spins 0, rounds 0, OS waits 0 |
RW-sx spins 0, rounds 0, OS waits 0 |
Spin rounds per wait: 10.00 RW-shared, 0.00 RW-excl, 0.00 RW-sx |
------------
|
TRANSACTIONS
|
------------
|
Trx id counter 99819 |
Purge done for trx's n:o < 99804 undo n:o < 0 state: running |
History list length 12 |
LIST OF TRANSACTIONS FOR EACH SESSION:
|
---TRANSACTION 421496633812272, ACTIVE 14172 sec starting index read |
mysql tables in use 6, locked 0 |
0 lock struct(s), heap size 1128, 0 row lock(s) |
MySQL thread id 1010, OS thread handle 140021828638464, query id 3652 localhost dev Sending data |
SELECT `commission`.`id`, `commission`.`id_account`, `commission`.`id_partner`, `commission`.`id_partner_link`, IFNULL((
|
SELECT SUM(ct1.amount)
|
FROM commission_transaction ct1
|
WHERE ct1.status = "success" |
AND ct1.type = "payment" |
AND ct1.id_commission = commission.id), 0) - |
IFNULL((
|
SELECT SUM(ct2.amount)
|
FROM commission_transaction ct2
|
WHERE ct2.status = "success" |
AND ct2.type = "chargeback" |
AND ct2.id_commission = comm
|
Trx read view will not see trx with id >= 99817, sees < 99817 |
--------
|
FILE I/O
|
--------
|
Pending flushes (fsync) log: 0; buffer pool: 0 |
25351 OS file reads, 23 OS file writes, 23 OS fsyncs |
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s |
-------------------------------------
|
INSERT BUFFER AND ADAPTIVE HASH INDEX
|
-------------------------------------
|
Ibuf: size 1, free list len 48011, seg size 48013, 0 merges |
merged operations:
|
insert 0, delete mark 0, delete 0 |
discarded operations:
|
insert 0, delete mark 0, delete 0 |
0.00 hash searches/s, 0.00 non-hash searches/s |
---
|
LOG
|
---
|
Log sequence number 197107173630 |
Log flushed up to 197107173630 |
Pages flushed up to 197107159144 |
Last checkpoint at 197107159132 |
0 pending log flushes, 0 pending chkp writes |
25 log i/o's done, 0.00 log i/o's/second |
----------------------
|
BUFFER POOL AND MEMORY
|
----------------------
|
Total large memory allocated 6459228160 |
Dictionary memory allocated 38445912 |
Buffer pool size 387120 |
Free buffers 361723 |
Database pages 25397 |
Old database pages 9395 |
Modified db pages 133 |
Percent of dirty pages(LRU & free pages): 0.034 |
Max dirty pages percent: 90.000 |
Pending reads 1 |
Pending writes: LRU 0, flush list 0 |
Pages made young 0, not young 0 |
0.00 youngs/s, 0.00 non-youngs/s |
Pages read 25264, created 132, written 0 |
0.00 reads/s, 0.00 creates/s, 0.00 writes/s |
No buffer pool page gets since the last printout
|
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s |
LRU len: 25397, unzip_LRU len: 0 |
I/O sum[0]:cur[24266], unzip sum[0]:cur[0] |
--------------
|
ROW OPERATIONS
|
--------------
|
1 read views open inside InnoDB |
Process ID=0, Main thread ID=0, state: sleeping |
Number of rows inserted 15, updated 5, deleted 1, read 7524234 |
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s |
Number of system rows inserted 0, updated 0, deleted 0, read 0 |
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s |
----------------------------
|
END OF INNODB MONITOR OUTPUT
|
============================
|
|
1 row in set (0.001 sec) |
Sorry, I had forgotten this ticket for a while, and found it accidentally now.
It is unclear which suggested change you are referring to. In any case, it looks like there is a lock conflict on a PRIMARY KEY record itself, not on any gap locks (which would not be acquired when using the READ COMMITTED isolation level):
---TRANSACTION 99730, ACTIVE 6142 sec starting index read
|
mysql tables in use 1, locked 1
|
LOCK WAIT 2 lock struct(s), heap size 1128, 1 row lock(s)
|
MySQL thread id 693, OS thread handle 139724550403840, query id 8855 localhost dev Updating
|
UPDATE `account_transaction` SET `bank_account_number` = '121212121212', `bank_routing_number` = '12121212', `bank_account_type` = 'Checking' WHERE (`account_transaction`.`id` = 12121212)
|
------- TRX HAS BEEN WAITING 6142 SEC FOR THIS LOCK TO BE GRANTED:
|
RECORD LOCKS space id 356 page no 529847 n bits 200 index PRIMARY of table `dev`.`account_transaction` trx id 99730 lock_mode X locks rec but not gap waiting
|
Record lock, heap no 127 PHYSICAL RECORD: n_fields 37; compact format; info bits 0
|
0: len 4; hex 041d237b; asc #{;;
|
1: len 6; hex 000000018591; asc ;;
|
2: len 7; hex 65000200241aae; asc e $ ;;
|
3: len 3; hex 0b9bbd; asc ;;
|
…
|
The actual primary key is 0x041d237b = 69018491. This record is not delete-marked (info bits 0) and I suppose that it could be implicitly locked by the transaction 0x18591 = 99729 (exactly one transaction right before the current one, which is 99730) which had updated or delete-unmarked the record (the most significant bit of the 7-byte DB_ROLL_PTR is clear). A number of transactions have been started since then:
Trx id counter 99819
|
Purge done for trx's n:o < 99804 undo n:o < 0 state: running
|
That the purge of committed transaction history was able to advance beyond 99729 looks very strange. Also the following looks strange:
LIST OF TRANSACTIONS FOR EACH SESSION:
|
---TRANSACTION 421496633812272, ACTIVE 14172 sec starting index read
|
That large number is 0x17F595521E530 in hexadecimal. I checked the code in trx_print_low():
if (const trx_id_t id = trx->id) { |
fprintf(f, "TRANSACTION " TRX_ID_FMT, trx->id); |
} else { |
fprintf(f, "TRANSACTION (%p)", trx); |
}
|
So, the print-out really is of a trx->id, and not the memory pointer of a read-only transaction (which should not acquire any locks in the first place).
Because the field DB_TRX_ID is only 48 bits (6 bytes, 12 hexadecimal digits), this transaction identifier (13 hexadecimal digits) is invalid. In some other places, InnoDB reserves 64 bits (8 bytes) for the transaction ID. This strongly looks like a duplicate of MDEV-27800, or something related.
The only thing that bothers me is that you report that this occurred on an upgrade from 10.1 to 10.5.16, and MDEV-27800 was supposed to be fixed in that version. Maybe I have missed something else, or you in fact had attempted an upgrade to some other MariaDB version that is later than 10.1 but older than 10.5.16.
The easiest fix of this corruption is to perform a logical dump and restore of the database, loading it to a newly initialized server. That would also give you benefits of the 10.5 default innodb_file_format=full_crc32 format (MDEV-19534).
Did you ever attempt an upgrade from 10.1 to older MariaDB version than 10.5.16? If yes, that could have caused some uninitialized data to be misinterpreted as real transaction identifiers. If not, then there apparently the fix of MDEV-27800 was incomplete, and we would need a copy of the 10.1 data directory (before any upgrade) to fix it.
Also, a last question: Was the database originally created with a very old version of MariaDB or MySQL? Quoting from MDEV-27800:
Unfortunately, before MySQL 5.1.48 and MariaDB 5.1.48, InnoDB did not always initialize data fields. The TRX_NO field in undo log pages could actually contain garbage, instead of 0.
stackoverdrive, without knowing the table schema or the configuration parameters, only guesses are possible. One guess would be that the long-deprecated option innodb_locks_unsafe_for_binlog (
MDEV-19563) will be ignored starting with MariaDB Server 10.5. Maybe cvicentiu and serg should not have introduced the MARIADB_REMOVED_OPTION to allow an upgraded server to start up without forcing the DBA to review the configuration parameters.An alternative of using SET TRANSACTION ISOLATION LEVEL READ COMMITTED was introduced for the option innodb_locks_unsafe_for_binlog a long time ago. Which transaction isolation level are you using?