[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <7bab1234-45d7-43f6-8ebf-4a2c923c6a46@redhat.com>
Date: Thu, 21 Nov 2024 10:46:23 +0100
From: David Hildenbrand <david@...hat.com>
To: syzbot <syzbot+c317c107c68f8bc257d9@...kaller.appspotmail.com>,
akpm@...ux-foundation.org, linux-kernel@...r.kernel.org, linux-mm@...ck.org,
syzkaller-bugs@...glegroups.com
Cc: David Howells <dhowells@...hat.com>
Subject: Re: [syzbot] [mm?] BUG: Bad page state in iomap_write_begin
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@...kaller.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
Powered by blists - more mailing lists