FS#71611 - [linux]: fsync/fdatasync report I/O error as of 5.13.4

Attached to Project: Arch Linux
Opened by Sebastian Goth (sgoth) - Sunday, 25 July 2021, 15:01 GMT
Last edited by Andreas Radke (AndyRTR) - Tuesday, 27 July 2021, 20:39 GMT
Task Type Bug Report
Category Kernel
Status Closed
Assigned To No-one
Architecture x86_64
Severity Critical
Priority Normal
Reported Version
Due in Version Undecided
Due Date Undecided
Percent Complete 100%
Votes 1
Private No

Details

Description:
As of kernel 5.13.4, i can't use any sqlite database on my f2fs /home anymore.
strace shows that fsync and fdatasync calls return -1 (EIO) but there are no related kernel messages at the same time.
fsck.f2fs shows no issues.

When i go back to 5.12.15.arch1-1, everything works again.

Additional info:
I was unable to write a trivial C program to reproduce the issue..

Trivial example in sqlite3 high level:
- I import a small database at once - bulk import/close doesn't seem to call fsync/fdatasync and works
- A single insert fails as it ensures fsync
- Disabling flushing makes inserts work


Steps to reproduce:
[~/tmp/f2fserror]$ sqlite3 db < test.sql
[~/tmp/f2fserror]$ sqlite3 db
SQLite version 3.36.0 2021-06-18 18:36:39
Enter ".help" for usage hints.
sqlite> .dump
PRAGMA foreign_keys=OFF;
BEGIN TRANSACTION;
CREATE TABLE num (
num integer not null primary key,
roman text not null
);
INSERT INTO num VALUES(2,'II');
INSERT INTO num VALUES(4,'IV');
INSERT INTO num VALUES(5,'V');
INSERT INTO num VALUES(7,'VII');
INSERT INTO num VALUES(9,'IX');
COMMIT;
sqlite> insert into num values (10, 'X');
Error: disk I/O error
sqlite> .dump
PRAGMA foreign_keys=OFF;
BEGIN TRANSACTION;
CREATE TABLE num (
num integer not null primary key,
roman text not null
);
INSERT INTO num VALUES(2,'II');
INSERT INTO num VALUES(4,'IV');
INSERT INTO num VALUES(5,'V');
INSERT INTO num VALUES(7,'VII');
INSERT INTO num VALUES(9,'IX');
COMMIT;
sqlite> pragma synchronous = off;
sqlite> insert into num values (10, 'X');
sqlite> .quit
[~/tmp/f2fserror]$ sqlite3 db
SQLite version 3.36.0 2021-06-18 18:36:39
Enter ".help" for usage hints.
sqlite> .dump
PRAGMA foreign_keys=OFF;
BEGIN TRANSACTION;
CREATE TABLE num (
num integer not null primary key,
roman text not null
);
INSERT INTO num VALUES(2,'II');
INSERT INTO num VALUES(4,'IV');
INSERT INTO num VALUES(5,'V');
INSERT INTO num VALUES(7,'VII');
INSERT INTO num VALUES(9,'IX');
INSERT INTO num VALUES(10,'X');
COMMIT;
sqlite>



Additional info:
I first encountered it in firefox with strange errors. Here is an strace snippet of one of the sqlite files with a fresh ~/.mozilla directory:

openat(AT_FDCWD, "/home/sgoth/.mozilla/firefox/c9jkdkze.default-release/favicons.sqlite", O_RDWR|O_CREAT|O_NOFOLLOW|O_CLOEXEC, 0644) = 134
newfstatat(134, "", {st_mode=S_IFREG|0644, st_size=0, ...}, AT_EMPTY_PATH) = 0
newfstatat(134, "", {st_mode=S_IFREG|0644, st_size=0, ...}, AT_EMPTY_PATH) = 0
lseek(134, 0, SEEK_SET) = 0
read(134, "", 100) = 0
fcntl(134, F_SETLK, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=1073741826, l_len=510}) = 0
newfstatat(134, "", {st_mode=S_IFREG|0644, st_size=0, ...}, AT_EMPTY_PATH) = 0
lseek(134, 24, SEEK_SET) = 24
read(134, "", 16) = 0
newfstatat(134, "", {st_mode=S_IFREG|0644, st_size=0, ...}, AT_EMPTY_PATH) = 0
lseek(134, 0, SEEK_SET) = 0
write(134, "SQLite format 3\0\200\0\1\1\0@ \0\0\0\1\0\0\0\1"..., 32768) = 32768
fsync(134) = 0
lseek(134, 24, SEEK_SET) = 24
read(134, "\0\0\0\1\0\0\0\1\0\0\0\0\0\0\0\0", 16) = 16
newfstatat(134, "", {st_mode=S_IFREG|0644, st_size=32768, ...}, AT_EMPTY_PATH) = 0
lseek(134, 0, SEEK_SET) = 0
write(134, "SQLite format 3\0\200\0\2\2\0@ \0\0\0\2\0\0\0\1"..., 32768) = 32768
fsync(134) = -1 EIO (Input/output error)
newfstatat(134, "", {st_mode=S_IFREG|0644, st_size=32768, ...}, AT_EMPTY_PATH) = 0
lseek(134, 0, SEEK_SET) = 0
write(134, "SQLite format 3\0\200\0\1\1\0@ \0\0\0\1\0\0\0\1"..., 32768) = 32768
fsync(134) = -1 EIO (Input/output error)
newfstatat(134, "", {st_mode=S_IFREG|0644, st_size=32768, ...}, AT_EMPTY_PATH) = 0
newfstatat(134, "", {st_mode=S_IFREG|0644, st_size=32768, ...}, AT_EMPTY_PATH) = 0
lseek(134, 0, SEEK_SET) = 0
write(134, "SQLite format 3\0\200\0\1\1\0@ \0\0\0\1\0\0\0\1"..., 32768) = 32768
fsync(134) = -1 EIO (Input/output error)
newfstatat(134, "", {st_mode=S_IFREG|0644, st_size=32768, ...}, AT_EMPTY_PATH) = 0
close(134) = 0

This task depends upon

Closed by  Andreas Radke (AndyRTR)
Tuesday, 27 July 2021, 20:39 GMT
Reason for closing:  None
Additional comments about closing:  see comment
Comment by Sebastian Goth (sgoth) - Sunday, 25 July 2021, 15:19 GMT
Reformatted the summary and dropped the essential: This is about F2FS filesystems
Comment by Sebastian Goth (sgoth) - Monday, 26 July 2021, 17:56 GMT
Oh well, here it goes.

Even though a fsck.f2fs didn't show any issues, i ran it with --dry-run only.
Digging further i saw the commit message in https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux.git/commit/?h=v5.13.4&id=63798e31f5888e322491863f88e9c03c435ce116 and double checked sb_status in sysfs only to see it was marked 'SBI_NEED_FSCK'.
Even better, past me decided to mount /home with fs_passno 0.

Actually running fsck then cleaned the flag and 5.13.4 handles sqlite3 behavior 'correctly' again. A kernel warning would have been nice there :/
Yay.

Sorry for the noise.

Loading...