Re: [PATCH 03/10] mm: shrinker: Add new stats for .to_text()

[Dave Chinner <david@fromorbit.com>]

On Sat, Aug 24, 2024 at 03:10:10PM -0400, Kent Overstreet wrote:
> Add a few new shrinker stats.
> 
> number of objects requested to free, number of objects freed:
> 
> Shrinkers won't necessarily free all objects requested for a variety of
> reasons, but if the two counts are wildly different something is likely
> amiss.
> 
> .scan_objects runtime:
> 
> If one shrinker is taking an excessive amount of time to free
> objects that will block kswapd from running other shrinkers.
> 
> Cc: Andrew Morton <akpm@linux-foundation.org>
> Cc: Qi Zheng <zhengqi.arch@bytedance.com>
> Cc: Roman Gushchin <roman.gushchin@linux.dev>
> Cc: linux-mm@kvack.org
> Signed-off-by: Kent Overstreet <kent.overstreet@linux.dev>
> ---
>  include/linux/shrinker.h |  6 ++++++
>  mm/shrinker.c            | 23 ++++++++++++++++++++++-
>  2 files changed, 28 insertions(+), 1 deletion(-)
> 
> diff --git a/include/linux/shrinker.h b/include/linux/shrinker.h
> index 6193612617a1..106622ddac77 100644
> --- a/include/linux/shrinker.h
> +++ b/include/linux/shrinker.h
> @@ -118,6 +118,12 @@ struct shrinker {
>  #endif
>  	/* objs pending delete, per node */
>  	atomic_long_t *nr_deferred;
> +
> +	atomic_long_t	objects_requested_to_free;
> +	atomic_long_t	objects_freed;
> +	unsigned long	last_freed;	/* timestamp, in jiffies */
> +	unsigned long	last_scanned;	/* timestamp, in jiffies */
> +	atomic64_t	ns_run;
>  };
>  #define DEFAULT_SEEKS 2 /* A good number if you don't know better. */
>  
> diff --git a/mm/shrinker.c b/mm/shrinker.c
> index ad52c269bb48..feaa8122afc9 100644
> --- a/mm/shrinker.c
> +++ b/mm/shrinker.c
> @@ -430,13 +430,24 @@ static unsigned long do_shrink_slab(struct shrink_control *shrinkctl,
>  	       total_scan >= freeable) {
>  		unsigned long ret;
>  		unsigned long nr_to_scan = min(batch_size, total_scan);
> +		u64 start_time = ktime_get_ns();
> +
> +		atomic_long_add(nr_to_scan, &shrinker->objects_requested_to_free);
>  
>  		shrinkctl->nr_to_scan = nr_to_scan;
>  		shrinkctl->nr_scanned = nr_to_scan;
>  		ret = shrinker->scan_objects(shrinker, shrinkctl);
> +
> +		atomic64_add(ktime_get_ns() - start_time, &shrinker->ns_run);
>  		if (ret == SHRINK_STOP)
>  			break;
>  		freed += ret;
> +		unsigned long now = jiffies;
> +		if (ret) {
> +			atomic_long_add(ret, &shrinker->objects_freed);
> +			shrinker->last_freed = now;
> +		}
> +		shrinker->last_scanned = now;
>  
>  		count_vm_events(SLABS_SCANNED, shrinkctl->nr_scanned);
>  		total_scan -= shrinkctl->nr_scanned;

Doing this inside the tight loop (adding 3 atomics and two calls to
ktime_get_ns()) is total overkill. Such fine grained accounting
doesn't given any extra insight into behaviour compared to
accounting the entire loop once.

e.g. the actual time the shrinker takes to run is the time the whole
loop takes to run, not only the individual shrinker->scan_objects
call.

The shrinker code already calculates the total objects scanned and
the total objects freed by the entire loop, so there is no reason to
be calculating this again using much more expensive atomic
operations.

And these are diagnostic stats - the do not need to be perfectly
correct and so atomics are unnecessary overhead the vast majority of
the time.  This code will have much lower impact on runtime overhead
written like this:

	start_time = ktime_get_ns();

	while (total_scan >= batch_size ||
               total_scan >= freeable) {
	.....
	}

	shrinker->objects_requested_to_free += scanned;
	shrinker->objects_freed += freed;

	end_time = ktime_get_ns();
	shrinker->ns_run += end_time - start_time;
	shrinker->last_scanned = end_time;
	if (freed)
		shrinker->last_freed = end_time;

And still give pretty much the exact same debug information without
any additional runtime overhead....

-Dave.
-- 
Dave Chinner
david@fromorbit.com