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

Incorrect multi-batch recovery of file size

    XMLWordPrintable

Details

    • Can result in hang or crash
    • When executing crash recovery in multiple batches, InnoDB may fail to extend a file and crash on a subsequent write to it.
    • Q3/2026 Server Development

    Description

      data.tar.xz and encryption_keys.txt is a data set that would crash after data recovery when innodb_immediate_scrub_data_uncompressed=ON would try to write out zeroes to page 134 that had been marked as freed:

      MDEV-14992 ac5617b78570c174f239da065362ccec456affc5

      2026-08-13 10:32:33 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=178365740
      2026-08-13 10:32:33 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-3d29e6-19-22.ibd' with space ID 241. Another data file called ./test/t2.ibd exists with the same space ID.
      2026-08-13 10:32:33 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-3d29e6-13-1e.ibd' with space ID 238. Another data file called ./test/t8.ibd exists with the same space ID.
      2026-08-13 10:32:33 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-3d29e6-13-1e.ibd' with space ID 238. Another data file called ./test/t8.ibd exists with the same space ID.
      2026-08-13 10:32:34 0 [Note] InnoDB: Multi-batch recovery needed at LSN 180821756
      2026-08-13 10:32:34 0 [Note] InnoDB: End of log at LSN=185909687
      2026-08-13 10:32:34 0 [Note] InnoDB: Multi-batch recovery needed at LSN 183304965
      2026-08-13 10:32:35 0 [Note] InnoDB: Multi-batch recovery needed at LSN 185673917
      2026-08-13 10:32:35 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-3d29e6-19-22.ibd' with space ID 241. Another data file called ./test/t2.ibd exists with the same space ID.
      2026-08-13 10:32:35 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-3d29e6-13-1e.ibd' with space ID 238. Another data file called ./test/t8.ibd exists with the same space ID.
      2026-08-13 10:32:35 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-3d29e6-13-1e.ibd' with space ID 238. Another data file called ./test/t8.ibd exists with the same space ID.
      2026-08-13 10:32:35 0 [Note] InnoDB: To recover: LSN 180838229/185909687; 1768 pages
      2026-08-13 10:32:36 0 [ERROR] [FATAL] InnoDB: Trying to write 4096 bytes at 548864 outside the bounds of the file: ./test/A.ibd
      

      In the log, the FSP_SIZE of that file was actually persisted to 1024 pages, way earlier than the FREE_PAGE record had been written. Everything for this file had been written as part of executing the following statement:

      CREATE TABLE A AS SELECT * FROM t7;
      

      Recovery does initially find the correct space->recv_size. I suspect that the culprit is the multi-batch recovery.

      To reproduce this issue, execute the following:

      tar xJf data.tar.xz -C /tmp
      _RR_TRACE_DIR=rr rr record sql/mariadbd --innodb-encrypt-log --plugin-dir=$PWD/plugin/file_key_management --plugin-load-add=file_key_management --file-key-management-filename=/tmp/encryption_keys.txt --datadir=/tmp/data --innodb-buffer-pool-size=6m --innodb-page-size=4k
      rr replay rr/latest-trace
      

      break fil_ibd_load
      cond 1 space_id==0xeb
      continue
      finish
      set $s=space
      watch -l $s.recv_size
      cond 2 $s.recv_size>0x300
      continue
      cond 2
      continue
      backtrace
      

      We will get the following:

      Thread 1 hit Hardware watchpoint 2: -location $s.recv_size
       
      Old value = 0x400
      New value = 0x64
      

      That is, the correct size that had been recovered during recv_scan_log_archive_skip_the_rest in the initial pass of multi-batch recovery is being overwritten with a wrong one.

      In the original rr replay trace that mleich shared with me, the file had only been extended to 60 (0x3c) pages instead of the correct size of 1024 pages.

      Initially, the file is being extended by one page at a time. To properly recover this data directory, also some compression plugins are needed. For the record, here is the original trace:

      ssh pluto
      rr replay /data/results/1786614522/MB-2436/1_clone/rr/latest-trace
      

      This problem blocks MDEV-14992 (BACKUP SERVER), because that implementation optimizes the amount of data that is being copied. In this case, the data directory only contains the first 4 pages of the file, and the rest can be recovered from the log records.

      To recover the dataset with an older version of the server than 13.0, the log file header would have to be rewritten by executing something similar to the directions given in MDEV-40728. It is a little more complicated, because some encryption metadata would have to be included as well.

      Attachments

        1. data.tar.xz
          9.46 MB
          Marko Mäkelä
        2. encryption_keys.txt
          0.4 kB
          Marko Mäkelä

        Issue Links

          Activity

            People

              marko Marko Mäkelä
              marko Marko Mäkelä
              Marko Mäkelä Marko Mäkelä
              Thirunarayanan Balathandayuthapani Thirunarayanan Balathandayuthapani
              Matthias Leich Matthias Leich
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Time Tracking

                  Estimated:
                  Original Estimate - 1d 3h 19m
                  1d 3h 19m
                  Remaining:
                  Remaining Estimate - 0d
                  0d
                  Logged:
                  Time Spent - 4.75h Time Not Required
                  4.75h

                  Git Integration

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