Re: [PATCH] NFSD: add rpc_status entry in nfsd debug filesystem

[Jeff Layton <jlayton@kernel.org>]

On Tue, 2023-07-11 at 12:33 +0200, Lorenzo Bianconi wrote:
> > On Mon, 2023-07-10 at 18:16 +0200, Lorenzo Bianconi wrote:
> > > Introduce rpc_status entry in nfsd debug filesystem in order to dump
> > > pending RPC requests debugging information.
> > > 
> > > Link: https://bugzilla.linux-nfs.org/show_bug.cgi?id=366
> > > Signed-off-by: Lorenzo Bianconi <lorenzo@kernel.org>
> > > ---
> > > Changes since RFCv1:
> > > - riduce time holding nfsd_mutex bumping svc_serv refcoung in
> > >   nfsd_rpc_status_open()
> > > - dump rqstp->rq_stime
> > > - add missing kdoc for nfsd_rpc_status_open()
> > > ---
> > >  fs/nfsd/nfs4proc.c |  4 +--
> > >  fs/nfsd/nfsctl.c   | 10 ++++++
> > >  fs/nfsd/nfsd.h     |  2 ++
> > >  fs/nfsd/nfssvc.c   | 88 ++++++++++++++++++++++++++++++++++++++++++++++
> > >  net/sunrpc/svc.c   |  2 +-
> > >  5 files changed, 102 insertions(+), 4 deletions(-)
> > > 
> > > diff --git a/fs/nfsd/nfs4proc.c b/fs/nfsd/nfs4proc.c
> > > index 5ae670807449..a4dd1ef104c3 100644
> > > --- a/fs/nfsd/nfs4proc.c
> > > +++ b/fs/nfsd/nfs4proc.c
> > > @@ -2452,8 +2452,6 @@ static inline void nfsd4_increment_op_stats(u32 opnum)
> > >  
> > > 
> > >  static const struct nfsd4_operation nfsd4_ops[];
> > >  
> > > 
> > > -static const char *nfsd4_op_name(unsigned opnum);
> > > -
> > >  /*
> > >   * Enforce NFSv4.1 COMPOUND ordering rules:
> > >   *
> > > @@ -3583,7 +3581,7 @@ void warn_on_nonidempotent_op(struct nfsd4_op *op)
> > >  	}
> > >  }
> > >  
> > > 
> > > -static const char *nfsd4_op_name(unsigned opnum)
> > > +const char *nfsd4_op_name(unsigned opnum)
> > >  {
> > >  	if (opnum < ARRAY_SIZE(nfsd4_ops))
> > >  		return nfsd4_ops[opnum].op_name;
> > > diff --git a/fs/nfsd/nfsctl.c b/fs/nfsd/nfsctl.c
> > > index 1b8b1aab9a15..629b4296e7c6 100644
> > > --- a/fs/nfsd/nfsctl.c
> > > +++ b/fs/nfsd/nfsctl.c
> > > @@ -57,6 +57,8 @@ enum {
> > >  	NFSD_RecoveryDir,
> > >  	NFSD_V4EndGrace,
> > >  #endif
> > > +	NFSD_Rpc_Status,
> > > +
> > >  	NFSD_MaxReserved
> > >  };
> > >  
> > > 
> > > @@ -195,6 +197,13 @@ static inline struct net *netns(struct file *file)
> > >  	return file_inode(file)->i_sb->s_fs_info;
> > >  }
> > >  
> > > 
> > > +static const struct file_operations nfsd_rpc_status_operations = {
> > > +	.open		= nfsd_rpc_status_open,
> > > +	.read		= seq_read,
> > > +	.llseek		= seq_lseek,
> > > +	.release	= nfsd_pool_stats_release,
> > > +};
> > > +
> > >  /*
> > >   * write_unlock_ip - Release all locks used by a client
> > >   *
> > > @@ -1400,6 +1409,7 @@ static int nfsd_fill_super(struct super_block *sb, struct fs_context *fc)
> > >  		[NFSD_RecoveryDir] = {"nfsv4recoverydir", &transaction_ops, S_IWUSR|S_IRUSR},
> > >  		[NFSD_V4EndGrace] = {"v4_end_grace", &transaction_ops, S_IWUSR|S_IRUGO},
> > >  #endif
> > > +		[NFSD_Rpc_Status] = {"rpc_status", &nfsd_rpc_status_operations, S_IRUGO},
> > >  		/* last one */ {""}
> > >  	};
> > >  
> > > 
> > > diff --git a/fs/nfsd/nfsd.h b/fs/nfsd/nfsd.h
> > > index d88498f8b275..75a3e1d55bc8 100644
> > > --- a/fs/nfsd/nfsd.h
> > > +++ b/fs/nfsd/nfsd.h
> > > @@ -94,6 +94,7 @@ int		nfsd_get_nrthreads(int n, int *, struct net *);
> > >  int		nfsd_set_nrthreads(int n, int *, struct net *);
> > >  int		nfsd_pool_stats_open(struct inode *, struct file *);
> > >  int		nfsd_pool_stats_release(struct inode *, struct file *);
> > > +int		nfsd_rpc_status_open(struct inode *inode, struct file *file);
> > >  void		nfsd_shutdown_threads(struct net *net);
> > >  
> > > 
> > >  void		nfsd_put(struct net *net);
> > > @@ -506,6 +507,7 @@ extern void nfsd4_ssc_init_umount_work(struct nfsd_net *nn);
> > >  
> > > 
> > >  extern void nfsd4_init_leases_net(struct nfsd_net *nn);
> > >  
> > > 
> > > +const char *nfsd4_op_name(unsigned opnum);
> > >  #else /* CONFIG_NFSD_V4 */
> > >  static inline int nfsd4_is_junction(struct dentry *dentry)
> > >  {
> > > diff --git a/fs/nfsd/nfssvc.c b/fs/nfsd/nfssvc.c
> > > index 2154fa63c5f2..ef1eb8b1c5bf 100644
> > > --- a/fs/nfsd/nfssvc.c
> > > +++ b/fs/nfsd/nfssvc.c
> > > @@ -1147,3 +1147,91 @@ int nfsd_pool_stats_release(struct inode *inode, struct file *file)
> > >  	mutex_unlock(&nfsd_mutex);
> > >  	return ret;
> > >  }
> > > +
> > > +static int nfsd_rpc_status_show(struct seq_file *m, void *v)
> > > +{
> > > +	struct inode *inode = file_inode(m->file);
> > > +	struct nfsd_net *nn = net_generic(inode->i_sb->s_fs_info, nfsd_net_id);
> > > +	int i;
> > > +
> > > +	rcu_read_lock();
> > > +
> > 
> > Much nicer without all of the heavyweight locking, I think!
> > 
> > > +	for (i = 0; i < nn->nfsd_serv->sv_nrpools; i++) {
> > > +		struct svc_rqst *rqstp;
> > > +
> > > +		seq_puts(m, "XID        | FLAGS      | PROG       |");
> > > +		seq_puts(m, " VERS       | PROC\t| TS(us)\t   |");
> > > +		seq_puts(m, " REMOTE - LOCAL IP ADDR");
> > > +		seq_puts(m, "\t\t\t\t\t\t\t\t   | NFS4 COMPOUND OPS\n");
> > 
> > It may be best to just eliminate the header, or at the very least, only
> > print it once by moving it outside of the for loop.
> > 
> > > +		list_for_each_entry_rcu(rqstp,
> > > +				&nn->nfsd_serv->sv_pools[i].sp_all_threads,
> > > +				rq_all) {
> > > +			if (!test_bit(RQ_BUSY, &rqstp->rq_flags))
> > > +				continue;
> > > +
> > > +			seq_printf(m,
> > > +				   "0x%08x | 0x%08lx | 0x%08x | NFSv%d      |"
> > > +				   " %s\t| %016lld |",
> > 
> > I'd definitely get rid of the '|' delimiters. I think that it'd be best
> > to just separate the fields by single spaces, as that will be simpler
> > for scripts to parse. There are plenty of examples in the kernel that do
> > that (/proc/locks, /proc/self/mountstats, etc.).
> > 
> > We can always write a simple shell or python script for nfs-utils that
> > parses and pretty-prints the fields.
> 
> Hi Jeff,
> 
> based on your comments above, I wrote the following simple python parser:
> 
> #!/usr/bin/env python3
> 
> if __name__ == '__main__':
>     with open('/proc/fs/nfsd/rpc_status', 'r') as f:
>         for l in f.readlines():
>             e = l.split()
> 
>             if len(e) < 8:
>                 continue
> 
>             print('connection\t: ' + e[6] + ' -> ' + e[7])
>             print('   xid\t\t: ' + e[0])
>             print('   flags\t: ' + e[1])
>             print('   program\t: ' + e[2])
>             print('   version\t: ' + e[3])
>             print('   proc\t\t: ' + e[4])
>             print('   time (us)\t: ' + e[5])
> 
>             if len(e) > 8:
>                 print('   compound ops\t: ' + " ".join(e[8:]))
> 
> 
> The output would be the following:
> 
> connection	: 192.168.122.1 -> 192.168.122.76
>    xid		: 0x00000000
>    flags	: 0x00000015
>    program	: 0x000186a3
>    version	: NFSv4
>    proc		: COMPOUND
>    time (us)	: 0000000449790533
> 
> 
> Is it something similar to what you mean?
> 
> Regards,
> Lorenzo
> 
> 

Yeah, something like that would be fine. Probably you'd want to spin
this up as a patch that adds this to the nfs-utils project. Most
userland nfs-related utilities are part of that package.
-- 
Jeff Layton <jlayton@kernel.org>