2024-03-16 04:30:02

by cheung wall

[permalink] [raw]
Subject: WARNING in mark_buffer_dirty

Hello,


when using Healer to fuzz the latest Linux Kernel, the following crash

was triggered on:


HEAD commit: 0dd3ee31125508cd67f7e7172247f05b7fd1753a (tag: v6.7)

git tree: upstream

console output: https://pastebin.com/raw/DnYhuiCu

kernel config: https://pastebin.com/raw/VecrLrRN

C reproducer: https://pastebin.com/raw/3tXH4hvU

Syzlang reproducer: https://pastebin.com/raw/Jxcujpb3


If you fix this issue, please add the following tag to the commit:

Reported-by: Qiang Zhang <[email protected]>

----------------------------------------------------------

WARNING: CPU: 0 PID: 2920 at fs/buffer.c:1176
mark_buffer_dirty+0x232/0x290
root/zhangqiang/kernel_fuzzing/zq-LLM-OS/llm-syz-environment/linux-6.7/fs/buffer.c:1176
Modules linked in:
CPU: 0 PID: 2920 Comm: syz-executor247 Not tainted 6.7.0 #2
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1 04/01/2014
sr 1:0:0:0: [sr0] tag#0 unaligned transfer
RIP: 0010:mark_buffer_dirty+0x232/0x290
root/zhangqiang/kernel_fuzzing/zq-LLM-OS/llm-syz-environment/linux-6.7/fs/buffer.c:1176
sr 1:0:0:0: [sr0] tag#0 unaligned transfer
Code: 00 00 00 00 00 fc ff df 48 c1 ea 03 80 3c 02 00 75 69 48 8b 3b
be 04 00 00 00 e8 29 5f fd ff e9 8e fe ff ff e8 bf 5d c3 ff 90 <0f> 0b
90 e9 ea fd ff ff 48 89 df e8 de b6 ef ff e9 14 fe ff ff 48
RSP: 0018:ffff88800918f9f0 EFLAGS: 00010293
RAX: 0000000000000000 RBX: ffff88800e9897e0 RCX: ffffffffabfb13b1
RDX: ffff88800c44e600 RSI: 0000000000000008 RDI: ffff88800e9897e0
RBP: 0000000000000200 R08: 0000000000000000 R09: ffffed1001d312fc
R10: ffff88800e9897e7 R11: 0000000000000000 R12: dffffc0000000000
R13: 0000000000000000 R14: ffff88800e9897e0 R15: 0000000000000200
sr 1:0:0:0: [sr0] tag#0 unaligned transfer
FS: 00005555557ca480(0000) GS:ffff8880a4200000(0000) knlGS:0000000000000000
sr 1:0:0:0: [sr0] tag#0 unaligned transfer
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000020400000 CR3: 0000000006c94005 CR4: 0000000000770ef0
PKRU: 55555554
Call Trace:
<TASK>
__block_commit_write+0xe9/0x200
root/zhangqiang/kernel_fuzzing/zq-LLM-OS/llm-syz-environment/linux-6.7/fs/buffer.c:2191
block_write_end+0xb1/0x1f0
root/zhangqiang/kernel_fuzzing/zq-LLM-OS/llm-syz-environment/linux-6.7/fs/buffer.c:2267
iomap_write_end+0x461/0x8c0
root/zhangqiang/kernel_fuzzing/zq-LLM-OS/llm-syz-environment/linux-6.7/fs/iomap/buffered-io.c:857
iomap_write_iter
root/zhangqiang/kernel_fuzzing/zq-LLM-OS/llm-syz-environment/linux-6.7/fs/iomap/buffered-io.c:938
[inline]
iomap_file_buffered_write+0x4eb/0x800
root/zhangqiang/kernel_fuzzing/zq-LLM-OS/llm-syz-environment/linux-6.7/fs/iomap/buffered-io.c:987
sr 1:0:0:0: [sr0] tag#0 unaligned transfer
sr 1:0:0:0: [sr0] tag#0 unaligned transfer
blkdev_buffered_write
root/zhangqiang/kernel_fuzzing/zq-LLM-OS/llm-syz-environment/linux-6.7/block/fops.c:646
[inline]
blkdev_write_iter+0x4ae/0xa40
root/zhangqiang/kernel_fuzzing/zq-LLM-OS/llm-syz-environment/linux-6.7/block/fops.c:696
call_write_iter
root/zhangqiang/kernel_fuzzing/zq-LLM-OS/llm-syz-environment/linux-6.7/./include/linux/fs.h:2020
[inline]
new_sync_write
root/zhangqiang/kernel_fuzzing/zq-LLM-OS/llm-syz-environment/linux-6.7/fs/read_write.c:491
[inline]
vfs_write+0x835/0xb30
root/zhangqiang/kernel_fuzzing/zq-LLM-OS/llm-syz-environment/linux-6.7/fs/read_write.c:584
ksys_write+0x104/0x210
root/zhangqiang/kernel_fuzzing/zq-LLM-OS/llm-syz-environment/linux-6.7/fs/read_write.c:637
sr 1:0:0:0: [sr0] tag#0 unaligned transfer
sr 1:0:0:0: [sr0] tag#0 unaligned transfer
do_syscall_x64
root/zhangqiang/kernel_fuzzing/zq-LLM-OS/llm-syz-environment/linux-6.7/arch/x86/entry/common.c:52
[inline]
do_syscall_64+0x46/0xf0
root/zhangqiang/kernel_fuzzing/zq-LLM-OS/llm-syz-environment/linux-6.7/arch/x86/entry/common.c:83
entry_SYSCALL_64_after_hwframe+0x6f/0x77
RIP: 0033:0x7f9c88c542fd
Code: c3 e8 b7 24 00 00 0f 1f 80 00 00 00 00 f3 0f 1e fa 48 89 f8 48
89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d
01 f0 ff ff 73 01 c3 48 c7 c1 b8 ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007ffd984ca008 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 00000000000bc285 RCX: 00007f9c88c542fd
RDX: 00000000fffffec2 RSI: 0000000020000040 RDI: 0000000000000003
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007ffd984ca04c
R13: 00007ffd984ca070 R14: 0000000000000370 R15: 00007f9c88ca5025
</TASK>


2024-03-16 04:54:34

by Matthew Wilcox

[permalink] [raw]
Subject: Re: WARNING in mark_buffer_dirty


This might be an iomap bug, so adding Christoph & Darrick.

On Sat, Mar 16, 2024 at 12:29:36PM +0800, cheung wall wrote:
> HEAD commit: 0dd3ee31125508cd67f7e7172247f05b7fd1753a (tag: v6.7)
> WARNING: CPU: 0 PID: 2920 at fs/buffer.c:1176
> mark_buffer_dirty+0x232/0x290

This is WARN_ON_ONCE(!buffer_uptodate(bh)), so we're trying to mark a
buffer dirty when that buffer is not uptodate.

> RIP: 0010:mark_buffer_dirty+0x232/0x290
> fs/buffer.c:1176
> Call Trace:
> <TASK>
> __block_commit_write+0xe9/0x200
> fs/buffer.c:2191

.. but line 2190 and 91 are:

set_buffer_uptodate(bh);
mark_buffer_dirty(bh);

and the folio is locked. So how do we clear the uptodate flag on the
buffer without the folio locked?

> block_write_end+0xb1/0x1f0
> fs/buffer.c:2267
> iomap_write_end+0x461/0x8c0
> fs/iomap/buffered-io.c:857
> iomap_write_iter
> fs/iomap/buffered-io.c:938
> [inline]
> iomap_file_buffered_write+0x4eb/0x800
> fs/iomap/buffered-io.c:987
> blkdev_buffered_write
> block/fops.c:646
> [inline]
> blkdev_write_iter+0x4ae/0xa40
> block/fops.c:696
> call_write_iter

2024-03-18 10:15:29

by Jan Kara

[permalink] [raw]
Subject: Re: WARNING in mark_buffer_dirty

On Sat 16-03-24 04:54:10, Matthew Wilcox wrote:
>
> This might be an iomap bug, so adding Christoph & Darrick.
>
> On Sat, Mar 16, 2024 at 12:29:36PM +0800, cheung wall wrote:
> > HEAD commit: 0dd3ee31125508cd67f7e7172247f05b7fd1753a (tag: v6.7)
> > WARNING: CPU: 0 PID: 2920 at fs/buffer.c:1176
> > mark_buffer_dirty+0x232/0x290
>
> This is WARN_ON_ONCE(!buffer_uptodate(bh)), so we're trying to mark a
> buffer dirty when that buffer is not uptodate.
>
> > RIP: 0010:mark_buffer_dirty+0x232/0x290
> > fs/buffer.c:1176
> > Call Trace:
> > <TASK>
> > __block_commit_write+0xe9/0x200
> > fs/buffer.c:2191
>
> ... but line 2190 and 91 are:
>
> set_buffer_uptodate(bh);
> mark_buffer_dirty(bh);
>
> and the folio is locked. So how do we clear the uptodate flag on the
> buffer without the folio locked?

Given this happens on block device page cache, I can imagine there's
someone operating on the cache directly using buffer heads without locking
the page. Filesystems do this all the time. I don't see the reproducer doing
anything like that but who knows...

Honza

> > block_write_end+0xb1/0x1f0
> > fs/buffer.c:2267
> > iomap_write_end+0x461/0x8c0
> > fs/iomap/buffered-io.c:857
> > iomap_write_iter
> > fs/iomap/buffered-io.c:938
> > [inline]
> > iomap_file_buffered_write+0x4eb/0x800
> > fs/iomap/buffered-io.c:987
> > blkdev_buffered_write
> > block/fops.c:646
> > [inline]
> > blkdev_write_iter+0x4ae/0xa40
> > block/fops.c:696
> > call_write_iter
>
--
Jan Kara <[email protected]>
SUSE Labs, CR