Skip to contentSkip to conversation

Chuck's iostat patch

PATCH Olaf Kirch 1 participant 1 message Mar 8, 2004

Subsystems (4)
lore
Share & tools
lore

Olaf Kirch

author
#0 lore raw

Hi Chuck, hi all,

I took Chuck's iostat patch and played with it a little. Attached you can find the results of this playing around.

This patch changes Chuck's work in two ways - one, all iostat sampling happens in the RPC layer now, rather than having to add "nfs_count_call" to every NFS function. This changes some things, e.g. the way in/out bytes are counted. Chuck's patch counts the payload bytes of a read/write request only, while my approach includes the RPC overhead.

Second, I ported it to 2.6, and made it use a seqfile for reading the proc file.

There is still the open question whether the proc file interface to retrieving and zapping the iostat counters is appropriate. It's probably not too hard to extend this stuff to have a timer printk the iostat values every second or so - the question is do we really want this, or isn't the procfs approach sufficient?

Comments?

Olaf

Signature · 3 lines
Olaf Kirch     |  Stop wasting entropy - start using predictable
[email protected]   |  tempfile names today!
---------------+ 
fs/Kconfig +24 -0
diff -X excl -purNa linux-2.6.3-iostat/fs/Kconfig linux-2.6.3/fs/Kconfig
@@ -1543,6 +1543,30 @@ config RPCSEC_GSS_KRB5
 	  Note: If you select this option, please ensure that you also
 	  enable the MD5 and DES crypto ciphers.
 
+config SUNRPC_IOSTATS
+	bool "Per-client I/O statistics (EXPERIMENTAL)"
+	depends on SUNRPC && EXPERIMENTAL && PROC_FS
+	help
+	  When this option is enabled, user-level tools can access I/O
+	  statistics for each NFS mount point via /proc.  The NFS client
+	  creates a tree of files under /proc/net/rpc/iostat that contain
+	  statistics on NFS read and write operations such as how many
+	  reads and writes have occurred, how long the NFS client has
+	  waited for them to complete (in total), and how many bytes have
+	  been read or written.  There is one such file for each mounted
+	  NFS file system.  The counters in each file can be zeroed at
+	  any time by writing to that file as root.
+
+	  Note that on SMP systems, the total I/O wait time includes the
+	  time the process had to wait for the big kernel lock before it
+	  could schedule the RPC for that I/O.  At this time the wait
+	  time is measured in microseconds.
+
+	  To use tools like iostat or sar to monitor your NFS client,
+	  you must enable this option by saying Y.  Saying N will result
+	  in an ever-so-slightly smaller and ever-so-slightly less
+	  CPU-intensive NFS client.
+
 config SMB_FS
 	tristate "SMB file system support (to mount Windows shares etc.)"
 	depends on INET
fs/nfs/inode.c +22 -0
diff -X excl -purNa linux-2.6.3-iostat/fs/nfs/inode.c linux-2.6.3/fs/nfs/inode.c
@@ -119,6 +119,22 @@ struct rpc_program		nfsacl_program = {
 };
 #endif  /* CONFIG_NFS_ACL */
 
+/*
+ * Names for iostat buckets
+ */
+static const char	*nfs_iostat_names[nfs_count_max] = {
+	[nfs_count_other]	= "other",
+	[nfs_count_read]	= "read",
+	[nfs_count_write]	= "write",
+	[nfs_count_commit]	= "commit",
+	[nfs_count_getattr]	= "getattr",
+	[nfs_count_lookup]	= "lookup",
+	[nfs_count_readdir]	= "readdir",
+	[nfs_count_symlink]	= "symlink",
+	[nfs_count_readlink]	= "readlink",
+	[nfs_count_remove]	= "remove",
+};
+
 static inline unsigned long
 nfs_fattr_to_ino_t(struct nfs_fattr *fattr)
 {
@@ -440,6 +456,12 @@ __nfs_create_client(struct nfs_server *s
 	clnt->cl_droppriv = (server->flags & NFS_MOUNT_BROKEN_SUID) ? 1 : 0;
 	clnt->cl_chatty   = 1;
 
+#ifdef CONFIG_SUNRPC_IOSTATS
+	/* For now, enable iostat unconditionally.
+	 * Not sure if we should have a sysctl to control this */
+	rpc_enable_iostats(clnt, nfs_count_max, nfs_iostat_names);
+#endif
+
 	return clnt;
 
 out_fail:
fs/nfs/nfs2xdr.c +18 -17
diff -X excl -purNa linux-2.6.3-iostat/fs/nfs/nfs2xdr.c linux-2.6.3/fs/nfs/nfs2xdr.c
@@ -651,30 +651,31 @@ nfs_stat_to_errno(int stat)
 # define MAX(a, b)	(((a) > (b))? (a) : (b))
 #endif
 
-#define PROC(proc, argtype, restype, timer)				\
+#define PROC(proc, argtype, restype, timer, op)				\
 [NFSPROC_##proc] = {							\
 	.p_proc	    =  NFSPROC_##proc,					\
 	.p_encode   =  (kxdrproc_t) nfs_xdr_##argtype,			\
 	.p_decode   =  (kxdrproc_t) nfs_xdr_##restype,			\
 	.p_bufsiz   =  MAX(NFS_##argtype##_sz,NFS_##restype##_sz) << 2,	\
-	.p_timer    =  timer						\
+	.p_timer    =  timer,						\
+	.p_metrics  =  nfs_count_##op					\
 	}
 struct rpc_procinfo	nfs_procedures[] = {
-    PROC(GETATTR,	fhandle,	attrstat, 1),
-    PROC(SETATTR,	sattrargs,	attrstat, 0),
-    PROC(LOOKUP,	diropargs,	diropres, 2),
-    PROC(READLINK,	readlinkargs,	readlinkres, 3),
-    PROC(READ,		readargs,	readres, 3),
-    PROC(WRITE,		writeargs,	writeres, 4),
-    PROC(CREATE,	createargs,	diropres, 0),
-    PROC(REMOVE,	diropargs,	stat, 0),
-    PROC(RENAME,	renameargs,	stat, 0),
-    PROC(LINK,		linkargs,	stat, 0),
-    PROC(SYMLINK,	symlinkargs,	stat, 0),
-    PROC(MKDIR,		createargs,	diropres, 0),
-    PROC(RMDIR,		diropargs,	stat, 0),
-    PROC(READDIR,	readdirargs,	readdirres, 3),
-    PROC(STATFS,	fhandle,	statfsres, 0),
+    PROC(GETATTR,	fhandle,	attrstat, 1, getattr),
+    PROC(SETATTR,	sattrargs,	attrstat, 0, other),
+    PROC(LOOKUP,	diropargs,	diropres, 2, lookup),
+    PROC(READLINK,	readlinkargs,	readlinkres, 3, readlink),
+    PROC(READ,		readargs,	readres, 3, read),
+    PROC(WRITE,		writeargs,	writeres, 4, write),
+    PROC(CREATE,	createargs,	diropres, 0, other),
+    PROC(REMOVE,	diropargs,	stat, 0, remove),
+    PROC(RENAME,	renameargs,	stat, 0, other),
+    PROC(LINK,		linkargs,	stat, 0, other),
+    PROC(SYMLINK,	symlinkargs,	stat, 0, symlink),
+    PROC(MKDIR,		createargs,	diropres, 0, other),
+    PROC(RMDIR,		diropargs,	stat, 0, other),
+    PROC(READDIR,	readdirargs,	readdirres, 3, readdir),
+    PROC(STATFS,	fhandle,	statfsres, 0, other),
 };
 
 struct rpc_version		nfs_version2 = {
fs/nfs/nfs3xdr.c +24 -23

61 lines not on this page · raw message

include/linux/nfs_fs_sb.h +16 -0
diff -X excl -purNa linux-2.6.3-iostat/include/linux/nfs_fs_sb.h linux-2.6.3/include/linux/nfs_fs_sb.h
@@ -44,6 +44,22 @@ struct nfs_server {
 #endif
 };
 
+/* iostat counters */
+enum {
+	nfs_count_other = 0,
+	nfs_count_read,
+	nfs_count_write,
+	nfs_count_commit,
+	nfs_count_getattr,
+	nfs_count_lookup,
+	nfs_count_readdir,
+	nfs_count_symlink,
+	nfs_count_readlink,
+	nfs_count_remove,
+
+	nfs_count_max,
+};
+
 /* Server capabilities */
 #define NFS_CAP_READDIRPLUS	(1)
 
include/linux/sunrpc/clnt.h +8 -0
diff -X excl -purNa linux-2.6.3-iostat/include/linux/sunrpc/clnt.h linux-2.6.3/include/linux/sunrpc/clnt.h
@@ -66,6 +66,11 @@ struct rpc_clnt {
 	struct rpc_rtt		cl_rtt_default;
 	struct rpc_portmap	cl_pmap_default;
 	char			cl_inline_name[32];
+
+	/* NFS iostat support */
+#ifdef CONFIG_SUNRPC_IOSTATS
+	struct rpc_iostat *	cl_iostat;
+#endif
 };
 #define cl_timeout		cl_xprt->timeout
 #define cl_prog			cl_pmap->pm_prog
@@ -102,6 +107,7 @@ struct rpc_procinfo {
 	unsigned int		p_bufsiz;	/* req. buffer size */
 	unsigned int		p_count;	/* call count */
 	unsigned int		p_timer;	/* Which RTT timer to use */
+	unsigned int		p_metrics;	/* iostat */
 };
 
 #define RPC_CONGESTED(clnt)	(RPCXPRT_CONGESTED((clnt)->cl_xprt))
@@ -130,6 +136,8 @@ void		rpc_clnt_sigmask(struct rpc_clnt *
 void		rpc_clnt_sigunmask(struct rpc_clnt *clnt, sigset_t *oldset);
 void		rpc_setbufsize(struct rpc_clnt *, unsigned int, unsigned int);
 
+void		rpc_init_iostat(struct rpc_clnt *clnt, unsigned int num_ops);
+
 static __inline__
 int rpc_call(struct rpc_clnt *clnt, u32 proc, void *argp, void *resp, int flags)
 {
include/linux/sunrpc/metrics.h +83 -0

83 lines not on this page · raw message

include/linux/sunrpc/sched.h +8 -0
diff -X excl -purNa linux-2.6.3-iostat/include/linux/sunrpc/sched.h linux-2.6.3/include/linux/sunrpc/sched.h
@@ -13,6 +13,7 @@
 #include <linux/sunrpc/types.h>
 #include <linux/wait.h>
 #include <linux/sunrpc/xdr.h>
+#include <linux/sunrpc/metrics.h>
 
 /*
  * This is the actual RPC procedure call info.
@@ -73,6 +74,13 @@ struct rpc_task {
 	unsigned short		tk_flags;	/* misc flags */
 	unsigned char		tk_active   : 1;/* Task has been activated */
 	unsigned long		tk_runstate;	/* Task run status */
+
+	/* IO stats support */
+#ifdef CONFIG_SUNRPC_IOSTATS
+	struct timeval		tk_inittime;
+	struct rpc_metrics	tk_metrics;
+#endif
+
 #ifdef RPC_DEBUG
 	unsigned short		tk_pid;		/* debugging aid */
 #endif
include/linux/sunrpc/stats.h +1 -0
diff -X excl -purNa linux-2.6.3-iostat/include/linux/sunrpc/stats.h linux-2.6.3/include/linux/sunrpc/stats.h
@@ -57,6 +57,7 @@ void			svc_seq_show(struct seq_file *,
 				     const struct svc_stat *);
 
 extern struct proc_dir_entry	*proc_net_rpc;
+extern struct proc_dir_entry	*proc_net_rpc_iostat;
 
 #else
 
include/linux/sunrpc/xprt.h +11 -0
diff -X excl -purNa linux-2.6.3-iostat/include/linux/sunrpc/xprt.h linux-2.6.3/include/linux/sunrpc/xprt.h
@@ -117,6 +117,7 @@ struct rpc_rqst {
 	u32			rq_bytes_sent;	/* Bytes we have sent */
 
 	unsigned long		rq_xtime;	/* when transmitted */
+	struct timeval		rq_xmittime;
 	int			rq_ntimeo;
 	int			rq_ntrans;
 };
@@ -150,6 +151,7 @@ struct rpc_xprt {
 	struct rpc_wait_queue	backlog;	/* waiting for slot */
 	struct rpc_rqst *	free;		/* free slots */
 	unsigned int		max_reqs;	/* total slots */
+	unsigned int		slots_inuse;
 	unsigned long		sockstate;	/* Socket state */
 	unsigned char		shutdown   : 1,	/* being shut down */
 				nocong	   : 1,	/* no congestion control */
@@ -178,6 +180,15 @@ struct rpc_xprt {
 	spinlock_t		sock_lock;	/* lock socket info */
 	spinlock_t		xprt_lock;	/* lock xprt info */
 	struct rpc_task *	snd_task;	/* Task blocked in send */
+	unsigned int		sndq_len;	/* length of send queue */
+
+	struct timeval		connectstart;
+	unsigned long long	connectwait;	/* total connect wait time */
+	unsigned long		connects;	/* total count of connects */
+	struct timeval		idlestart;
+	unsigned long		idle_secs;	/* total idle time */
+	unsigned long		major_timeouts;	/* total major timeouts */
+	unsigned int		backlog_len;	/* length of backlog queue */
 
 	struct list_head	recv;
 
net/sunrpc/Makefile +1 -0
diff -X excl -purNa linux-2.6.3-iostat/net/sunrpc/Makefile linux-2.6.3/net/sunrpc/Makefile
@@ -13,3 +13,4 @@ sunrpc-y := clnt.o xprt.o sched.o \
 	    sunrpc_syms.o cache.o rpc_pipe.o
 sunrpc-$(CONFIG_PROC_FS) += stats.o
 sunrpc-$(CONFIG_SYSCTL) += sysctl.o
+sunrpc-$(CONFIG_SUNRPC_IOSTATS) += iostats.o
net/sunrpc/clnt.c +4 -1
diff -X excl -purNa linux-2.6.3-iostat/net/sunrpc/clnt.c linux-2.6.3/net/sunrpc/clnt.c
@@ -198,6 +198,7 @@ rpc_clone_client(struct rpc_clnt *clnt)
 	atomic_inc(&new->cl_parent->cl_count);
 	if (new->cl_auth)
 		atomic_inc(&new->cl_auth->au_count);
+	new->cl_iostat = NULL;
 out:
 	return new;
 out_no_clnt:
@@ -250,6 +251,7 @@ rpc_destroy_client(struct rpc_clnt *clnt
 
 	dprintk("RPC: destroying %s client for %s\n",
 			clnt->cl_protname, clnt->cl_server);
+	rpc_disable_iostats(clnt);
 	if (clnt->cl_auth) {
 		rpcauth_destroy(clnt->cl_auth);
 		clnt->cl_auth = NULL;
@@ -362,7 +364,7 @@ int rpc_call_sync(struct rpc_clnt *clnt,
 		rpc_release_task(task);
 	}
 
-	rpc_clnt_sigunmask(clnt, &oldset);		
+	rpc_clnt_sigunmask(clnt, &oldset);
 
 	return status;
 }
@@ -795,6 +797,7 @@ call_timeout(struct rpc_task *task)
 	to->to_retries = clnt->cl_timeout.to_retries;
 
 	dprintk("RPC: %4d call_timeout (major)\n", task->tk_pid);
+	clnt->cl_xprt->major_timeouts++;
 	if (RPC_IS_SOFT(task)) {
 		if (clnt->cl_chatty)
 			printk(KERN_NOTICE "%s: server %s not responding, timed out\n",
net/sunrpc/iostats.c +322 -0

322 lines not on this page · raw message

net/sunrpc/sched.c +19 -0
diff -X excl -purNa linux-2.6.3-iostat/net/sunrpc/sched.c linux-2.6.3/net/sunrpc/sched.c
@@ -540,6 +540,10 @@ __rpc_execute(struct rpc_task *task)
 			rpc_set_sleeping(task);
 			if (RPC_IS_ASYNC(task)) {
 				spin_unlock_bh(&rpc_queue_lock);
+#ifdef CONFIG_SUNRPC_IOSTATS
+				task->tk_metrics.rm_execute =
+					rpc_calc_latency(&task->tk_inittime);
+#endif
 				return 0;
 			}
 		}
@@ -577,11 +581,18 @@ __rpc_execute(struct rpc_task *task)
 		}
 	}
 
+#ifdef CONFIG_SUNRPC_IOSTATS
+	task->tk_metrics.rm_execute = rpc_calc_latency(&task->tk_inittime);
+#endif
 	if (task->tk_exit) {
 		task->tk_exit(task);
 		/* If tk_action is non-null, the user wants us to restart */
 		if (task->tk_action) {
 			if (!RPC_ASSASSINATED(task)) {
+#ifdef CONFIG_SUNRPC_IOSTATS
+				if (task->tk_client && task->tk_client->cl_iostat)
+					rpc_update_iostat(task->tk_client->cl_iostat, task);
+#endif
 				/* Release RPC slot and buffer memory */
 				if (task->tk_rqstp)
 					xprt_release(task);
@@ -592,6 +603,11 @@ __rpc_execute(struct rpc_task *task)
 		}
 	}
 
+#ifdef CONFIG_SUNRPC_IOSTATS
+	if (task->tk_client && task->tk_client->cl_iostat)
+		rpc_update_iostat(task->tk_client->cl_iostat, task);
+#endif
+
 	dprintk("RPC: %4d exit() = %d\n", task->tk_pid, task->tk_status);
 	status = task->tk_status;
 
@@ -625,6 +641,9 @@ rpc_execute(struct rpc_task *task)
 		goto out_err;
 	}
 
+#ifdef CONFIG_SUNRPC_IOSTATS
+	do_gettimeofday(&task->tk_inittime);
+#endif
 	task->tk_active = 1;
 	rpc_set_running(task);
 	return __rpc_execute(task);
net/sunrpc/stats.c +15 -0
diff -X excl -purNa linux-2.6.3-iostat/net/sunrpc/stats.c linux-2.6.3/net/sunrpc/stats.c
@@ -25,6 +25,7 @@
 #define RPCDBG_FACILITY	RPCDBG_MISC
 
 struct proc_dir_entry	*proc_net_rpc = NULL;
+struct proc_dir_entry	*proc_net_rpc_iostat = NULL;
 
 /*
  * Get RPC client stats
@@ -160,6 +161,14 @@ rpc_proc_init(void)
 			ent->owner = THIS_MODULE;
 			proc_net_rpc = ent;
 		}
+
+#ifdef CONFIG_SUNRPC_IOSTATS
+		ent = proc_mkdir("iostat", proc_net_rpc);
+		if (ent) {
+			ent->owner = THIS_MODULE;
+			proc_net_rpc_iostat = ent;
+		}
+#endif
 	}
 }
 
@@ -167,6 +176,12 @@ void
 rpc_proc_exit(void)
 {
 	dprintk("RPC: unregistering /proc/net/rpc\n");
+#ifdef CONFIG_SUNRPC_IOSTATS
+	if (proc_net_rpc_iostat) {
+		proc_net_rpc_iostat = NULL;
+		remove_proc_entry("iostat", proc_net_rpc);
+	}
+#endif
 	if (proc_net_rpc) {
 		proc_net_rpc = NULL;
 		remove_proc_entry("net/rpc", 0);
net/sunrpc/xprt.c +47 -6

131 lines not on this page · raw message