Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 23.128.96.18 as permitted sender) client-ip=23.128.96.18;
Date:   Fri, 25 Jun 2021 12:16:52 +0200
From:   Peter Zijlstra <peterz@infradead.org>
To:     Bharata B Rao <bharata@linux.ibm.com>
Cc:     Srikar Dronamraju <srikar@linux.vnet.ibm.com>,
        linux-next@vger.kernel.org, linuxppc-dev@lists.ozlabs.org,
        LKML <linux-kernel@vger.kernel.org>,
        Valentin Schneider <valentin.schneider@arm.com>,
        Ingo Molnar <mingo@kernel.org>
Subject: Re: PowerPC guest getting "BUG: scheduling while atomic" on
 linux-next-20210623 during secondary CPUs bringup
Message-ID: <YNWtFKdSuoYTfSon@hirez.programming.kicks-ass.net>
References: <YNSq3UQTjm6HWELA@in.ibm.com>
 <20210625054608.fmwt7lxuhp7inkjx@linux.vnet.ibm.com>
 <YNWFiZii+MINhUC3@hirez.programming.kicks-ass.net>
 <YNWZfKK+KBQSUdG5@in.ibm.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <YNWZfKK+KBQSUdG5@in.ibm.com>
Precedence: bulk

On Fri, Jun 25, 2021 at 02:23:16PM +0530, Bharata B Rao wrote:
> On Fri, Jun 25, 2021 at 09:28:09AM +0200, Peter Zijlstra wrote:
> > On Fri, Jun 25, 2021 at 11:16:08AM +0530, Srikar Dronamraju wrote:
> > > * Bharata B Rao <bharata@linux.ibm.com> [2021-06-24 21:25:09]:
> > > 
> > > > A PowerPC KVM guest gets the following BUG message when booting
> > > > linux-next-20210623:
> > > > 
> > > > smp: Bringing up secondary CPUs ...
> > > > BUG: scheduling while atomic: swapper/1/0/0x00000000
> > 
> > 'funny', your preempt_count is actually too low. The check here is for
> > preempt_count() == DISABLE_OFFSET (aka. 1 when PREEMPT=y), but you have
> > 0.
> > 
> > > > no locks held by swapper/1/0.
> > > > Modules linked in:
> > > > CPU: 1 PID: 0 Comm: swapper/1 Not tainted 5.13.0-rc7-next-20210623
> > > > Call Trace:
> > > > [c00000000ae5bc20] [c000000000badc64] dump_stack_lvl+0x98/0xe0 (unreliable)
> > > > [c00000000ae5bc60] [c000000000210200] __schedule_bug+0xb0/0xe0
> > > > [c00000000ae5bcd0] [c000000001609e28] __schedule+0x1788/0x1c70
> > > > [c00000000ae5be20] [c00000000160a8cc] schedule_idle+0x3c/0x70
> > > > [c00000000ae5be50] [c00000000022984c] do_idle+0x2bc/0x420
> > > > [c00000000ae5bf00] [c000000000229d88] cpu_startup_entry+0x38/0x40
> > > > [c00000000ae5bf30] [c0000000000666c0] start_secondary+0x290/0x2a0
> > > > [c00000000ae5bf90] [c00000000000be54] start_secondary_prolog+0x10/0x14
> > > > 
> > > > <The above repeats for all the secondary CPUs>
> > > > 
> > > > smp: Brought up 2 nodes, 16 CPUs
> > > > numa: Node 0 CPUs: 0-7
> > > > numa: Node 1 CPUs: 8-15
> > > > 
> > > > This seems to have started from next-20210521 and isn't seen on
> > > > next-20210511.
> > > > 
> > > 
> > > Bharata,
> > > 
> > > I think the regression is due to Commit f1a0a376ca0c ("sched/core:
> > > Initialize the idle task with preemption disabled")
> > 
> > So that extra preempt_disable() that got removed would've incremented it
> > to 1 and then things would've been fine.
> > 
> > Except.. Valentin changed things such that preempt_count() should've
> > been inittialized to 1, instead of 0, but for some raisin that didn't
> > stick.. what gives.
> > 
> > So we have init_idle(p) -> init_idle_preempt_count(p) ->
> > task_thread_info(p)->preempt_count = PREEMPT_DISABLED;
> > 
> > But somehow, by the time you're running start_secondary(), that's gotten
> > to be 0 again. Does DEBUG_PREEMPT give more clues?
> 
> PREEMPTION is off here.

You mean: CONFIG_PREEMPTION=n, what about CONFIG_PREEMPT_COUNT?

Because if both are =n, then I don't see how that warning could trigger.
in_atomic_preempt_off() would then result in prempt_count() == 0, and
per the print above, it *is* 0.