Re: kernel BUG in block_invalidatepage

Re: kernel BUG in block_invalidatepage

[Hao Sun]

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

Re: kernel BUG in block_invalidatepage

[Jens Axboe]

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

Re: kernel BUG in block_invalidatepage

[Matthew Wilcox]

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/

Re: kernel BUG in block_invalidatepage

[Hao Sun]

Matthew Wilcox <willy@infradead.org> 于2021年10月7日周四 下午10:20写道：
>
> 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/

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

Re: kernel BUG in block_invalidatepage

[Matthew Wilcox]

On Fri, Oct 08, 2021 at 11:02:14AM +0800, Hao Sun wrote:
> Matthew Wilcox <willy@infradead.org> 于2021年10月7日周四 下午10:20写道：
> >
> > 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/
> 
> 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.