lkml.org 
[lkml]   [2023]   [Jan]   [9]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: [linus:master] [mm, slub] 0af8489b02: kernel_BUG_at_include/linux/mm.h
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

>
>

\
 
 \ /
  Last update: 2023-03-26 23:33    [W:0.096 / U:2.092 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site