Re: [PATCH v2 1/1] rcu/kvfree: Update KFREE_DRAIN_JIFFIES interval

From: Paul E. McKenney
Date: Mon Jun 27 2022 - 17:31:33 EST

Next message: Serge Semin: "Re: [PATCH v2 05/16] dt-bindings: dma: add Canaan k210 to Synopsys DesignWare DMA"
Previous message: kernel test robot: "[intel-tdx:kvm-upstream-workaround 434/442] arch/x86/kvm/mmu/mmu.c:981:21: warning: variable 'type' set but not used"
In reply to: Uladzislau Rezki (Sony): "[PATCH v2 1/1] rcu/kvfree: Update KFREE_DRAIN_JIFFIES interval"
Next in thread: Uladzislau Rezki: "Re: [PATCH v2 1/1] rcu/kvfree: Update KFREE_DRAIN_JIFFIES interval"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

On Mon, Jun 27, 2022 at 09:53:53PM +0200, Uladzislau Rezki (Sony) wrote:
> Currently the monitor work is scheduled with a fixed interval that
> is HZ/20 or each 50 milliseconds. The drawback of such approach is
> a low utilization of page slot in some scenarios. The page can store
> up to 512 records. For example on Android system it can look like:

I was looking at queuing this one, but we need a bit more data. In
the meantime, here is my wordsmithing of the above paragraph:

Currently the monitor work is scheduled with a fixed interval of HZ/20,
which is roughly 50 milliseconds. The drawback of this approach is
low utilization of the 512 page slots in scenarios with infrequence
kvfree_rcu() calls. For example on an Android system:

> <snip>
> kworker/3:0-13872 [003] .... 11286.007048: rcu_invoke_kfree_bulk_callback: rcu_preempt bulk=0x0000000026522604 nr_records=1
> kworker/3:0-13872 [003] .... 11286.015638: rcu_invoke_kfree_bulk_callback: rcu_preempt bulk=0x0000000095ed6fca nr_records=2
> kworker/1:2-20434 [001] .... 11286.051230: rcu_invoke_kfree_bulk_callback: rcu_preempt bulk=0x0000000044872ffd nr_records=1
> kworker/1:2-20434 [001] .... 11286.059322: rcu_invoke_kfree_bulk_callback: rcu_preempt bulk=0x0000000026522604 nr_records=2
> kworker/0:1-20052 [000] .... 11286.095295: rcu_invoke_kfree_bulk_callback: rcu_preempt bulk=0x0000000044872ffd nr_records=2
> kworker/0:1-20052 [000] .... 11286.103418: rcu_invoke_kfree_bulk_callback: rcu_preempt bulk=0x00000000cbcf05db nr_records=1
> kworker/2:3-14372 [002] .... 11286.135155: rcu_invoke_kfree_bulk_callback: rcu_preempt bulk=0x0000000095ed6fca nr_records=2
> kworker/2:3-14372 [002] .... 11286.135198: rcu_invoke_kfree_bulk_callback: rcu_preempt bulk=0x0000000044872ffd nr_records=1
> kworker/1:2-20434 [001] .... 11286.155377: rcu_invoke_kfree_bulk_callback: rcu_preempt bulk=0x00000000cbcf05db nr_records=5
> kworker/2:3-14372 [002] .... 11286.167181: rcu_invoke_kfree_bulk_callback: rcu_preempt bulk=0x0000000026522604 nr_records=5
> kworker/1:2-20434 [001] .... 11286.179202: rcu_invoke_kfree_bulk_callback: rcu_preempt bulk=0x000000008ef95e14 nr_records=1
> kworker/2:3-14372 [002] .... 11286.187398: rcu_invoke_kfree_bulk_callback: rcu_preempt bulk=0x00000000c597d297 nr_records=6
> kworker/3:0-13872 [003] .... 11286.187445: rcu_invoke_kfree_bulk_callback: rcu_preempt bulk=0x0000000050bf92e2 nr_records=3
> kworker/1:2-20434 [001] .... 11286.198975: rcu_invoke_kfree_bulk_callback: rcu_preempt bulk=0x00000000cbcf05db nr_records=4
> kworker/1:2-20434 [001] .... 11286.207203: rcu_invoke_kfree_bulk_callback: rcu_preempt bulk=0x0000000095ed6fca nr_records=4
> <snip>
>
> where a page only carries few records to reclaim a memory. In order
> to improve batching and make utilization more efficient the patch sets
> a drain interval to 1 second as default one. When a flood is detected
> an interval is adjusted in a way that a reclaim work is re-scheduled
> on a next timer jiffy.

And of the above paragraph:

Out of 512 slots, in all cases, fewer than 10 were actually used.
In order to improve batching and make utilization more efficient this
commit sets a drain interval to a fixed 1-second interval. Floods are
detected when a page fills quickly, and in that case, the reclaim work
is re-scheduled for the next scheduling-clock tick (jiffy).

---

But what we need now is a trace like the one above showing higher utilization
of the pages. Could you please supply this?

> - default -
> Total time taken by all kfree'ers: 11510245312 ns, loops: 10000, batches: 1553, memory footprint: 70MB
> Total time taken by all kfree'ers: 9813329636 ns, loops: 10000, batches: 1544, memory footprint: 67MB
> Total time taken by all kfree'ers: 10085206318 ns, loops: 10000, batches: 1499, memory footprint: 156MB
> Total time taken by all kfree'ers: 9582207782 ns, loops: 10000, batches: 1456, memory footprint: 103MB
> Total time taken by all kfree'ers: 9872195750 ns, loops: 10000, batches: 1519, memory footprint: 105MB
> Total time taken by all kfree'ers: 9574438300 ns, loops: 10000, batches: 1480, memory footprint: 101MB
> Total time taken by all kfree'ers: 9990015265 ns, loops: 10000, batches: 1489, memory footprint: 127MB
> Total time taken by all kfree'ers: 9978971689 ns, loops: 10000, batches: 1455, memory footprint: 94MB
> Total time taken by all kfree'ers: 10357628090 ns, loops: 10000, batches: 1456, memory footprint: 64MB
> Total time taken by all kfree'ers: 9838469975 ns, loops: 10000, batches: 1448, memory footprint: 131MB
>
> - patch -
> Total time taken by all kfree'ers: 8488575321 ns, loops: 10000, batches: 1735, memory footprint: 82MB
> Total time taken by all kfree'ers: 9256401034 ns, loops: 10000, batches: 1762, memory footprint: 76MB
> Total time taken by all kfree'ers: 9198011994 ns, loops: 10000, batches: 1751, memory footprint: 82MB
> Total time taken by all kfree'ers: 10590540622 ns, loops: 10000, batches: 1540, memory footprint: 94MB
> Total time taken by all kfree'ers: 9953902918 ns, loops: 10000, batches: 1638, memory footprint: 89MB
> Total time taken by all kfree'ers: 10176669464 ns, loops: 10000, batches: 1613, memory footprint: 84MB
> Total time taken by all kfree'ers: 9387490978 ns, loops: 10000, batches: 1762, memory footprint: 85MB
> Total time taken by all kfree'ers: 9530535341 ns, loops: 10000, batches: 1781, memory footprint: 66MB
> Total time taken by all kfree'ers: 9945442340 ns, loops: 10000, batches: 1758, memory footprint: 68MB
> Total time taken by all kfree'ers: 9188848287 ns, loops: 10000, batches: 1781, memory footprint: 67MB
>
> Signed-off-by: Uladzislau Rezki (Sony) <urezki@xxxxxxxxx>
> ---
> kernel/rcu/tree.c | 28 ++++++++++++++++++++++++----
> 1 file changed, 24 insertions(+), 4 deletions(-)
>
> diff --git a/kernel/rcu/tree.c b/kernel/rcu/tree.c
> index fd16c0b46d9e..c11670ba008e 100644
> --- a/kernel/rcu/tree.c
> +++ b/kernel/rcu/tree.c
> @@ -3249,7 +3249,7 @@ EXPORT_SYMBOL_GPL(call_rcu);
>
>
> /* Maximum number of jiffies to wait before draining a batch. */
> -#define KFREE_DRAIN_JIFFIES (HZ / 50)
> +#define KFREE_DRAIN_JIFFIES (HZ)
> #define KFREE_N_BATCHES 2
> #define FREE_N_CHANNELS 2
>
> @@ -3510,6 +3510,26 @@ need_offload_krc(struct kfree_rcu_cpu *krcp)
> return !!krcp->head;
> }
>
> +static void
> +schedule_delayed_monitor_work(struct kfree_rcu_cpu *krcp)
> +{
> + long delay, delay_left;
> +
> + delay = READ_ONCE(krcp->count) >= KVFREE_BULK_MAX_ENTR ?
> + 1:KFREE_DRAIN_JIFFIES;

The above fits as one line in 100 characters, like this:

delay = READ_ONCE(krcp->count) >= KVFREE_BULK_MAX_ENTR ? 1 : KFREE_DRAIN_JIFFIES;

Many of the blank lines below this point in this function are better
removed.

Other than that, looks good! Could you please resend with the added
trace with the patch applied?

Thanx, Paul

> +
> + if (delayed_work_pending(&krcp->monitor_work)) {
> + delay_left = krcp->monitor_work.timer.expires - jiffies;
> +
> + if (delay < delay_left)
> + mod_delayed_work(system_wq, &krcp->monitor_work, delay);
> +
> + return;
> + }
> +
> + queue_delayed_work(system_wq, &krcp->monitor_work, delay);
> +}
> +
> /*
> * This function is invoked after the KFREE_DRAIN_JIFFIES timeout.
> */
> @@ -3567,7 +3587,7 @@ static void kfree_rcu_monitor(struct work_struct *work)
> // work to repeat an attempt. Because previous batches are
> // still in progress.
> if (need_offload_krc(krcp))
> - schedule_delayed_work(&krcp->monitor_work, KFREE_DRAIN_JIFFIES);
> + schedule_delayed_monitor_work(krcp);
>
> raw_spin_unlock_irqrestore(&krcp->lock, flags);
> }
> @@ -3755,7 +3775,7 @@ void kvfree_call_rcu(struct rcu_head *head, rcu_callback_t func)
>
> // Set timer to drain after KFREE_DRAIN_JIFFIES.
> if (rcu_scheduler_active == RCU_SCHEDULER_RUNNING)
> - schedule_delayed_work(&krcp->monitor_work, KFREE_DRAIN_JIFFIES);
> + schedule_delayed_monitor_work(krcp);
>
> unlock_return:
> krc_this_cpu_unlock(krcp, flags);
> @@ -3831,7 +3851,7 @@ void __init kfree_rcu_scheduler_running(void)
>
> raw_spin_lock_irqsave(&krcp->lock, flags);
> if (need_offload_krc(krcp))
> - schedule_delayed_work_on(cpu, &krcp->monitor_work, KFREE_DRAIN_JIFFIES);
> + schedule_delayed_monitor_work(krcp);
> raw_spin_unlock_irqrestore(&krcp->lock, flags);
> }
> }
> --
> 2.30.2
>

Next message: Serge Semin: "Re: [PATCH v2 05/16] dt-bindings: dma: add Canaan k210 to Synopsys DesignWare DMA"
Previous message: kernel test robot: "[intel-tdx:kvm-upstream-workaround 434/442] arch/x86/kvm/mmu/mmu.c:981:21: warning: variable 'type' set but not used"
In reply to: Uladzislau Rezki (Sony): "[PATCH v2 1/1] rcu/kvfree: Update KFREE_DRAIN_JIFFIES interval"
Next in thread: Uladzislau Rezki: "Re: [PATCH v2 1/1] rcu/kvfree: Update KFREE_DRAIN_JIFFIES interval"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]