On Thu, Aug 18, 2022 at 7:05 PM Joel Fernandes <joel@xxxxxxxxxxxxxxxxx> wrote:
>
> On Thu, Aug 18, 2022 at 1:23 PM Joel Fernandes <joel@xxxxxxxxxxxxxxxxx> wrote:
> >
> > [Sorry, adding back the CC list]
> >
> > On Mon, Aug 8, 2022 at 11:45 PM Joel Fernandes (Google)
> > <joel@xxxxxxxxxxxxxxxxx> wrote:
> > >
> > > This is required to prevent callbacks triggering RCU machinery too
> > > quickly and too often, which adds more power to the system.
> > >
> > > When testing, we found that these paths were invoked often when the
> > > system is not doing anything (screen is ON but otherwise idle).
> >
> > Unfortunately, I am seeing a slow down in ChromeOS boot performance
> > after applying this particular patch. It is the first time I could
> > test ChromeOS boot times with the series since it was hard to find a
> > ChromeOS device that runs the upstream kernel.
> >
> > Anyway, Vlad, Neeraj, do you guys also see slower boot times with this
> > patch? I wonder if the issue is with wake up interaction with the nocb
> > GP threads.
> >
> > We ought to disable lazy RCU during boot since it would have little
> > benefit anyway. But I am also concerned about some deeper problem I
> > did not catch before.
> >
> > I'll look into tracing the fs paths to see if I can narrow down what's
> > causing it. Will also try a newer kernel, I am currently testing on
> > 5.19-rc4.
>
> I got somewhere with this. It looks like queuing CBs as lazy CBs
> instead of normal CBs, are triggering expedited stalls during the boot
> process:
>
> 39.949198] rcu: INFO: rcu_preempt detected expedited stalls on
> CPUs/tasks: { } 28 jiffies s: 69 root: 0x0/.
>
> No idea how/why lazy RCU CBs would be related to expedited GP issues,
> but maybe something hangs and causes that side-effect.
>
> initcall_debug did not help, as it seems initcalls all work fine, and
> then 8 seconds after the boot, it starts slowing down a lot, followed
> by the RCU stall messages. As a next step I'll enable ftrace during
> the boot to see if I can get more insight. But I believe, its not the
> FS layer, the FS layer just triggers lazy CBs, but there is something
> wrong with the core lazy-RCU work itself.
>
> This kernel is 5.19-rc4. I'll also try to rebase ChromeOS on more
> recent kernels and debug.
More digging, thanks to trace_event= boot option , I find that the
boot process does have some synchronous waits, and though these are
"non-lazy", for some reason the lazy CBs that were previously queued
are making them wait for the *full* lazy duration. Which points to a
likely bug in the lazy RCU logic. These synchronous CBs should never
be waiting like the lazy ones:
[ 17.715904] => trace_dump_stack
[ 17.715904] => __wait_rcu_gp
[ 17.715904] => synchronize_rcu
[ 17.715904] => selinux_netcache_avc_callback
[ 17.715904] => avc_ss_reset
[ 17.715904] => sel_write_enforce
[ 17.715904] => vfs_write
[ 17.715904] => ksys_write
[ 17.715904] => do_syscall_64
[ 17.715904] => entry_SYSCALL_64_after_hwframe
I'm tired so I'll resume the debug later.
