kernel BUG in block_invalidatepage

kernel BUG in block_invalidatepage

[Hao Sun]

Hello,

When using Healer to fuzz the latest Linux kernel, the following crash
was triggered.

HEAD commit: 7d2a07b76933 Linux 5.14
git tree: upstream
console output:
https://drive.google.com/file/d/1Z-djyuwIRtlIKNHdLxoUnr8NqDu9zd9S/view?usp=sharing
kernel config: https://drive.google.com/file/d/1XD9WYDViQLSXN7RGwH8AGGDvP9JvOghx/view?usp=sharing

Sorry, I don't have a reproducer for this crash, hope the symbolized
report can help.
If you fix this issue, please add the following tag to the commit:
Reported-by: Hao Sun <sunhao.th@gmail.com>

------------[ cut here ]------------
kernel BUG at fs/buffer.c:1510!
invalid opcode: 0000 [#1] PREEMPT SMP KASAN
CPU: 1 PID: 8695 Comm: syz-executor Not tainted 5.14.0 #25
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.13.0-1ubuntu1.1 04/01/2014
RIP: 0010:block_invalidatepage+0x54d/0x660 fs/buffer.c:1510
Code: ff ff e8 c6 aa 9d ff b9 02 00 00 00 be 02 00 00 00 48 89 ef 48
c7 c2 c0 5e 20 89 e8 7d 0e 49 07 e9 29 fe ff ff e8 a3 aa 9d ff <0f> 0b
e8 9c aa 9d ff 0f 0b e8 95 aa 9d ff 48 83 eb 01 e9 83 fb ff
RSP: 0018:ffffc90000a376f8 EFLAGS: 00010246
RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffff88810dd8b980
RDX: 0000000000000000 RSI: ffff88810dd8b980 RDI: 0000000000000002
RBP: 0000000000000000 R08: ffffffff81d74ddd R09: 0000000000001000
R10: 0000000000000005 R11: fffff940000b0000 R12: ffffea0000580000
R13: 0000000000000000 R14: 0000000000200000 R15: 0000000000200000
FS:  0000000000000000(0000) GS:ffff888119f00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007ffcb1d285b7 CR3: 0000000104f5d005 CR4: 0000000000770ee0
PKRU: 55555554
Call Trace:
 do_invalidatepage mm/truncate.c:157 [inline]
 truncate_cleanup_page+0x3e4/0x620 mm/truncate.c:176
 truncate_inode_pages_range+0x26c/0x1960 mm/truncate.c:325
 kill_bdev.isra.0+0x5f/0x80 fs/block_dev.c:86
 blkdev_flush_mapping+0xdf/0x2e0 fs/block_dev.c:1243
 blkdev_put_whole+0xe8/0x110 fs/block_dev.c:1277
 blkdev_put+0x268/0x720 fs/block_dev.c:1576
 blkdev_close+0x8c/0xb0 fs/block_dev.c:1586
 __fput+0x288/0x920 fs/file_table.c:280
 task_work_run+0xe0/0x1a0 kernel/task_work.c:164
 exit_task_work include/linux/task_work.h:32 [inline]
 do_exit+0xbe4/0x2e00 kernel/exit.c:825
 do_group_exit+0x125/0x340 kernel/exit.c:922
 get_signal+0x4d5/0x25a0 kernel/signal.c:2808
 arch_do_signal_or_restart+0x2ed/0x1c40 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+0x192/0x2a0 kernel/entry/common.c:209
 __syscall_exit_to_user_mode_work kernel/entry/common.c:291 [inline]
 syscall_exit_to_user_mode+0x19/0x50 kernel/entry/common.c:302
 do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x4739cd
Code: Unable to access opcode bytes at RIP 0x4739a3.
RSP: 002b:00007f6c0fac6218 EFLAGS: 00000246 ORIG_RAX: 00000000000000ca
RAX: fffffffffffffe00 RBX: 000000000059c0a0 RCX: 00000000004739cd
RDX: 0000000000000000 RSI: 0000000000000080 RDI: 000000000059c0a8
RBP: 000000000059c0a8 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000059c0ac
R13: 00007ffcdd11bbff R14: 00007ffcdd11bda0 R15: 00007f6c0fac6300
Modules linked in:
Dumping ftrace buffer:
   (ftrace buffer empty)
---[ end trace 4d1faf5c7a1da2c5 ]---
RIP: 0010:block_invalidatepage+0x54d/0x660 fs/buffer.c:1510
Code: ff ff e8 c6 aa 9d ff b9 02 00 00 00 be 02 00 00 00 48 89 ef 48
c7 c2 c0 5e 20 89 e8 7d 0e 49 07 e9 29 fe ff ff e8 a3 aa 9d ff <0f> 0b
e8 9c aa 9d ff 0f 0b e8 95 aa 9d ff 48 83 eb 01 e9 83 fb ff
RSP: 0018:ffffc90000a376f8 EFLAGS: 00010246
RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffff88810dd8b980
RDX: 0000000000000000 RSI: ffff88810dd8b980 RDI: 0000000000000002
RBP: 0000000000000000 R08: ffffffff81d74ddd R09: 0000000000001000
R10: 0000000000000005 R11: fffff940000b0000 R12: ffffea0000580000
R13: 0000000000000000 R14: 0000000000200000 R15: 0000000000200000
FS:  0000000000000000(0000) GS:ffff888119f00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f6945606000 CR3: 000000010abb2004 CR4: 0000000000770ee0
PKRU: 55555554

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.