Re: [PATCH v6 1/4] rcu: Make call_rcu() lazy to save power

Joel Fernandes
2022-09-25T17:47:02Z

Hi Vlad,

On Sun, Sep 25, 2022 at 10:57:10AM +0200, Uladzislau Rezki wrote:
> > Implement timer-based RCU lazy callback batching. The batch is flushed
> > whenever a certain amount of time has passed, or the batch on a
> > particular CPU grows too big. Also memory pressure will flush it in a
> > future patch.
> >
> > To handle several corner cases automagically (such as rcu_barrier() and
> > hotplug), we re-use bypass lists to handle lazy CBs. The bypass list
> > length has the lazy CB length included in it. A separate lazy CB length
> > counter is also introduced to keep track of the number of lazy CBs.
> >
> > v5->v6:
> >
> > [ Frederic Weisbec: Program the lazy timer only if WAKE_NOT, since other
> > deferral levels wake much earlier so for those it is not needed. ]
> >
> > [ Frederic Weisbec: Use flush flags to keep bypass API code clean. ]
> >
> > [ Frederic Weisbec: Make rcu_barrier() wake up only if main list empty. ]
> >
> > [ Frederic Weisbec: Remove extra 'else if' branch in rcu_nocb_try_bypass(). ]
> >
> > [ Joel: Fix issue where I was not resetting lazy_len after moving it to rdp ]
> >
> > [ Paul/Thomas/Joel: Make call_rcu() default lazy so users don't mess up. ]
> >
> I think it make sense to add some data to the commit message
> illustrating what this patch does.

Sure, will do!

> From my side i gave a try of this patch on my setup. Some data:
>
> <snip>
> root@pc638:/home/urezki/rcu_v6# ./perf_script_parser ./perf_v6.script | sort -nk 6 | grep rcu
> name: rcuop/23 pid: 184 woken-up 1 interval: min 0 max 0 avg 0
> name: rcuop/26 pid: 206 woken-up 1 interval: min 0 max 0 avg 0
> name: rcuop/29 pid: 227 woken-up 1 interval: min 0 max 0 avg 0
> name: rcuop/2 pid: 35 woken-up 1 interval: min 0 max 0 avg 0
> name: rcuop/33 pid: 256 woken-up 1 interval: min 0 max 0 avg 0
> name: rcuop/34 pid: 263 woken-up 1 interval: min 0 max 0 avg 0
> name: rcuop/35 pid: 270 woken-up 1 interval: min 0 max 0 avg 0
> name: rcuop/36 pid: 277 woken-up 1 interval: min 0 max 0 avg 0
> name: rcuop/37 pid: 284 woken-up 1 interval: min 0 max 0 avg 0
> name: rcuop/38 pid: 291 woken-up 1 interval: min 0 max 0 avg 0
> name: rcuop/49 pid: 370 woken-up 1 interval: min 0 max 0 avg 0
> name: rcuop/59 pid: 441 woken-up 1 interval: min 0 max 0 avg 0
> name: rcuop/63 pid: 469 woken-up 1 interval: min 0 max 0 avg 0
> name: rcuog/0 pid: 16 woken-up 2 interval: min 8034 max 8034 avg 4017
> name: rcuog/24 pid: 191 woken-up 2 interval: min 7941 max 7941 avg 3970
> name: rcuog/32 pid: 248 woken-up 2 interval: min 7542 max 7542 avg 3771
> name: rcuog/48 pid: 362 woken-up 2 interval: min 8065 max 8065 avg 4032
> name: rcuog/56 pid: 419 woken-up 2 interval: min 8076 max 8076 avg 4038
> name: rcuop/21 pid: 170 woken-up 2 interval: min 13311438 max 13311438 avg 6655719
> name: rcuog/16 pid: 134 woken-up 4 interval: min 8029 max 13303387 avg 3329863
> name: rcuop/9 pid: 85 woken-up 4 interval: min 10007570 max 10007586 avg 7505684
> name: rcuog/8 pid: 77 woken-up 8 interval: min 6240 max 10001242 avg 3753622
> name: rcu_preempt pid: 15 woken-up 18 interval: min 6058 max 9999713 avg 2140788
> name: test_rcu/0 pid: 1411 woken-up 10003 interval: min 165 max 19072 avg 4275
> root@pc638:/home/urezki/rcu_v6#
>
> root@pc638:/home/urezki/rcu_v6# ./perf_script_parser ./perf_default.script | sort -nk 6 | grep rcu
> name: rcuop/33 pid: 256 woken-up 1 interval: min 0 max 0 avg 0
> name: rcuop/51 pid: 384 woken-up 1 interval: min 0 max 0 avg 0
> name: rcuog/32 pid: 248 woken-up 2 interval: min 11927 max 11927 avg 5963
> name: rcuop/63 pid: 469 woken-up 2 interval: min 23963 max 23963 avg 11981
> name: rcuog/56 pid: 419 woken-up 3 interval: min 11132 max 23967 avg 11699
> name: rcuop/50 pid: 377 woken-up 3 interval: min 8057 max 4944344 avg 1650800
> name: rcuog/48 pid: 362 woken-up 8 interval: min 2712 max 37430015 avg 5298801
> name: rcuop/16 pid: 135 woken-up 4790 interval: min 7340 max 16649 avg 8843
> name: rcuog/16 pid: 134 woken-up 4792 interval: min 7368 max 16644 avg 8844
> name: rcu_preempt pid: 15 woken-up 5302 interval: min 26 max 12179 avg 7994
> name: test_rcu/0 pid: 1353 woken-up 10003 interval: min 169 max 18508 avg 4236
> root@pc638:/home/urezki/rcu_v6#
> <snip>
>
> so it is obvious that the patch does the job.

Thanks a lot for testing!

> On my KVM machine the boot time is affected:
>
> <snip>
> [ 2.273406] e1000 0000:00:03.0 eth0: Intel(R) PRO/1000 Network Connection
> [ 11.945283] e1000 0000:00:03.0 ens3: renamed from eth0
> [ 22.165198] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
> [ 22.165206] cdrom: Uniform CD-ROM driver Revision: 3.20
> [ 32.406981] sr 1:0:0:0: Attached scsi CD-ROM sr0
> [ 104.115418] process '/usr/bin/fstype' started with executable stack
> [ 104.170142] EXT4-fs (sda1): mounted filesystem with ordered data mode. Quota mode: none.
> [ 104.340125] systemd[1]: systemd 241 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid)
> [ 104.340193] systemd[1]: Detected virtualization kvm.
> [ 104.340196] systemd[1]: Detected architecture x86-64.
> [ 104.359032] systemd[1]: Set hostname to <pc638>.
> [ 105.740109] random: crng init done
> [ 105.741267] systemd[1]: Reached target Remote File Systems.
> <snip>
>
> 2 - 11 and second delay is between 32 - 104. So there are still users which must
> be waiting for "RCU" in a sync way.

I was wondering if you can compare boot logs and see which timestamp does the
slow down start from. That way, we can narrow down the callback. Also another
idea is, add "trace_event=rcu:rcu_callback,rcu:rcu_invoke_callback
ftrace_dump_on_oops" to the boot params, and then manually call
"tracing_off(); panic();" from the code at the first printk that seems off in
your comparison of good vs bad. For example, if "crng init done" timestamp is
off, put the "tracing_off(); panic();" there. Then grab the serial console
output to see what were the last callbacks that was queued/invoked.

> > diff --git a/include/linux/rcupdate.h b/include/linux/rcupdate.h
> > index 08605ce7379d..40ae36904825 100644
> > --- a/include/linux/rcupdate.h
> > +++ b/include/linux/rcupdate.h
> > @@ -108,6 +108,13 @@ static inline int rcu_preempt_depth(void)
> >
> > #endif /* #else #ifdef CONFIG_PREEMPT_RCU */
> >
> > +#ifdef CONFIG_RCU_LAZY
> > +void call_rcu_flush(struct rcu_head *head, rcu_callback_t func);
> > +#else
> > +static inline void call_rcu_flush(struct rcu_head *head,
> > + rcu_callback_t func) { call_rcu(head, func); }
> > +#endif
> > +
> > /* Internal to kernel */
> > void rcu_init(void);
> > extern int rcu_scheduler_active;
> > diff --git a/kernel/rcu/Kconfig b/kernel/rcu/Kconfig
> > index f53ad63b2bc6..edd632e68497 100644
> > --- a/kernel/rcu/Kconfig
> > +++ b/kernel/rcu/Kconfig
> > @@ -314,4 +314,12 @@ config TASKS_TRACE_RCU_READ_MB
> > Say N here if you hate read-side memory barriers.
> > Take the default if you are unsure.
> >
> > +config RCU_LAZY
> > + bool "RCU callback lazy invocation functionality"
> > + depends on RCU_NOCB_CPU
> > + default n
> > + help
> > + To save power, batch RCU callbacks and flush after delay, memory
> > + pressure or callback list growing too big.
> > +
> >
> Do you think you need this kernel option? Can we just consider and make
> it a run-time configurable? For example much more users will give it a try,
> so it will increase a coverage. By default it can be off.
>
> Also you do not need to do:
>
> #ifdef LAZY

How does the "LAZY" macro end up being runtime-configurable? That's static /
compile time. Did I miss something?

> ...
> #else
> ...
> #endif
>
> >
> > +/*
> > + * LAZY_FLUSH_JIFFIES decides the maximum amount of time that
> > + * can elapse before lazy callbacks are flushed. Lazy callbacks
> > + * could be flushed much earlier for a number of other reasons
> > + * however, LAZY_FLUSH_JIFFIES will ensure no lazy callbacks are
> > + * left unsubmitted to RCU after those many jiffies.
> > + */
> > +#define LAZY_FLUSH_JIFFIES (10 * HZ)
> > +static unsigned long jiffies_till_flush = LAZY_FLUSH_JIFFIES;
> Make it configurable? I do not think you actually need 10 seconds here.
> Reducing it will reduce a possibility to hit a low memory condition. 1
> second would be far enough i think.

Hmm, I can make the delay configurable but for now I'll keep this as default
as all of our power testing has been done with that and I don't want risk
losing the optimization.

Honestly, I am not worried too about memory pressure as we have a shrinker
which triggers flushes on the slightest hint of memory pressure. If it is not
handling it properly, then we need to fix the shrinker.

thanks,

- Joel