Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-29111

locking occurring when upgrading to 10.5 from 10.1

Details

    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

          Activity

            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?

            marko Marko Mäkelä added a comment - 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?

            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]>
            

            stackoverdrive StackOverdrive added a comment - 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)
            

            stackoverdrive StackOverdrive added a comment - 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).

            marko Marko Mäkelä added a comment - 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.

            marko Marko Mäkelä added a comment - 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.

            People

              marko Marko Mäkelä
              stackoverdrive StackOverdrive
              Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

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