Re: kernel BUG in block_invalidatepage
5 messages,
3 authors,
2021-10-08 · open the first message on its own page
Hello,
This crash can still be triggered repeatedly on the latest kernel.
HEAD commit: 60a9483534ed Merge tag 'warning-fixes-20211005'
git tree: upstream
kernel config: https://drive.google.com/file/d/1u-ncYGLkq3xqdlNQYJz8-G6Fhf3H-moP/view?usp=sharing
------------[ cut here ]------------
kernel BUG at fs/buffer.c:1514!
invalid opcode: 0000 [#1] PREEMPT SMP
CPU: 3 PID: 25416 Comm: syz-executor Not tainted 5.15.0-rc4+ #22
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
rel-1.12.0-59-gc9ba5276e321-prebuilt.qemu.org 04/01/2014
RIP: 0010:block_invalidatepage+0x27f/0x2a0 fs/buffer.c:1514
Code: ff ff e8 b4 fd d6 ff b9 02 00 00 00 be 02 00 00 00 4c 89 ff 48
c7 c2 40 b1 25 84 e8 8b 1b c5 02 e9 c9 fe ff ff e8 91 fd d6 ff <0f> 0b
e8 8a fd d6 ff 0f 0b e8 83 fd d6 ff 48 8d 5d ff e9 57 ff ff
RSP: 0018:ffffc9000538fa70 EFLAGS: 00010293
RAX: 0000000000000000 RBX: ffffea0004518000 RCX: 0000000000000000
RDX: ffff88810dd2a280 RSI: ffffffff8160943f RDI: ffffea0004518000
RBP: ffffea0004518000 R08: 0000000000000001 R09: 0000000000000000
R10: ffffc9000538f908 R11: 0000000000000001 R12: ffffffff816091c0
R13: ffffc9000538fb78 R14: 0000000000000000 R15: ffffc9000538fb00
FS: 0000000000000000(0000) GS:ffff88813dd00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000020590008 CR3: 000000000588a000 CR4: 0000000000750ee0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
PKRU: 55555554
Call Trace:
do_invalidatepage mm/truncate.c:157 [inline]
truncate_cleanup_page+0x15c/0x280 mm/truncate.c:176
truncate_inode_pages_range+0x169/0xc20 mm/truncate.c:325
kill_bdev.isra.16+0x28/0x30 block/bdev.c:77
blkdev_flush_mapping+0x4c/0x130 block/bdev.c:658
blkdev_put_whole+0x54/0x60 block/bdev.c:689
blkdev_put+0x6f/0x210 block/bdev.c:953
blkdev_close+0x26/0x30 block/fops.c:460
__fput+0xdf/0x380 fs/file_table.c:280
task_work_run+0x86/0xd0 kernel/task_work.c:164
exit_task_work include/linux/task_work.h:32 [inline]
do_exit+0x4f1/0x11c0 kernel/exit.c:825
do_group_exit+0x57/0xe0 kernel/exit.c:922
get_signal+0x1d0/0x10b0 kernel/signal.c:2868
arch_do_signal_or_restart+0xa9/0x860 arch/x86/kernel/signal.c:865
handle_signal_work kernel/entry/common.c:148 [inline]
exit_to_user_mode_loop kernel/entry/common.c:172 [inline]
exit_to_user_mode_prepare+0xf2/0x280 kernel/entry/common.c:207
__syscall_exit_to_user_mode_work kernel/entry/common.c:289 [inline]
syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:300
do_syscall_64+0x40/0xb0 arch/x86/entry/common.c:86
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x4196af
Code: Unable to access opcode bytes at RIP 0x419685.
RSP: 002b:00007faeee07b9c0 EFLAGS: 00000293 ORIG_RAX: 0000000000000012
RAX: 0000000000000000 RBX: 0000000000000003 RCX: 00000000004196af
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000003
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000000
R13: 0000000000000000 R14: 0000000000000003 R15: 000000002059c040
Modules linked in:
Dumping ftrace buffer:
(ftrace buffer empty)
---[ end trace bb86c370c06fa387 ]---
RIP: 0010:block_invalidatepage+0x27f/0x2a0 fs/buffer.c:1514
Code: ff ff e8 b4 fd d6 ff b9 02 00 00 00 be 02 00 00 00 4c 89 ff 48
c7 c2 40 b1 25 84 e8 8b 1b c5 02 e9 c9 fe ff ff e8 91 fd d6 ff <0f> 0b
e8 8a fd d6 ff 0f 0b e8 83 fd d6 ff 48 8d 5d ff e9 57 ff ff
RSP: 0018:ffffc9000538fa70 EFLAGS: 00010293
RAX: 0000000000000000 RBX: ffffea0004518000 RCX: 0000000000000000
RDX: ffff88810dd2a280 RSI: ffffffff8160943f RDI: ffffea0004518000
RBP: ffffea0004518000 R08: 0000000000000001 R09: 0000000000000000
R10: ffffc9000538f908 R11: 0000000000000001 R12: ffffffff816091c0
R13: ffffc9000538fb78 R14: 0000000000000000 R15: ffffc9000538fb00
FS: 0000000000000000(0000) GS:ffff88813dd00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f397f798010 CR3: 0000000012392000 CR4: 0000000000750ee0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
PKRU: 55555554
On 10/7/21 12:40 AM, Hao Sun wrote: Hello,
This crash can still be triggered repeatedly on the latest kernel.
HEAD commit: 60a9483534ed Merge tag 'warning-fixes-20211005'
git tree: upstream
kernel config: https://drive.google.com/file/d/1u-ncYGLkq3xqdlNQYJz8-G6Fhf3H-moP/view?usp=sharing
------------[ cut here ]------------
kernel BUG at fs/buffer.c:1514!
invalid opcode: 0000 [#1] PREEMPT SMP
CPU: 3 PID: 25416 Comm: syz-executor Not tainted 5.15.0-rc4+ #22
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
rel-1.12.0-59-gc9ba5276e321-prebuilt.qemu.org 04/01/2014
RIP: 0010:block_invalidatepage+0x27f/0x2a0 fs/buffer.c:1514
Code: ff ff e8 b4 fd d6 ff b9 02 00 00 00 be 02 00 00 00 4c 89 ff 48
c7 c2 40 b1 25 84 e8 8b 1b c5 02 e9 c9 fe ff ff e8 91 fd d6 ff <0f> 0b
e8 8a fd d6 ff 0f 0b e8 83 fd d6 ff 48 8d 5d ff e9 57 ff ff
RSP: 0018:ffffc9000538fa70 EFLAGS: 00010293
RAX: 0000000000000000 RBX: ffffea0004518000 RCX: 0000000000000000
RDX: ffff88810dd2a280 RSI: ffffffff8160943f RDI: ffffea0004518000
RBP: ffffea0004518000 R08: 0000000000000001 R09: 0000000000000000
R10: ffffc9000538f908 R11: 0000000000000001 R12: ffffffff816091c0
R13: ffffc9000538fb78 R14: 0000000000000000 R15: ffffc9000538fb00
FS: 0000000000000000(0000) GS:ffff88813dd00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000020590008 CR3: 000000000588a000 CR4: 0000000000750ee0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
PKRU: 55555554
Call Trace:
do_invalidatepage mm/truncate.c:157 [inline]
truncate_cleanup_page+0x15c/0x280 mm/truncate.c:176
truncate_inode_pages_range+0x169/0xc20 mm/truncate.c:325
kill_bdev.isra.16+0x28/0x30 block/bdev.c:77
blkdev_flush_mapping+0x4c/0x130 block/bdev.c:658
blkdev_put_whole+0x54/0x60 block/bdev.c:689
blkdev_put+0x6f/0x210 block/bdev.c:953
blkdev_close+0x26/0x30 block/fops.c:460
__fput+0xdf/0x380 fs/file_table.c:280
task_work_run+0x86/0xd0 kernel/task_work.c:164
exit_task_work include/linux/task_work.h:32 [inline]
do_exit+0x4f1/0x11c0 kernel/exit.c:825
do_group_exit+0x57/0xe0 kernel/exit.c:922
get_signal+0x1d0/0x10b0 kernel/signal.c:2868
arch_do_signal_or_restart+0xa9/0x860 arch/x86/kernel/signal.c:865
handle_signal_work kernel/entry/common.c:148 [inline]
exit_to_user_mode_loop kernel/entry/common.c:172 [inline]
exit_to_user_mode_prepare+0xf2/0x280 kernel/entry/common.c:207
__syscall_exit_to_user_mode_work kernel/entry/common.c:289 [inline]
syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:300
do_syscall_64+0x40/0xb0 arch/x86/entry/common.c:86
entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x4196af
Code: Unable to access opcode bytes at RIP 0x419685.
RSP: 002b:00007faeee07b9c0 EFLAGS: 00000293 ORIG_RAX: 0000000000000012
RAX: 0000000000000000 RBX: 0000000000000003 RCX: 00000000004196af
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000003
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000000
R13: 0000000000000000 R14: 0000000000000003 R15: 000000002059c040
Modules linked in:
Dumping ftrace buffer:
(ftrace buffer empty)
---[ end trace bb86c370c06fa387 ]---
RIP: 0010:block_invalidatepage+0x27f/0x2a0 fs/buffer.c:1514
Code: ff ff e8 b4 fd d6 ff b9 02 00 00 00 be 02 00 00 00 4c 89 ff 48
c7 c2 40 b1 25 84 e8 8b 1b c5 02 e9 c9 fe ff ff e8 91 fd d6 ff <0f> 0b
e8 8a fd d6 ff 0f 0b e8 83 fd d6 ff 48 8d 5d ff e9 57 ff ff
RSP: 0018:ffffc9000538fa70 EFLAGS: 00010293
RAX: 0000000000000000 RBX: ffffea0004518000 RCX: 0000000000000000
RDX: ffff88810dd2a280 RSI: ffffffff8160943f RDI: ffffea0004518000
RBP: ffffea0004518000 R08: 0000000000000001 R09: 0000000000000000
R10: ffffc9000538f908 R11: 0000000000000001 R12: ffffffff816091c0
R13: ffffc9000538fb78 R14: 0000000000000000 R15: ffffc9000538fb00
FS: 0000000000000000(0000) GS:ffff88813dd00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f397f798010 CR3: 0000000012392000 CR4: 0000000000750ee0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
PKRU: 55555554
Some more details would be nice here... What's being run to trigger
this?
--
Jens Axboe
On Thu, Oct 07, 2021 at 02:40:29PM +0800, Hao Sun wrote: Hello,
This crash can still be triggered repeatedly on the latest kernel.
I asked you three days ago to try a patch and report the results:
https://lore.kernel.org/linux-mm/YVtWhVNFhLbA9+Tl@casper.infradead.org/
Matthew Wilcox [off-list ref] 于2021年10月7日周四 下午10:20写道：
On Thu, Oct 07, 2021 at 02:40:29PM +0800, Hao Sun wrote: quoted Hello,
This crash can still be triggered repeatedly on the latest kernel.
I asked you three days ago to try a patch and report the results:
https://lore.kernel.org/linux-mm/YVtWhVNFhLbA9+Tl@casper.infradead.org/
Sorry, I missed that.
Here are the results.
Used reproducer: https://paste.ubuntu.com/p/yrYsn4zpcn/
Kernel log *before* applying the patch: https://paste.ubuntu.com/p/WtkFKB6Vy9/
Kernel log *after* applying the patch: https://paste.ubuntu.com/p/S2VrtDdggp/
Symbolized log: https://paste.ubuntu.com/p/RwXjCXDxB8/
In summary, the reproducer can crash the kernel with the same
backtrace before applying the patch.
After applying the patch, the reproducer program took about 3 minutes
to crash the kernel and the backtrace seems different (RIP points to
create_empty_buffers now).
All the above tests were done on commit 60a9483534ed (Merge tag
'warning-fixes-20211005').
Regards
Hao
On Fri, Oct 08, 2021 at 11:02:14AM +0800, Hao Sun wrote: Matthew Wilcox [off-list ref] 于2021年10月7日周四 下午10:20写道： quoted
On Thu, Oct 07, 2021 at 02:40:29PM +0800, Hao Sun wrote: quoted Hello,
This crash can still be triggered repeatedly on the latest kernel.
I asked you three days ago to try a patch and report the results:
https://lore.kernel.org/linux-mm/YVtWhVNFhLbA9+Tl@casper.infradead.org/
Sorry, I missed that.
Here are the results.
Used reproducer: https://paste.ubuntu.com/p/yrYsn4zpcn/
Kernel log *before* applying the patch: https://paste.ubuntu.com/p/WtkFKB6Vy9/
Kernel log *after* applying the patch: https://paste.ubuntu.com/p/S2VrtDdggp/
Symbolized log: https://paste.ubuntu.com/p/RwXjCXDxB8/
OK, so that's ioctl(fd, BLKRRPART). That reproducer is a beast, and I
can't help but think it could be minimised.
I think I see what's going on here though. We open a block device, mount
some stuff on it. khugepaged comes through and decides to create a THP
for some of the pages on it. Nobody has it open for write, so why not?
But then the filesystem on top of it dirties something -- it doesn't
need to go through an open file descriptor because it's a filesystem.
So when we call BLKRRPART, it tries to write the dirty things back
(which it should) and things go wrong because the writeback path is not
equipped to handle compound pages.
So, yeah, let's do what Yang Shi suggested and tell khugepaged to never
try to work on block devices. I can't think how any of this could happen
except to a block device, so there's no more insight to be gained here.