| Message ID | 20240824191020.3170516-4-kent.overstreet@linux.dev (mailing list archive) |
|---|---|
| State | New |
| Headers | show |
| Series | shrinker debugging, .to_text() report (resend) | expand |
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.
On Wed, Aug 28, 2024 at 12:36:08PM GMT, Dave Chinner wrote: > 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.... *nod* This is all going to be noise compared to the expense of ->scan() itself, but there's no reason not to, I'll make the change...
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; @@ -812,9 +823,19 @@ EXPORT_SYMBOL_GPL(shrinker_free); void shrinker_to_text(struct seq_buf *out, struct shrinker *shrinker) { struct shrink_control sc = { .gfp_mask = GFP_KERNEL, }; + unsigned long nr_freed = atomic_long_read(&shrinker->objects_freed); seq_buf_puts(out, shrinker->name); - seq_buf_printf(out, " objects: %lu\n", shrinker->count_objects(shrinker, &sc)); + seq_buf_putc(out, '\n'); + + seq_buf_printf(out, "objects: %lu\n", shrinker->count_objects(shrinker, &sc)); + seq_buf_printf(out, "requested to free: %lu\n", atomic_long_read(&shrinker->objects_requested_to_free)); + seq_buf_printf(out, "objects freed: %lu\n", nr_freed); + seq_buf_printf(out, "last scanned: %li sec ago\n", (jiffies - shrinker->last_scanned) / HZ); + seq_buf_printf(out, "last freed: %li sec ago\n", (jiffies - shrinker->last_freed) / HZ); + seq_buf_printf(out, "ns per object freed: %llu\n", nr_freed + ? div64_ul(atomic64_read(&shrinker->ns_run), nr_freed) + : 0); if (shrinker->to_text) { shrinker->to_text(out, shrinker);
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(-)