Re: [linus:master] [mm, slub] 0af8489b02: kernel_BUG_at_include/linux/mm.h

[Oliver Sang <oliver.sang@intel.com>]

[-- Attachment #1: Type: text/plain, Size: 5778 bytes --]

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
> 
> > 
> > 

[-- Attachment #2: dmesg-parent-bug-at-page-flags-h.xz --]
[-- Type: application/x-xz, Size: 57060 bytes --]

[-- Attachment #3: dmesg-parent-bug-at-list_debug-c.xz --]
[-- Type: application/x-xz, Size: 58640 bytes --]

[-- Attachment #4: dmesg-parent-bug-at-usercopy-c.xz --]
[-- Type: application/x-xz, Size: 55760 bytes --]