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

mariabackup loop on Read redo log up to LSN

Details

    • Bug
    • Status: Open (View Workflow)
    • Major
    • Resolution: Unresolved
    • 10.3.38
    • None
    • Backup
    • None
    • Debian 11

    Description

      Hi, I'm trying to backup my mariadb server environment (master + replica).
      I've ran this command:

      mariabackup --backup --target-dir=/backup/ --user=backup --password=backup --host=192.168.xxx.xxx

      The command loop on:

      2023-06-09 13:51:10 0 [Note] InnoDB: Read redo log up to LSN=1625600
      [00] 2023-06-09 13:51:10 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:11 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:12 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:13 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:14 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:15 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:16 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:17 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:18 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:19 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:20 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:21 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:22 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:23 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:24 >> log scanned up to (1625437)
      2023-06-09 13:51:25 0 [Note] InnoDB: Read redo log up to LSN=1625600
      [00] 2023-06-09 13:51:25 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:26 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:27 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:28 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:29 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:30 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:31 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:32 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:33 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:34 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:35 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:36 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:37 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:38 >> log scanned up to (1625437)
      [00] 2023-06-09 13:51:39 >> log scanned up to (1625437)
      

      I've tried several times, but same result... I'm trying to make a full backup pointing on my replica server.

      Server side, with "show processlist" I can see the backup connection on sleep and others connection like:

      id User Host db Command Time State Progress
      1 system user NULL Daemon NULL InnoDB purge worker NULL 0.000
      2 system user NULL Daemon NULL InnoDB purge coordinator NULL 0.000
      3 system user NULL Daemon NULL InnoDB purge worker NULL 0.000
      4 system user NULL Daemon NULL InnoDB purge worker NULL 0.000
      5 system user NULL Daemon NULL InnoDB shutdown handler NULL 0.000

      Any ideas to solve? Thanks a lot

      Attachments

        Issue Links

          Activity

            This the "show engine innodb status" output...

             
            =====================================
            2023-06-16 15:40:36 0x7f42c8521700 INNODB MONITOR OUTPUT
            =====================================
            Per second averages calculated from the last 35 seconds
            -----------------
            BACKGROUND THREAD
            -----------------
            srv_master_thread loops: 2291203 srv_active, 0 srv_shutdown, 190383 srv_idle
            srv_master_thread log flush and writes: 2481513
            ----------
            SEMAPHORES
            ----------
            OS WAIT ARRAY INFO: reservation count 605370221
            OS WAIT ARRAY INFO: signal count 387498064
            RW-shared spins 113460664, rounds 1325628978, OS waits 35669327
            RW-excl spins 109517156, rounds 489343901, OS waits 3882404
            RW-sx spins 4534492, rounds 81766293, OS waits 1430009
            Spin rounds per wait: 11.68 RW-shared, 4.47 RW-excl, 18.03 RW-sx
            ------------------------
            LATEST DETECTED DEADLOCK
            ------------------------
            2023-06-15 09:35:04 0x7f4420166700
            *** (1) TRANSACTION:
            TRANSACTION 14554536583, ACTIVE 0 sec inserting
            mysql tables in use 1, locked 1
            LOCK WAIT 3 lock struct(s), heap size 1128, 2 row lock(s)
            MySQL thread id 11372646, OS thread handle 139930572228352, query id 2605663046 192.168.100.59 d9_sancasciano Update
            INSERT INTO "semaphore" ("name", "value", "expire") VALUES ('cron', '662026395648abf28db5da3.54430695', '1686815404.898')
            *** (1) WAITING FOR THIS LOCK TO BE GRANTED:
            RECORD LOCKS space id 850609 page no 3 n bits 72 index PRIMARY of table "d9_sancasciano"."semaphore" trx id 14554536583 lock_mode X locks rec but not gap waiting
            Record lock, heap no 2 PHYSICAL RECORD: n_fields 5; compact format; info bits 32
             0: len 4; hex 63726f6e; asc cron;;
             1: len 6; hex 00036383caa9; asc   c   ;;
             2: len 7; hex 7200005dbf0be2; asc r  ]   ;;
             3: len 30; hex 3130363232353033373036343861626466653030663535352e3338323634; asc 1062250370648abdfe00f555.38264; (total 33 bytes);
             4: len 8; hex 9eef7f60b022d941; asc    ` " A;;
             
            *** (2) TRANSACTION:
            TRANSACTION 14554536584, ACTIVE 0 sec inserting
            mysql tables in use 1, locked 1
            3 lock struct(s), heap size 1128, 2 row lock(s)
            MySQL thread id 11372652, OS thread handle 139930572842752, query id 2605663047 192.168.100.59 d9_sancasciano Update
            INSERT INTO "semaphore" ("name", "value", "expire") VALUES ('cron', '182559208648abf28db5fa8.01710098', '1686815404.8981')
            *** (2) HOLDS THE LOCK(S):
            RECORD LOCKS space id 850609 page no 3 n bits 72 index PRIMARY of table "d9_sancasciano"."semaphore" trx id 14554536584 lock mode S locks rec but not gap
            Record lock, heap no 2 PHYSICAL RECORD: n_fields 5; compact format; info bits 32
             0: len 4; hex 63726f6e; asc cron;;
             1: len 6; hex 00036383caa9; asc   c   ;;
             2: len 7; hex 7200005dbf0be2; asc r  ]   ;;
             3: len 30; hex 3130363232353033373036343861626466653030663535352e3338323634; asc 1062250370648abdfe00f555.38264; (total 33 bytes);
             4: len 8; hex 9eef7f60b022d941; asc    ` " A;;
             
            *** (2) WAITING FOR THIS LOCK TO BE GRANTED:
            RECORD LOCKS space id 850609 page no 3 n bits 72 index PRIMARY of table "d9_sancasciano"."semaphore" trx id 14554536584 lock_mode X locks rec but not gap waiting
            Record lock, heap no 2 PHYSICAL RECORD: n_fields 5; compact format; info bits 32
             0: len 4; hex 63726f6e; asc cron;;
             1: len 6; hex 00036383caa9; asc   c   ;;
             2: len 7; hex 7200005dbf0be2; asc r  ]   ;;
             3: len 30; hex 3130363232353033373036343861626466653030663535352e3338323634; asc 1062250370648abdfe00f555.38264; (total 33 bytes);
             4: len 8; hex 9eef7f60b022d941; asc    ` " A;;
             
            *** WE ROLL BACK TRANSACTION (2)
            ------------
            TRANSACTIONS
            ------------
            Trx id counter 14586125499
            Purge done for trx's n:o < 14586125499 undo n:o < 0 state: running but idle
            History list length 25
            LIST OF TRANSACTIONS FOR EACH SESSION:
            ---TRANSACTION 421405608165640, not started
            0 lock struct(s), heap size 1128, 0 row lock(s)
            ---TRANSACTION 421405608161464, not started
            0 lock struct(s), heap size 1128, 0 row lock(s)
            ---TRANSACTION 421405608190696, not started
            0 lock struct(s), heap size 1128, 0 row lock(s)
            ---TRANSACTION 421405608173992, not started
            0 lock struct(s), heap size 1128, 0 row lock(s)
            ---TRANSACTION 421405608157288, not started
            0 lock struct(s), heap size 1128, 0 row lock(s)
            --------
            FILE I/O
            --------
            I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
            I/O thread 1 state: waiting for completed aio requests (log thread)
            I/O thread 2 state: waiting for completed aio requests (read thread)
            I/O thread 3 state: waiting for completed aio requests (read thread)
            I/O thread 4 state: waiting for completed aio requests (read thread)
            I/O thread 5 state: waiting for completed aio requests (read thread)
            I/O thread 6 state: waiting for completed aio requests (read thread)
            I/O thread 7 state: waiting for completed aio requests (read thread)
            I/O thread 8 state: waiting for completed aio requests (read thread)
            I/O thread 9 state: waiting for completed aio requests (read thread)
            I/O thread 10 state: waiting for completed aio requests (read thread)
            I/O thread 11 state: waiting for completed aio requests (read thread)
            I/O thread 12 state: waiting for completed aio requests (read thread)
            I/O thread 13 state: waiting for completed aio requests (read thread)
            I/O thread 14 state: waiting for completed aio requests (read thread)
            I/O thread 15 state: waiting for completed aio requests (read thread)
            I/O thread 16 state: waiting for completed aio requests (read thread)
            I/O thread 17 state: waiting for completed aio requests (read thread)
            I/O thread 18 state: waiting for completed aio requests (read thread)
            I/O thread 19 state: waiting for completed aio requests (read thread)
            I/O thread 20 state: waiting for completed aio requests (read thread)
            I/O thread 21 state: waiting for completed aio requests (read thread)
            I/O thread 22 state: waiting for completed aio requests (read thread)
            I/O thread 23 state: waiting for completed aio requests (read thread)
            I/O thread 24 state: waiting for completed aio requests (read thread)
            I/O thread 25 state: waiting for completed aio requests (read thread)
            I/O thread 26 state: waiting for completed aio requests (read thread)
            I/O thread 27 state: waiting for completed aio requests (read thread)
            I/O thread 28 state: waiting for completed aio requests (read thread)
            I/O thread 29 state: waiting for completed aio requests (read thread)
            I/O thread 30 state: waiting for completed aio requests (read thread)
            I/O thread 31 state: waiting for completed aio requests (read thread)
            I/O thread 32 state: waiting for completed aio requests (read thread)
            I/O thread 33 state: waiting for completed aio requests (read thread)
            I/O thread 34 state: waiting for completed aio requests (read thread)
            I/O thread 35 state: waiting for completed aio requests (read thread)
            I/O thread 36 state: waiting for completed aio requests (read thread)
            I/O thread 37 state: waiting for completed aio requests (read thread)
            I/O thread 38 state: waiting for completed aio requests (read thread)
            I/O thread 39 state: waiting for completed aio requests (read thread)
            I/O thread 40 state: waiting for completed aio requests (read thread)
            I/O thread 41 state: waiting for completed aio requests (read thread)
            I/O thread 42 state: waiting for completed aio requests (read thread)
            I/O thread 43 state: waiting for completed aio requests (read thread)
            I/O thread 44 state: waiting for completed aio requests (read thread)
            I/O thread 45 state: waiting for completed aio requests (read thread)
            I/O thread 46 state: waiting for completed aio requests (read thread)
            I/O thread 47 state: waiting for completed aio requests (read thread)
            I/O thread 48 state: waiting for completed aio requests (read thread)
            I/O thread 49 state: waiting for completed aio requests (read thread)
            I/O thread 50 state: waiting for completed aio requests (read thread)
            I/O thread 51 state: waiting for completed aio requests (read thread)
            I/O thread 52 state: waiting for completed aio requests (read thread)
            I/O thread 53 state: waiting for completed aio requests (read thread)
            I/O thread 54 state: waiting for completed aio requests (read thread)
            I/O thread 55 state: waiting for completed aio requests (read thread)
            I/O thread 56 state: waiting for completed aio requests (read thread)
            I/O thread 57 state: waiting for completed aio requests (read thread)
            I/O thread 58 state: waiting for completed aio requests (read thread)
            I/O thread 59 state: waiting for completed aio requests (read thread)
            I/O thread 60 state: waiting for completed aio requests (read thread)
            I/O thread 61 state: waiting for completed aio requests (read thread)
            I/O thread 62 state: waiting for completed aio requests (read thread)
            I/O thread 63 state: waiting for completed aio requests (read thread)
            I/O thread 64 state: waiting for completed aio requests (read thread)
            I/O thread 65 state: waiting for completed aio requests (read thread)
            I/O thread 66 state: waiting for completed aio requests (write thread)
            I/O thread 67 state: waiting for completed aio requests (write thread)
            I/O thread 68 state: waiting for completed aio requests (write thread)
            I/O thread 69 state: waiting for completed aio requests (write thread)
            I/O thread 70 state: waiting for completed aio requests (write thread)
            I/O thread 71 state: waiting for completed aio requests (write thread)
            I/O thread 72 state: waiting for completed aio requests (write thread)
            I/O thread 73 state: waiting for completed aio requests (write thread)
            I/O thread 74 state: waiting for completed aio requests (write thread)
            I/O thread 75 state: waiting for completed aio requests (write thread)
            I/O thread 76 state: waiting for completed aio requests (write thread)
            I/O thread 77 state: waiting for completed aio requests (write thread)
            I/O thread 78 state: waiting for completed aio requests (write thread)
            I/O thread 79 state: waiting for completed aio requests (write thread)
            I/O thread 80 state: waiting for completed aio requests (write thread)
            I/O thread 81 state: waiting for completed aio requests (write thread)
            I/O thread 82 state: waiting for completed aio requests (write thread)
            I/O thread 83 state: waiting for completed aio requests (write thread)
            I/O thread 84 state: waiting for completed aio requests (write thread)
            I/O thread 85 state: waiting for completed aio requests (write thread)
            I/O thread 86 state: waiting for completed aio requests (write thread)
            I/O thread 87 state: waiting for completed aio requests (write thread)
            I/O thread 88 state: waiting for completed aio requests (write thread)
            I/O thread 89 state: waiting for completed aio requests (write thread)
            I/O thread 90 state: waiting for completed aio requests (write thread)
            I/O thread 91 state: waiting for completed aio requests (write thread)
            I/O thread 92 state: waiting for completed aio requests (write thread)
            I/O thread 93 state: waiting for completed aio requests (write thread)
            I/O thread 94 state: waiting for completed aio requests (write thread)
            I/O thread 95 state: waiting for completed aio requests (write thread)
            I/O thread 96 state: waiting for completed aio requests (write thread)
            I/O thread 97 state: waiting for completed aio requests (write thread)
            I/O thread 98 state: waiting for completed aio requests (write thread)
            I/O thread 99 state: waiting for completed aio requests (write thread)
            I/O thread 100 state: waiting for completed aio requests (write thread)
            I/O thread 101 state: waiting for completed aio requests (write thread)
            I/O thread 102 state: waiting for completed aio requests (write thread)
            I/O thread 103 state: waiting for completed aio requests (write thread)
            I/O thread 104 state: waiting for completed aio requests (write thread)
            I/O thread 105 state: waiting for completed aio requests (write thread)
            I/O thread 106 state: waiting for completed aio requests (write thread)
            I/O thread 107 state: waiting for completed aio requests (write thread)
            I/O thread 108 state: waiting for completed aio requests (write thread)
            I/O thread 109 state: waiting for completed aio requests (write thread)
            I/O thread 110 state: waiting for completed aio requests (write thread)
            I/O thread 111 state: waiting for completed aio requests (write thread)
            I/O thread 112 state: waiting for completed aio requests (write thread)
            I/O thread 113 state: waiting for completed aio requests (write thread)
            I/O thread 114 state: waiting for completed aio requests (write thread)
            I/O thread 115 state: waiting for completed aio requests (write thread)
            I/O thread 116 state: waiting for completed aio requests (write thread)
            I/O thread 117 state: waiting for completed aio requests (write thread)
            I/O thread 118 state: waiting for completed aio requests (write thread)
            I/O thread 119 state: waiting for completed aio requests (write thread)
            I/O thread 120 state: waiting for completed aio requests (write thread)
            I/O thread 121 state: waiting for completed aio requests (write thread)
            I/O thread 122 state: waiting for completed aio requests (write thread)
            I/O thread 123 state: waiting for completed aio requests (write thread)
            I/O thread 124 state: waiting for completed aio requests (write thread)
            I/O thread 125 state: waiting for completed aio requests (write thread)
            I/O thread 126 state: waiting for completed aio requests (write thread)
            I/O thread 127 state: waiting for completed aio requests (write thread)
            I/O thread 128 state: waiting for completed aio requests (write thread)
            I/O thread 129 state: waiting for completed aio requests (write thread)
            Pending normal aio reads: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] , aio writes: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] ,
             ibuf aio reads:, log i/o's:, sync i/o's:
            Pending flushes (fsync) log: 0; buffer pool: 0
            308763051 OS file reads, 154666053 OS file writes, 100393792 OS fsyncs
            254.88 reads/s, 16368 avg bytes/read, 65.23 writes/s, 31.00 fsyncs/s
            -------------------------------------
            INSERT BUFFER AND ADAPTIVE HASH INDEX
            -------------------------------------
            Ibuf: size 1, free list len 1343, seg size 1345, 1600034 merges
            merged operations:
             insert 2349796, delete mark 10579745, delete 3360115
            discarded operations:
             insert 7, delete mark 4, delete 0
            Hash table size 1106407, node heap has 163 buffer(s)
            Hash table size 1106407, node heap has 172 buffer(s)
            Hash table size 1106407, node heap has 315 buffer(s)
            Hash table size 1106407, node heap has 340 buffer(s)
            Hash table size 1106407, node heap has 202 buffer(s)
            Hash table size 1106407, node heap has 276 buffer(s)
            Hash table size 1106407, node heap has 549 buffer(s)
            Hash table size 1106407, node heap has 170 buffer(s)
            9002.31 hash searches/s, 7492.04 non-hash searches/s
            ---
            LOG
            ---
            Log sequence number 13815524744212
            Log flushed up to   13815524410702
            Pages flushed up to 13815463999846
            Last checkpoint at  13815463842223
            0 pending log flushes, 0 pending chkp writes
            37173925 log i/o's done, 3.11 log i/o's/second
            ----------------------
            BUFFER POOL AND MEMORY
            ----------------------
            Total large memory allocated 4418699264
            Dictionary memory allocated 58261280
            Buffer pool size   262144
            Free buffers       4085
            Database pages     255766
            Old database pages 94334
            Modified db pages  812
            Percent of dirty pages(LRU & free pages): 0.312
            Max dirty pages percent: 75.000
            Pending reads 0
            Pending writes: LRU 0, flush list 0, single page 0
            Pages made young 726638625, not young 8140358952
            481.84 youngs/s, 1862.00 non-youngs/s
            Pages read 308730981, created 47154616, written 95434350
            254.88 reads/s, 3.14 creates/s, 54.03 writes/s
            Buffer pool hit rate 995 / 1000, young-making rate 8 / 1000 not 33 / 1000
            Pages read ahead 3.51/s, evicted without access 0.00/s, Random read ahead 0.00/s
            LRU len: 255766, unzip_LRU len: 174
            I/O sum[46604]:cur[20], unzip sum[44]:cur[0]
            ----------------------
            INDIVIDUAL BUFFER POOL INFO
            ----------------------
            ---BUFFER POOL 0
            Buffer pool size   65536
            Free buffers       1023
            Database pages     63962
            Old database pages 23591
            Modified db pages  333
            Percent of dirty pages(LRU & free pages): 0.512
            Max dirty pages percent: 75.000
            Pending reads 0
            Pending writes: LRU 0, flush list 0, single page 0
            Pages made young 178274920, not young 1913356743
            116.08 youngs/s, 388.62 non-youngs/s
            Pages read 77154143, created 11789983, written 32487319
            52.86 reads/s, 0.77 creates/s, 16.17 writes/s
            Buffer pool hit rate 996 / 1000, young-making rate 7 / 1000 not 24 / 1000
            Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
            LRU len: 63962, unzip_LRU len: 57
            I/O sum[11651]:cur[5], unzip sum[11]:cur[0]
            ---BUFFER POOL 1
            Buffer pool size   65536
            Free buffers       1019
            Database pages     63895
            Old database pages 23567
            Modified db pages  51
            Percent of dirty pages(LRU & free pages): 0.079
            Max dirty pages percent: 75.000
            Pending reads 0
            Pending writes: LRU 0, flush list 0, single page 0
            Pages made young 178555553, not young 2039751844
            221.85 youngs/s, 48.83 non-youngs/s
            Pages read 76600171, created 11772433, written 19031649
            10.57 reads/s, 1.00 creates/s, 10.66 writes/s
            Buffer pool hit rate 999 / 1000, young-making rate 20 / 1000 not 4 / 1000
            Pages read ahead 0.69/s, evicted without access 0.00/s, Random read ahead 0.00/s
            LRU len: 63895, unzip_LRU len: 33
            I/O sum[11651]:cur[5], unzip sum[11]:cur[0]
            ---BUFFER POOL 2
            Buffer pool size   65536
            Free buffers       1021
            Database pages     63945
            Old database pages 23585
            Modified db pages  221
            Percent of dirty pages(LRU & free pages): 0.340
            Max dirty pages percent: 75.000
            Pending reads 0
            Pending writes: LRU 0, flush list 0, single page 0
            Pages made young 182352302, not young 1940911358
            89.88 youngs/s, 605.58 non-youngs/s
            Pages read 74642938, created 11799540, written 19490621
            87.34 reads/s, 0.97 creates/s, 12.54 writes/s
            Buffer pool hit rate 994 / 1000, young-making rate 5 / 1000 not 38 / 1000
            Pages read ahead 1.83/s, evicted without access 0.00/s, Random read ahead 0.00/s
            LRU len: 63945, unzip_LRU len: 39
            I/O sum[11651]:cur[5], unzip sum[11]:cur[0]
            ---BUFFER POOL 3
            Buffer pool size   65536
            Free buffers       1022
            Database pages     63964
            Old database pages 23591
            Modified db pages  207
            Percent of dirty pages(LRU & free pages): 0.319
            Max dirty pages percent: 75.000
            Pending reads 0
            Pending writes: LRU 0, flush list 0, single page 0
            Pages made young 187455850, not young 2246339007
            54.03 youngs/s, 818.98 non-youngs/s
            Pages read 80333729, created 11792660, written 24424761
            104.11 reads/s, 0.40 creates/s, 14.66 writes/s
            Buffer pool hit rate 991 / 1000, young-making rate 4 / 1000 not 66 / 1000
            Pages read ahead 1.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
            LRU len: 63964, unzip_LRU len: 45
            I/O sum[11651]:cur[5], unzip sum[11]:cur[0]
            --------------
            ROW OPERATIONS
            --------------
            0 queries inside InnoDB, 0 queries in queue
            0 read views open inside InnoDB
            Process ID=3229, Main thread ID=139926059009792, state: sleeping
            Number of rows inserted 111212694, updated 32990275, deleted 37939869, read 465271749563
            103.88 inserts/s, 97.48 updates/s, 102.65 deletes/s, 58113.25 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
            ============================
            

            stepassia Stefano Passiatore added a comment - This the "show engine innodb status" output...   ===================================== 2023 - 06 - 16 15 : 40 : 36 0x7f42c8521700 INNODB MONITOR OUTPUT ===================================== Per second averages calculated from the last 35 seconds ----------------- BACKGROUND THREAD ----------------- srv_master_thread loops: 2291203 srv_active, 0 srv_shutdown, 190383 srv_idle srv_master_thread log flush and writes: 2481513 ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 605370221 OS WAIT ARRAY INFO: signal count 387498064 RW-shared spins 113460664 , rounds 1325628978 , OS waits 35669327 RW-excl spins 109517156 , rounds 489343901 , OS waits 3882404 RW-sx spins 4534492 , rounds 81766293 , OS waits 1430009 Spin rounds per wait: 11.68 RW-shared, 4.47 RW-excl, 18.03 RW-sx ------------------------ LATEST DETECTED DEADLOCK ------------------------ 2023 - 06 - 15 09 : 35 : 04 0x7f4420166700 *** ( 1 ) TRANSACTION: TRANSACTION 14554536583 , ACTIVE 0 sec inserting mysql tables in use 1 , locked 1 LOCK WAIT 3 lock struct(s), heap size 1128 , 2 row lock(s) MySQL thread id 11372646 , OS thread handle 139930572228352 , query id 2605663046 192.168 . 100.59 d9_sancasciano Update INSERT INTO "semaphore" ( "name" , "value" , "expire" ) VALUES ( 'cron' , '662026395648abf28db5da3.54430695' , '1686815404.898' ) *** ( 1 ) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 850609 page no 3 n bits 72 index PRIMARY of table "d9_sancasciano" . "semaphore" trx id 14554536583 lock_mode X locks rec but not gap waiting Record lock, heap no 2 PHYSICAL RECORD: n_fields 5 ; compact format; info bits 32 0 : len 4 ; hex 63726f6e; asc cron;; 1 : len 6 ; hex 00036383caa9; asc c ;; 2 : len 7 ; hex 7200005dbf0be2; asc r ] ;; 3 : len 30 ; hex 3130363232353033373036343861626466653030663535352e3338323634; asc 1062250370648abdfe00f555. 38264 ; (total 33 bytes); 4 : len 8 ; hex 9eef7f60b022d941; asc ` " A;;   *** ( 2 ) TRANSACTION: TRANSACTION 14554536584 , ACTIVE 0 sec inserting mysql tables in use 1 , locked 1 3 lock struct(s), heap size 1128 , 2 row lock(s) MySQL thread id 11372652 , OS thread handle 139930572842752 , query id 2605663047 192.168 . 100.59 d9_sancasciano Update INSERT INTO "semaphore" ( "name" , "value" , "expire" ) VALUES ( 'cron' , '182559208648abf28db5fa8.01710098' , '1686815404.8981' ) *** ( 2 ) HOLDS THE LOCK(S): RECORD LOCKS space id 850609 page no 3 n bits 72 index PRIMARY of table "d9_sancasciano" . "semaphore" trx id 14554536584 lock mode S locks rec but not gap Record lock, heap no 2 PHYSICAL RECORD: n_fields 5 ; compact format; info bits 32 0 : len 4 ; hex 63726f6e; asc cron;; 1 : len 6 ; hex 00036383caa9; asc c ;; 2 : len 7 ; hex 7200005dbf0be2; asc r ] ;; 3 : len 30 ; hex 3130363232353033373036343861626466653030663535352e3338323634; asc 1062250370648abdfe00f555. 38264 ; (total 33 bytes); 4 : len 8 ; hex 9eef7f60b022d941; asc ` " A;;   *** ( 2 ) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 850609 page no 3 n bits 72 index PRIMARY of table "d9_sancasciano" . "semaphore" trx id 14554536584 lock_mode X locks rec but not gap waiting Record lock, heap no 2 PHYSICAL RECORD: n_fields 5 ; compact format; info bits 32 0 : len 4 ; hex 63726f6e; asc cron;; 1 : len 6 ; hex 00036383caa9; asc c ;; 2 : len 7 ; hex 7200005dbf0be2; asc r ] ;; 3 : len 30 ; hex 3130363232353033373036343861626466653030663535352e3338323634; asc 1062250370648abdfe00f555. 38264 ; (total 33 bytes); 4 : len 8 ; hex 9eef7f60b022d941; asc ` " A;;   *** WE ROLL BACK TRANSACTION ( 2 ) ------------ TRANSACTIONS ------------ Trx id counter 14586125499 Purge done for trx's n:o < 14586125499 undo n:o < 0 state: running but idle History list length 25 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 421405608165640 , not started 0 lock struct(s), heap size 1128 , 0 row lock(s) ---TRANSACTION 421405608161464 , not started 0 lock struct(s), heap size 1128 , 0 row lock(s) ---TRANSACTION 421405608190696 , not started 0 lock struct(s), heap size 1128 , 0 row lock(s) ---TRANSACTION 421405608173992 , not started 0 lock struct(s), heap size 1128 , 0 row lock(s) ---TRANSACTION 421405608157288 , not started 0 lock struct(s), heap size 1128 , 0 row lock(s) -------- FILE I/O -------- I/O thread 0 state: waiting for completed aio requests (insert buffer thread) I/O thread 1 state: waiting for completed aio requests (log thread) I/O thread 2 state: waiting for completed aio requests (read thread) I/O thread 3 state: waiting for completed aio requests (read thread) I/O thread 4 state: waiting for completed aio requests (read thread) I/O thread 5 state: waiting for completed aio requests (read thread) I/O thread 6 state: waiting for completed aio requests (read thread) I/O thread 7 state: waiting for completed aio requests (read thread) I/O thread 8 state: waiting for completed aio requests (read thread) I/O thread 9 state: waiting for completed aio requests (read thread) I/O thread 10 state: waiting for completed aio requests (read thread) I/O thread 11 state: waiting for completed aio requests (read thread) I/O thread 12 state: waiting for completed aio requests (read thread) I/O thread 13 state: waiting for completed aio requests (read thread) I/O thread 14 state: waiting for completed aio requests (read thread) I/O thread 15 state: waiting for completed aio requests (read thread) I/O thread 16 state: waiting for completed aio requests (read thread) I/O thread 17 state: waiting for completed aio requests (read thread) I/O thread 18 state: waiting for completed aio requests (read thread) I/O thread 19 state: waiting for completed aio requests (read thread) I/O thread 20 state: waiting for completed aio requests (read thread) I/O thread 21 state: waiting for completed aio requests (read thread) I/O thread 22 state: waiting for completed aio requests (read thread) I/O thread 23 state: waiting for completed aio requests (read thread) I/O thread 24 state: waiting for completed aio requests (read thread) I/O thread 25 state: waiting for completed aio requests (read thread) I/O thread 26 state: waiting for completed aio requests (read thread) I/O thread 27 state: waiting for completed aio requests (read thread) I/O thread 28 state: waiting for completed aio requests (read thread) I/O thread 29 state: waiting for completed aio requests (read thread) I/O thread 30 state: waiting for completed aio requests (read thread) I/O thread 31 state: waiting for completed aio requests (read thread) I/O thread 32 state: waiting for completed aio requests (read thread) I/O thread 33 state: waiting for completed aio requests (read thread) I/O thread 34 state: waiting for completed aio requests (read thread) I/O thread 35 state: waiting for completed aio requests (read thread) I/O thread 36 state: waiting for completed aio requests (read thread) I/O thread 37 state: waiting for completed aio requests (read thread) I/O thread 38 state: waiting for completed aio requests (read thread) I/O thread 39 state: waiting for completed aio requests (read thread) I/O thread 40 state: waiting for completed aio requests (read thread) I/O thread 41 state: waiting for completed aio requests (read thread) I/O thread 42 state: waiting for completed aio requests (read thread) I/O thread 43 state: waiting for completed aio requests (read thread) I/O thread 44 state: waiting for completed aio requests (read thread) I/O thread 45 state: waiting for completed aio requests (read thread) I/O thread 46 state: waiting for completed aio requests (read thread) I/O thread 47 state: waiting for completed aio requests (read thread) I/O thread 48 state: waiting for completed aio requests (read thread) I/O thread 49 state: waiting for completed aio requests (read thread) I/O thread 50 state: waiting for completed aio requests (read thread) I/O thread 51 state: waiting for completed aio requests (read thread) I/O thread 52 state: waiting for completed aio requests (read thread) I/O thread 53 state: waiting for completed aio requests (read thread) I/O thread 54 state: waiting for completed aio requests (read thread) I/O thread 55 state: waiting for completed aio requests (read thread) I/O thread 56 state: waiting for completed aio requests (read thread) I/O thread 57 state: waiting for completed aio requests (read thread) I/O thread 58 state: waiting for completed aio requests (read thread) I/O thread 59 state: waiting for completed aio requests (read thread) I/O thread 60 state: waiting for completed aio requests (read thread) I/O thread 61 state: waiting for completed aio requests (read thread) I/O thread 62 state: waiting for completed aio requests (read thread) I/O thread 63 state: waiting for completed aio requests (read thread) I/O thread 64 state: waiting for completed aio requests (read thread) I/O thread 65 state: waiting for completed aio requests (read thread) I/O thread 66 state: waiting for completed aio requests (write thread) I/O thread 67 state: waiting for completed aio requests (write thread) I/O thread 68 state: waiting for completed aio requests (write thread) I/O thread 69 state: waiting for completed aio requests (write thread) I/O thread 70 state: waiting for completed aio requests (write thread) I/O thread 71 state: waiting for completed aio requests (write thread) I/O thread 72 state: waiting for completed aio requests (write thread) I/O thread 73 state: waiting for completed aio requests (write thread) I/O thread 74 state: waiting for completed aio requests (write thread) I/O thread 75 state: waiting for completed aio requests (write thread) I/O thread 76 state: waiting for completed aio requests (write thread) I/O thread 77 state: waiting for completed aio requests (write thread) I/O thread 78 state: waiting for completed aio requests (write thread) I/O thread 79 state: waiting for completed aio requests (write thread) I/O thread 80 state: waiting for completed aio requests (write thread) I/O thread 81 state: waiting for completed aio requests (write thread) I/O thread 82 state: waiting for completed aio requests (write thread) I/O thread 83 state: waiting for completed aio requests (write thread) I/O thread 84 state: waiting for completed aio requests (write thread) I/O thread 85 state: waiting for completed aio requests (write thread) I/O thread 86 state: waiting for completed aio requests (write thread) I/O thread 87 state: waiting for completed aio requests (write thread) I/O thread 88 state: waiting for completed aio requests (write thread) I/O thread 89 state: waiting for completed aio requests (write thread) I/O thread 90 state: waiting for completed aio requests (write thread) I/O thread 91 state: waiting for completed aio requests (write thread) I/O thread 92 state: waiting for completed aio requests (write thread) I/O thread 93 state: waiting for completed aio requests (write thread) I/O thread 94 state: waiting for completed aio requests (write thread) I/O thread 95 state: waiting for completed aio requests (write thread) I/O thread 96 state: waiting for completed aio requests (write thread) I/O thread 97 state: waiting for completed aio requests (write thread) I/O thread 98 state: waiting for completed aio requests (write thread) I/O thread 99 state: waiting for completed aio requests (write thread) I/O thread 100 state: waiting for completed aio requests (write thread) I/O thread 101 state: waiting for completed aio requests (write thread) I/O thread 102 state: waiting for completed aio requests (write thread) I/O thread 103 state: waiting for completed aio requests (write thread) I/O thread 104 state: waiting for completed aio requests (write thread) I/O thread 105 state: waiting for completed aio requests (write thread) I/O thread 106 state: waiting for completed aio requests (write thread) I/O thread 107 state: waiting for completed aio requests (write thread) I/O thread 108 state: waiting for completed aio requests (write thread) I/O thread 109 state: waiting for completed aio requests (write thread) I/O thread 110 state: waiting for completed aio requests (write thread) I/O thread 111 state: waiting for completed aio requests (write thread) I/O thread 112 state: waiting for completed aio requests (write thread) I/O thread 113 state: waiting for completed aio requests (write thread) I/O thread 114 state: waiting for completed aio requests (write thread) I/O thread 115 state: waiting for completed aio requests (write thread) I/O thread 116 state: waiting for completed aio requests (write thread) I/O thread 117 state: waiting for completed aio requests (write thread) I/O thread 118 state: waiting for completed aio requests (write thread) I/O thread 119 state: waiting for completed aio requests (write thread) I/O thread 120 state: waiting for completed aio requests (write thread) I/O thread 121 state: waiting for completed aio requests (write thread) I/O thread 122 state: waiting for completed aio requests (write thread) I/O thread 123 state: waiting for completed aio requests (write thread) I/O thread 124 state: waiting for completed aio requests (write thread) I/O thread 125 state: waiting for completed aio requests (write thread) I/O thread 126 state: waiting for completed aio requests (write thread) I/O thread 127 state: waiting for completed aio requests (write thread) I/O thread 128 state: waiting for completed aio requests (write thread) I/O thread 129 state: waiting for completed aio requests (write thread) Pending normal aio reads: [ 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 ] , aio writes: [ 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 , 0 ] , ibuf aio reads:, log i/o 's:, sync i/o' s: Pending flushes (fsync) log: 0 ; buffer pool: 0 308763051 OS file reads, 154666053 OS file writes, 100393792 OS fsyncs 254.88 reads/s, 16368 avg bytes/read, 65.23 writes/s, 31.00 fsyncs/s ------------------------------------- INSERT BUFFER AND ADAPTIVE HASH INDEX ------------------------------------- Ibuf: size 1 , free list len 1343 , seg size 1345 , 1600034 merges merged operations: insert 2349796 , delete mark 10579745 , delete 3360115 discarded operations: insert 7 , delete mark 4 , delete 0 Hash table size 1106407 , node heap has 163 buffer(s) Hash table size 1106407 , node heap has 172 buffer(s) Hash table size 1106407 , node heap has 315 buffer(s) Hash table size 1106407 , node heap has 340 buffer(s) Hash table size 1106407 , node heap has 202 buffer(s) Hash table size 1106407 , node heap has 276 buffer(s) Hash table size 1106407 , node heap has 549 buffer(s) Hash table size 1106407 , node heap has 170 buffer(s) 9002.31 hash searches/s, 7492.04 non-hash searches/s --- LOG --- Log sequence number 13815524744212 Log flushed up to 13815524410702 Pages flushed up to 13815463999846 Last checkpoint at 13815463842223 0 pending log flushes, 0 pending chkp writes 37173925 log i/o 's done, 3.11 log i/o' s/second ---------------------- BUFFER POOL AND MEMORY ---------------------- Total large memory allocated 4418699264 Dictionary memory allocated 58261280 Buffer pool size 262144 Free buffers 4085 Database pages 255766 Old database pages 94334 Modified db pages 812 Percent of dirty pages(LRU & free pages): 0.312 Max dirty pages percent: 75.000 Pending reads 0 Pending writes: LRU 0 , flush list 0 , single page 0 Pages made young 726638625 , not young 8140358952 481.84 youngs/s, 1862.00 non-youngs/s Pages read 308730981 , created 47154616 , written 95434350 254.88 reads/s, 3.14 creates/s, 54.03 writes/s Buffer pool hit rate 995 / 1000 , young-making rate 8 / 1000 not 33 / 1000 Pages read ahead 3.51 /s, evicted without access 0.00 /s, Random read ahead 0.00 /s LRU len: 255766 , unzip_LRU len: 174 I/O sum[ 46604 ]:cur[ 20 ], unzip sum[ 44 ]:cur[ 0 ] ---------------------- INDIVIDUAL BUFFER POOL INFO ---------------------- ---BUFFER POOL 0 Buffer pool size 65536 Free buffers 1023 Database pages 63962 Old database pages 23591 Modified db pages 333 Percent of dirty pages(LRU & free pages): 0.512 Max dirty pages percent: 75.000 Pending reads 0 Pending writes: LRU 0 , flush list 0 , single page 0 Pages made young 178274920 , not young 1913356743 116.08 youngs/s, 388.62 non-youngs/s Pages read 77154143 , created 11789983 , written 32487319 52.86 reads/s, 0.77 creates/s, 16.17 writes/s Buffer pool hit rate 996 / 1000 , young-making rate 7 / 1000 not 24 / 1000 Pages read ahead 0.00 /s, evicted without access 0.00 /s, Random read ahead 0.00 /s LRU len: 63962 , unzip_LRU len: 57 I/O sum[ 11651 ]:cur[ 5 ], unzip sum[ 11 ]:cur[ 0 ] ---BUFFER POOL 1 Buffer pool size 65536 Free buffers 1019 Database pages 63895 Old database pages 23567 Modified db pages 51 Percent of dirty pages(LRU & free pages): 0.079 Max dirty pages percent: 75.000 Pending reads 0 Pending writes: LRU 0 , flush list 0 , single page 0 Pages made young 178555553 , not young 2039751844 221.85 youngs/s, 48.83 non-youngs/s Pages read 76600171 , created 11772433 , written 19031649 10.57 reads/s, 1.00 creates/s, 10.66 writes/s Buffer pool hit rate 999 / 1000 , young-making rate 20 / 1000 not 4 / 1000 Pages read ahead 0.69 /s, evicted without access 0.00 /s, Random read ahead 0.00 /s LRU len: 63895 , unzip_LRU len: 33 I/O sum[ 11651 ]:cur[ 5 ], unzip sum[ 11 ]:cur[ 0 ] ---BUFFER POOL 2 Buffer pool size 65536 Free buffers 1021 Database pages 63945 Old database pages 23585 Modified db pages 221 Percent of dirty pages(LRU & free pages): 0.340 Max dirty pages percent: 75.000 Pending reads 0 Pending writes: LRU 0 , flush list 0 , single page 0 Pages made young 182352302 , not young 1940911358 89.88 youngs/s, 605.58 non-youngs/s Pages read 74642938 , created 11799540 , written 19490621 87.34 reads/s, 0.97 creates/s, 12.54 writes/s Buffer pool hit rate 994 / 1000 , young-making rate 5 / 1000 not 38 / 1000 Pages read ahead 1.83 /s, evicted without access 0.00 /s, Random read ahead 0.00 /s LRU len: 63945 , unzip_LRU len: 39 I/O sum[ 11651 ]:cur[ 5 ], unzip sum[ 11 ]:cur[ 0 ] ---BUFFER POOL 3 Buffer pool size 65536 Free buffers 1022 Database pages 63964 Old database pages 23591 Modified db pages 207 Percent of dirty pages(LRU & free pages): 0.319 Max dirty pages percent: 75.000 Pending reads 0 Pending writes: LRU 0 , flush list 0 , single page 0 Pages made young 187455850 , not young 2246339007 54.03 youngs/s, 818.98 non-youngs/s Pages read 80333729 , created 11792660 , written 24424761 104.11 reads/s, 0.40 creates/s, 14.66 writes/s Buffer pool hit rate 991 / 1000 , young-making rate 4 / 1000 not 66 / 1000 Pages read ahead 1.00 /s, evicted without access 0.00 /s, Random read ahead 0.00 /s LRU len: 63964 , unzip_LRU len: 45 I/O sum[ 11651 ]:cur[ 5 ], unzip sum[ 11 ]:cur[ 0 ] -------------- ROW OPERATIONS -------------- 0 queries inside InnoDB, 0 queries in queue 0 read views open inside InnoDB Process ID= 3229 , Main thread ID= 139926059009792 , state: sleeping Number of rows inserted 111212694 , updated 32990275 , deleted 37939869 , read 465271749563 103.88 inserts/s, 97.48 updates/s, 102.65 deletes/s, 58113.25 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 ============================

            MariaDB Server 10.3 is no longer supported, and 10.4 will soon reach its end of life as well. The redo log format and its parsing were rewritten in MDEV-12353 and MDEV-14425.

            That said, there is a well known design problem that could explain this. Because the circular ib_logfile0 is being written by one process (the MariaDB server) and concurrently read by mariadb-backup --backup in another process, it is possible that the backup process fails to keep up. A solution would be to make the server responsible for backing up the log (MDEV-14992) so that an overwrite can be avoided. A work-around might be to force a log checkpoint at the start of the backup (MDEV-30000), so that less log will need to be copied during the backup.

            marko Marko Mäkelä added a comment - MariaDB Server 10.3 is no longer supported, and 10.4 will soon reach its end of life as well. The redo log format and its parsing were rewritten in MDEV-12353 and MDEV-14425 . That said, there is a well known design problem that could explain this. Because the circular ib_logfile0 is being written by one process (the MariaDB server) and concurrently read by mariadb-backup --backup in another process, it is possible that the backup process fails to keep up. A solution would be to make the server responsible for backing up the log ( MDEV-14992 ) so that an overwrite can be avoided. A work-around might be to force a log checkpoint at the start of the backup ( MDEV-30000 ), so that less log will need to be copied during the backup.

            People

              Unassigned Unassigned
              stepassia Stefano Passiatore
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

                Created:
                Updated:

                Git Integration

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