[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <Y7we1QAnJR3Kp5tU@xsang-OptiPlex-9020>
Date: Mon, 9 Jan 2023 22:04:05 +0800
From: Oliver Sang <oliver.sang@...el.com>
To: Vlastimil Babka <vbabka@...e.cz>
CC: Hyeonggon Yoo <42.hyeyoo@...il.com>, <oe-lkp@...ts.linux.dev>,
<lkp@...el.com>, Mike Rapoport <rppt@...ux.ibm.com>,
Christoph Lameter <cl@...ux.com>,
<linux-kernel@...r.kernel.org>, <linux-mm@...ck.org>,
Matthew Wilcox <willy@...radead.org>
Subject: Re: [linus:master] [mm, slub] 0af8489b02:
kernel_BUG_at_include/linux/mm.h
sorry, missed the attachment...
On Mon, Jan 09, 2023 at 10:01:15PM +0800, Oliver Sang wrote:
> hi, Vlastimil,
>
> On Fri, Jan 06, 2023 at 11:13:15AM +0100, Vlastimil Babka wrote:
> > On 1/5/23 02:46, Oliver Sang wrote:
> > > hi, Hyeonggon, hi, Vlastimil,
> > >
> > > On Wed, Jan 04, 2023 at 06:04:20PM +0900, Hyeonggon Yoo wrote:
> > >> On Tue, Jan 03, 2023 at 09:46:33PM +0800, Oliver Sang wrote:
> > >> > On Tue, Jan 03, 2023 at 11:42:11AM +0100, Vlastimil Babka wrote:
> > >> > > So the events leading up to this could be something like:
> > >> > >
> > >> > > - 0x2daee is order-1 slab folio of the inode cache, sitting on the partial list
> > >> > > - despite being on partial list, it's freed ???
> > >> > > - somebody else allocates order-2 page 0x2daec and uses it for whatever,
> > >> > > then frees it
> > >> > > - 0x2daec is reallocated as order-1 slab from names_cache, then freed
> > >> > > - we try to allocate from the slab page 0x2daee and trip on the PageTail
> > >> > >
> > >> > > Except, the freeing of order-2 page would have reset the PageTail and
> > >> > > compound_head in 0x2daec, so this is even more complicated or involves some
> > >> > > extra race?
> > >> >
> > >> > FYI, we ran tests more up to 500 times, then saw different issues but rate is
> > >> > actually low
> > >> >
> > >> > 56d5a2b9ba85a390 0af8489b0216fa1dd83e264bef8
> > >> > ---------------- ---------------------------
> > >> > fail:runs %reproduction fail:runs
> > >> > | | |
> > >> > :500 12% 61:500 dmesg.invalid_opcode:#[##]
> > >> > :500 3% 14:500 dmesg.kernel_BUG_at_include/linux/mm.h
> > >> > :500 3% 17:500 dmesg.kernel_BUG_at_include/linux/page-flags.h
> > >> > :500 5% 26:500 dmesg.kernel_BUG_at_lib/list_debug.c
> > >> > :500 0% 2:500 dmesg.kernel_BUG_at_mm/page_alloc.c
> > >> > :500 0% 2:500 dmesg.kernel_BUG_at_mm/usercopy.c
> > >> >
> > >
> > > hi Vlastimil,
> > >
> > > as you mentioned
> > >> Hm even if rate is low, the different kinds of reports could be useful to
> > >> see, if all of that is caused by the commit.
> > >
> > > we tried to run tests even more times, but with the config which enable
> > > CONFIG_DEBUG_PAGEALLOC
> > > CONFIG_DEBUG_PAGEALLOC_ENABLE_DEFAULT
> > > (config is attached as
> > > config-6.1.0-rc2-00014-g0af8489b0216+CONFIG_DEBUG_PAGEALLOC+CONFIG_DEBUG_PAGEALLOC_ENABLE_DEFAULT
> > > the only diff with previous config is
> > > @@ -5601,7 +5601,8 @@ CONFIG_HAVE_KCSAN_COMPILER=y
> > > # Memory Debugging
> > > #
> > > CONFIG_PAGE_EXTENSION=y
> > > -# CONFIG_DEBUG_PAGEALLOC is not set
> > > +CONFIG_DEBUG_PAGEALLOC=y
> > > +CONFIG_DEBUG_PAGEALLOC_ENABLE_DEFAULT=y
> > > CONFIG_PAGE_OWNER=y
> > > # CONFIG_PAGE_POISONING is not set
> > > CONFIG_DEBUG_PAGE_REF=y
> > > )
> > >
> > > what we found now is some issues are also reproduced on parent now (still by
> > > rcutorture tests here), though seems lower rate on parent.
> > >
> > > =========================================================================================
> > > compiler/kconfig/rootfs/runtime/tbox_group/test/testcase/torture_type:
> > > gcc-11/i386-randconfig-a012-20221226+CONFIG_DEBUG_PAGEALLOC+CONFIG_DEBUG_PAGEALLOC_ENABLE_DEFAULT/debian-11.1-i386-20220923.cgz/300s/vm-snb/default/rcutorture/tasks-tracing
> > >
> > > 56d5a2b9ba85a390 0af8489b0216fa1dd83e264bef8
> > > ---------------- ---------------------------
> > > fail:runs %reproduction fail:runs
> > > | | |
> > > 8:985 19% 199:990 dmesg.invalid_opcode:#[##]
> > > :985 5% 51:990 dmesg.kernel_BUG_at_include/linux/mm.h
> > > 3:985 4% 41:990 dmesg.kernel_BUG_at_include/linux/page-flags.h
> > > 4:985 10% 102:990 dmesg.kernel_BUG_at_lib/list_debug.c
> > > :985 0% 2:990 dmesg.kernel_BUG_at_mm/page_alloc.c
> > > 1:985 0% 3:990 dmesg.kernel_BUG_at_mm/usercopy.c
> > >
> > > however, we noticed dmesg.kernel_BUG_at_include/linux/mm.h still have
> > > relatively high rate on this commit but keeps clean on parent.
> >
> > Well that's interesting. As long as any bugs happen in the parent, it could
> > mean the commit we suspect is just changing the circumstances and creating
> > conditions that increase the bug happening - e.g. because it causes slab
> > pages to be always immediately freed when the last object is freed.
> >
> > So I would be curiou about how some of the reports from the parent look like
> > in detail.
>
> since now we have below 3 also for parent:
> 3:985 4% 41:990 dmesg.kernel_BUG_at_include/linux/page-flags.h
> 4:985 10% 102:990 dmesg.kernel_BUG_at_lib/list_debug.c
> 1:985 0% 3:990 dmesg.kernel_BUG_at_mm/usercopy.c
> I pick one dmesg for each case from parent commit (56d5a2b9ba85a390) as
> attached:
> dmesg-parent-bug-at-page-flags-h.xz
> dmesg-parent-bug-at-list_debug-c.xz
> dmesg-parent-bug-at-usercopy-c.xz
> FYI
>
> > And if the rate at the parent (has it increased thanks to the
> > DEBUG_PAGEALLOC?) is sufficient to bisect to the truly first bad commit. Thanks!
>
> got it. Thanks for suggestion!
>
> since 0af8489b02 is based on v6.1-rc2, we will test (both rectorture and boot)
> with same config upon v6.1-rc2 to see if it's really clean there.
> if so we will use dmesg.invalid_opcode:#[##] to trigger new bisect.
>
> will keep you updated. Thanks
>
> >
> >
Download attachment "dmesg-parent-bug-at-page-flags-h.xz" of type "application/x-xz" (57060 bytes)
Download attachment "dmesg-parent-bug-at-list_debug-c.xz" of type "application/x-xz" (58640 bytes)
Download attachment "dmesg-parent-bug-at-usercopy-c.xz" of type "application/x-xz" (55760 bytes)
Powered by blists - more mailing lists