Re: [PATCH v3 4/5] sunrpc: add debugfs file for displaying client rpc_task queue

[Anna Schumaker <Anna.Schumaker@netapp.com>]

On 11/26/2014 03:13 PM, Anna Schumaker wrote:
> Hi Jeff,
> 
> On 11/26/2014 02:44 PM, Jeff Layton wrote:
>> It's possible to get a dump of the RPC task queue by writing a value to
>> /proc/sys/sunrpc/rpc_debug. If you write any value to that file, you get
>> a dump of the RPC client task list into the log buffer. This is a rather
>> inconvenient interface however, and makes it hard to get immediate info
>> about the task queue.
>>
>> Add a new directory hierarchy under debugfs:
>>
>>     sunrpc/
>>         rpc_clnt/
>>             <clientid>/
>>
>> Within each clientid directory we create a new "tasks" file that will
>> dump info similar to what shows up in the log buffer, but with a few
>> small differences -- we avoid printing raw kernel addresses in favor of
>> symbolic names and the XID is also displayed.
> 
> What do I have to do to get tasks to show up in the tasks file?  I'm running xfstests and occasionally running "cat" on 0/tasks and 3/tasks, but both are empty.

Ah, apparently I had to wait for generic/074 to run.  Now things are showing up!

Anna

> 
> Anna
> 
>>
>> Signed-off-by: Jeff Layton <jlayton@primarydata.com>
>> ---
>>  include/linux/sunrpc/clnt.h  |   4 +
>>  include/linux/sunrpc/debug.h |  31 +++++++
>>  net/sunrpc/Kconfig           |   1 +
>>  net/sunrpc/Makefile          |   1 +
>>  net/sunrpc/clnt.c            |  10 ++-
>>  net/sunrpc/debugfs.c         | 191 +++++++++++++++++++++++++++++++++++++++++++
>>  net/sunrpc/sunrpc_syms.c     |   8 ++
>>  7 files changed, 245 insertions(+), 1 deletion(-)
>>  create mode 100644 net/sunrpc/debugfs.c
>>
>> diff --git a/include/linux/sunrpc/clnt.h b/include/linux/sunrpc/clnt.h
>> index 70736b98c721..d86acc63b25f 100644
>> --- a/include/linux/sunrpc/clnt.h
>> +++ b/include/linux/sunrpc/clnt.h
>> @@ -63,6 +63,9 @@ struct rpc_clnt {
>>  	struct rpc_rtt		cl_rtt_default;
>>  	struct rpc_timeout	cl_timeout_default;
>>  	const struct rpc_program *cl_program;
>> +#if IS_ENABLED(CONFIG_SUNRPC_DEBUG)
>> +	struct dentry		*cl_debugfs;	/* debugfs directory */
>> +#endif
>>  };
>>  
>>  /*
>> @@ -176,5 +179,6 @@ size_t		rpc_peeraddr(struct rpc_clnt *, struct sockaddr *, size_t);
>>  const char	*rpc_peeraddr2str(struct rpc_clnt *, enum rpc_display_format_t);
>>  int		rpc_localaddr(struct rpc_clnt *, struct sockaddr *, size_t);
>>  
>> +const char *rpc_proc_name(const struct rpc_task *task);
>>  #endif /* __KERNEL__ */
>>  #endif /* _LINUX_SUNRPC_CLNT_H */
>> diff --git a/include/linux/sunrpc/debug.h b/include/linux/sunrpc/debug.h
>> index 43f38ee9668c..835339707094 100644
>> --- a/include/linux/sunrpc/debug.h
>> +++ b/include/linux/sunrpc/debug.h
>> @@ -53,9 +53,40 @@ extern unsigned int		nlm_debug;
>>  /*
>>   * Sysctl interface for RPC debugging
>>   */
>> +
>> +struct rpc_clnt;
>> +
>>  #if IS_ENABLED(CONFIG_SUNRPC_DEBUG)
>>  void		rpc_register_sysctl(void);
>>  void		rpc_unregister_sysctl(void);
>> +int		sunrpc_debugfs_init(void);
>> +void		sunrpc_debugfs_exit(void);
>> +int		rpc_clnt_debugfs_register(struct rpc_clnt *);
>> +void		rpc_clnt_debugfs_unregister(struct rpc_clnt *);
>> +#else
>> +static inline int
>> +sunrpc_debugfs_init(void)
>> +{
>> +	return 0;
>> +}
>> +
>> +static inline void
>> +sunrpc_debugfs_exit(void)
>> +{
>> +	return;
>> +}
>> +
>> +static inline int
>> +rpc_clnt_debugfs_register(struct rpc_clnt *clnt)
>> +{
>> +	return 0;
>> +}
>> +
>> +static inline void
>> +rpc_clnt_debugfs_unregister(struct rpc_clnt *clnt)
>> +{
>> +	return;
>> +}
>>  #endif
>>  
>>  #endif /* _LINUX_SUNRPC_DEBUG_H_ */
>> diff --git a/net/sunrpc/Kconfig b/net/sunrpc/Kconfig
>> index 0754d0f466d2..fb78117b896c 100644
>> --- a/net/sunrpc/Kconfig
>> +++ b/net/sunrpc/Kconfig
>> @@ -35,6 +35,7 @@ config RPCSEC_GSS_KRB5
>>  config SUNRPC_DEBUG
>>  	bool "RPC: Enable dprintk debugging"
>>  	depends on SUNRPC && SYSCTL
>> +	select DEBUG_FS
>>  	help
>>  	  This option enables a sysctl-based debugging interface
>>  	  that is be used by the 'rpcdebug' utility to turn on or off
>> diff --git a/net/sunrpc/Makefile b/net/sunrpc/Makefile
>> index e5a7a1cac8f3..15e6f6c23c5d 100644
>> --- a/net/sunrpc/Makefile
>> +++ b/net/sunrpc/Makefile
>> @@ -14,6 +14,7 @@ sunrpc-y := clnt.o xprt.o socklib.o xprtsock.o sched.o \
>>  	    addr.o rpcb_clnt.o timer.o xdr.o \
>>  	    sunrpc_syms.o cache.o rpc_pipe.o \
>>  	    svc_xprt.o
>> +sunrpc-$(CONFIG_SUNRPC_DEBUG) += debugfs.o
>>  sunrpc-$(CONFIG_SUNRPC_BACKCHANNEL) += backchannel_rqst.o bc_svc.o
>>  sunrpc-$(CONFIG_PROC_FS) += stats.o
>>  sunrpc-$(CONFIG_SYSCTL) += sysctl.o
>> diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c
>> index 36c64ef460cf..05da12a33945 100644
>> --- a/net/sunrpc/clnt.c
>> +++ b/net/sunrpc/clnt.c
>> @@ -305,6 +305,10 @@ static int rpc_client_register(struct rpc_clnt *clnt,
>>  	struct super_block *pipefs_sb;
>>  	int err;
>>  
>> +	err = rpc_clnt_debugfs_register(clnt);
>> +	if (err)
>> +		return err;
>> +
>>  	pipefs_sb = rpc_get_sb_net(net);
>>  	if (pipefs_sb) {
>>  		err = rpc_setup_pipedir(pipefs_sb, clnt);
>> @@ -331,6 +335,7 @@ err_auth:
>>  out:
>>  	if (pipefs_sb)
>>  		rpc_put_sb_net(net);
>> +	rpc_clnt_debugfs_unregister(clnt);
>>  	return err;
>>  }
>>  
>> @@ -670,6 +675,7 @@ int rpc_switch_client_transport(struct rpc_clnt *clnt,
>>  
>>  	rpc_unregister_client(clnt);
>>  	__rpc_clnt_remove_pipedir(clnt);
>> +	rpc_clnt_debugfs_unregister(clnt);
>>  
>>  	/*
>>  	 * A new transport was created.  "clnt" therefore
>> @@ -771,6 +777,7 @@ rpc_free_client(struct rpc_clnt *clnt)
>>  			rcu_dereference(clnt->cl_xprt)->servername);
>>  	if (clnt->cl_parent != clnt)
>>  		parent = clnt->cl_parent;
>> +	rpc_clnt_debugfs_unregister(clnt);
>>  	rpc_clnt_remove_pipedir(clnt);
>>  	rpc_unregister_client(clnt);
>>  	rpc_free_iostats(clnt->cl_metrics);
>> @@ -1397,7 +1404,8 @@ rpc_restart_call(struct rpc_task *task)
>>  EXPORT_SYMBOL_GPL(rpc_restart_call);
>>  
>>  #if IS_ENABLED(CONFIG_SUNRPC_DEBUG)
>> -static const char *rpc_proc_name(const struct rpc_task *task)
>> +const char
>> +*rpc_proc_name(const struct rpc_task *task)
>>  {
>>  	const struct rpc_procinfo *proc = task->tk_msg.rpc_proc;
>>  
>> diff --git a/net/sunrpc/debugfs.c b/net/sunrpc/debugfs.c
>> new file mode 100644
>> index 000000000000..3d7745683ca3
>> --- /dev/null
>> +++ b/net/sunrpc/debugfs.c
>> @@ -0,0 +1,191 @@
>> +/**
>> + * debugfs interface for sunrpc
>> + *
>> + * (c) 2014 Jeff Layton <jlayton@primarydata.com>
>> + */
>> +
>> +#include <linux/debugfs.h>
>> +#include <linux/sunrpc/sched.h>
>> +#include <linux/sunrpc/clnt.h>
>> +#include "netns.h"
>> +
>> +static struct dentry *topdir;
>> +static struct dentry *rpc_clnt_dir;
>> +
>> +struct rpc_clnt_iter {
>> +	struct rpc_clnt	*clnt;
>> +	loff_t		pos;
>> +};
>> +
>> +static int
>> +tasks_show(struct seq_file *f, void *v)
>> +{
>> +	u32 xid = 0;
>> +	struct rpc_task *task = v;
>> +	struct rpc_clnt *clnt = task->tk_client;
>> +	const char *rpc_waitq = "none";
>> +
>> +	if (RPC_IS_QUEUED(task))
>> +		rpc_waitq = rpc_qname(task->tk_waitqueue);
>> +
>> +	if (task->tk_rqstp)
>> +		xid = be32_to_cpu(task->tk_rqstp->rq_xid);
>> +
>> +	seq_printf(f, "%5u %04x %6d 0x%x 0x%x %8ld %ps %sv%u %s a:%ps q:%s\n",
>> +		task->tk_pid, task->tk_flags, task->tk_status,
>> +		clnt->cl_clid, xid, task->tk_timeout, task->tk_ops,
>> +		clnt->cl_program->name, clnt->cl_vers, rpc_proc_name(task),
>> +		task->tk_action, rpc_waitq);
>> +	return 0;
>> +}
>> +
>> +static void *
>> +tasks_start(struct seq_file *f, loff_t *ppos)
>> +	__acquires(&clnt->cl_lock)
>> +{
>> +	struct rpc_clnt_iter *iter = f->private;
>> +	loff_t pos = *ppos;
>> +	struct rpc_clnt *clnt = iter->clnt;
>> +	struct rpc_task *task;
>> +
>> +	iter->pos = pos + 1;
>> +	spin_lock(&clnt->cl_lock);
>> +	list_for_each_entry(task, &clnt->cl_tasks, tk_task)
>> +		if (pos-- == 0)
>> +			return task;
>> +	return NULL;
>> +}
>> +
>> +static void *
>> +tasks_next(struct seq_file *f, void *v, loff_t *pos)
>> +{
>> +	struct rpc_clnt_iter *iter = f->private;
>> +	struct rpc_clnt *clnt = iter->clnt;
>> +	struct rpc_task *task = v;
>> +	struct list_head *next = task->tk_task.next;
>> +
>> +	++iter->pos;
>> +	++*pos;
>> +
>> +	/* If there's another task on list, return it */
>> +	if (next == &clnt->cl_tasks)
>> +		return NULL;
>> +	return list_entry(next, struct rpc_task, tk_task);
>> +}
>> +
>> +static void
>> +tasks_stop(struct seq_file *f, void *v)
>> +	__releases(&clnt->cl_lock)
>> +{
>> +	struct rpc_clnt_iter *iter = f->private;
>> +	struct rpc_clnt *clnt = iter->clnt;
>> +
>> +	spin_unlock(&clnt->cl_lock);
>> +}
>> +
>> +static const struct seq_operations tasks_seq_operations = {
>> +	.start	= tasks_start,
>> +	.next	= tasks_next,
>> +	.stop	= tasks_stop,
>> +	.show	= tasks_show,
>> +};
>> +
>> +static int tasks_open(struct inode *inode, struct file *filp)
>> +{
>> +	int ret = seq_open_private(filp, &tasks_seq_operations,
>> +					sizeof(struct rpc_clnt_iter));
>> +
>> +	if (!ret) {
>> +		struct seq_file *seq = filp->private_data;
>> +		struct rpc_clnt_iter *iter = seq->private;
>> +
>> +		iter->clnt = inode->i_private;
>> +
>> +		if (!atomic_inc_not_zero(&iter->clnt->cl_count)) {
>> +			seq_release_private(inode, filp);
>> +			ret = -EINVAL;
>> +		}
>> +	}
>> +
>> +	return ret;
>> +}
>> +
>> +static int
>> +tasks_release(struct inode *inode, struct file *filp)
>> +{
>> +	struct seq_file *seq = filp->private_data;
>> +	struct rpc_clnt_iter *iter = seq->private;
>> +
>> +	rpc_release_client(iter->clnt);
>> +	return seq_release_private(inode, filp);
>> +}
>> +
>> +static const struct file_operations tasks_fops = {
>> +	.owner		= THIS_MODULE,
>> +	.open		= tasks_open,
>> +	.read		= seq_read,
>> +	.llseek		= seq_lseek,
>> +	.release	= tasks_release,
>> +};
>> +
>> +int
>> +rpc_clnt_debugfs_register(struct rpc_clnt *clnt)
>> +{
>> +	int len;
>> +	char name[9]; /* 8 for hex digits + NULL terminator */
>> +
>> +	/* Already registered? */
>> +	if (clnt->cl_debugfs)
>> +		return 0;
>> +
>> +	len = snprintf(name, sizeof(name), "%x", clnt->cl_clid);
>> +	if (len >= sizeof(name))
>> +		return -EINVAL;
>> +
>> +	/* make the per-client dir */
>> +	clnt->cl_debugfs = debugfs_create_dir(name, rpc_clnt_dir);
>> +	if (!clnt->cl_debugfs)
>> +		return -ENOMEM;
>> +
>> +	/* make tasks file */
>> +	if (!debugfs_create_file("tasks", S_IFREG | S_IRUSR, clnt->cl_debugfs,
>> +				 clnt, &tasks_fops)) {
>> +		debugfs_remove_recursive(clnt->cl_debugfs);
>> +		clnt->cl_debugfs = NULL;
>> +		return -ENOMEM;
>> +	}
>> +
>> +	return 0;
>> +}
>> +
>> +void
>> +rpc_clnt_debugfs_unregister(struct rpc_clnt *clnt)
>> +{
>> +	debugfs_remove_recursive(clnt->cl_debugfs);
>> +	clnt->cl_debugfs = NULL;
>> +}
>> +
>> +void __exit
>> +sunrpc_debugfs_exit(void)
>> +{
>> +	debugfs_remove_recursive(topdir);
>> +}
>> +
>> +int __init
>> +sunrpc_debugfs_init(void)
>> +{
>> +	topdir = debugfs_create_dir("sunrpc", NULL);
>> +	if (!topdir)
>> +		goto out;
>> +
>> +	rpc_clnt_dir = debugfs_create_dir("rpc_clnt", topdir);
>> +	if (!rpc_clnt_dir)
>> +		goto out_remove;
>> +
>> +	return 0;
>> +out_remove:
>> +	debugfs_remove_recursive(topdir);
>> +	topdir = NULL;
>> +out:
>> +	return -ENOMEM;
>> +}
>> diff --git a/net/sunrpc/sunrpc_syms.c b/net/sunrpc/sunrpc_syms.c
>> index f632e476ab6c..e37fbed87956 100644
>> --- a/net/sunrpc/sunrpc_syms.c
>> +++ b/net/sunrpc/sunrpc_syms.c
>> @@ -97,6 +97,11 @@ init_sunrpc(void)
>>  	err = register_rpc_pipefs();
>>  	if (err)
>>  		goto out4;
>> +
>> +	err = sunrpc_debugfs_init();
>> +	if (err)
>> +		goto out5;
>> +
>>  #if IS_ENABLED(CONFIG_SUNRPC_DEBUG)
>>  	rpc_register_sysctl();
>>  #endif
>> @@ -104,6 +109,8 @@ init_sunrpc(void)
>>  	init_socket_xprt();	/* clnt sock transport */
>>  	return 0;
>>  
>> +out5:
>> +	unregister_rpc_pipefs();
>>  out4:
>>  	unregister_pernet_subsys(&sunrpc_net_ops);
>>  out3:
>> @@ -120,6 +127,7 @@ cleanup_sunrpc(void)
>>  	rpcauth_remove_module();
>>  	cleanup_socket_xprt();
>>  	svc_cleanup_xprt_sock();
>> +	sunrpc_debugfs_exit();
>>  	unregister_rpc_pipefs();
>>  	rpc_destroy_mempool();
>>  	unregister_pernet_subsys(&sunrpc_net_ops);
>>
>