From: Oliver Sang <oliver.sang@intel.com>
To: Mel Gorman <mgorman@techsingularity.net>
Cc: Andrew Morton <akpm@linux-foundation.org>,
0day robot <lkp@intel.com>, LKML <linux-kernel@vger.kernel.org>,
linux-mm@kvack.org, lkp@lists.01.org,
Nicolas Saenz Julienne <nsaenzju@redhat.com>,
Marcelo Tosatti <mtosatti@redhat.com>,
Vlastimil Babka <vbabka@suse.cz>,
Michal Hocko <mhocko@kernel.org>, Hugh Dickins <hughd@google.com>
Subject: Re: [mm/page_alloc] 2bd8eec68f: BUG:sleeping_function_called_from_invalid_context_at_mm/gup.c
Date: Thu, 7 Jul 2022 16:22:24 +0800 [thread overview]
Message-ID: <YsaXwMrksMXtCh/p@xsang-OptiPlex-9020> (raw)
In-Reply-To: <20220706145241.GG27531@techsingularity.net>
Hi Mel Gorman,
On Wed, Jul 06, 2022 at 03:52:41PM +0100, Mel Gorman wrote:
> On Wed, Jul 06, 2022 at 10:21:36PM +0800, Oliver Sang wrote:
> > > I tried reproducing this on a 2-socket machine with Xeon
> > > Gold Gold 5218R CPUs. It was necessary to set timeouts in both
> > > vm/settings and kselftest/runner.sh to avoid timeouts. Testing with
> > > a standard config on my original 5.19-rc3 baseline and the baseline
> > > b13baccc3850ca8b8cccbf8ed9912dbaa0fdf7f3 both passed. I tried your kernel
> > > config with i915 disabled (would not build) and necessary storage drivers
> > > and network drivers enabled (for boot and access). The kernel log shows
> > > a bunch of warnings related to USBAN during boot and during some of the
> > > tests but otherwise compaction_test completed successfully as well as
> > > the other VM tests.
> > >
> > > Is this always reproducible?
> >
> > not always but high rate.
> > we actually also observed other dmesgs stats for both 2bd8eec68f74 and its
> > parent
>
> Ok, it's unclear what the "other dmesg stats" are but given that it happens
> for the parent. Does 5.19-rc2 (your baseline) have the same messages as
> 2bd8eec68f74^?
yeah, 5.19-rc2 has similar results as 2bd8eec68f74^ by multi-runs, while
2bd8eec68f74 looks quite similar to '-fix' commit which we applied it as
292baeb4c714.
take the 'BUG:sleeping_function_called_from_invalid_context_at_mm/gup.c'
we reported as example:
v5.19-rc2 eec0ff5df2945d19039d16841b9 2bd8eec68f740608db5ea58ecff 292baeb4c7149ac2cb844137481
---------------- --------------------------- --------------------------- ---------------------------
fail:runs %reproduction fail:runs %reproduction fail:runs %reproduction fail:runs
| | | | | | |
:31 0% :20 55% 11:20 65% 13:21 dmesg.BUG:sleeping_function_called_from_invalid_context_at_mm/gup.c
the 'fail:runs' means we observed the issue 'fail' times while running 'runs'
times.
for v5.19-rc2, " :31", so we run the same jobs upon v5.19-rc2 31 times, but
never see this
"dmesg.BUG:sleeping_function_called_from_invalid_context_at_mm/gup.c"
for eec0ff5df2 (2bd8eec68f74^), also clean on 20 runs.
but for both
2bd8eec68f74 ("mm/page_alloc: Replace local_lock with normal spinlock")
292baeb4c714 ("mm/page_alloc: replace local_lock with normal spinlock -fix")
it almost can reproduce in half of runs (11 out of 20 runs, 13 out of 31 runs
respectively)
the full comparison of these 4 commits are as [1]
generally, for those dmesg.BUG:sleeping_function_called_from_invalid***,
quite clean on v5.19-rc2 2bd8eec68f74^,
but have similar rate on 2bd8eec68f74 & 292baeb4c714
but we also obversed other issues, such like "dmesg.RIP:rcu_eqs_exit",
almost always happen on all 4 commits (this is what I said 'other dmesg
stats', sorry for confusion, and I will avoid using this kind of 'internal'
words in the future)
> Does the kselftests vm suite always pass but sometimes
> fails with 2bd8eec68f74?
below is results of kselftests vm suite, so it's really like what you said,
sometimes fails with 2bd8eec68f74 (also 292baeb4c714)
one example is
kernel-selftests.vm.run_vmtests.sh../userfaultfd_anon_20_16
if always pass on v5.19-rc2 and 2bd8eec68f74^
but fail 6 times out of 20 runs on 2bd8eec68f74, and fail 5 times out of
21 runs on 292baeb4c714
but since this rate seems not match with above issues, so not sure if they
are related?
v5.19-rc2 eec0ff5df2945d19039d16841b9 2bd8eec68f740608db5ea58ecff 292baeb4c7149ac2cb844137481
---------------- --------------------------- --------------------------- ---------------------------
fail:runs %reproduction fail:runs %reproduction fail:runs %reproduction fail:runs
| | | | | | |
31:31 -35% 20:20 0% 20:20 5% 21:21 kernel-selftests.vm.madv_populate.fail
31:31 -35% 20:20 0% 20:20 5% 21:21 kernel-selftests.vm.run_vmtests.sh../gup_test_a.pass
31:31 -35% 20:20 0% 20:20 5% 21:21 kernel-selftests.vm.run_vmtests.sh../gup_test_ct_F_0x1_0_19_0x1000.pass
31:31 -35% 20:20 0% 20:20 5% 21:21 kernel-selftests.vm.run_vmtests.sh../gup_test_u.pass
31:31 -35% 20:20 0% 20:20 5% 21:21 kernel-selftests.vm.run_vmtests.sh../hugepage_mmap.pass
31:31 -35% 20:20 0% 20:20 5% 21:21 kernel-selftests.vm.run_vmtests.sh../hugepage_mremap_./huge/huge_mremap.pass
31:31 -35% 20:20 0% 20:20 5% 21:21 kernel-selftests.vm.run_vmtests.sh../hugepage_shm.pass
31:31 -35% 20:20 0% 20:20 5% 21:21 kernel-selftests.vm.run_vmtests.sh../hugepage_vmemmap.pass
31:31 -35% 20:20 0% 20:20 5% 21:21 kernel-selftests.vm.run_vmtests.sh../hugetlb_madvise_./huge/madvise_test.pass
31:31 -35% 20:20 0% 20:20 5% 21:21 kernel-selftests.vm.run_vmtests.sh../map_fixed_noreplace.pass
31:31 -35% 20:20 0% 20:20 5% 21:21 kernel-selftests.vm.run_vmtests.sh../map_hugetlb.pass
31:31 -35% 20:20 -30% 14:20 -20% 16:21 kernel-selftests.vm.run_vmtests.sh../userfaultfd_anon_20_16.pass
31:31 -35% 20:20 -30% 14:20 -20% 16:21 kernel-selftests.vm.run_vmtests.sh../userfaultfd_hugetlb_256_32.pass
29:31 -32% 19:20 -29% 13:20 -34% 12:21 kernel-selftests.vm.run_vmtests.sh../userfaultfd_shmem_20_16.pass
31:31 -35% 20:20 -35% 13:20 -25% 15:21 kernel-selftests.vm.run_vmtests.sh.fail
31:31 -35% 20:20 0% 20:20 5% 21:21 kernel-selftests.vm.soft-dirty.pass
31:31 -35% 20:20 0% 20:20 5% 21:21 kernel-selftests.vm.split_huge_page_test.pass
>
> > but those dmesg.BUG:sleeping_function_called_from_invalid_context_at*
> > seem only happen on 2bd8eec68f74 as well as the '-fix' commit.
> >
>
> And roughly how often does it happen? I'm running it in a loop now to
> see if I can trigger it locally.
just as above, the 'BUG:sleeping_function_called_from_invalid_context_at_mm/gup.c'
has around 50% rate to happen upon 2bd8eec68f74 & 292baeb4c714
BTW, will test that patch you mentioned in another mail later and update you
with the results.
>
> --
> Mel Gorman
> SUSE Labs
[1]
v5.19-rc2 eec0ff5df2945d19039d16841b9 2bd8eec68f740608db5ea58ecff 292baeb4c7149ac2cb844137481
---------------- --------------------------- --------------------------- ---------------------------
fail:runs %reproduction fail:runs %reproduction fail:runs %reproduction fail:runs
| | | | | | |
:31 0% :20 75% 15:20 70% 14:21 dmesg.BUG:scheduling_while_atomic
:31 0% :20 5% 1:20 0% :21 dmesg.BUG:sleeping_function_called_from_invalid_context_at_fs/binfmt_elf.c
:31 0% :20 5% 1:20 10% 2:21 dmesg.BUG:sleeping_function_called_from_invalid_context_at_fs/dcache.c
:31 0% :20 5% 1:20 5% 1:21 dmesg.BUG:sleeping_function_called_from_invalid_context_at_include/linux/freezer.h
:31 0% :20 10% 2:20 25% 5:21 dmesg.BUG:sleeping_function_called_from_invalid_context_at_include/linux/mmu_notifier.h
:31 0% :20 5% 1:20 0% :21 dmesg.BUG:sleeping_function_called_from_invalid_context_at_include/linux/percpu-rwsem.h
:31 0% :20 40% 8:20 40% 8:21 dmesg.BUG:sleeping_function_called_from_invalid_context_at_include/linux/sched/mm.h
:31 0% :20 10% 2:20 0% :21 dmesg.BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/mutex.c
:31 0% :20 10% 2:20 10% 2:21 dmesg.BUG:sleeping_function_called_from_invalid_context_at_lib/strncpy_from_user.c
:31 0% :20 55% 11:20 65% 13:21 dmesg.BUG:sleeping_function_called_from_invalid_context_at_mm/gup.c
:31 0% :20 15% 3:20 5% 1:21 dmesg.BUG:sleeping_function_called_from_invalid_context_at_mm/memory.c
:31 0% :20 60% 12:20 55% 11:21 dmesg.BUG:sleeping_function_called_from_invalid_context_at_mm/migrate.c
:31 0% :20 5% 1:20 5% 1:21 dmesg.BUG:sleeping_function_called_from_invalid_context_at_mm/page_alloc.c
:31 0% :20 0% :20 5% 1:21 dmesg.BUG:sleeping_function_called_from_invalid_context_at_mm/rmap.c
:31 0% :20 15% 3:20 0% :21 dmesg.BUG:sleeping_function_called_from_invalid_context_at_mm/vmalloc.c
:31 0% :20 45% 9:20 45% 9:21 dmesg.BUG:workqueue_leaked_lock_or_atomic
:31 0% :20 25% 5:20 15% 3:21 dmesg.Kernel_panic-not_syncing:Attempted_to_kill_init!exitcode=
:31 0% :20 5% 1:20 0% :21 dmesg.RIP:__clear_user
29:31 -29% 20:20 6% 20:20 11% 21:21 dmesg.RIP:rcu_eqs_exit
29:31 -29% 20:20 6% 20:20 11% 21:21 dmesg.RIP:sched_clock_tick
:31 0% :20 5% 1:20 0% :21 dmesg.RIP:smp_call_function_many_cond
29:31 -29% 20:20 6% 20:20 11% 21:21 dmesg.WARNING:at_kernel/rcu/tree.c:#rcu_eqs_exit
29:31 -29% 20:20 6% 20:20 11% 21:21 dmesg.WARNING:at_kernel/sched/clock.c:#sched_clock_tick
:31 0% :20 5% 1:20 0% :21 dmesg.WARNING:at_kernel/smp.c:#smp_call_function_many_cond
29:31 -29% 20:20 6% 20:20 11% 21:21 dmesg.WARNING:suspicious_RCU_usage
29:31 -29% 20:20 6% 20:20 11% 21:21 dmesg.boot_failures
11:31 -6% 9:20 -5% 6:20 5% 8:21 dmesg.include/linux/rcupdate.h:#rcu_read_lock()used_illegally_while_idle
11:31 -6% 9:20 -5% 6:20 5% 8:21 dmesg.include/linux/rcupdate.h:#rcu_read_unlock()used_illegally_while_idle
29:31 -29% 20:20 6% 20:20 11% 21:21 dmesg.include/trace/events/error_report.h:#suspicious_rcu_dereference_check()usage
29:31 -29% 20:20 6% 20:20 11% 21:21 dmesg.include/trace/events/lock.h:#suspicious_rcu_dereference_check()usage
next prev parent reply other threads:[~2022-07-07 8:22 UTC|newest]
Thread overview: 38+ messages / expand[flat|nested] mbox.gz Atom feed top
2022-06-13 12:56 [PATCH v4 00/7] Drain remote per-cpu directly Mel Gorman
2022-06-13 12:56 ` [PATCH 1/7] mm/page_alloc: Add page->buddy_list and page->pcp_list Mel Gorman
2022-06-13 12:56 ` [PATCH 2/7] mm/page_alloc: Use only one PCP list for THP-sized allocations Mel Gorman
2022-06-13 12:56 ` [PATCH 3/7] mm/page_alloc: Split out buddy removal code from rmqueue into separate helper Mel Gorman
2022-06-13 12:56 ` [PATCH 4/7] mm/page_alloc: Remove mistaken page == NULL check in rmqueue Mel Gorman
2022-06-13 12:56 ` [PATCH 5/7] mm/page_alloc: Protect PCP lists with a spinlock Mel Gorman
2022-06-16 15:59 ` Vlastimil Babka
2022-06-13 12:56 ` [PATCH 6/7] mm/page_alloc: Remotely drain per-cpu lists Mel Gorman
2022-06-16 16:41 ` Vlastimil Babka
2022-06-13 12:56 ` [PATCH 7/7] mm/page_alloc: Replace local_lock with normal spinlock Mel Gorman
2022-06-15 22:43 ` Yu Zhao
[not found] ` <CGME20220615224855eucas1p1ea6d90c23ec9423dfe04b267f6dddd2a@eucas1p1.samsung.com>
2022-06-15 22:48 ` Marek Szyprowski
2022-06-15 23:04 ` Andrew Morton
2022-06-16 3:05 ` Yu Zhao
2022-06-17 7:55 ` Vlastimil Babka
2022-06-17 6:47 ` Marek Szyprowski
2022-06-21 9:21 ` Mel Gorman
2022-06-16 17:01 ` Vlastimil Babka
2022-06-16 21:07 ` Yu Zhao
2022-06-17 7:57 ` Vlastimil Babka
2022-06-21 9:27 ` Mel Gorman
2022-06-21 9:26 ` Mel Gorman
2022-06-17 9:39 ` Nicolas Saenz Julienne
2022-06-21 9:29 ` Mel Gorman
2022-06-21 9:31 ` Nicolas Saenz Julienne
2022-07-03 9:44 ` [mm/page_alloc] 2bd8eec68f: BUG:sleeping_function_called_from_invalid_context_at_mm/gup.c kernel test robot
2022-07-03 20:22 ` Andrew Morton
2022-07-05 13:51 ` Oliver Sang
2022-07-06 9:55 ` Mel Gorman
2022-07-06 11:53 ` Mel Gorman
2022-07-06 14:21 ` Oliver Sang
2022-07-06 14:52 ` Mel Gorman
2022-07-07 8:22 ` Oliver Sang [this message]
2022-07-06 14:25 ` Oliver Sang
2022-07-06 14:53 ` Mel Gorman
2022-07-07 21:55 ` Vlastimil Babka
2022-07-08 10:56 ` Mel Gorman
2022-07-12 5:04 ` Oliver Sang
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=YsaXwMrksMXtCh/p@xsang-OptiPlex-9020 \
--to=oliver.sang@intel.com \
--cc=akpm@linux-foundation.org \
--cc=hughd@google.com \
--cc=linux-kernel@vger.kernel.org \
--cc=linux-mm@kvack.org \
--cc=lkp@intel.com \
--cc=lkp@lists.01.org \
--cc=mgorman@techsingularity.net \
--cc=mhocko@kernel.org \
--cc=mtosatti@redhat.com \
--cc=nsaenzju@redhat.com \
--cc=vbabka@suse.cz \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).