Re: [syzbot] [mm?] BUG: Bad page state in iomap_write_begin

[David Hildenbrand <david@redhat.com>]

On 21.11.24 10:26, David Hildenbrand wrote:
> On 20.11.24 09:37, syzbot wrote:
>> Hello,
>>
>> syzbot found the following issue on:
>>
>> HEAD commit:    e8bdb3c8be08 Merge tag 'riscv-for-linus-6.12-rc8' of git:/..
>> git tree:       upstream
>> console output: https://syzkaller.appspot.com/x/log.txt?x=1644d2c0580000
>> kernel config:  https://syzkaller.appspot.com/x/.config?x=d2aeec8c0b2e420c
>> dashboard link: https://syzkaller.appspot.com/bug?extid=c317c107c68f8bc257d9
>> compiler:       Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
>> syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=1144d2c0580000
>> C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=176252e8580000
>>
>> Downloadable assets:
>> disk image (non-bootable): https://storage.googleapis.com/syzbot-assets/7feb34a89c2a/non_bootable_disk-e8bdb3c8.raw.xz
>> vmlinux: https://storage.googleapis.com/syzbot-assets/fcae16ff0e0f/vmlinux-e8bdb3c8.xz
>> kernel image: https://storage.googleapis.com/syzbot-assets/758973beace8/bzImage-e8bdb3c8.xz
>> mounted in repro #1: https://storage.googleapis.com/syzbot-assets/a097a300c8a9/mount_0.gz
>> mounted in repro #2: https://storage.googleapis.com/syzbot-assets/36b9fff6ab5e/mount_6.gz
>>
>> IMPORTANT: if you fix the issue, please add the following tag to the commit:
>> Reported-by: syzbot+c317c107c68f8bc257d9@syzkaller.appspotmail.com
>>
>> BUG: Bad page state in process syz-executor315  pfn:49e01
>> page: refcount:0 mapcount:0 mapping:0000000000000000 index:0x1 pfn:0x49e01
>> head: order:0 mapcount:0 entire_mapcount:0 nr_pages_mapped:0 pincount:-1
> 
> So, we have a pincount underflow on a large folio (order-9). We
> allocated the folio in iomap_write_begin()->__iomap_get_folio(). Nothing
> special.
> 
> [...]
> 
>>    </TASK>
>> BUG: Bad page state in process syz-executor315  pfn:49e00
>> page: refcount:0 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x49e00
>> head: order:0 mapcount:0 entire_mapcount:0 nr_pages_mapped:0 pincount:0
>> flags: 0x4fff0000000004d(locked|referenced|uptodate|head|node=1|zone=1|lastcpupid=0x7ff)
>> raw: 04fff0000000004d dead000000000100 dead000000000122 0000000000000000
>> raw: 0000000000000000 0000000000000000 00000000ffffffff 0000000000000000
>> head: 04fff0000000004d dead000000000100 dead000000000122 0000000000000000
>> head: 0000000000000000 0000000000000000 00000000ffffffff 0000000000000000
>> head: 04fff00000000000 0000000000000000 ffffffffffffffff 0000000000000000
>> head: 0000000000000200 0000000000000000 00000000ffffffff 0000000000000000
>> page dumped because: PAGE_FLAGS_CHECK_AT_FREE flag(s) set
> 
> And we seem to have an unexpected flag set on the head page of the same
> large folio. Likely PG_locked.
> 
> ...
> 
>> XFS (loop0): Unmounting Filesystem 9f1cad42-11bd-4e12-8f0b-f07876b81d9a
>> BUG: Bad page state in process syz-executor315  pfn:49c01
>> page: refcount:0 mapcount:0 mapping:0000000000000000 index:0x1 pfn:0x49c01
>> head: order:0 mapcount:0 entire_mapcount:0 nr_pages_mapped:0 pincount:-1
>> flags: 0x4fff0000000004d(locked|referenced|uptodate|head|node=1|zone=1|lastcpupid=0x7ff)
>> raw: 04fff00000000000 ffffea0001270001 ffffffffffffffff ffffffff00000000
>> raw: 0000000000000200 0000000000000000 00000000ffffffff 0000000000000000
>> head: 04fff0000000004d dead000000000100 dead000000000122 0000000000000000
>> head: 0000000000000000 0000000000000000 00000000ffffffff 0000000000000000
>> head: 04fff00000000000 ffffea0001270001 ffffffffffffffff ffffffff00000000
>> head: 0000000000000200 0000000000000000 00000000ffffffff 0000000000000000
>> page dumped because: nonzero pincount
> 
> [...]
> 
>>    </TASK>
>> BUG: Bad page state in process syz-executor315  pfn:49c00
>> page: refcount:0 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x49c00
>> head: order:0 mapcount:0 entire_mapcount:0 nr_pages_mapped:0 pincount:0
>> flags: 0x4fff0000000004d(locked|referenced|uptodate|head|node=1|zone=1|lastcpupid=0x7ff)
>> raw: 04fff0000000004d dead000000000100 dead000000000122 0000000000000000
>> raw: 0000000000000000 0000000000000000 00000000ffffffff 0000000000000000
>> head: 04fff0000000004d dead000000000100 dead000000000122 0000000000000000
>> head: 0000000000000000 0000000000000000 00000000ffffffff 0000000000000000
>> head: 04fff00000000000 0000000000000000 ffffffffffffffff 0000000000000000
>> head: 0000000000000200 0000000000000000 00000000ffffffff 0000000000000000
>> page dumped because: PAGE_FLAGS_CHECK_AT_FREE flag(s) set
>> page_owner tracks the page as allocated
> 
> Same thing, different folio.
> 
> 
> So we seem to be repeatedly freeing a large folio that
> (a) Is locked
> (b) Has a pincount underflow
> 
> Likely because we have an unbalanced unpin, that happens before
> evicting/truncating the folio. If we then evict/truncate the (locked)
> folio, we free the folio before unlocking it and dropping the actual
> last reference.
> 
> Not sure why we see a comparable thing with small folios (pincount part
> of refcount, but on unpin our refcount should seriously underflow
> immediately)
> 
> CCing David

If I get the reproducer right, it does:

(1) Create a temporary folder and chdir into it

(2) Mounts an (XFS?) image (syz_mount_image() magic )

(3) Opens a file1 in there

(4) Writes some data into it using write(). Likely this allocates the 
folios.

(5) Mmaps the file1 (MAP_UNINITIALIZED|MAP_LOCKED|MAP_FIXED|MAP_SHARED)

(6) Creates a socket -- socket() -- and binds it -- bind().

(7) Writes some more data into the mmap of file1 using memcpy.

(8) Mounts another (?) image (syz_mount_image() magic )

(9) Opens a file2 in there with O_SYNC|O_DIRECT|O_CREAT|O_RDWR.

(10) Calls ioctl(0xc0185879) on the file2

(11) Calls sendmsg() on the socket. msghdr and all data seems to reside 
completely in the mmap of file1.

(12) Calls symlink(0,0)

(13) Calls rename(0,0)


I doubt 12+13 are relevant. Likely (11) is the problematic bit: we are 
performing direct-io on folios allocated during (4) from file1 into file2.

I have not deciphered yet what the ioctl in (10) does.

It triggers on first attempt, so it doesn't seem to be racy.

-- 
Cheers,

David / dhildenb