[MDEV-25909] Unnecessary calls to fil_ibd_load() slow down recovery Created: 2021-06-14  Updated: 2023-12-22

Status: Open
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.2, 10.3, 10.4, 10.5, 10.6
Fix Version/s: 10.6

Type: Bug Priority: Major
Reporter: Marko Mäkelä Assignee: Thirunarayanan Balathandayuthapani
Resolution: Unresolved Votes: 0
Labels: performance, recovery

Issue Links:
Relates
relates to MDEV-27014 InnoDB fails to restore page 0 from t... Closed
relates to MDEV-28389 Data too long for column 'line' Closed
relates to MDEV-29987 Bogus errors about file size in the t... Closed
relates to MDEV-32120 [ERROR] InnoDB: Expected tablespace i... Open
relates to MDEV-24626 Remove synchronous write of page0 and... Closed
relates to MDEV-25568 "RENAME TABLE" causes "Ignoring data ... Closed
relates to MDEV-25852 Orphan #sql*.ibd files are occasional... Closed
relates to MDEV-26326 MDEV-24626 (remove synchronous page0 ... Closed

 Description   

As I noted in MDEV-25852, recovery should probably maintain a mapping from file names to tablespace IDs, so that it can avoid repeated reads of the same page. We are not only unnecessarily re-reading files during recovery, but also displaying messages about it:

10.6 6fbf978eec4506eb46737ac4da00ea04403ae855

2021-06-10 20:59:34 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-3116aa-53.ibd' with space ID 1594. Another data file called ./cool_down/t3.ibd exists with the same space ID.
2021-06-10 20:59:34 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-3116aa-53.ibd' with space ID 1594. Another data file called ./cool_down/t3.ibd exists with the same space ID.
2021-06-10 20:59:34 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-3116aa-53.ibd' with space ID 1594. Another data file called ./cool_down/t3.ibd exists with the same space ID.
2021-06-10 20:59:34 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-3116aa-53.ibd' with space ID 1606. Another data file called ./cool_down/t1.ibd exists with the same space ID.
2021-06-10 20:59:34 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-3116aa-53.ibd' with space ID 1606. Another data file called ./cool_down/t1.ibd exists with the same space ID.
2021-06-10 20:59:34 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-3116aa-53.ibd' with space ID 1606. Another data file called ./cool_down/t1.ibd exists with the same space ID.
2021-06-10 20:59:34 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-3116aa-57.ibd' with space ID 1624. Another data file called ./cool_down/t4.ibd exists with the same space ID.
2021-06-10 20:59:34 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-3116aa-57.ibd' with space ID 1624. Another data file called ./cool_down/t4.ibd exists with the same space ID.
2021-06-10 20:59:34 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-3116aa-57.ibd' with space ID 1624. Another data file called ./cool_down/t4.ibd exists with the same space ID.
2021-06-10 20:59:35 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-3116aa-57.ibd' with space ID 1811. Another data file called ./test/t4.ibd exists with the same space ID.
2021-06-10 20:59:35 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-3116aa-57.ibd' with space ID 1811. Another data file called ./test/t4.ibd exists with the same space ID.
2021-06-10 20:59:35 0 [Note] InnoDB: Ignoring data file './test/#sql-alter-3116aa-57.ibd' with space ID 1811. Another data file called ./test/t4.ibd exists with the same space ID.

In deferred_spaces.add() the existence of a name-to-ID mapping would avoid a full traversal of the data structure:

    char *fil_path= fil_make_filepath(nullptr, {filename, strlen(filename)},
                                      IBD, false);
    const item defer{lsn, fil_path, false};
    ut_free(fil_path);
 
    /* The file name must be unique. Keep the one with the latest LSN. */
    auto d= defers.begin();
 
    while (d != defers.end())
    {
      if (d->second.file_name != defer.file_name)
        ++d;

Here, also the call to fil_make_filepath() could be unnecessary and possibly should be removed. (It has to be tested extensively with DATA DIRECTORY.)
Last, somewhat related to this (and MDEV-24626), I think that Datafile::read_first_page() needs to be simplified. We should only read the first innodb_page_size bytes from the file. If the file is shorter than that, or all bytes are NUL, we will use deferred_spaces. If the FSP_SPACE_FLAGS matches our innodb_page_size and the checksum are valid, we will return the tablespace ID. Else, we will use deferred_spaces.



 Comments   
Comment by Marko Mäkelä [ 2021-07-30 ]

It seems to me that the function Datafile::find_space_id() can be removed altogether. As far as I can tell, one attempt to read page 0 of each .ibd file that is mentioned by FILE_ records should be sufficient.

Comment by Marko Mäkelä [ 2021-07-30 ]

I was thinking whether Datafile::restore_from_doublewrite() is unnecessary, but I concluded that it still is necessary in the following scenario:

  1. The file has already been created and page 0 written.
  2. The checkpoint LSN has been advanced past the FIL_PAGE_LSN of that first write of page 0, so that the page cannot be recovered solely based on redo log records.
  3. The page is modified again.
  4. A doublewrite copy of the modified page 0 is written.
  5. The page is being written to the file, but the server is killed in the middle of the write.
  6. Recovery will read a corrupted page 0.
  7. Recovery will restore a valid copy of the page from the doublewrite buffer.
Comment by Marko Mäkelä [ 2021-11-02 ]

The test innodb.corrupted_during_recovery is failing quite a bit starting with 10.6, like this:

10.6 d4a89b92629328f7e18b7e0595f88f24

innodb.corrupted_during_recovery 'innodb' w1 [ fail ]  Found warnings/errors in server log file!
        Test ended at 2021-10-27 10:14:27
Warnings:
Warning	1406	Data too long for column 'line' at row 8
line
 len 16384; hex 0000000000000003ffffffffffffffff…2021-10-27
^ Found warnings in /dev/shm/var/1/log/mysqld.1.err
ok

Hopefully such page dumps (which are only output by CMAKE_BUILD_TYPE=RelWithDebInfo builds) would no longer appear once this code has been fixed.

Comment by Marko Mäkelä [ 2023-11-09 ]

While analyzing MDEV-32737, I came up with some additional ideas for improvements:

  • Ensure that fil_ibd_load() issues an error message before returning FIL_LOAD_INVALID, so that the caller fil_name_process() can avoid doing that.
  • In the "Ignoring data file" message, mention the expected space_id that was passed to fil_ibd_load(), in addition to mentioning the unexpected space->id.
Generated at Thu Feb 08 09:41:19 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.