[PATCH v2 0/2] Get callbacks/names of shrinkers from tracepoints

[PATCH v2 0/2] Get callbacks/names of shrinkers from tracepoints

[Janani Ravichandran]

Currently, it is not possible to know which shrinkers are being run.
Even though the callbacks are printed using %pF in tracepoints 
mm_shrink_slab_start and mm_shrink_slab_end, they are not visible to
userspace tools like perf.

To address this, this patchset
1. Enables the display of names of shrinker callbacks in tracepoints
mm_shrink_slab_start and mm_shrink_slab_end.
2. Adds a new tracepoint in the callback of the superblock shrinker to
get specific names of superblock types.

Changes since v1 at https://lkml.org/lkml/2016/7/9/33:
1. This patchset does not introduce a new variable to hold names of
shrinkers, unlike v1. It makes mm_shrink_slab_start and
mm_shrink_slab_end print names of callbacks instead.
2. It also adds a new tracepoint for superblock shrinkers to display
more specific name information, which v1 did not do.

Thanks to Dave Chinner and Tony Jones for their suggestions.

Janani Ravichandran (2):
  include: trace: Display names of shrinker callbacks
  fs: super.c: Add tracepoint to get name of superblock shrinker

 fs/super.c                    |  2 ++
 include/trace/events/vmscan.h | 39 +++++++++++++++++++++++++++++++++++++--
 2 files changed, 39 insertions(+), 2 deletions(-)

-- 
2.7.0

[PATCH v2 1/2] include: trace: Display names of shrinker callbacks

[Janani Ravichandran]

This patch enables the names of callbacks in mm_shrink_slab_start and
mm_shrink_slab_end to be seen by userspace tools.
This should give some information regarding the identity of the
shrinkers being run.

Signed-off-by: Janani Ravichandran <janani.rvchndrn@gmail.com>
---
 include/trace/events/vmscan.h | 18 ++++++++++++++++--
 1 file changed, 16 insertions(+), 2 deletions(-)

diff --git a/include/trace/events/vmscan.h b/include/trace/events/vmscan.h
index c88fd09..7091c29 100644
--- a/include/trace/events/vmscan.h
+++ b/include/trace/events/vmscan.h
@@ -16,6 +16,8 @@
 #define RECLAIM_WB_SYNC		0x0004u /* Unused, all reclaim async */
 #define RECLAIM_WB_ASYNC	0x0008u
 
+#define SHRINKER_NAME_LEN	(size_t)32
+
 #define show_reclaim_flags(flags)				\
 	(flags) ? __print_flags(flags, "|",			\
 		{RECLAIM_WB_ANON,	"RECLAIM_WB_ANON"},	\
@@ -196,6 +198,7 @@ TRACE_EVENT(mm_shrink_slab_start,
 	TP_STRUCT__entry(
 		__field(struct shrinker *, shr)
 		__field(void *, shrink)
+		__array(char, shrinker_name, SHRINKER_NAME_LEN)
 		__field(int, nid)
 		__field(long, nr_objects_to_shrink)
 		__field(gfp_t, gfp_flags)
@@ -207,8 +210,12 @@ TRACE_EVENT(mm_shrink_slab_start,
 	),
 
 	TP_fast_assign(
+		char sym[KSYM_SYMBOL_LEN];
+
 		__entry->shr = shr;
 		__entry->shrink = shr->scan_objects;
+		sprint_symbol(sym, (unsigned long)__entry->shrink);
+		strlcpy(__entry->shrinker_name, sym, SHRINKER_NAME_LEN);
 		__entry->nid = sc->nid;
 		__entry->nr_objects_to_shrink = nr_objects_to_shrink;
 		__entry->gfp_flags = sc->gfp_mask;
@@ -219,9 +226,10 @@ TRACE_EVENT(mm_shrink_slab_start,
 		__entry->total_scan = total_scan;
 	),
 
-	TP_printk("%pF %p: nid: %d objects to shrink %ld gfp_flags %s pgs_scanned %ld lru_pgs %ld cache items %ld delta %lld total_scan %ld",
+	TP_printk("%pF %p name:%s nid: %d objects to shrink %ld gfp_flags %s pgs_scanned %ld lru_pgs %ld cache items %ld delta %lld total_scan %ld",
 		__entry->shrink,
 		__entry->shr,
+		__entry->shrinker_name,
 		__entry->nid,
 		__entry->nr_objects_to_shrink,
 		show_gfp_flags(__entry->gfp_flags),
@@ -242,6 +250,7 @@ TRACE_EVENT(mm_shrink_slab_end,
 	TP_STRUCT__entry(
 		__field(struct shrinker *, shr)
 		__field(int, nid)
+		__array(char, shrinker_name, SHRINKER_NAME_LEN)
 		__field(void *, shrink)
 		__field(long, unused_scan)
 		__field(long, new_scan)
@@ -250,18 +259,23 @@ TRACE_EVENT(mm_shrink_slab_end,
 	),
 
 	TP_fast_assign(
+		char sym[KSYM_SYMBOL_LEN];
+
 		__entry->shr = shr;
 		__entry->nid = nid;
 		__entry->shrink = shr->scan_objects;
+		sprint_symbol(sym, (unsigned long)__entry->shrink);
+		strlcpy(__entry->shrinker_name, sym, SHRINKER_NAME_LEN);
 		__entry->unused_scan = unused_scan_cnt;
 		__entry->new_scan = new_scan_cnt;
 		__entry->retval = shrinker_retval;
 		__entry->total_scan = total_scan;
 	),
 
-	TP_printk("%pF %p: nid: %d unused scan count %ld new scan count %ld total_scan %ld last shrinker return val %d",
+	TP_printk("%pF %p name:%s nid: %d unused scan count %ld new scan count %ld total_scan %ld last shrinker return val %d",
 		__entry->shrink,
 		__entry->shr,
+		__entry->shrinker_name,
 		__entry->nid,
 		__entry->unused_scan,
 		__entry->new_scan,
-- 
2.7.0

[PATCH v2 2/2] fs: super.c: Add tracepoint to get name of superblock shrinker

[Janani Ravichandran]

This patch adds a new tracepoint to gather specific name information
of the superblock types.
This tracepoint can be used in conjunction with mm_shrink_slab_start and
mm_shrink_slab_end to get information like latency, number of
objects scanned by that particular shrinker, etc. The shrinker struct
address printed by mm_shrink_slab_start, mm_shrink_slab_end 
and the new tracepoint can help tie information together.

However, the specific superblock type can only be identified if the
while condition in do_shrink_slab() of vmscan.c is true and the 
callback for the superblock shrinker is invoked.

Here's a sample output of a postprocessing script to observe how long
the shrinkers took. In this case, the while condition was true each time
and the superblock callback was invoked. The names cgroup, ext4, proc,
etc were obtained from the new tracepoint in the callback.

name:ext4_es_scan 518582ns
name:super_cache_scan/cgroup 1319939ns
name:super_cache_scan/ext4 16954600ns
name:super_cache_scan/proc 27466703ns
name:super_cache_scan/sysfs 11412903ns
name:super_cache_scan/tmpfs 71323ns

However, in cases where the callback is not invoked, it is not possible
to obtain name information from the new tracepoint. In such cases, the
output would be something like:

name:deferred_split_scan 345972ns
name:ext4_es_scan 2719002ns
name:i915_gem_shrinker_scan 10915266ns
name:scan_shadow_nodes 3349303ns
name:super_cache_scan 18970732ns
name:super_cache_scan/ext4 1293938ns
name:super_cache_scan/tmpfs 21588ns

On line 5,we can see that there were times when the super_cache_scan
callback wasn't invoked and therefore no name information was obtained.

Signed-off-by: Janani Ravichandran <janani.rvchndrn@gmail.com>
---

Changes since v1:

v1 did not have any mechanism to print names of specific superblock
types . This version introduces that.

 fs/super.c                    |  2 ++
 include/trace/events/vmscan.h | 21 +++++++++++++++++++++
 2 files changed, 23 insertions(+)

diff --git a/fs/super.c b/fs/super.c
index c2ff475..be7b493 100644
--- a/fs/super.c
+++ b/fs/super.c
@@ -35,6 +35,7 @@
 #include <linux/lockdep.h>
 #include <linux/user_namespace.h>
 #include "internal.h"
+#include <trace/events/vmscan.h>
 
 
 static LIST_HEAD(super_blocks);
@@ -64,6 +65,7 @@ static unsigned long super_cache_scan(struct shrinker *shrink,
 	long	inodes;
 
 	sb = container_of(shrink, struct super_block, s_shrink);
+	trace_mm_shrinker_callback(shrink, sb->s_type->name);
 
 	/*
 	 * Deadlock avoidance.  We may hold various FS locks, and we don't want
diff --git a/include/trace/events/vmscan.h b/include/trace/events/vmscan.h
index 7091c29..5c8703e 100644
--- a/include/trace/events/vmscan.h
+++ b/include/trace/events/vmscan.h
@@ -283,6 +283,27 @@ TRACE_EVENT(mm_shrink_slab_end,
 		__entry->retval)
 );
 
+TRACE_EVENT(mm_shrinker_callback,
+	TP_PROTO(struct shrinker *shr, const char *shrinker_name),
+
+	TP_ARGS(shr, shrinker_name),
+
+	TP_STRUCT__entry(
+		__field(struct shrinker *, shr)
+		__array(char, shrinker_name, SHRINKER_NAME_LEN)
+	),
+
+	TP_fast_assign(
+		__entry->shr = shr;
+		strlcpy(__entry->shrinker_name, shrinker_name,
+		       	SHRINKER_NAME_LEN);
+	),
+
+	TP_printk("shrinker:%p shrinker_name:%s",
+		__entry->shr,
+		__entry->shrinker_name)
+);
+
 DECLARE_EVENT_CLASS(mm_vmscan_lru_isolate_template,
 
 	TP_PROTO(int classzone_idx,
-- 
2.7.0

Re: [PATCH v2 2/2] fs: super.c: Add tracepoint to get name of superblock shrinker

[Al Viro]

On Thu, Aug 18, 2016 at 02:09:31AM -0400, Janani Ravichandran wrote:

>  static LIST_HEAD(super_blocks);
> @@ -64,6 +65,7 @@ static unsigned long super_cache_scan(struct shrinker *shrink,
>  	long	inodes;
>  
>  	sb = container_of(shrink, struct super_block, s_shrink);
> +	trace_mm_shrinker_callback(shrink, sb->s_type->name);

IOW, we are (should that patch be accepted) obliged to keep the function in
question and the guts of struct shrinker indefinitely.

NAK.  Keep your debugging patches in your tree and maintain them yourself.
And if a change in the kernel data structures breaks them (and your userland
code relying on those), it's your problem.

Tracepoints are very nice for local debugging/data collection/etc. patches.
Accepting them into mainline shifts the responsibility for updating them
to the rest of us, and unlike you we can't update the userland side.

Adding a userland ABI means pledging to keep it alive pretty much indefinitely.
It's not automatically unacceptable (hell, new syscalls get added from time
to time), but it should come with a serious analysis of what's getting exposed
and it shouldn't be accepted without such.

Re: [PATCH v2 2/2] fs: super.c: Add tracepoint to get name of superblock shrinker

[Michal Hocko]

On Thu 18-08-16 07:32:39, Al Viro wrote:
> On Thu, Aug 18, 2016 at 02:09:31AM -0400, Janani Ravichandran wrote:
> 
> >  static LIST_HEAD(super_blocks);
> > @@ -64,6 +65,7 @@ static unsigned long super_cache_scan(struct shrinker *shrink,
> >  	long	inodes;
> >  
> >  	sb = container_of(shrink, struct super_block, s_shrink);
> > +	trace_mm_shrinker_callback(shrink, sb->s_type->name);
> 
> IOW, we are (should that patch be accepted) obliged to keep the function in
> question and the guts of struct shrinker indefinitely.

I am not aware that trace points are considered a stable ABI. Is that
documented anywhere? We have changed/removed some of them in the
past. If there is a debugging tool parsing them the tool itself is
responsible to keep track of any changes.
-- 
Michal Hocko
SUSE Labs

Re: [PATCH v2 2/2] fs: super.c: Add tracepoint to get name of superblock shrinker

[Rik van Riel]

On Thu, 2016-08-18 at 07:32 +0100, Al Viro wrote:
> On Thu, Aug 18, 2016 at 02:09:31AM -0400, Janani Ravichandran wrote:
> 
> >  static LIST_HEAD(super_blocks);
> > @@ -64,6 +65,7 @@ static unsigned long super_cache_scan(struct
> > shrinker *shrink,
> >  	long	inodes;
> >  
> >  	sb = container_of(shrink, struct super_block, s_shrink);
> > +	trace_mm_shrinker_callback(shrink, sb->s_type->name);
> 
> IOW, we are (should that patch be accepted) obliged to keep the
> function in
> question and the guts of struct shrinker indefinitely.
> 
> NAK.  Keep your debugging patches in your tree and maintain them
> yourself.
> And if a change in the kernel data structures breaks them (and your
> userland
> code relying on those), it's your problem.
> 
> Tracepoints are very nice for local debugging/data collection/etc.
> patches.
> 

The issue is that production systems often need
debugging, and when there are performance issues
we need some way to gather all the necessary info,
without rebooting the production system into a
special debug kernel.

This is not an ABI that userspace can rely on,
and should not be considered as such. Any
performance tracing/debugging scripts can be
easily changed to match the kernel running on
the system in question.