[MDEV-27900] aio returning partial reads/writes looks like InnoDB: Database page corruption on btrfs with io_uring Created: 2022-02-20  Updated: 2022-07-25  Resolved: 2022-03-12

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.6.7
Fix Version/s: 10.5.16, 10.6.8, 10.7.4, 10.8.3

Type: Bug Priority: Major
Reporter: ajs124 Assignee: Daniel Black
Resolution: Fixed Votes: 1
Labels: None
Environment:

NixOS 21.11 and unstable. Linux kernel 5.16.8

Issue Links:
Duplicate
is duplicated by MDEV-27975 mariadb-server won't startup on insta... Closed
Relates
relates to MDEV-24854 Change innodb_flush_method=O_DIRECT b... Closed

 Description    

Feb 17 23:47:45 apfelkirsch systemd[1]: Starting MySQL Server...
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] /nix/store/svbwxblrhai6fcij9p9pmyyafa5pcqls-mariadb-server-10.6.5/bin/mysqld (server 10.6.5-MariaDB) starting as process 16475 ...
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Warning] WSREP: Failed to guess base node address. Set it explicitly via wsrep_node_address.
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Warning] WSREP: Failed to guess base node address. Set it explicitly via wsrep_node_address.
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Warning] WSREP: Guessing address for incoming client connections failed. Try setting wsrep_node_incoming_address explicitly.
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] WSREP: Node addr:
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB: Number of pools: 1
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB: Using liburing
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB: Completed initialization of buffer pool
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=42161,42161
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB: 128 rollback segments are active.
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB: Removed temporary tablespace data file: "./ibtmp1"
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB: Creating shared tablespace for temporary tables
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB: 10.6.5 started; log sequence number 42173; transaction id 14
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] Plugin 'FEEDBACK' is disabled.
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [ERROR] InnoDB: Database page corruption on disk or a failed read of file './ibdata1' page [page id: space=0, page number=9]. You may have to recover from a backup.
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB: Page dump in ascii and hex (16384 bytes):
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]:  len 16384; hex 000000000000002022-02-17 23:47:45 0 [ERROR] InnoDB: Database page corruption on disk or a failed read of file './ibdata1' page [page id: space=0, page number=243]. You may have to recover from a backup.
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 09ffffffffffffffff00000000000099ab2022-02-17 23:47:45 0 [Note] InnoDB: Page dump in ascii and hex (16384 bytes):
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]:  len 16384; hex 00000000000000f3ffff45bf000000000000000000ffffffffffff000000000000000000009e6e00030000000000022022-02-17 23:47:45 0 [ERROR] InnoDB: Database page corruption on disk or a failed read of file './mysql/innodb_table_stats.ibd' page [page id: space=1, page number=0]. You may have to recover from a backup.
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB: Page dump in ascii and hex (16384 bytes):
 
 
 
[…]
 
 
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: InnoDB: End of page dump
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB: Uncompressed page, stored checksum in field1 0, calculated checksums for field1: crc32 2039713970, innodb 724040756, page type 17855, stored checksum in field2 0, innodb checksum for field2: 1607711317,  page LSN 0 39339, low 4 bytes of LSN at page end 0, page number (if stored to page already) 9, space id (if created with >= MySQL-4.1.1 and stored already) 0
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB: Page may be an index page where index id is 5
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB: Index 5 is `ID_IND` in table `SYS_TABLES`
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB:  You can use CHECK TABLE to scan your table for corruption. Please refer to https://mariadb.com/kb/en/library/innodb-recovery-modes/ for information about forcing recovery.
 
Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [ERROR] [FATAL] InnoDB: Aborting because of a corrupt database page.
 
Feb 17 23:47:46 apfelkirsch systemd[1]: mysql.service: Main process exited, code=killed, status=6/ABRT

See https://github.com/NixOS/nixpkgs/issues/160516 and https://github.com/NixOS/nixpkgs/issues/160145 for potentially more details.

 Comments   
Comment by Marko Mäkelä [ 2022-02-20 ]

This actually looks like a duplicate of MDEV-27449.

In both server error logs, we can observe that the io_uring interface is being used:

2022-01-09  9:46:34 0 [Note] InnoDB: Using liburing
 
 Feb 17 23:47:45 apfelkirsch mysql-start[16475]: 2022-02-17 23:47:45 0 [Note] InnoDB: Using liburing

I am not familiar with btrfs, but I read somewhere that it could be a good idea to disable the copy-on-write feature on the data directory, with something like the following:

chattr +C /var/lib/mysql

Has that been tried?

Does the page dump in the error log match the contents of page 9 in the file?

od -Ax -t x1 -j 0x24000 -N 0x4000 ibdata1

Is this repeatable on the first startup after initializing a new database?

Comment by Marko Mäkelä [ 2022-02-20 ]

Furthermore, is this repeatable if the server was always started up with innodb_use_native_aio=0?

Comment by Marko Mäkelä [ 2022-02-20 ]

Could this simply be due to innodb_flush_method=O_DIRECT not being compatible with btrfs due to some reason? As it was noted in MDEV-24854, setting innodb_flush_method=fsync (the pre-10.6 default value) allowed MariaDB to start up on btrfs.

Comment by Daniel Black [ 2022-02-21 ]

https://github.com/NixOS/nixpkgs/issues/160516 lists innodb_use_native_aio=0 as a workaround.

Comment by Daniel Black [ 2022-02-21 ]

Using same loopback image created in MDEV-24854.

mariadb-10.6.8-4030a9fb2eb699361c58d71878e97b282647319a, kernel - 5.17.0-0.rc4.96.fc36.x86_64

 
$  scripts/mysql_install_db --no-defaults --srcdir=$OLDPWD --builddir=$PWD --datadir=/mnt/btrfstest/dd
 
Installing MariaDB/MySQL system tables in '/mnt/btrfstest/dd' ...
 
OK
 
 
 
~/repos/build-mariadb-server-10.6 
$   sql/mysqld --no-defaults --skip-networking --datadir=/mnt/btrfstest/dd  --verbose
 
2022-02-21 14:43:31 0 [Note] sql/mysqld (server 10.6.8-MariaDB) starting as process 121966 ...
 
2022-02-21 14:43:31 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
 
2022-02-21 14:43:31 0 [Note] InnoDB: Number of pools: 1
 
2022-02-21 14:43:31 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions
 
2022-02-21 14:43:31 0 [Note] InnoDB: Using liburing
 
2022-02-21 14:43:31 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
 
2022-02-21 14:43:31 0 [Note] InnoDB: Completed initialization of buffer pool
 
2022-02-21 14:43:31 0 [Note] InnoDB: 128 rollback segments are active.
 
2022-02-21 14:43:31 0 [Note] InnoDB: Creating shared tablespace for temporary tables
 
2022-02-21 14:43:31 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
 
2022-02-21 14:43:31 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
 
2022-02-21 14:43:31 0 [Note] InnoDB: 10.6.8 started; log sequence number 42173; transaction id 14
 
2022-02-21 14:43:31 0 [Note] InnoDB: Loading buffer pool(s) from /mnt/btrfstest/dd/ib_buffer_pool
 
2022-02-21 14:43:31 0 [Note] CONNECT: Version 1.07.0002 March 22, 2021
 
2022-02-21 14:43:31 0 [Note] Plugin 'FEEDBACK' is disabled.
 
2022-02-21 14:43:31 0 [ERROR] InnoDB: Database page corruption on disk or a failed read of file './ibdata1' page [page id: space=0, page number=9]. You may have to recover from a backup.
 
2022-02-21 14:43:31 0 [Note] InnoDB: Page dump in ascii and hex (16384 bytes):
 
 len 16384; hex 00000000000000092022-02-21 14:43:31 0 [ERROR] InnoDB: Database page corruption on disk or a failed read of file './ibdata1' page [page id: space=0, page number=243]. You may have to recover from a backup.
 
ffffffffffffff2022-02-21 14:43:31 0 [Note] InnoDB: Page dump in ascii and hex (16384 bytes):
 
 len 16384; hex 00000000000000f3ffffff0000000000009c2045bf00ffffff0000000000ffffff00000000000000020171000900000000015500020006000700000000000000090000000000000000000000000500000000000000020572000000000000000204b208010000030085690000006e66696d756d000908a0d3000300000803000073757072656d756d000000000013080000100500a000000000000000000000000000000b5359535f464f524549474e18080000180500c0000000000000000c5359ffffff535f464fff0000524549474e5f434f4c531308ffffff0000200500ff0000db000000000000000d5359535f56495254550000000000000056414c00000000000020080000280501030000ffffffff0000ffffffff0000000000000000000e6d7973000000716c2f696e6e6f64625f7461626c655f7300ffffffff0000ffffffff0000000000746174732000ffff080000300501ffff0000ffffffff000005d6692b000000000000000f6d7973716c2f696e6e6f64625f696e6465785fd2007374617473220800003805015500000000000000106d7973716c2f7472616e73616374696f6e5f72656769737472791c0800004005000000f4ffffff74000000000000ffffff00116d79ffffffffffffffffffffffffffffffffffff73716c2f67ffffffffffffffffff7469645f736c6176655fffffffffffffffffff706f7300ffffffffffffff2022-02-21 14:43:31 0 [ERROR] InnoDB: Database page corruption on disk or a failed read of file './mysql/innodb_table_stats.ibd' page [page id: space=1, page number=0]. You may have to recover from a backup.
 
002022-02-21 14:43:31 0 [Note] InnoDB: Page dump in ascii and hex (16384 bytes):
 
 len 16384; hex 00ffff00ffff00000000ff00ff000000000000ff0000ff00000000ff0000ff0000ffff000000ffffffffff00000000ffffffffff00000000ffff000000000000871dffffffffff000000ff00ff08ff00ff000000000000000000000000000000000000ffffffff000000ff00000000ffffffffff00000000ff00010000000100000000000000ff0000000000060000000000000000000000000000000000ffffffffffffffff000000000000000000000000000000000000000000000000000000004000000000150000000400000000ffff00000000000000000000ffff0000000000000000000000000000ffff000000ffffffff00ffffff0000000000000000000000000100000000009e00000000009e00000000ffffffffffff00ffffff0000000000000000000000ffffff0000000000ffff000000000000000000000000ffff000000000000ffff000000000000000000000000000000ffff00000000000000000000000000ffffff00ffffffffff0000ffff00ffffff000000000000000003000000000000000000000000000000ffffffff0000ffffffff000000000001000000000000000200000000000000570000260000000000000000000000000000000000000000000002002600ffffffff000000000000000000ff0000ffffff000000000000000000ffffffff000000000000ffffffff000000000002aaffffff00000000ffffffff00000000ff000000ff000000ff0000000000000000000000ffffffff0000ffffffff0000ff0000000000000000ff0000ff0000000000ffff000000000000000000000000000000000000ff000000000000000000000000000000000000000000ffffff0000ffffffff000005d669d2000000000000000000000000000000000000000000000000000000000000000000f5ffff00ffffff000000000000ff0000000000ffffffff00ff00ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff00000000000000ff0000000000000000000000ffffff00000000000000000000000000ffffffffffff0000000000000000ffffff000000ffffffff00000000000000000000000000ffffffffffffffffffffffffffffffffffff00000000000000580000000000000000ffffffff0000ffffffff000000000000ffffffff0000ffffffff000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000ffff0000000000000000000000000000000000000000ffff0000ffffffff000005d669d2000000f6ffffffffff000000000000000000ffffffffffffffffffffffffffffffffffffffffffffffffffffffffff

innodb_use_native_aio=0 reading the same datadir is starts without problem

 
$   sql/mysqld --no-defaults --skip-networking --datadir=/mnt/btrfstest/dd  --verbose --innodb_use_native_aio=0 --socket /tmp/mysql.sock
 
2022-02-21 14:51:07 0 [Note] sql/mysqld (server 10.6.8-MariaDB) starting as process 122494 ...
 
2022-02-21 14:51:07 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
 
2022-02-21 14:51:07 0 [Note] InnoDB: Number of pools: 1
 
2022-02-21 14:51:07 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions
 
2022-02-21 14:51:07 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
 
2022-02-21 14:51:07 0 [Note] InnoDB: Completed initialization of buffer pool
 
2022-02-21 14:51:07 0 [Note] InnoDB: 128 rollback segments are active.
 
2022-02-21 14:51:07 0 [Note] InnoDB: Creating shared tablespace for temporary tables
 
2022-02-21 14:51:07 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
 
2022-02-21 14:51:07 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
 
2022-02-21 14:51:07 0 [Note] InnoDB: 10.6.8 started; log sequence number 42197; transaction id 14
 
2022-02-21 14:51:07 0 [Note] InnoDB: Loading buffer pool(s) from /mnt/btrfstest/dd/ib_buffer_pool
 
2022-02-21 14:51:07 0 [Note] CONNECT: Version 1.07.0002 March 22, 2021
 
2022-02-21 14:51:07 0 [Note] Plugin 'FEEDBACK' is disabled.
 
2022-02-21 14:51:07 0 [Note] InnoDB: Buffer pool(s) load completed at 220221 14:51:07
 
2022-02-21 14:51:07 0 [Note] sql/mysqld: ready for connections.
 
Version: '10.6.8-MariaDB'  socket: '/tmp/mysql.sock'  port: 0  MariaDB Server
 
^C2022-02-21 14:51:34 0 [Note] sql/mysqld (initiated by: unknown): Normal shutdown
 
2022-02-21 14:51:34 0 [Note] InnoDB: FTS optimize thread exiting.
 
2022-02-21 14:51:34 0 [Note] InnoDB: Starting shutdown...
 
2022-02-21 14:51:34 0 [Note] InnoDB: Dumping buffer pool(s) to /mnt/btrfstest/dd/ib_buffer_pool
 
2022-02-21 14:51:34 0 [Note] InnoDB: Buffer pool(s) dump completed at 220221 14:51:34
 
2022-02-21 14:51:35 0 [Note] InnoDB: Removed temporary tablespace data file: "./ibtmp1"
 
2022-02-21 14:51:35 0 [Note] InnoDB: Shutdown completed; log sequence number 42209; transaction id 15
 
2022-02-21 14:51:35 0 [Note] sql/mysqld: Shutdown complete

--innodb_use_native_aio=1 afterwards generated same result. chattr +C didn't change the result of the corruption.

$ od -Ax -t x1 -j 0x24000 -N 0x4000 ibdata1
 
024000 00 00 00 00 00 00 00 09 ff ff ff ff ff ff ff ff
 
024010 00 00 00 00 00 00 9c 20 45 bf 00 00 00 00 00 00
 
024020 00 00 00 00 00 00 00 02 01 71 00 09 00 00 00 00
 
024030 01 55 00 02 00 06 00 07 00 00 00 00 00 00 00 09
 
024040 00 00 00 00 00 00 00 00 00 05 00 00 00 00 00 00
 
024050 00 02 05 72 00 00 00 00 00 00 00 02 04 b2 08 01
 
024060 00 00 03 00 85 69 6e 66 69 6d 75 6d 00 09 08 00
 
024070 08 03 00 00 73 75 70 72 65 6d 75 6d 00 13 08 00
 
024080 00 10 05 00 a0 00 00 00 00 00 00 00 0b 53 59 53
 
024090 5f 46 4f 52 45 49 47 4e 18 08 00 00 18 05 00 c0
 
0240a0 00 00 00 00 00 00 00 0c 53 59 53 5f 46 4f 52 45
 
0240b0 49 47 4e 5f 43 4f 4c 53 13 08 00 00 20 05 00 db
 
0240c0 00 00 00 00 00 00 00 0d 53 59 53 5f 56 49 52 54
 
0240d0 55 41 4c 20 08 00 00 28 05 01 03 00 00 00 00 00
 
0240e0 00 00 0e 6d 79 73 71 6c 2f 69 6e 6e 6f 64 62 5f
 
0240f0 74 61 62 6c 65 5f 73 74 61 74 73 20 08 00 00 30
 
024100 05 01 2b 00 00 00 00 00 00 00 0f 6d 79 73 71 6c
 
024110 2f 69 6e 6e 6f 64 62 5f 69 6e 64 65 78 5f 73 74
 
024120 61 74 73 22 08 00 00 38 05 01 55 00 00 00 00 00
 
024130 00 00 10 6d 79 73 71 6c 2f 74 72 61 6e 73 61 63
 
024140 74 69 6f 6e 5f 72 65 67 69 73 74 72 79 1c 08 00
 
024150 00 40 05 00 74 00 00 00 00 00 00 00 11 6d 79 73
 
024160 71 6c 2f 67 74 69 64 5f 73 6c 61 76 65 5f 70 6f
 
024170 73 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
024180 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
*
 
027ff0 00 00 00 00 00 74 00 65 00 00 9c 20 b3 73 ac c6
 
028000

use aio=0 on mysql_install_db (still with chattr +C)

 
$  scripts/mysql_install_db --no-defaults --srcdir=$OLDPWD --builddir=$PWD --datadir=/mnt/btrfstest/noaio  --innodb_use_native_aio=0
 
Installing MariaDB/MySQL system tables in '/mnt/btrfstest/noaio' ...
 
OK
 
 
 
~/repos/build-mariadb-server-10.6 
$  sql/mysqld --no-defaults --skip-networking --datadir=/mnt/btrfstest/noaio  --verbose --innodb_use_native_aio=1 --socket /tmp/mysql.sock
 
2022-02-21 14:59:31 0 [Note] sql/mysqld (server 10.6.8-MariaDB) starting as process 123017 ...
 
2022-02-21 14:59:31 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
 
2022-02-21 14:59:31 0 [Note] InnoDB: Number of pools: 1
 
2022-02-21 14:59:31 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions
 
2022-02-21 14:59:31 0 [Note] InnoDB: Using liburing
 
2022-02-21 14:59:31 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
 
2022-02-21 14:59:31 0 [Note] InnoDB: Completed initialization of buffer pool
 
2022-02-21 14:59:31 0 [Note] InnoDB: 128 rollback segments are active.
 
2022-02-21 14:59:31 0 [Note] InnoDB: Creating shared tablespace for temporary tables
 
2022-02-21 14:59:31 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
 
2022-02-21 14:59:31 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
 
2022-02-21 14:59:31 0 [Note] InnoDB: 10.6.8 started; log sequence number 42173; transaction id 14
 
2022-02-21 14:59:31 0 [Note] InnoDB: Loading buffer pool(s) from /mnt/btrfstest/noaio/ib_buffer_pool
 
2022-02-21 14:59:31 0 [Note] CONNECT: Version 1.07.0002 March 22, 2021
 
2022-02-21 14:59:31 0 [Note] Plugin 'FEEDBACK' is disabled.
 
2022-02-21 14:59:31 0 [ERROR] InnoDB: Database page corruption on disk or a failed read of file './ibdata1' page [page id: space=0, page number=9]. You may have to recover from a backup.
 
2022-02-21 14:59:31 0 [Note] InnoDB: Page dump in ascii and hex (16384 bytes):
 
 len 16384; hex 0000000000000009ffffffffffffffff0000000000009c2045bf0000000000000000000000000002012022-02-21 14:59:31 0 [ERROR] InnoDB: Database page corruption on disk or a failed read of file './ibdata1' page [page id: space=0, page number=243]. You may have to recover from a backup.
 
710009002022-02-21 14:59:31 0 [Note] InnoDB: Page dump in ascii and hex (16384 bytes):

Comment by Heinz Wiesinger [ 2022-03-01 ]

I ran into this issue on Slackware (-current 2022-02-25) with both 10.6.7 and 10.7.3. After discussing on zulip I can confirm that setting either innodb_use_native_aio=0 or innodb_flush_method=fsync work around the bug for me.

Comment by Marko Mäkelä [ 2022-03-01 ]

I think that this needs to be resolved in the Linux kernel somehow.

Comment by Daniel Black [ 2022-03-01 ]

pprkut from zulip - your kernel version was 5.16.11. Chasing up now.

Comment by Daniel Black [ 2022-03-03 ]

Kernel patch: https://lore.kernel.org/linux-btrfs/CABVffENfbsC6HjGbskRZGR2NvxbnQi17gAuW65eOM+QRzsr8Bg@mail.gmail.com/T/#mb2738e675e48e0e0778a2e8d1537dec5ec0d3d3a thanks to the great work by Filipe Manana (Suse).

Comment by Daniel Black [ 2022-03-10 ]

So the problem as Filipe Manana described is that we didn't look at the return values.

And its true, the in the aio code we set m_ret_len to be the value returned by the underlying call, and except for the Windows case, we otherwise ignore it.

If we assume the the cb->m_buffer isn't used by the AIO handlers, which was the case for innodb, we can just resubmit.

bb-10.6-danielblack-MDEV-27900-resubmit-partial-reads for going through tests. Discussions on the linux mailing lists indicates that under some circumstances it might happen in AIO. So most of the patch will go into 10.5, and the uring to 10.6.

Generated at Thu Feb 08 09:56:27 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.