Chuck's iostat patch
Subsystems (4)
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
@@ -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
@@ -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
@@ -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
@@ -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
@@ -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
@@ -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
@@ -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
@@ -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
@@ -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
@@ -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 *clntdprintk ("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
@@ -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
@@ -25,6 +25,7 @@#define RPCDBG_FACILITY RPCDBG_MISCstruct 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 @@ voidrpc_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