* [PATCH v4 00/21] NFS add tracepoints (final version) @ 2013-08-22 0:23 Trond Myklebust 2013-08-22 0:23 ` [PATCH v4 01/21] NFS: refactor code for calculating the crc32 hash of a filehandle Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:23 UTC (permalink / raw) To: linux-nfs The following patchset sets up a number of ftrace tracepoints for use when debugging NFSv4 state operations and NFS performance issues. Changes in v2: - Fixed compile bugs - We need to convert the delegation recall status to a negative number - Added tracepoints for read/write, pnfs and slot table debugging. Changes in v3: - Added tracepoints for generic NFS code - lookups - atomic open - inode cache consistency operations - internal fsync and data flush operations - Assorted cleanups and bugfixes Changes in v4: - Fix the include file bug - Add more tracepoints for the generic NFS code - rename and sillyrename - generic directory related changes (file create/mknod/mkdir/rmdir/...) - Add debugging for NFSv4 free stateid events Trond Myklebust (21): NFS: refactor code for calculating the crc32 hash of a filehandle NFS: Add event tracing for generic NFS events NFS: Pass in lookup flags from nfs_atomic_open to nfs_lookup NFS: Add event tracing for generic NFS lookups NFS: Add tracepoints for debugging generic file create events NFS: Add tracepoints for debugging directory changes NFS: Add tracepoints for debugging NFS rename and sillyrename issues NFS: Add tracepoints for debugging NFS hard links NFSv4: Add tracepoints for debugging state management problems NFSv4: Add tracepoints for debugging file open NFSv4: Add tracepoints for debugging file locking NFSv4: Add tracepoints for debugging lookup/create operations NFSv4: Add tracepoints for debugging inode manipulations NFSv4: Add tracepoints for debugging rename NFSv4: Add tracepoints for debugging delegations NFSv4: Add tracepoints for debugging the idmapper NFSv4: Add tracepoints for debugging getattr NFSv4: Add tracepoints for debugging reads and writes NFSv4.1: Add tracepoints for debugging layoutget/return/commit NFSv4.1: Add tracepoints for debugging slot table operations NFSv4.1: Add tracepoints for debugging test_stateid events fs/nfs/Makefile | 7 +- fs/nfs/callback_proc.c | 3 + fs/nfs/delegation.c | 3 + fs/nfs/dir.c | 49 +- fs/nfs/file.c | 5 + fs/nfs/idmap.c | 5 + fs/nfs/inode.c | 32 +- fs/nfs/internal.h | 20 + fs/nfs/nfs4filelayout.c | 4 + fs/nfs/nfs4proc.c | 130 ++++-- fs/nfs/nfs4session.h | 10 + fs/nfs/nfs4trace.c | 17 + fs/nfs/nfs4trace.h | 1148 +++++++++++++++++++++++++++++++++++++++++++++++ fs/nfs/nfstrace.c | 9 + fs/nfs/nfstrace.h | 729 ++++++++++++++++++++++++++++++ fs/nfs/pnfs.c | 3 + fs/nfs/unlink.c | 5 + fs/nfs/write.c | 15 +- 18 files changed, 2142 insertions(+), 52 deletions(-) create mode 100644 fs/nfs/nfs4trace.c create mode 100644 fs/nfs/nfs4trace.h create mode 100644 fs/nfs/nfstrace.c create mode 100644 fs/nfs/nfstrace.h -- 1.8.3.1 ^ permalink raw reply [flat|nested] 22+ messages in thread
* [PATCH v4 01/21] NFS: refactor code for calculating the crc32 hash of a filehandle 2013-08-22 0:23 [PATCH v4 00/21] NFS add tracepoints (final version) Trond Myklebust @ 2013-08-22 0:23 ` Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 02/21] NFS: Add event tracing for generic NFS events Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:23 UTC (permalink / raw) To: linux-nfs We want to be able to display the crc32 hash of the filehandle in tracepoints. Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/inode.c | 3 +-- fs/nfs/internal.h | 20 ++++++++++++++++++++ 2 files changed, 21 insertions(+), 2 deletions(-) diff --git a/fs/nfs/inode.c b/fs/nfs/inode.c index af6e806..9a98b04 100644 --- a/fs/nfs/inode.c +++ b/fs/nfs/inode.c @@ -38,7 +38,6 @@ #include <linux/slab.h> #include <linux/compat.h> #include <linux/freezer.h> -#include <linux/crc32.h> #include <asm/uaccess.h> @@ -1190,7 +1189,7 @@ u32 _nfs_display_fhandle_hash(const struct nfs_fh *fh) { /* wireshark uses 32-bit AUTODIN crc and does a bitwise * not on the result */ - return ~crc32(0xFFFFFFFF, &fh->data[0], fh->size); + return nfs_fhandle_hash(fh); } /* diff --git a/fs/nfs/internal.h b/fs/nfs/internal.h index 9b694f1..50f7068 100644 --- a/fs/nfs/internal.h +++ b/fs/nfs/internal.h @@ -5,6 +5,7 @@ #include "nfs4_fs.h" #include <linux/mount.h> #include <linux/security.h> +#include <linux/crc32.h> #define NFS_MS_MASK (MS_RDONLY|MS_NOSUID|MS_NODEV|MS_NOEXEC|MS_SYNCHRONOUS) @@ -574,3 +575,22 @@ u64 nfs_timespec_to_change_attr(const struct timespec *ts) { return ((u64)ts->tv_sec << 30) + ts->tv_nsec; } + +#ifdef CONFIG_CRC32 +/** + * nfs_fhandle_hash - calculate the crc32 hash for the filehandle + * @fh - pointer to filehandle + * + * returns a crc32 hash for the filehandle that is compatible with + * the one displayed by "wireshark". + */ +static inline u32 nfs_fhandle_hash(const struct nfs_fh *fh) +{ + return ~crc32_le(0xFFFFFFFF, &fh->data[0], fh->size); +} +#else +static inline u32 nfs_fhandle_hash(const struct nfs_fh *fh) +{ + return 0; +} +#endif -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
* [PATCH v4 02/21] NFS: Add event tracing for generic NFS events 2013-08-22 0:23 ` [PATCH v4 01/21] NFS: refactor code for calculating the crc32 hash of a filehandle Trond Myklebust @ 2013-08-22 0:24 ` Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 03/21] NFS: Pass in lookup flags from nfs_atomic_open to nfs_lookup Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:24 UTC (permalink / raw) To: linux-nfs Add tracepoints for inode attribute updates, attribute revalidation, writeback start/end fsync start/end, attribute change start/end, permission check start/end. The intention is to enable performance tracing using 'perf'as well as improving debugging. Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/Makefile | 3 +- fs/nfs/dir.c | 16 ++++-- fs/nfs/file.c | 5 ++ fs/nfs/inode.c | 29 +++++++++- fs/nfs/nfstrace.c | 8 +++ fs/nfs/nfstrace.h | 166 ++++++++++++++++++++++++++++++++++++++++++++++++++++++ fs/nfs/write.c | 15 ++++- 7 files changed, 231 insertions(+), 11 deletions(-) create mode 100644 fs/nfs/nfstrace.c create mode 100644 fs/nfs/nfstrace.h diff --git a/fs/nfs/Makefile b/fs/nfs/Makefile index e0bb048..6bd483b 100644 --- a/fs/nfs/Makefile +++ b/fs/nfs/Makefile @@ -4,9 +4,10 @@ obj-$(CONFIG_NFS_FS) += nfs.o +CFLAGS_nfstrace.o += -I$(src) nfs-y := client.o dir.o file.o getroot.o inode.o super.o \ direct.o pagelist.o read.o symlink.o unlink.o \ - write.o namespace.o mount_clnt.o + write.o namespace.o mount_clnt.o nfstrace.o nfs-$(CONFIG_ROOT_NFS) += nfsroot.o nfs-$(CONFIG_SYSCTL) += sysctl.o nfs-$(CONFIG_NFS_FSCACHE) += fscache.o fscache-index.o diff --git a/fs/nfs/dir.c b/fs/nfs/dir.c index 5d737bd..be3da6f 100644 --- a/fs/nfs/dir.c +++ b/fs/nfs/dir.c @@ -43,6 +43,8 @@ #include "internal.h" #include "fscache.h" +#include "nfstrace.h" + /* #define NFS_DEBUG_VERBOSE 1 */ static int nfs_opendir(struct inode *, struct file *); @@ -2178,9 +2180,11 @@ static int nfs_do_access(struct inode *inode, struct rpc_cred *cred, int mask) struct nfs_access_entry cache; int status; + trace_nfs_access_enter(inode); + status = nfs_access_get_cached(inode, cred, &cache); if (status == 0) - goto out; + goto out_cached; /* Be clever: ask server to check for all possible rights */ cache.mask = MAY_EXEC | MAY_WRITE | MAY_READ; @@ -2193,13 +2197,15 @@ static int nfs_do_access(struct inode *inode, struct rpc_cred *cred, int mask) if (!S_ISDIR(inode->i_mode)) set_bit(NFS_INO_STALE, &NFS_I(inode)->flags); } - return status; + goto out; } nfs_access_add_cache(inode, &cache); +out_cached: + if ((mask & ~cache.mask & (MAY_READ | MAY_WRITE | MAY_EXEC)) != 0) + status = -EACCES; out: - if ((mask & ~cache.mask & (MAY_READ | MAY_WRITE | MAY_EXEC)) == 0) - return 0; - return -EACCES; + trace_nfs_access_exit(inode, status); + return status; } static int nfs_open_permission_mask(int openflags) diff --git a/fs/nfs/file.c b/fs/nfs/file.c index 94e94bd..d6a9db0 100644 --- a/fs/nfs/file.c +++ b/fs/nfs/file.c @@ -37,6 +37,8 @@ #include "iostat.h" #include "fscache.h" +#include "nfstrace.h" + #define NFSDBG_FACILITY NFSDBG_FILE static const struct vm_operations_struct nfs_file_vm_ops; @@ -294,6 +296,8 @@ nfs_file_fsync(struct file *file, loff_t start, loff_t end, int datasync) int ret; struct inode *inode = file_inode(file); + trace_nfs_fsync_enter(inode); + do { ret = filemap_write_and_wait_range(inode->i_mapping, start, end); if (ret != 0) @@ -310,6 +314,7 @@ nfs_file_fsync(struct file *file, loff_t start, loff_t end, int datasync) end = LLONG_MAX; } while (ret == -EAGAIN); + trace_nfs_fsync_exit(inode, ret); return ret; } diff --git a/fs/nfs/inode.c b/fs/nfs/inode.c index 9a98b04..4bcb00a 100644 --- a/fs/nfs/inode.c +++ b/fs/nfs/inode.c @@ -51,6 +51,8 @@ #include "nfs.h" #include "netns.h" +#include "nfstrace.h" + #define NFSDBG_FACILITY NFSDBG_VFS #define NFS_64_BIT_INODE_NUMBERS_ENABLED 1 @@ -503,6 +505,8 @@ nfs_setattr(struct dentry *dentry, struct iattr *attr) if ((attr->ia_valid & ~(ATTR_FILE|ATTR_OPEN)) == 0) return 0; + trace_nfs_setattr_enter(inode); + /* Write all dirty data */ if (S_ISREG(inode->i_mode)) { nfs_inode_dio_wait(inode); @@ -522,6 +526,7 @@ nfs_setattr(struct dentry *dentry, struct iattr *attr) error = nfs_refresh_inode(inode, fattr); nfs_free_fattr(fattr); out: + trace_nfs_setattr_exit(inode, error); return error; } EXPORT_SYMBOL_GPL(nfs_setattr); @@ -591,6 +596,7 @@ int nfs_getattr(struct vfsmount *mnt, struct dentry *dentry, struct kstat *stat) int need_atime = NFS_I(inode)->cache_validity & NFS_INO_INVALID_ATIME; int err; + trace_nfs_getattr_enter(inode); /* Flush out writes to the server in order to update c/mtime. */ if (S_ISREG(inode->i_mode)) { nfs_inode_dio_wait(inode); @@ -621,6 +627,7 @@ int nfs_getattr(struct vfsmount *mnt, struct dentry *dentry, struct kstat *stat) stat->ino = nfs_compat_user_ino64(NFS_FILEID(inode)); } out: + trace_nfs_getattr_exit(inode, err); return err; } EXPORT_SYMBOL_GPL(nfs_getattr); @@ -875,6 +882,8 @@ __nfs_revalidate_inode(struct nfs_server *server, struct inode *inode) dfprintk(PAGECACHE, "NFS: revalidating (%s/%Ld)\n", inode->i_sb->s_id, (long long)NFS_FILEID(inode)); + trace_nfs_revalidate_inode_enter(inode); + if (is_bad_inode(inode)) goto out; if (NFS_STALE(inode)) @@ -925,6 +934,7 @@ err_out: nfs4_label_free(label); out: nfs_free_fattr(fattr); + trace_nfs_revalidate_inode_exit(inode, status); return status; } @@ -975,6 +985,7 @@ static int nfs_invalidate_mapping(struct inode *inode, struct address_space *map spin_unlock(&inode->i_lock); nfs_inc_stats(inode, NFSIOS_DATAINVALIDATE); nfs_fscache_wait_on_invalidate(inode); + dfprintk(PAGECACHE, "NFS: (%s/%Ld) data cache invalidated\n", inode->i_sb->s_id, (long long)NFS_FILEID(inode)); return 0; @@ -1008,8 +1019,12 @@ int nfs_revalidate_mapping(struct inode *inode, struct address_space *mapping) if (ret < 0) goto out; } - if (nfsi->cache_validity & NFS_INO_INVALID_DATA) + if (nfsi->cache_validity & NFS_INO_INVALID_DATA) { + trace_nfs_invalidate_mapping_enter(inode); ret = nfs_invalidate_mapping(inode, mapping); + trace_nfs_invalidate_mapping_exit(inode, ret); + } + out: return ret; } @@ -1268,9 +1283,17 @@ static int nfs_inode_attrs_need_update(const struct inode *inode, const struct n static int nfs_refresh_inode_locked(struct inode *inode, struct nfs_fattr *fattr) { + int ret; + + trace_nfs_refresh_inode_enter(inode); + if (nfs_inode_attrs_need_update(inode, fattr)) - return nfs_update_inode(inode, fattr); - return nfs_check_inode_attributes(inode, fattr); + ret = nfs_update_inode(inode, fattr); + else + ret = nfs_check_inode_attributes(inode, fattr); + + trace_nfs_refresh_inode_exit(inode, ret); + return ret; } /** diff --git a/fs/nfs/nfstrace.c b/fs/nfs/nfstrace.c new file mode 100644 index 0000000..cc91461 --- /dev/null +++ b/fs/nfs/nfstrace.c @@ -0,0 +1,8 @@ +/* + * Copyright (c) 2013 Trond Myklebust <Trond.Myklebust@netapp.com> + */ +#include <linux/nfs_fs.h> +#include "internal.h" + +#define CREATE_TRACE_POINTS +#include "nfstrace.h" diff --git a/fs/nfs/nfstrace.h b/fs/nfs/nfstrace.h new file mode 100644 index 0000000..73c8e1e --- /dev/null +++ b/fs/nfs/nfstrace.h @@ -0,0 +1,166 @@ +/* + * Copyright (c) 2013 Trond Myklebust <Trond.Myklebust@netapp.com> + */ +#undef TRACE_SYSTEM +#define TRACE_SYSTEM nfs + +#if !defined(_TRACE_NFS_H) || defined(TRACE_HEADER_MULTI_READ) +#define _TRACE_NFS_H + +#include <linux/tracepoint.h> + +#define nfs_show_file_type(ftype) \ + __print_symbolic(ftype, \ + { DT_UNKNOWN, "UNKNOWN" }, \ + { DT_FIFO, "FIFO" }, \ + { DT_CHR, "CHR" }, \ + { DT_DIR, "DIR" }, \ + { DT_BLK, "BLK" }, \ + { DT_REG, "REG" }, \ + { DT_LNK, "LNK" }, \ + { DT_SOCK, "SOCK" }, \ + { DT_WHT, "WHT" }) + +#define nfs_show_cache_validity(v) \ + __print_flags(v, "|", \ + { NFS_INO_INVALID_ATTR, "INVALID_ATTR" }, \ + { NFS_INO_INVALID_DATA, "INVALID_DATA" }, \ + { NFS_INO_INVALID_ATIME, "INVALID_ATIME" }, \ + { NFS_INO_INVALID_ACCESS, "INVALID_ACCESS" }, \ + { NFS_INO_INVALID_ACL, "INVALID_ACL" }, \ + { NFS_INO_REVAL_PAGECACHE, "REVAL_PAGECACHE" }, \ + { NFS_INO_REVAL_FORCED, "REVAL_FORCED" }, \ + { NFS_INO_INVALID_LABEL, "INVALID_LABEL" }) + +#define nfs_show_nfsi_flags(v) \ + __print_flags(v, "|", \ + { 1 << NFS_INO_ADVISE_RDPLUS, "ADVISE_RDPLUS" }, \ + { 1 << NFS_INO_STALE, "STALE" }, \ + { 1 << NFS_INO_FLUSHING, "FLUSHING" }, \ + { 1 << NFS_INO_FSCACHE, "FSCACHE" }, \ + { 1 << NFS_INO_COMMIT, "COMMIT" }, \ + { 1 << NFS_INO_LAYOUTCOMMIT, "NEED_LAYOUTCOMMIT" }, \ + { 1 << NFS_INO_LAYOUTCOMMITTING, "LAYOUTCOMMIT" }) + +DECLARE_EVENT_CLASS(nfs_inode_event, + TP_PROTO( + const struct inode *inode + ), + + TP_ARGS(inode), + + TP_STRUCT__entry( + __field(dev_t, dev) + __field(u32, fhandle) + __field(u64, fileid) + __field(u64, version) + ), + + TP_fast_assign( + const struct nfs_inode *nfsi = NFS_I(inode); + __entry->dev = inode->i_sb->s_dev; + __entry->fileid = nfsi->fileid; + __entry->fhandle = nfs_fhandle_hash(&nfsi->fh); + __entry->version = inode->i_version; + ), + + TP_printk( + "fileid=%02x:%02x:%llu fhandle=0x%08x version=%llu ", + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->fileid, + __entry->fhandle, + (unsigned long long)__entry->version + ) +); + +DECLARE_EVENT_CLASS(nfs_inode_event_done, + TP_PROTO( + const struct inode *inode, + int error + ), + + TP_ARGS(inode, error), + + TP_STRUCT__entry( + __field(int, error) + __field(dev_t, dev) + __field(u32, fhandle) + __field(unsigned char, type) + __field(u64, fileid) + __field(u64, version) + __field(loff_t, size) + __field(unsigned long, nfsi_flags) + __field(unsigned long, cache_validity) + ), + + TP_fast_assign( + const struct nfs_inode *nfsi = NFS_I(inode); + __entry->error = error; + __entry->dev = inode->i_sb->s_dev; + __entry->fileid = nfsi->fileid; + __entry->fhandle = nfs_fhandle_hash(&nfsi->fh); + __entry->type = nfs_umode_to_dtype(inode->i_mode); + __entry->version = inode->i_version; + __entry->size = i_size_read(inode); + __entry->nfsi_flags = nfsi->flags; + __entry->cache_validity = nfsi->cache_validity; + ), + + TP_printk( + "error=%d fileid=%02x:%02x:%llu fhandle=0x%08x " + "type=%u (%s) version=%llu size=%lld " + "cache_validity=%lu (%s) nfs_flags=%ld (%s)", + __entry->error, + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->fileid, + __entry->fhandle, + __entry->type, + nfs_show_file_type(__entry->type), + (unsigned long long)__entry->version, + (long long)__entry->size, + __entry->cache_validity, + nfs_show_cache_validity(__entry->cache_validity), + __entry->nfsi_flags, + nfs_show_nfsi_flags(__entry->nfsi_flags) + ) +); + +#define DEFINE_NFS_INODE_EVENT(name) \ + DEFINE_EVENT(nfs_inode_event, name, \ + TP_PROTO( \ + const struct inode *inode \ + ), \ + TP_ARGS(inode)) +#define DEFINE_NFS_INODE_EVENT_DONE(name) \ + DEFINE_EVENT(nfs_inode_event_done, name, \ + TP_PROTO( \ + const struct inode *inode, \ + int error \ + ), \ + TP_ARGS(inode, error)) +DEFINE_NFS_INODE_EVENT(nfs_refresh_inode_enter); +DEFINE_NFS_INODE_EVENT_DONE(nfs_refresh_inode_exit); +DEFINE_NFS_INODE_EVENT(nfs_revalidate_inode_enter); +DEFINE_NFS_INODE_EVENT_DONE(nfs_revalidate_inode_exit); +DEFINE_NFS_INODE_EVENT(nfs_invalidate_mapping_enter); +DEFINE_NFS_INODE_EVENT_DONE(nfs_invalidate_mapping_exit); +DEFINE_NFS_INODE_EVENT(nfs_getattr_enter); +DEFINE_NFS_INODE_EVENT_DONE(nfs_getattr_exit); +DEFINE_NFS_INODE_EVENT(nfs_setattr_enter); +DEFINE_NFS_INODE_EVENT_DONE(nfs_setattr_exit); +DEFINE_NFS_INODE_EVENT(nfs_writeback_page_enter); +DEFINE_NFS_INODE_EVENT_DONE(nfs_writeback_page_exit); +DEFINE_NFS_INODE_EVENT(nfs_writeback_inode_enter); +DEFINE_NFS_INODE_EVENT_DONE(nfs_writeback_inode_exit); +DEFINE_NFS_INODE_EVENT(nfs_fsync_enter); +DEFINE_NFS_INODE_EVENT_DONE(nfs_fsync_exit); +DEFINE_NFS_INODE_EVENT(nfs_access_enter); +DEFINE_NFS_INODE_EVENT_DONE(nfs_access_exit); + +#endif /* _TRACE_NFS_H */ + +#undef TRACE_INCLUDE_PATH +#define TRACE_INCLUDE_PATH . +#define TRACE_INCLUDE_FILE nfstrace +/* This part must be outside protection */ +#include <trace/define_trace.h> diff --git a/fs/nfs/write.c b/fs/nfs/write.c index f1bdb72..d37e8ca 100644 --- a/fs/nfs/write.c +++ b/fs/nfs/write.c @@ -31,6 +31,8 @@ #include "fscache.h" #include "pnfs.h" +#include "nfstrace.h" + #define NFSDBG_FACILITY NFSDBG_PAGECACHE #define MIN_POOL_WRITE (32) @@ -1732,8 +1734,14 @@ int nfs_wb_all(struct inode *inode) .range_start = 0, .range_end = LLONG_MAX, }; + int ret; + + trace_nfs_writeback_inode_enter(inode); + + ret = sync_inode(inode, &wbc); - return sync_inode(inode, &wbc); + trace_nfs_writeback_inode_exit(inode, ret); + return ret; } EXPORT_SYMBOL_GPL(nfs_wb_all); @@ -1781,6 +1789,8 @@ int nfs_wb_page(struct inode *inode, struct page *page) }; int ret; + trace_nfs_writeback_page_enter(inode); + for (;;) { wait_on_page_writeback(page); if (clear_page_dirty_for_io(page)) { @@ -1789,14 +1799,15 @@ int nfs_wb_page(struct inode *inode, struct page *page) goto out_error; continue; } + ret = 0; if (!PagePrivate(page)) break; ret = nfs_commit_inode(inode, FLUSH_SYNC); if (ret < 0) goto out_error; } - return 0; out_error: + trace_nfs_writeback_page_exit(inode, ret); return ret; } -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
* [PATCH v4 03/21] NFS: Pass in lookup flags from nfs_atomic_open to nfs_lookup 2013-08-22 0:24 ` [PATCH v4 02/21] NFS: Add event tracing for generic NFS events Trond Myklebust @ 2013-08-22 0:24 ` Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 04/21] NFS: Add event tracing for generic NFS lookups Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:24 UTC (permalink / raw) To: linux-nfs When doing an open of a directory, ensure that we do pass the lookup flags from nfs_atomic_open into nfs_lookup. Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/dir.c | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/fs/nfs/dir.c b/fs/nfs/dir.c index be3da6f..29d5463 100644 --- a/fs/nfs/dir.c +++ b/fs/nfs/dir.c @@ -1407,6 +1407,7 @@ int nfs_atomic_open(struct inode *dir, struct dentry *dentry, struct dentry *res; struct iattr attr = { .ia_valid = ATTR_OPEN }; struct inode *inode; + unsigned int lookup_flags = 0; int err; /* Expect a negative dentry */ @@ -1429,6 +1430,7 @@ int nfs_atomic_open(struct inode *dir, struct dentry *dentry, */ return -ENOENT; } + lookup_flags = LOOKUP_OPEN|LOOKUP_DIRECTORY; goto no_open; } @@ -1479,7 +1481,7 @@ out: return err; no_open: - res = nfs_lookup(dir, dentry, 0); + res = nfs_lookup(dir, dentry, lookup_flags); err = PTR_ERR(res); if (IS_ERR(res)) goto out; -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
* [PATCH v4 04/21] NFS: Add event tracing for generic NFS lookups 2013-08-22 0:24 ` [PATCH v4 03/21] NFS: Pass in lookup flags from nfs_atomic_open to nfs_lookup Trond Myklebust @ 2013-08-22 0:24 ` Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 05/21] NFS: Add tracepoints for debugging generic file create events Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:24 UTC (permalink / raw) To: linux-nfs Add tracepoints for lookup, lookup_revalidate and atomic_open Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/dir.c | 7 ++ fs/nfs/nfstrace.c | 1 + fs/nfs/nfstrace.h | 195 ++++++++++++++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 203 insertions(+) diff --git a/fs/nfs/dir.c b/fs/nfs/dir.c index 29d5463..2263a6b 100644 --- a/fs/nfs/dir.c +++ b/fs/nfs/dir.c @@ -1102,7 +1102,9 @@ static int nfs_lookup_revalidate(struct dentry *dentry, unsigned int flags) if (IS_ERR(label)) goto out_error; + trace_nfs_lookup_revalidate_enter(dir, dentry, flags); error = NFS_PROTO(dir)->lookup(dir, &dentry->d_name, fhandle, fattr, label); + trace_nfs_lookup_revalidate_exit(dir, dentry, flags, error); if (error) goto out_bad; if (nfs_compare_fh(NFS_FH(inode), fhandle)) @@ -1315,6 +1317,7 @@ struct dentry *nfs_lookup(struct inode *dir, struct dentry * dentry, unsigned in parent = dentry->d_parent; /* Protect against concurrent sillydeletes */ + trace_nfs_lookup_enter(dir, dentry, flags); nfs_block_sillyrename(parent); error = NFS_PROTO(dir)->lookup(dir, &dentry->d_name, fhandle, fattr, label); if (error == -ENOENT) @@ -1341,6 +1344,7 @@ no_entry: nfs_set_verifier(dentry, nfs_save_change_attribute(dir)); out_unblock_sillyrename: nfs_unblock_sillyrename(parent); + trace_nfs_lookup_exit(dir, dentry, flags, error); nfs4_label_free(label); out: nfs_free_fattr(fattr); @@ -1451,12 +1455,14 @@ int nfs_atomic_open(struct inode *dir, struct dentry *dentry, if (IS_ERR(ctx)) goto out; + trace_nfs_atomic_open_enter(dir, ctx, open_flags); nfs_block_sillyrename(dentry->d_parent); inode = NFS_PROTO(dir)->open_context(dir, ctx, open_flags, &attr); nfs_unblock_sillyrename(dentry->d_parent); if (IS_ERR(inode)) { put_nfs_open_context(ctx); err = PTR_ERR(inode); + trace_nfs_atomic_open_exit(dir, ctx, open_flags, err); switch (err) { case -ENOENT: d_drop(dentry); @@ -1477,6 +1483,7 @@ int nfs_atomic_open(struct inode *dir, struct dentry *dentry, } err = nfs_finish_open(ctx, ctx->dentry, file, open_flags, opened); + trace_nfs_atomic_open_exit(dir, ctx, open_flags, err); out: return err; diff --git a/fs/nfs/nfstrace.c b/fs/nfs/nfstrace.c index cc91461..4eb0aea 100644 --- a/fs/nfs/nfstrace.c +++ b/fs/nfs/nfstrace.c @@ -2,6 +2,7 @@ * Copyright (c) 2013 Trond Myklebust <Trond.Myklebust@netapp.com> */ #include <linux/nfs_fs.h> +#include <linux/namei.h> #include "internal.h" #define CREATE_TRACE_POINTS diff --git a/fs/nfs/nfstrace.h b/fs/nfs/nfstrace.h index 73c8e1e..fba194b 100644 --- a/fs/nfs/nfstrace.h +++ b/fs/nfs/nfstrace.h @@ -157,6 +157,201 @@ DEFINE_NFS_INODE_EVENT_DONE(nfs_fsync_exit); DEFINE_NFS_INODE_EVENT(nfs_access_enter); DEFINE_NFS_INODE_EVENT_DONE(nfs_access_exit); +#define show_lookup_flags(flags) \ + __print_flags((unsigned long)flags, "|", \ + { LOOKUP_AUTOMOUNT, "AUTOMOUNT" }, \ + { LOOKUP_DIRECTORY, "DIRECTORY" }, \ + { LOOKUP_OPEN, "OPEN" }, \ + { LOOKUP_CREATE, "CREATE" }, \ + { LOOKUP_EXCL, "EXCL" }) + +DECLARE_EVENT_CLASS(nfs_lookup_event, + TP_PROTO( + const struct inode *dir, + const struct dentry *dentry, + unsigned int flags + ), + + TP_ARGS(dir, dentry, flags), + + TP_STRUCT__entry( + __field(unsigned int, flags) + __field(dev_t, dev) + __field(u64, dir) + __string(name, dentry->d_name.name) + ), + + TP_fast_assign( + __entry->dev = dir->i_sb->s_dev; + __entry->dir = NFS_FILEID(dir); + __entry->flags = flags; + __assign_str(name, dentry->d_name.name); + ), + + TP_printk( + "flags=%u (%s) name=%02x:%02x:%llu/%s", + __entry->flags, + show_lookup_flags(__entry->flags), + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->dir, + __get_str(name) + ) +); + +#define DEFINE_NFS_LOOKUP_EVENT(name) \ + DEFINE_EVENT(nfs_lookup_event, name, \ + TP_PROTO( \ + const struct inode *dir, \ + const struct dentry *dentry, \ + unsigned int flags \ + ), \ + TP_ARGS(dir, dentry, flags)) + +DECLARE_EVENT_CLASS(nfs_lookup_event_done, + TP_PROTO( + const struct inode *dir, + const struct dentry *dentry, + unsigned int flags, + int error + ), + + TP_ARGS(dir, dentry, flags, error), + + TP_STRUCT__entry( + __field(int, error) + __field(unsigned int, flags) + __field(dev_t, dev) + __field(u64, dir) + __string(name, dentry->d_name.name) + ), + + TP_fast_assign( + __entry->dev = dir->i_sb->s_dev; + __entry->dir = NFS_FILEID(dir); + __entry->error = error; + __entry->flags = flags; + __assign_str(name, dentry->d_name.name); + ), + + TP_printk( + "error=%d flags=%u (%s) name=%02x:%02x:%llu/%s", + __entry->error, + __entry->flags, + show_lookup_flags(__entry->flags), + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->dir, + __get_str(name) + ) +); + +#define DEFINE_NFS_LOOKUP_EVENT_DONE(name) \ + DEFINE_EVENT(nfs_lookup_event_done, name, \ + TP_PROTO( \ + const struct inode *dir, \ + const struct dentry *dentry, \ + unsigned int flags, \ + int error \ + ), \ + TP_ARGS(dir, dentry, flags, error)) + +DEFINE_NFS_LOOKUP_EVENT(nfs_lookup_enter); +DEFINE_NFS_LOOKUP_EVENT_DONE(nfs_lookup_exit); +DEFINE_NFS_LOOKUP_EVENT(nfs_lookup_revalidate_enter); +DEFINE_NFS_LOOKUP_EVENT_DONE(nfs_lookup_revalidate_exit); + +#define show_open_flags(flags) \ + __print_flags((unsigned long)flags, "|", \ + { O_CREAT, "O_CREAT" }, \ + { O_EXCL, "O_EXCL" }, \ + { O_TRUNC, "O_TRUNC" }, \ + { O_APPEND, "O_APPEND" }, \ + { O_DSYNC, "O_DSYNC" }, \ + { O_DIRECT, "O_DIRECT" }, \ + { O_DIRECTORY, "O_DIRECTORY" }) + +#define show_fmode_flags(mode) \ + __print_flags(mode, "|", \ + { ((__force unsigned long)FMODE_READ), "READ" }, \ + { ((__force unsigned long)FMODE_WRITE), "WRITE" }, \ + { ((__force unsigned long)FMODE_EXEC), "EXEC" }) + +TRACE_EVENT(nfs_atomic_open_enter, + TP_PROTO( + const struct inode *dir, + const struct nfs_open_context *ctx, + unsigned int flags + ), + + TP_ARGS(dir, ctx, flags), + + TP_STRUCT__entry( + __field(unsigned int, flags) + __field(unsigned int, fmode) + __field(dev_t, dev) + __field(u64, dir) + __string(name, ctx->dentry->d_name.name) + ), + + TP_fast_assign( + __entry->dev = dir->i_sb->s_dev; + __entry->dir = NFS_FILEID(dir); + __entry->flags = flags; + __entry->fmode = (__force unsigned int)ctx->mode; + __assign_str(name, ctx->dentry->d_name.name); + ), + + TP_printk( + "flags=%u (%s) fmode=%s name=%02x:%02x:%llu/%s", + __entry->flags, + show_open_flags(__entry->flags), + show_fmode_flags(__entry->fmode), + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->dir, + __get_str(name) + ) +); + +TRACE_EVENT(nfs_atomic_open_exit, + TP_PROTO( + const struct inode *dir, + const struct nfs_open_context *ctx, + unsigned int flags, + int error + ), + + TP_ARGS(dir, ctx, flags, error), + + TP_STRUCT__entry( + __field(int, error) + __field(unsigned int, flags) + __field(unsigned int, fmode) + __field(dev_t, dev) + __field(u64, dir) + __string(name, ctx->dentry->d_name.name) + ), + + TP_fast_assign( + __entry->error = error; + __entry->dev = dir->i_sb->s_dev; + __entry->dir = NFS_FILEID(dir); + __entry->flags = flags; + __entry->fmode = (__force unsigned int)ctx->mode; + __assign_str(name, ctx->dentry->d_name.name); + ), + + TP_printk( + "error=%d flags=%u (%s) fmode=%s " + "name=%02x:%02x:%llu/%s", + __entry->error, + __entry->flags, + show_open_flags(__entry->flags), + show_fmode_flags(__entry->fmode), + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->dir, + __get_str(name) + ) +); + #endif /* _TRACE_NFS_H */ #undef TRACE_INCLUDE_PATH -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
* [PATCH v4 05/21] NFS: Add tracepoints for debugging generic file create events 2013-08-22 0:24 ` [PATCH v4 04/21] NFS: Add event tracing for generic NFS lookups Trond Myklebust @ 2013-08-22 0:24 ` Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 06/21] NFS: Add tracepoints for debugging directory changes Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:24 UTC (permalink / raw) To: linux-nfs Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/dir.c | 2 ++ fs/nfs/nfstrace.h | 70 +++++++++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 72 insertions(+) diff --git a/fs/nfs/dir.c b/fs/nfs/dir.c index 2263a6b..9c07812 100644 --- a/fs/nfs/dir.c +++ b/fs/nfs/dir.c @@ -1612,7 +1612,9 @@ int nfs_create(struct inode *dir, struct dentry *dentry, attr.ia_mode = mode; attr.ia_valid = ATTR_MODE; + trace_nfs_create_enter(dir, dentry, open_flags); error = NFS_PROTO(dir)->create(dir, dentry, &attr, open_flags); + trace_nfs_create_exit(dir, dentry, open_flags, error); if (error != 0) goto out_err; return 0; diff --git a/fs/nfs/nfstrace.h b/fs/nfs/nfstrace.h index fba194b..2963a05 100644 --- a/fs/nfs/nfstrace.h +++ b/fs/nfs/nfstrace.h @@ -352,6 +352,76 @@ TRACE_EVENT(nfs_atomic_open_exit, ) ); +TRACE_EVENT(nfs_create_enter, + TP_PROTO( + const struct inode *dir, + const struct dentry *dentry, + unsigned int flags + ), + + TP_ARGS(dir, dentry, flags), + + TP_STRUCT__entry( + __field(unsigned int, flags) + __field(dev_t, dev) + __field(u64, dir) + __string(name, dentry->d_name.name) + ), + + TP_fast_assign( + __entry->dev = dir->i_sb->s_dev; + __entry->dir = NFS_FILEID(dir); + __entry->flags = flags; + __assign_str(name, dentry->d_name.name); + ), + + TP_printk( + "flags=%u (%s) name=%02x:%02x:%llu/%s", + __entry->flags, + show_open_flags(__entry->flags), + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->dir, + __get_str(name) + ) +); + +TRACE_EVENT(nfs_create_exit, + TP_PROTO( + const struct inode *dir, + const struct dentry *dentry, + unsigned int flags, + int error + ), + + TP_ARGS(dir, dentry, flags, error), + + TP_STRUCT__entry( + __field(int, error) + __field(unsigned int, flags) + __field(dev_t, dev) + __field(u64, dir) + __string(name, dentry->d_name.name) + ), + + TP_fast_assign( + __entry->error = error; + __entry->dev = dir->i_sb->s_dev; + __entry->dir = NFS_FILEID(dir); + __entry->flags = flags; + __assign_str(name, dentry->d_name.name); + ), + + TP_printk( + "error=%d flags=%u (%s) name=%02x:%02x:%llu/%s", + __entry->error, + __entry->flags, + show_open_flags(__entry->flags), + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->dir, + __get_str(name) + ) +); + #endif /* _TRACE_NFS_H */ #undef TRACE_INCLUDE_PATH -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
* [PATCH v4 06/21] NFS: Add tracepoints for debugging directory changes 2013-08-22 0:24 ` [PATCH v4 05/21] NFS: Add tracepoints for debugging generic file create events Trond Myklebust @ 2013-08-22 0:24 ` Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 07/21] NFS: Add tracepoints for debugging NFS rename and sillyrename issues Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:24 UTC (permalink / raw) To: linux-nfs Add tracepoints for mknod, mkdir, rmdir, remove (unlink) and symlink. Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/dir.c | 15 +++++++++- fs/nfs/nfstrace.h | 90 +++++++++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 104 insertions(+), 1 deletion(-) diff --git a/fs/nfs/dir.c b/fs/nfs/dir.c index 9c07812..e41dec5 100644 --- a/fs/nfs/dir.c +++ b/fs/nfs/dir.c @@ -1642,7 +1642,9 @@ nfs_mknod(struct inode *dir, struct dentry *dentry, umode_t mode, dev_t rdev) attr.ia_mode = mode; attr.ia_valid = ATTR_MODE; + trace_nfs_mknod_enter(dir, dentry); status = NFS_PROTO(dir)->mknod(dir, dentry, &attr, rdev); + trace_nfs_mknod_exit(dir, dentry, status); if (status != 0) goto out_err; return 0; @@ -1666,7 +1668,9 @@ int nfs_mkdir(struct inode *dir, struct dentry *dentry, umode_t mode) attr.ia_valid = ATTR_MODE; attr.ia_mode = mode | S_IFDIR; + trace_nfs_mkdir_enter(dir, dentry); error = NFS_PROTO(dir)->mkdir(dir, dentry, &attr); + trace_nfs_mkdir_exit(dir, dentry, error); if (error != 0) goto out_err; return 0; @@ -1689,12 +1693,14 @@ int nfs_rmdir(struct inode *dir, struct dentry *dentry) dfprintk(VFS, "NFS: rmdir(%s/%ld), %s\n", dir->i_sb->s_id, dir->i_ino, dentry->d_name.name); + trace_nfs_rmdir_enter(dir, dentry); error = NFS_PROTO(dir)->rmdir(dir, &dentry->d_name); /* Ensure the VFS deletes this inode */ if (error == 0 && dentry->d_inode != NULL) clear_nlink(dentry->d_inode); else if (error == -ENOENT) nfs_dentry_handle_enoent(dentry); + trace_nfs_rmdir_exit(dir, dentry, error); return error; } @@ -1722,6 +1728,7 @@ static int nfs_safe_remove(struct dentry *dentry) goto out; } + trace_nfs_remove_enter(dir, dentry); if (inode != NULL) { NFS_PROTO(inode)->return_delegation(inode); error = NFS_PROTO(dir)->remove(dir, &dentry->d_name); @@ -1731,6 +1738,7 @@ static int nfs_safe_remove(struct dentry *dentry) error = NFS_PROTO(dir)->remove(dir, &dentry->d_name); if (error == -ENOENT) nfs_dentry_handle_enoent(dentry); + trace_nfs_remove_exit(dir, dentry, error); out: return error; } @@ -1748,13 +1756,14 @@ int nfs_unlink(struct inode *dir, struct dentry *dentry) dfprintk(VFS, "NFS: unlink(%s/%ld, %s)\n", dir->i_sb->s_id, dir->i_ino, dentry->d_name.name); + trace_nfs_unlink_enter(dir, dentry); spin_lock(&dentry->d_lock); if (d_count(dentry) > 1) { spin_unlock(&dentry->d_lock); /* Start asynchronous writeout of the inode */ write_inode_now(dentry->d_inode, 0); error = nfs_sillyrename(dir, dentry); - return error; + goto out; } if (!d_unhashed(dentry)) { __d_drop(dentry); @@ -1766,6 +1775,8 @@ int nfs_unlink(struct inode *dir, struct dentry *dentry) nfs_set_verifier(dentry, nfs_save_change_attribute(dir)); } else if (need_rehash) d_rehash(dentry); +out: + trace_nfs_unlink_exit(dir, dentry, error); return error; } EXPORT_SYMBOL_GPL(nfs_unlink); @@ -1812,7 +1823,9 @@ int nfs_symlink(struct inode *dir, struct dentry *dentry, const char *symname) memset(kaddr + pathlen, 0, PAGE_SIZE - pathlen); kunmap_atomic(kaddr); + trace_nfs_symlink_enter(dir, dentry); error = NFS_PROTO(dir)->symlink(dir, dentry, page, pathlen, &attr); + trace_nfs_symlink_exit(dir, dentry, error); if (error != 0) { dfprintk(VFS, "NFS: symlink(%s/%ld, %s, %s) error %d\n", dir->i_sb->s_id, dir->i_ino, diff --git a/fs/nfs/nfstrace.h b/fs/nfs/nfstrace.h index 2963a05..5827906 100644 --- a/fs/nfs/nfstrace.h +++ b/fs/nfs/nfstrace.h @@ -422,6 +422,96 @@ TRACE_EVENT(nfs_create_exit, ) ); +DECLARE_EVENT_CLASS(nfs_directory_event, + TP_PROTO( + const struct inode *dir, + const struct dentry *dentry + ), + + TP_ARGS(dir, dentry), + + TP_STRUCT__entry( + __field(dev_t, dev) + __field(u64, dir) + __string(name, dentry->d_name.name) + ), + + TP_fast_assign( + __entry->dev = dir->i_sb->s_dev; + __entry->dir = NFS_FILEID(dir); + __assign_str(name, dentry->d_name.name); + ), + + TP_printk( + "name=%02x:%02x:%llu/%s", + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->dir, + __get_str(name) + ) +); + +#define DEFINE_NFS_DIRECTORY_EVENT(name) \ + DEFINE_EVENT(nfs_directory_event, name, \ + TP_PROTO( \ + const struct inode *dir, \ + const struct dentry *dentry \ + ), \ + TP_ARGS(dir, dentry)) + +DECLARE_EVENT_CLASS(nfs_directory_event_done, + TP_PROTO( + const struct inode *dir, + const struct dentry *dentry, + int error + ), + + TP_ARGS(dir, dentry, error), + + TP_STRUCT__entry( + __field(int, error) + __field(dev_t, dev) + __field(u64, dir) + __string(name, dentry->d_name.name) + ), + + TP_fast_assign( + __entry->dev = dir->i_sb->s_dev; + __entry->dir = NFS_FILEID(dir); + __entry->error = error; + __assign_str(name, dentry->d_name.name); + ), + + TP_printk( + "error=%d name=%02x:%02x:%llu/%s", + __entry->error, + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->dir, + __get_str(name) + ) +); + +#define DEFINE_NFS_DIRECTORY_EVENT_DONE(name) \ + DEFINE_EVENT(nfs_directory_event_done, name, \ + TP_PROTO( \ + const struct inode *dir, \ + const struct dentry *dentry, \ + int error \ + ), \ + TP_ARGS(dir, dentry, error)) + +DEFINE_NFS_DIRECTORY_EVENT(nfs_mknod_enter); +DEFINE_NFS_DIRECTORY_EVENT_DONE(nfs_mknod_exit); +DEFINE_NFS_DIRECTORY_EVENT(nfs_mkdir_enter); +DEFINE_NFS_DIRECTORY_EVENT_DONE(nfs_mkdir_exit); +DEFINE_NFS_DIRECTORY_EVENT(nfs_rmdir_enter); +DEFINE_NFS_DIRECTORY_EVENT_DONE(nfs_rmdir_exit); +DEFINE_NFS_DIRECTORY_EVENT(nfs_remove_enter); +DEFINE_NFS_DIRECTORY_EVENT_DONE(nfs_remove_exit); +DEFINE_NFS_DIRECTORY_EVENT(nfs_unlink_enter); +DEFINE_NFS_DIRECTORY_EVENT_DONE(nfs_unlink_exit); +DEFINE_NFS_DIRECTORY_EVENT(nfs_symlink_enter); +DEFINE_NFS_DIRECTORY_EVENT_DONE(nfs_symlink_exit); + #endif /* _TRACE_NFS_H */ #undef TRACE_INCLUDE_PATH -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
* [PATCH v4 07/21] NFS: Add tracepoints for debugging NFS rename and sillyrename issues 2013-08-22 0:24 ` [PATCH v4 06/21] NFS: Add tracepoints for debugging directory changes Trond Myklebust @ 2013-08-22 0:24 ` Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 08/21] NFS: Add tracepoints for debugging NFS hard links Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:24 UTC (permalink / raw) To: linux-nfs Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/dir.c | 3 ++ fs/nfs/nfstrace.h | 138 ++++++++++++++++++++++++++++++++++++++++++++++++++++++ fs/nfs/unlink.c | 5 ++ 3 files changed, 146 insertions(+) diff --git a/fs/nfs/dir.c b/fs/nfs/dir.c index e41dec5..dca7deb 100644 --- a/fs/nfs/dir.c +++ b/fs/nfs/dir.c @@ -1909,6 +1909,7 @@ int nfs_rename(struct inode *old_dir, struct dentry *old_dentry, new_dentry->d_parent->d_name.name, new_dentry->d_name.name, d_count(new_dentry)); + trace_nfs_rename_enter(old_dir, old_dentry, new_dir, new_dentry); /* * For non-directories, check whether the target is busy and if so, * make a copy of the dentry and then do a silly-rename. If the @@ -1955,6 +1956,8 @@ int nfs_rename(struct inode *old_dir, struct dentry *old_dentry, out: if (rehash) d_rehash(rehash); + trace_nfs_rename_exit(old_dir, old_dentry, + new_dir, new_dentry, error); if (!error) { if (new_inode != NULL) nfs_drop_nlink(new_inode); diff --git a/fs/nfs/nfstrace.h b/fs/nfs/nfstrace.h index 5827906..a20f0d1 100644 --- a/fs/nfs/nfstrace.h +++ b/fs/nfs/nfstrace.h @@ -512,6 +512,144 @@ DEFINE_NFS_DIRECTORY_EVENT_DONE(nfs_unlink_exit); DEFINE_NFS_DIRECTORY_EVENT(nfs_symlink_enter); DEFINE_NFS_DIRECTORY_EVENT_DONE(nfs_symlink_exit); +DECLARE_EVENT_CLASS(nfs_rename_event, + TP_PROTO( + const struct inode *old_dir, + const struct dentry *old_dentry, + const struct inode *new_dir, + const struct dentry *new_dentry + ), + + TP_ARGS(old_dir, old_dentry, new_dir, new_dentry), + + TP_STRUCT__entry( + __field(dev_t, dev) + __field(u64, old_dir) + __field(u64, new_dir) + __string(old_name, old_dentry->d_name.name) + __string(new_name, new_dentry->d_name.name) + ), + + TP_fast_assign( + __entry->dev = old_dir->i_sb->s_dev; + __entry->old_dir = NFS_FILEID(old_dir); + __entry->new_dir = NFS_FILEID(new_dir); + __assign_str(old_name, old_dentry->d_name.name); + __assign_str(new_name, new_dentry->d_name.name); + ), + + TP_printk( + "old_name=%02x:%02x:%llu/%s new_name=%02x:%02x:%llu/%s", + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->old_dir, + __get_str(old_name), + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->new_dir, + __get_str(new_name) + ) +); +#define DEFINE_NFS_RENAME_EVENT(name) \ + DEFINE_EVENT(nfs_rename_event, name, \ + TP_PROTO( \ + const struct inode *old_dir, \ + const struct dentry *old_dentry, \ + const struct inode *new_dir, \ + const struct dentry *new_dentry \ + ), \ + TP_ARGS(old_dir, old_dentry, new_dir, new_dentry)) + +DECLARE_EVENT_CLASS(nfs_rename_event_done, + TP_PROTO( + const struct inode *old_dir, + const struct dentry *old_dentry, + const struct inode *new_dir, + const struct dentry *new_dentry, + int error + ), + + TP_ARGS(old_dir, old_dentry, new_dir, new_dentry, error), + + TP_STRUCT__entry( + __field(dev_t, dev) + __field(int, error) + __field(u64, old_dir) + __string(old_name, old_dentry->d_name.name) + __field(u64, new_dir) + __string(new_name, new_dentry->d_name.name) + ), + + TP_fast_assign( + __entry->dev = old_dir->i_sb->s_dev; + __entry->old_dir = NFS_FILEID(old_dir); + __entry->new_dir = NFS_FILEID(new_dir); + __entry->error = error; + __assign_str(old_name, old_dentry->d_name.name); + __assign_str(new_name, new_dentry->d_name.name); + ), + + TP_printk( + "error=%d old_name=%02x:%02x:%llu/%s " + "new_name=%02x:%02x:%llu/%s", + __entry->error, + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->old_dir, + __get_str(old_name), + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->new_dir, + __get_str(new_name) + ) +); +#define DEFINE_NFS_RENAME_EVENT_DONE(name) \ + DEFINE_EVENT(nfs_rename_event_done, name, \ + TP_PROTO( \ + const struct inode *old_dir, \ + const struct dentry *old_dentry, \ + const struct inode *new_dir, \ + const struct dentry *new_dentry, \ + int error \ + ), \ + TP_ARGS(old_dir, old_dentry, new_dir, \ + new_dentry, error)) + +DEFINE_NFS_RENAME_EVENT(nfs_rename_enter); +DEFINE_NFS_RENAME_EVENT_DONE(nfs_rename_exit); + +DEFINE_NFS_RENAME_EVENT_DONE(nfs_sillyrename_rename); + +TRACE_EVENT(nfs_sillyrename_unlink, + TP_PROTO( + const struct nfs_unlinkdata *data, + int error + ), + + TP_ARGS(data, error), + + TP_STRUCT__entry( + __field(dev_t, dev) + __field(int, error) + __field(u64, dir) + __dynamic_array(char, name, data->args.name.len + 1) + ), + + TP_fast_assign( + struct inode *dir = data->dir; + size_t len = data->args.name.len; + __entry->dev = dir->i_sb->s_dev; + __entry->dir = NFS_FILEID(dir); + __entry->error = error; + memcpy(__get_dynamic_array(name), + data->args.name.name, len); + ((char *)__get_dynamic_array(name))[len] = 0; + ), + + TP_printk( + "error=%d name=%02x:%02x:%llu/%s", + __entry->error, + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->dir, + __get_str(name) + ) +); #endif /* _TRACE_NFS_H */ #undef TRACE_INCLUDE_PATH diff --git a/fs/nfs/unlink.c b/fs/nfs/unlink.c index 488fd16..2c1485d 100644 --- a/fs/nfs/unlink.c +++ b/fs/nfs/unlink.c @@ -20,6 +20,8 @@ #include "iostat.h" #include "delegation.h" +#include "nfstrace.h" + /** * nfs_free_unlinkdata - release data from a sillydelete operation. * @data: pointer to unlink structure. @@ -77,6 +79,7 @@ static void nfs_async_unlink_done(struct rpc_task *task, void *calldata) struct nfs_unlinkdata *data = calldata; struct inode *dir = data->dir; + trace_nfs_sillyrename_unlink(data, task->tk_status); if (!NFS_PROTO(dir)->unlink_done(task, dir)) rpc_restart_call_prepare(task); } @@ -336,6 +339,8 @@ static void nfs_async_rename_done(struct rpc_task *task, void *calldata) struct inode *new_dir = data->new_dir; struct dentry *old_dentry = data->old_dentry; + trace_nfs_sillyrename_rename(old_dir, old_dentry, + new_dir, data->new_dentry, task->tk_status); if (!NFS_PROTO(old_dir)->rename_done(task, old_dir, new_dir)) { rpc_restart_call_prepare(task); return; -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
* [PATCH v4 08/21] NFS: Add tracepoints for debugging NFS hard links 2013-08-22 0:24 ` [PATCH v4 07/21] NFS: Add tracepoints for debugging NFS rename and sillyrename issues Trond Myklebust @ 2013-08-22 0:24 ` Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 09/21] NFSv4: Add tracepoints for debugging state management problems Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:24 UTC (permalink / raw) To: linux-nfs Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/dir.c | 2 ++ fs/nfs/nfstrace.h | 70 +++++++++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 72 insertions(+) diff --git a/fs/nfs/dir.c b/fs/nfs/dir.c index dca7deb..4ce7f76 100644 --- a/fs/nfs/dir.c +++ b/fs/nfs/dir.c @@ -1860,6 +1860,7 @@ nfs_link(struct dentry *old_dentry, struct inode *dir, struct dentry *dentry) old_dentry->d_parent->d_name.name, old_dentry->d_name.name, dentry->d_parent->d_name.name, dentry->d_name.name); + trace_nfs_link_enter(inode, dir, dentry); NFS_PROTO(inode)->return_delegation(inode); d_drop(dentry); @@ -1868,6 +1869,7 @@ nfs_link(struct dentry *old_dentry, struct inode *dir, struct dentry *dentry) ihold(inode); d_add(dentry, inode); } + trace_nfs_link_exit(inode, dir, dentry, error); return error; } EXPORT_SYMBOL_GPL(nfs_link); diff --git a/fs/nfs/nfstrace.h b/fs/nfs/nfstrace.h index a20f0d1..89fe741 100644 --- a/fs/nfs/nfstrace.h +++ b/fs/nfs/nfstrace.h @@ -512,6 +512,76 @@ DEFINE_NFS_DIRECTORY_EVENT_DONE(nfs_unlink_exit); DEFINE_NFS_DIRECTORY_EVENT(nfs_symlink_enter); DEFINE_NFS_DIRECTORY_EVENT_DONE(nfs_symlink_exit); +TRACE_EVENT(nfs_link_enter, + TP_PROTO( + const struct inode *inode, + const struct inode *dir, + const struct dentry *dentry + ), + + TP_ARGS(inode, dir, dentry), + + TP_STRUCT__entry( + __field(dev_t, dev) + __field(u64, fileid) + __field(u64, dir) + __string(name, dentry->d_name.name) + ), + + TP_fast_assign( + __entry->dev = inode->i_sb->s_dev; + __entry->fileid = NFS_FILEID(inode); + __entry->dir = NFS_FILEID(dir); + __assign_str(name, dentry->d_name.name); + ), + + TP_printk( + "fileid=%02x:%02x:%llu name=%02x:%02x:%llu/%s", + MAJOR(__entry->dev), MINOR(__entry->dev), + __entry->fileid, + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->dir, + __get_str(name) + ) +); + +TRACE_EVENT(nfs_link_exit, + TP_PROTO( + const struct inode *inode, + const struct inode *dir, + const struct dentry *dentry, + int error + ), + + TP_ARGS(inode, dir, dentry, error), + + TP_STRUCT__entry( + __field(int, error) + __field(dev_t, dev) + __field(u64, fileid) + __field(u64, dir) + __string(name, dentry->d_name.name) + ), + + TP_fast_assign( + __entry->dev = inode->i_sb->s_dev; + __entry->fileid = NFS_FILEID(inode); + __entry->dir = NFS_FILEID(dir); + __entry->error = error; + __assign_str(name, dentry->d_name.name); + ), + + TP_printk( + "error=%d fileid=%02x:%02x:%llu name=%02x:%02x:%llu/%s", + __entry->error, + MAJOR(__entry->dev), MINOR(__entry->dev), + __entry->fileid, + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->dir, + __get_str(name) + ) +); + DECLARE_EVENT_CLASS(nfs_rename_event, TP_PROTO( const struct inode *old_dir, -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
* [PATCH v4 09/21] NFSv4: Add tracepoints for debugging state management problems 2013-08-22 0:24 ` [PATCH v4 08/21] NFS: Add tracepoints for debugging NFS hard links Trond Myklebust @ 2013-08-22 0:24 ` Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 10/21] NFSv4: Add tracepoints for debugging file open Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:24 UTC (permalink / raw) To: linux-nfs Set up basic tracepoints for debugging client id creation/destruction and session creation/destruction. Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/Makefile | 4 +- fs/nfs/nfs4proc.c | 12 +++ fs/nfs/nfs4trace.c | 10 +++ fs/nfs/nfs4trace.h | 220 +++++++++++++++++++++++++++++++++++++++++++++++++++++ 4 files changed, 245 insertions(+), 1 deletion(-) create mode 100644 fs/nfs/nfs4trace.c create mode 100644 fs/nfs/nfs4trace.h diff --git a/fs/nfs/Makefile b/fs/nfs/Makefile index 6bd483b..7238c4b 100644 --- a/fs/nfs/Makefile +++ b/fs/nfs/Makefile @@ -20,9 +20,11 @@ nfsv3-y := nfs3super.o nfs3client.o nfs3proc.o nfs3xdr.o nfsv3-$(CONFIG_NFS_V3_ACL) += nfs3acl.o obj-$(CONFIG_NFS_V4) += nfsv4.o +CFLAGS_nfs4trace.o += -I$(src) nfsv4-y := nfs4proc.o nfs4xdr.o nfs4state.o nfs4renewd.o nfs4super.o nfs4file.o \ delegation.o idmap.o callback.o callback_xdr.o callback_proc.o \ - nfs4namespace.o nfs4getroot.o nfs4client.o dns_resolve.o + nfs4namespace.o nfs4getroot.o nfs4client.o dns_resolve.o \ + nfs4trace.o nfsv4-$(CONFIG_NFS_USE_LEGACY_DNS) += cache_lib.o nfsv4-$(CONFIG_SYSCTL) += nfs4sysctl.o nfsv4-$(CONFIG_NFS_V4_1) += nfs4session.o pnfs.o pnfs_dev.o diff --git a/fs/nfs/nfs4proc.c b/fs/nfs/nfs4proc.c index b577ebb..f077487 100644 --- a/fs/nfs/nfs4proc.c +++ b/fs/nfs/nfs4proc.c @@ -66,6 +66,8 @@ #include "nfs4session.h" #include "fscache.h" +#include "nfs4trace.h" + #define NFSDBG_FACILITY NFSDBG_PROC #define NFS4_POLL_RETRY_MIN (HZ/10) @@ -4060,6 +4062,7 @@ static void nfs4_renew_done(struct rpc_task *task, void *calldata) struct nfs_client *clp = data->client; unsigned long timestamp = data->timestamp; + trace_nfs4_renew_async(clp, task->tk_status); if (task->tk_status < 0) { /* Unless we're shutting down, schedule state recovery! */ if (test_bit(NFS_CS_RENEWD, &clp->cl_res_state) == 0) @@ -4726,6 +4729,7 @@ int nfs4_proc_setclientid(struct nfs_client *clp, u32 program, clp->cl_rpcclient->cl_auth->au_ops->au_name, setclientid.sc_name_len, setclientid.sc_name); status = rpc_call_sync(clp->cl_rpcclient, &msg, RPC_TASK_TIMEOUT); + trace_nfs4_setclientid(clp, status); dprintk("NFS reply setclientid: %d\n", status); return status; } @@ -4753,6 +4757,7 @@ int nfs4_proc_setclientid_confirm(struct nfs_client *clp, clp->cl_rpcclient->cl_auth->au_ops->au_name, clp->cl_clientid); status = rpc_call_sync(clp->cl_rpcclient, &msg, RPC_TASK_TIMEOUT); + trace_nfs4_setclientid_confirm(clp, status); dprintk("NFS reply setclientid_confirm: %d\n", status); return status; } @@ -5888,6 +5893,7 @@ int nfs4_proc_bind_conn_to_session(struct nfs_client *clp, struct rpc_cred *cred } status = rpc_call_sync(clp->cl_rpcclient, &msg, RPC_TASK_TIMEOUT); + trace_nfs4_bind_conn_to_session(clp, status); if (status == 0) { if (memcmp(res.session->sess_id.data, clp->cl_session->sess_id.data, NFS4_MAX_SESSIONID_LEN)) { @@ -5973,6 +5979,7 @@ int nfs4_proc_exchange_id(struct nfs_client *clp, struct rpc_cred *cred) } status = rpc_call_sync(clp->cl_rpcclient, &msg, RPC_TASK_TIMEOUT); + trace_nfs4_exchange_id(clp, status); if (status == 0) status = nfs4_check_cl_exchange_flags(res.flags); @@ -6033,6 +6040,7 @@ static int _nfs4_proc_destroy_clientid(struct nfs_client *clp, int status; status = rpc_call_sync(clp->cl_rpcclient, &msg, RPC_TASK_TIMEOUT); + trace_nfs4_destroy_clientid(clp, status); if (status) dprintk("NFS: Got error %d from the server %s on " "DESTROY_CLIENTID.", status, clp->cl_hostname); @@ -6296,6 +6304,7 @@ static int _nfs4_proc_create_session(struct nfs_client *clp, args.flags = (SESSION4_PERSIST | SESSION4_BACK_CHAN); status = rpc_call_sync(session->clp->cl_rpcclient, &msg, RPC_TASK_TIMEOUT); + trace_nfs4_create_session(clp, status); if (!status) { /* Verify the session's negotiated channel_attrs values */ @@ -6359,6 +6368,7 @@ int nfs4_proc_destroy_session(struct nfs4_session *session, return status; status = rpc_call_sync(session->clp->cl_rpcclient, &msg, RPC_TASK_TIMEOUT); + trace_nfs4_destroy_session(session->clp, status); if (status) dprintk("NFS: Got error %d from the server on DESTROY_SESSION. " @@ -6408,6 +6418,7 @@ static void nfs41_sequence_call_done(struct rpc_task *task, void *data) if (!nfs41_sequence_done(task, task->tk_msg.rpc_resp)) return; + trace_nfs4_sequence(clp, task->tk_status); if (task->tk_status < 0) { dprintk("%s ERROR %d\n", __func__, task->tk_status); if (atomic_read(&clp->cl_count) == 1) @@ -6560,6 +6571,7 @@ static void nfs4_reclaim_complete_done(struct rpc_task *task, void *data) if (!nfs41_sequence_done(task, res)) return; + trace_nfs4_reclaim_complete(clp, task->tk_status); if (nfs41_reclaim_complete_handle_errors(task, clp) == -EAGAIN) { rpc_restart_call_prepare(task); return; diff --git a/fs/nfs/nfs4trace.c b/fs/nfs/nfs4trace.c new file mode 100644 index 0000000..3f02183 --- /dev/null +++ b/fs/nfs/nfs4trace.c @@ -0,0 +1,10 @@ +/* + * Copyright (c) 2013 Trond Myklebust <Trond.Myklebust@netapp.com> + */ +#include <linux/nfs_fs.h> +#include "nfs4_fs.h" +#include "internal.h" + +#define CREATE_TRACE_POINTS +#include "nfs4trace.h" + diff --git a/fs/nfs/nfs4trace.h b/fs/nfs/nfs4trace.h new file mode 100644 index 0000000..9653feb --- /dev/null +++ b/fs/nfs/nfs4trace.h @@ -0,0 +1,220 @@ +/* + * Copyright (c) 2013 Trond Myklebust <Trond.Myklebust@netapp.com> + */ +#undef TRACE_SYSTEM +#define TRACE_SYSTEM nfs4 + +#if !defined(_TRACE_NFS4_H) || defined(TRACE_HEADER_MULTI_READ) +#define _TRACE_NFS4_H + +#include <linux/tracepoint.h> + +#define show_nfsv4_errors(error) \ + __print_symbolic(error, \ + { NFS4_OK, "OK" }, \ + /* Mapped by nfs4_stat_to_errno() */ \ + { -EPERM, "EPERM" }, \ + { -ENOENT, "ENOENT" }, \ + { -EIO, "EIO" }, \ + { -ENXIO, "ENXIO" }, \ + { -EACCES, "EACCES" }, \ + { -EEXIST, "EEXIST" }, \ + { -EXDEV, "EXDEV" }, \ + { -ENOTDIR, "ENOTDIR" }, \ + { -EISDIR, "EISDIR" }, \ + { -EFBIG, "EFBIG" }, \ + { -ENOSPC, "ENOSPC" }, \ + { -EROFS, "EROFS" }, \ + { -EMLINK, "EMLINK" }, \ + { -ENAMETOOLONG, "ENAMETOOLONG" }, \ + { -ENOTEMPTY, "ENOTEMPTY" }, \ + { -EDQUOT, "EDQUOT" }, \ + { -ESTALE, "ESTALE" }, \ + { -EBADHANDLE, "EBADHANDLE" }, \ + { -EBADCOOKIE, "EBADCOOKIE" }, \ + { -ENOTSUPP, "ENOTSUPP" }, \ + { -ETOOSMALL, "ETOOSMALL" }, \ + { -EREMOTEIO, "EREMOTEIO" }, \ + { -EBADTYPE, "EBADTYPE" }, \ + { -EAGAIN, "EAGAIN" }, \ + { -ELOOP, "ELOOP" }, \ + { -EOPNOTSUPP, "EOPNOTSUPP" }, \ + { -EDEADLK, "EDEADLK" }, \ + /* RPC errors */ \ + { -ENOMEM, "ENOMEM" }, \ + { -EKEYEXPIRED, "EKEYEXPIRED" }, \ + { -ETIMEDOUT, "ETIMEDOUT" }, \ + { -ERESTARTSYS, "ERESTARTSYS" }, \ + { -ECONNREFUSED, "ECONNREFUSED" }, \ + { -ECONNRESET, "ECONNRESET" }, \ + { -ENETUNREACH, "ENETUNREACH" }, \ + { -EHOSTUNREACH, "EHOSTUNREACH" }, \ + { -EHOSTDOWN, "EHOSTDOWN" }, \ + { -EPIPE, "EPIPE" }, \ + { -EPFNOSUPPORT, "EPFNOSUPPORT" }, \ + { -EPROTONOSUPPORT, "EPROTONOSUPPORT" }, \ + /* NFSv4 native errors */ \ + { -NFS4ERR_ACCESS, "ACCESS" }, \ + { -NFS4ERR_ATTRNOTSUPP, "ATTRNOTSUPP" }, \ + { -NFS4ERR_ADMIN_REVOKED, "ADMIN_REVOKED" }, \ + { -NFS4ERR_BACK_CHAN_BUSY, "BACK_CHAN_BUSY" }, \ + { -NFS4ERR_BADCHAR, "BADCHAR" }, \ + { -NFS4ERR_BADHANDLE, "BADHANDLE" }, \ + { -NFS4ERR_BADIOMODE, "BADIOMODE" }, \ + { -NFS4ERR_BADLAYOUT, "BADLAYOUT" }, \ + { -NFS4ERR_BADLABEL, "BADLABEL" }, \ + { -NFS4ERR_BADNAME, "BADNAME" }, \ + { -NFS4ERR_BADOWNER, "BADOWNER" }, \ + { -NFS4ERR_BADSESSION, "BADSESSION" }, \ + { -NFS4ERR_BADSLOT, "BADSLOT" }, \ + { -NFS4ERR_BADTYPE, "BADTYPE" }, \ + { -NFS4ERR_BADXDR, "BADXDR" }, \ + { -NFS4ERR_BAD_COOKIE, "BAD_COOKIE" }, \ + { -NFS4ERR_BAD_HIGH_SLOT, "BAD_HIGH_SLOT" }, \ + { -NFS4ERR_BAD_RANGE, "BAD_RANGE" }, \ + { -NFS4ERR_BAD_SEQID, "BAD_SEQID" }, \ + { -NFS4ERR_BAD_SESSION_DIGEST, "BAD_SESSION_DIGEST" }, \ + { -NFS4ERR_BAD_STATEID, "BAD_STATEID" }, \ + { -NFS4ERR_CB_PATH_DOWN, "CB_PATH_DOWN" }, \ + { -NFS4ERR_CLID_INUSE, "CLID_INUSE" }, \ + { -NFS4ERR_CLIENTID_BUSY, "CLIENTID_BUSY" }, \ + { -NFS4ERR_COMPLETE_ALREADY, "COMPLETE_ALREADY" }, \ + { -NFS4ERR_CONN_NOT_BOUND_TO_SESSION, \ + "CONN_NOT_BOUND_TO_SESSION" }, \ + { -NFS4ERR_DEADLOCK, "DEADLOCK" }, \ + { -NFS4ERR_DEADSESSION, "DEAD_SESSION" }, \ + { -NFS4ERR_DELAY, "DELAY" }, \ + { -NFS4ERR_DELEG_ALREADY_WANTED, \ + "DELEG_ALREADY_WANTED" }, \ + { -NFS4ERR_DELEG_REVOKED, "DELEG_REVOKED" }, \ + { -NFS4ERR_DENIED, "DENIED" }, \ + { -NFS4ERR_DIRDELEG_UNAVAIL, "DIRDELEG_UNAVAIL" }, \ + { -NFS4ERR_DQUOT, "DQUOT" }, \ + { -NFS4ERR_ENCR_ALG_UNSUPP, "ENCR_ALG_UNSUPP" }, \ + { -NFS4ERR_EXIST, "EXIST" }, \ + { -NFS4ERR_EXPIRED, "EXPIRED" }, \ + { -NFS4ERR_FBIG, "FBIG" }, \ + { -NFS4ERR_FHEXPIRED, "FHEXPIRED" }, \ + { -NFS4ERR_FILE_OPEN, "FILE_OPEN" }, \ + { -NFS4ERR_GRACE, "GRACE" }, \ + { -NFS4ERR_HASH_ALG_UNSUPP, "HASH_ALG_UNSUPP" }, \ + { -NFS4ERR_INVAL, "INVAL" }, \ + { -NFS4ERR_IO, "IO" }, \ + { -NFS4ERR_ISDIR, "ISDIR" }, \ + { -NFS4ERR_LAYOUTTRYLATER, "LAYOUTTRYLATER" }, \ + { -NFS4ERR_LAYOUTUNAVAILABLE, "LAYOUTUNAVAILABLE" }, \ + { -NFS4ERR_LEASE_MOVED, "LEASE_MOVED" }, \ + { -NFS4ERR_LOCKED, "LOCKED" }, \ + { -NFS4ERR_LOCKS_HELD, "LOCKS_HELD" }, \ + { -NFS4ERR_LOCK_RANGE, "LOCK_RANGE" }, \ + { -NFS4ERR_MINOR_VERS_MISMATCH, "MINOR_VERS_MISMATCH" }, \ + { -NFS4ERR_MLINK, "MLINK" }, \ + { -NFS4ERR_MOVED, "MOVED" }, \ + { -NFS4ERR_NAMETOOLONG, "NAMETOOLONG" }, \ + { -NFS4ERR_NOENT, "NOENT" }, \ + { -NFS4ERR_NOFILEHANDLE, "NOFILEHANDLE" }, \ + { -NFS4ERR_NOMATCHING_LAYOUT, "NOMATCHING_LAYOUT" }, \ + { -NFS4ERR_NOSPC, "NOSPC" }, \ + { -NFS4ERR_NOTDIR, "NOTDIR" }, \ + { -NFS4ERR_NOTEMPTY, "NOTEMPTY" }, \ + { -NFS4ERR_NOTSUPP, "NOTSUPP" }, \ + { -NFS4ERR_NOT_ONLY_OP, "NOT_ONLY_OP" }, \ + { -NFS4ERR_NOT_SAME, "NOT_SAME" }, \ + { -NFS4ERR_NO_GRACE, "NO_GRACE" }, \ + { -NFS4ERR_NXIO, "NXIO" }, \ + { -NFS4ERR_OLD_STATEID, "OLD_STATEID" }, \ + { -NFS4ERR_OPENMODE, "OPENMODE" }, \ + { -NFS4ERR_OP_ILLEGAL, "OP_ILLEGAL" }, \ + { -NFS4ERR_OP_NOT_IN_SESSION, "OP_NOT_IN_SESSION" }, \ + { -NFS4ERR_PERM, "PERM" }, \ + { -NFS4ERR_PNFS_IO_HOLE, "PNFS_IO_HOLE" }, \ + { -NFS4ERR_PNFS_NO_LAYOUT, "PNFS_NO_LAYOUT" }, \ + { -NFS4ERR_RECALLCONFLICT, "RECALLCONFLICT" }, \ + { -NFS4ERR_RECLAIM_BAD, "RECLAIM_BAD" }, \ + { -NFS4ERR_RECLAIM_CONFLICT, "RECLAIM_CONFLICT" }, \ + { -NFS4ERR_REJECT_DELEG, "REJECT_DELEG" }, \ + { -NFS4ERR_REP_TOO_BIG, "REP_TOO_BIG" }, \ + { -NFS4ERR_REP_TOO_BIG_TO_CACHE, \ + "REP_TOO_BIG_TO_CACHE" }, \ + { -NFS4ERR_REQ_TOO_BIG, "REQ_TOO_BIG" }, \ + { -NFS4ERR_RESOURCE, "RESOURCE" }, \ + { -NFS4ERR_RESTOREFH, "RESTOREFH" }, \ + { -NFS4ERR_RETRY_UNCACHED_REP, "RETRY_UNCACHED_REP" }, \ + { -NFS4ERR_RETURNCONFLICT, "RETURNCONFLICT" }, \ + { -NFS4ERR_ROFS, "ROFS" }, \ + { -NFS4ERR_SAME, "SAME" }, \ + { -NFS4ERR_SHARE_DENIED, "SHARE_DENIED" }, \ + { -NFS4ERR_SEQUENCE_POS, "SEQUENCE_POS" }, \ + { -NFS4ERR_SEQ_FALSE_RETRY, "SEQ_FALSE_RETRY" }, \ + { -NFS4ERR_SEQ_MISORDERED, "SEQ_MISORDERED" }, \ + { -NFS4ERR_SERVERFAULT, "SERVERFAULT" }, \ + { -NFS4ERR_STALE, "STALE" }, \ + { -NFS4ERR_STALE_CLIENTID, "STALE_CLIENTID" }, \ + { -NFS4ERR_STALE_STATEID, "STALE_STATEID" }, \ + { -NFS4ERR_SYMLINK, "SYMLINK" }, \ + { -NFS4ERR_TOOSMALL, "TOOSMALL" }, \ + { -NFS4ERR_TOO_MANY_OPS, "TOO_MANY_OPS" }, \ + { -NFS4ERR_UNKNOWN_LAYOUTTYPE, "UNKNOWN_LAYOUTTYPE" }, \ + { -NFS4ERR_UNSAFE_COMPOUND, "UNSAFE_COMPOUND" }, \ + { -NFS4ERR_WRONGSEC, "WRONGSEC" }, \ + { -NFS4ERR_WRONG_CRED, "WRONG_CRED" }, \ + { -NFS4ERR_WRONG_TYPE, "WRONG_TYPE" }, \ + { -NFS4ERR_XDEV, "XDEV" }) + +DECLARE_EVENT_CLASS(nfs4_clientid_event, + TP_PROTO( + const struct nfs_client *clp, + int error + ), + + TP_ARGS(clp, error), + + TP_STRUCT__entry( + __string(dstaddr, + rpc_peeraddr2str(clp->cl_rpcclient, + RPC_DISPLAY_ADDR)) + __field(int, error) + ), + + TP_fast_assign( + __entry->error = error; + __assign_str(dstaddr, + rpc_peeraddr2str(clp->cl_rpcclient, + RPC_DISPLAY_ADDR)); + ), + + TP_printk( + "error=%d (%s) dstaddr=%s", + __entry->error, + show_nfsv4_errors(__entry->error), + __get_str(dstaddr) + ) +); +#define DEFINE_NFS4_CLIENTID_EVENT(name) \ + DEFINE_EVENT(nfs4_clientid_event, name, \ + TP_PROTO( \ + const struct nfs_client *clp, \ + int error \ + ), \ + TP_ARGS(clp, error)) +DEFINE_NFS4_CLIENTID_EVENT(nfs4_setclientid); +DEFINE_NFS4_CLIENTID_EVENT(nfs4_setclientid_confirm); +DEFINE_NFS4_CLIENTID_EVENT(nfs4_renew); +DEFINE_NFS4_CLIENTID_EVENT(nfs4_renew_async); +#ifdef CONFIG_NFS_V4_1 +DEFINE_NFS4_CLIENTID_EVENT(nfs4_exchange_id); +DEFINE_NFS4_CLIENTID_EVENT(nfs4_create_session); +DEFINE_NFS4_CLIENTID_EVENT(nfs4_destroy_session); +DEFINE_NFS4_CLIENTID_EVENT(nfs4_destroy_clientid); +DEFINE_NFS4_CLIENTID_EVENT(nfs4_bind_conn_to_session); +DEFINE_NFS4_CLIENTID_EVENT(nfs4_sequence); +DEFINE_NFS4_CLIENTID_EVENT(nfs4_reclaim_complete); +#endif /* CONFIG_NFS_V4_1 */ + +#endif /* _TRACE_NFS4_H */ + +#undef TRACE_INCLUDE_PATH +#define TRACE_INCLUDE_PATH . +#define TRACE_INCLUDE_FILE nfs4trace +/* This part must be outside protection */ +#include <trace/define_trace.h> -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
* [PATCH v4 10/21] NFSv4: Add tracepoints for debugging file open 2013-08-22 0:24 ` [PATCH v4 09/21] NFSv4: Add tracepoints for debugging state management problems Trond Myklebust @ 2013-08-22 0:24 ` Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 11/21] NFSv4: Add tracepoints for debugging file locking Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:24 UTC (permalink / raw) To: linux-nfs Set up basic tracepoints for debugging NFSv4 file open/close Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/nfs4proc.c | 4 ++ fs/nfs/nfs4trace.h | 125 +++++++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 129 insertions(+) diff --git a/fs/nfs/nfs4proc.c b/fs/nfs/nfs4proc.c index f077487..ce37c68 100644 --- a/fs/nfs/nfs4proc.c +++ b/fs/nfs/nfs4proc.c @@ -1438,6 +1438,7 @@ static int nfs4_do_open_reclaim(struct nfs_open_context *ctx, struct nfs4_state int err; do { err = _nfs4_do_open_reclaim(ctx, state); + trace_nfs4_open_reclaim(ctx, 0, err); if (nfs4_clear_cap_atomic_open_v1(server, err, &exception)) continue; if (err != -NFS4ERR_DELAY) @@ -1893,6 +1894,7 @@ static int nfs4_do_open_expired(struct nfs_open_context *ctx, struct nfs4_state do { err = _nfs4_open_expired(ctx, state); + trace_nfs4_open_expired(ctx, 0, err); if (nfs4_clear_cap_atomic_open_v1(server, err, &exception)) continue; switch (err) { @@ -2195,6 +2197,7 @@ static struct nfs4_state *nfs4_do_open(struct inode *dir, do { status = _nfs4_do_open(dir, ctx, flags, sattr, label); res = ctx->state; + trace_nfs4_open_file(ctx, flags, status); if (status == 0) break; /* NOTE: BAD_SEQID means the server and client disagree about the @@ -2385,6 +2388,7 @@ static void nfs4_close_done(struct rpc_task *task, void *data) dprintk("%s: begin!\n", __func__); if (!nfs4_sequence_done(task, &calldata->res.seq_res)) return; + trace_nfs4_close(state, &calldata->arg, &calldata->res, task->tk_status); /* hmm. we are done with the inode, and in the process of freeing * the state_owner. we keep this around to process errors */ diff --git a/fs/nfs/nfs4trace.h b/fs/nfs/nfs4trace.h index 9653feb..a558dc9 100644 --- a/fs/nfs/nfs4trace.h +++ b/fs/nfs/nfs4trace.h @@ -161,6 +161,19 @@ { -NFS4ERR_WRONG_TYPE, "WRONG_TYPE" }, \ { -NFS4ERR_XDEV, "XDEV" }) +#define show_open_flags(flags) \ + __print_flags(flags, "|", \ + { O_CREAT, "O_CREAT" }, \ + { O_EXCL, "O_EXCL" }, \ + { O_TRUNC, "O_TRUNC" }, \ + { O_DIRECT, "O_DIRECT" }) + +#define show_fmode_flags(mode) \ + __print_flags(mode, "|", \ + { ((__force unsigned long)FMODE_READ), "READ" }, \ + { ((__force unsigned long)FMODE_WRITE), "WRITE" }, \ + { ((__force unsigned long)FMODE_EXEC), "EXEC" }) + DECLARE_EVENT_CLASS(nfs4_clientid_event, TP_PROTO( const struct nfs_client *clp, @@ -211,6 +224,118 @@ DEFINE_NFS4_CLIENTID_EVENT(nfs4_sequence); DEFINE_NFS4_CLIENTID_EVENT(nfs4_reclaim_complete); #endif /* CONFIG_NFS_V4_1 */ +DECLARE_EVENT_CLASS(nfs4_open_event, + TP_PROTO( + const struct nfs_open_context *ctx, + int flags, + int error + ), + + TP_ARGS(ctx, flags, error), + + TP_STRUCT__entry( + __field(int, error) + __field(unsigned int, flags) + __field(unsigned int, fmode) + __field(dev_t, dev) + __field(u32, fhandle) + __field(u64, fileid) + __field(u64, dir) + __string(name, ctx->dentry->d_name.name) + ), + + TP_fast_assign( + const struct nfs4_state *state = ctx->state; + const struct inode *inode = NULL; + + __entry->error = error; + __entry->flags = flags; + __entry->fmode = (__force unsigned int)ctx->mode; + __entry->dev = ctx->dentry->d_sb->s_dev; + if (!IS_ERR(state)) + inode = state->inode; + if (inode != NULL) { + __entry->fileid = NFS_FILEID(inode); + __entry->fhandle = nfs_fhandle_hash(NFS_FH(inode)); + } else { + __entry->fileid = 0; + __entry->fhandle = 0; + } + __entry->dir = NFS_FILEID(ctx->dentry->d_parent->d_inode); + __assign_str(name, ctx->dentry->d_name.name); + ), + + TP_printk( + "error=%d (%s) flags=%d (%s) fmode=%s " + "fileid=%02x:%02x:%llu fhandle=0x%08x " + "name=%02x:%02x:%llu/%s", + __entry->error, + show_nfsv4_errors(__entry->error), + __entry->flags, + show_open_flags(__entry->flags), + show_fmode_flags(__entry->fmode), + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->fileid, + __entry->fhandle, + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->dir, + __get_str(name) + ) +); + +#define DEFINE_NFS4_OPEN_EVENT(name) \ + DEFINE_EVENT(nfs4_open_event, name, \ + TP_PROTO( \ + const struct nfs_open_context *ctx, \ + int flags, \ + int error \ + ), \ + TP_ARGS(ctx, flags, error)) +DEFINE_NFS4_OPEN_EVENT(nfs4_open_reclaim); +DEFINE_NFS4_OPEN_EVENT(nfs4_open_expired); +DEFINE_NFS4_OPEN_EVENT(nfs4_open_file); + +TRACE_EVENT(nfs4_close, + TP_PROTO( + const struct nfs4_state *state, + const struct nfs_closeargs *args, + const struct nfs_closeres *res, + int error + ), + + TP_ARGS(state, args, res, error), + + TP_STRUCT__entry( + __field(dev_t, dev) + __field(u32, fhandle) + __field(u64, fileid) + __field(unsigned int, fmode) + __field(int, error) + ), + + TP_fast_assign( + const struct inode *inode = state->inode; + + __entry->dev = inode->i_sb->s_dev; + __entry->fileid = NFS_FILEID(inode); + __entry->fhandle = nfs_fhandle_hash(NFS_FH(inode)); + __entry->fmode = (__force unsigned int)state->state; + __entry->error = error; + ), + + TP_printk( + "error=%d (%s) fmode=%s fileid=%02x:%02x:%llu " + "fhandle=0x%08x", + __entry->error, + show_nfsv4_errors(__entry->error), + __entry->fmode ? show_fmode_flags(__entry->fmode) : + "closed", + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->fileid, + __entry->fhandle + ) +); + #endif /* _TRACE_NFS4_H */ #undef TRACE_INCLUDE_PATH -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
* [PATCH v4 11/21] NFSv4: Add tracepoints for debugging file locking 2013-08-22 0:24 ` [PATCH v4 10/21] NFSv4: Add tracepoints for debugging file open Trond Myklebust @ 2013-08-22 0:24 ` Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 12/21] NFSv4: Add tracepoints for debugging lookup/create operations Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:24 UTC (permalink / raw) To: linux-nfs Set up basic tracepoints for debugging NFSv4 file lock/unlock Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/nfs4proc.c | 9 +++++-- fs/nfs/nfs4trace.h | 75 ++++++++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 82 insertions(+), 2 deletions(-) diff --git a/fs/nfs/nfs4proc.c b/fs/nfs/nfs4proc.c index ce37c68..0b27837 100644 --- a/fs/nfs/nfs4proc.c +++ b/fs/nfs/nfs4proc.c @@ -4960,8 +4960,9 @@ static int nfs4_proc_getlk(struct nfs4_state *state, int cmd, struct file_lock * int err; do { - err = nfs4_handle_exception(NFS_SERVER(state->inode), - _nfs4_proc_getlk(state, cmd, request), + err = _nfs4_proc_getlk(state, cmd, request); + trace_nfs4_get_lock(request, state, cmd, err); + err = nfs4_handle_exception(NFS_SERVER(state->inode), err, &exception); } while (exception.retry); return err; @@ -5159,6 +5160,7 @@ static int nfs4_proc_unlck(struct nfs4_state *state, int cmd, struct file_lock * rpc_put_task(task); out: request->fl_flags = fl_flags; + trace_nfs4_unlock(request, state, F_SETLK, status); return status; } @@ -5382,6 +5384,7 @@ static int nfs4_lock_reclaim(struct nfs4_state *state, struct file_lock *request if (test_bit(NFS_DELEGATED_STATE, &state->flags) != 0) return 0; err = _nfs4_do_setlk(state, F_SETLK, request, NFS_LOCK_RECLAIM); + trace_nfs4_lock_reclaim(request, state, F_SETLK, err); if (err != -NFS4ERR_DELAY) break; nfs4_handle_exception(server, err, &exception); @@ -5404,6 +5407,7 @@ static int nfs4_lock_expired(struct nfs4_state *state, struct file_lock *request if (test_bit(NFS_DELEGATED_STATE, &state->flags) != 0) return 0; err = _nfs4_do_setlk(state, F_SETLK, request, NFS_LOCK_EXPIRED); + trace_nfs4_lock_expired(request, state, F_SETLK, err); switch (err) { default: goto out; @@ -5526,6 +5530,7 @@ static int nfs4_proc_setlk(struct nfs4_state *state, int cmd, struct file_lock * do { err = _nfs4_proc_setlk(state, cmd, request); + trace_nfs4_set_lock(request, state, cmd, err); if (err == -NFS4ERR_DENIED) err = -EAGAIN; err = nfs4_handle_exception(NFS_SERVER(state->inode), diff --git a/fs/nfs/nfs4trace.h b/fs/nfs/nfs4trace.h index a558dc9..3f124db 100644 --- a/fs/nfs/nfs4trace.h +++ b/fs/nfs/nfs4trace.h @@ -336,6 +336,81 @@ TRACE_EVENT(nfs4_close, ) ); +#define show_lock_cmd(type) \ + __print_symbolic((int)type, \ + { F_GETLK, "GETLK" }, \ + { F_SETLK, "SETLK" }, \ + { F_SETLKW, "SETLKW" }) +#define show_lock_type(type) \ + __print_symbolic((int)type, \ + { F_RDLCK, "RDLCK" }, \ + { F_WRLCK, "WRLCK" }, \ + { F_UNLCK, "UNLCK" }) + +DECLARE_EVENT_CLASS(nfs4_lock_event, + TP_PROTO( + const struct file_lock *request, + const struct nfs4_state *state, + int cmd, + int error + ), + + TP_ARGS(request, state, cmd, error), + + TP_STRUCT__entry( + __field(int, error) + __field(int, cmd) + __field(char, type) + __field(loff_t, start) + __field(loff_t, end) + __field(dev_t, dev) + __field(u32, fhandle) + __field(u64, fileid) + ), + + TP_fast_assign( + const struct inode *inode = state->inode; + + __entry->error = error; + __entry->cmd = cmd; + __entry->type = request->fl_type; + __entry->start = request->fl_start; + __entry->end = request->fl_end; + __entry->dev = inode->i_sb->s_dev; + __entry->fileid = NFS_FILEID(inode); + __entry->fhandle = nfs_fhandle_hash(NFS_FH(inode)); + ), + + TP_printk( + "error=%d (%s) cmd=%s:%s range=%lld:%lld " + "fileid=%02x:%02x:%llu fhandle=0x%08x", + __entry->error, + show_nfsv4_errors(__entry->error), + show_lock_cmd(__entry->cmd), + show_lock_type(__entry->type), + (long long)__entry->start, + (long long)__entry->end, + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->fileid, + __entry->fhandle + ) +); + +#define DEFINE_NFS4_LOCK_EVENT(name) \ + DEFINE_EVENT(nfs4_lock_event, name, \ + TP_PROTO( \ + const struct file_lock *request, \ + const struct nfs4_state *state, \ + int cmd, \ + int error \ + ), \ + TP_ARGS(request, state, cmd, error)) +DEFINE_NFS4_LOCK_EVENT(nfs4_get_lock); +DEFINE_NFS4_LOCK_EVENT(nfs4_set_lock); +DEFINE_NFS4_LOCK_EVENT(nfs4_lock_reclaim); +DEFINE_NFS4_LOCK_EVENT(nfs4_lock_expired); +DEFINE_NFS4_LOCK_EVENT(nfs4_unlock); + #endif /* _TRACE_NFS4_H */ #undef TRACE_INCLUDE_PATH -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
* [PATCH v4 12/21] NFSv4: Add tracepoints for debugging lookup/create operations 2013-08-22 0:24 ` [PATCH v4 11/21] NFSv4: Add tracepoints for debugging file locking Trond Myklebust @ 2013-08-22 0:24 ` Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 13/21] NFSv4: Add tracepoints for debugging inode manipulations Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:24 UTC (permalink / raw) To: linux-nfs Set up basic tracepoints for debugging NFSv4 lookup, unlink/remove, symlink, mkdir, mknod, fs_locations and secinfo. Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/nfs4proc.c | 36 ++++++++++++++++++++++-------------- fs/nfs/nfs4trace.h | 50 ++++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 72 insertions(+), 14 deletions(-) diff --git a/fs/nfs/nfs4proc.c b/fs/nfs/nfs4proc.c index 0b27837..9ff50a5 100644 --- a/fs/nfs/nfs4proc.c +++ b/fs/nfs/nfs4proc.c @@ -3022,6 +3022,7 @@ static int nfs4_proc_lookup_common(struct rpc_clnt **clnt, struct inode *dir, int err; do { err = _nfs4_proc_lookup(client, dir, name, fhandle, fattr, label); + trace_nfs4_lookup(dir, name, err); switch (err) { case -NFS4ERR_BADNAME: err = -ENOENT; @@ -3257,8 +3258,9 @@ static int nfs4_proc_remove(struct inode *dir, struct qstr *name) struct nfs4_exception exception = { }; int err; do { - err = nfs4_handle_exception(NFS_SERVER(dir), - _nfs4_proc_remove(dir, name), + err = _nfs4_proc_remove(dir, name); + trace_nfs4_remove(dir, name, err); + err = nfs4_handle_exception(NFS_SERVER(dir), err, &exception); } while (exception.retry); return err; @@ -3287,7 +3289,8 @@ static void nfs4_proc_unlink_rpc_prepare(struct rpc_task *task, struct nfs_unlin static int nfs4_proc_unlink_done(struct rpc_task *task, struct inode *dir) { - struct nfs_removeres *res = task->tk_msg.rpc_resp; + struct nfs_unlinkdata *data = task->tk_calldata; + struct nfs_removeres *res = &data->res; if (!nfs4_sequence_done(task, &res->seq_res)) return 0; @@ -3529,9 +3532,9 @@ static int nfs4_proc_symlink(struct inode *dir, struct dentry *dentry, label = nfs4_label_init_security(dir, dentry, sattr, &l); do { - err = nfs4_handle_exception(NFS_SERVER(dir), - _nfs4_proc_symlink(dir, dentry, page, - len, sattr, label), + err = _nfs4_proc_symlink(dir, dentry, page, len, sattr, label); + trace_nfs4_symlink(dir, &dentry->d_name, err); + err = nfs4_handle_exception(NFS_SERVER(dir), err, &exception); } while (exception.retry); @@ -3568,8 +3571,9 @@ static int nfs4_proc_mkdir(struct inode *dir, struct dentry *dentry, sattr->ia_mode &= ~current_umask(); do { - err = nfs4_handle_exception(NFS_SERVER(dir), - _nfs4_proc_mkdir(dir, dentry, sattr, label), + err = _nfs4_proc_mkdir(dir, dentry, sattr, label); + trace_nfs4_mkdir(dir, &dentry->d_name, err); + err = nfs4_handle_exception(NFS_SERVER(dir), err, &exception); } while (exception.retry); nfs4_label_release_security(label); @@ -3676,8 +3680,9 @@ static int nfs4_proc_mknod(struct inode *dir, struct dentry *dentry, sattr->ia_mode &= ~current_umask(); do { - err = nfs4_handle_exception(NFS_SERVER(dir), - _nfs4_proc_mknod(dir, dentry, sattr, label, rdev), + err = _nfs4_proc_mknod(dir, dentry, sattr, label, rdev); + trace_nfs4_mknod(dir, &dentry->d_name, err); + err = nfs4_handle_exception(NFS_SERVER(dir), err, &exception); } while (exception.retry); @@ -5797,8 +5802,10 @@ int nfs4_proc_fs_locations(struct rpc_clnt *client, struct inode *dir, struct nfs4_exception exception = { }; int err; do { - err = nfs4_handle_exception(NFS_SERVER(dir), - _nfs4_proc_fs_locations(client, dir, name, fs_locations, page), + err = _nfs4_proc_fs_locations(client, dir, name, + fs_locations, page); + trace_nfs4_get_fs_locations(dir, name, err); + err = nfs4_handle_exception(NFS_SERVER(dir), err, &exception); } while (exception.retry); return err; @@ -5837,8 +5844,9 @@ int nfs4_proc_secinfo(struct inode *dir, const struct qstr *name, struct nfs4_exception exception = { }; int err; do { - err = nfs4_handle_exception(NFS_SERVER(dir), - _nfs4_proc_secinfo(dir, name, flavors), + err = _nfs4_proc_secinfo(dir, name, flavors); + trace_nfs4_secinfo(dir, name, err); + err = nfs4_handle_exception(NFS_SERVER(dir), err, &exception); } while (exception.retry); return err; diff --git a/fs/nfs/nfs4trace.h b/fs/nfs/nfs4trace.h index 3f124db..2646a50 100644 --- a/fs/nfs/nfs4trace.h +++ b/fs/nfs/nfs4trace.h @@ -411,6 +411,56 @@ DEFINE_NFS4_LOCK_EVENT(nfs4_lock_reclaim); DEFINE_NFS4_LOCK_EVENT(nfs4_lock_expired); DEFINE_NFS4_LOCK_EVENT(nfs4_unlock); +DECLARE_EVENT_CLASS(nfs4_lookup_event, + TP_PROTO( + const struct inode *dir, + const struct qstr *name, + int error + ), + + TP_ARGS(dir, name, error), + + TP_STRUCT__entry( + __field(dev_t, dev) + __field(int, error) + __field(u64, dir) + __string(name, name->name) + ), + + TP_fast_assign( + __entry->dev = dir->i_sb->s_dev; + __entry->dir = NFS_FILEID(dir); + __entry->error = error; + __assign_str(name, name->name); + ), + + TP_printk( + "error=%d (%s) name=%02x:%02x:%llu/%s", + __entry->error, + show_nfsv4_errors(__entry->error), + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->dir, + __get_str(name) + ) +); + +#define DEFINE_NFS4_LOOKUP_EVENT(name) \ + DEFINE_EVENT(nfs4_lookup_event, name, \ + TP_PROTO( \ + const struct inode *dir, \ + const struct qstr *name, \ + int error \ + ), \ + TP_ARGS(dir, name, error)) + +DEFINE_NFS4_LOOKUP_EVENT(nfs4_lookup); +DEFINE_NFS4_LOOKUP_EVENT(nfs4_symlink); +DEFINE_NFS4_LOOKUP_EVENT(nfs4_mkdir); +DEFINE_NFS4_LOOKUP_EVENT(nfs4_mknod); +DEFINE_NFS4_LOOKUP_EVENT(nfs4_remove); +DEFINE_NFS4_LOOKUP_EVENT(nfs4_get_fs_locations); +DEFINE_NFS4_LOOKUP_EVENT(nfs4_secinfo); + #endif /* _TRACE_NFS4_H */ #undef TRACE_INCLUDE_PATH -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
* [PATCH v4 13/21] NFSv4: Add tracepoints for debugging inode manipulations 2013-08-22 0:24 ` [PATCH v4 12/21] NFSv4: Add tracepoints for debugging lookup/create operations Trond Myklebust @ 2013-08-22 0:24 ` Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 14/21] NFSv4: Add tracepoints for debugging rename Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:24 UTC (permalink / raw) To: linux-nfs Set up basic tracepoints for debugging NFSv4 setattr, access, readlink, readdir, get_acl set_acl get_security_label, and set_security_label. Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/nfs4proc.c | 36 ++++++++++++++++++++++-------------- fs/nfs/nfs4trace.h | 51 +++++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 73 insertions(+), 14 deletions(-) diff --git a/fs/nfs/nfs4proc.c b/fs/nfs/nfs4proc.c index 9ff50a5..42a0b7f 100644 --- a/fs/nfs/nfs4proc.c +++ b/fs/nfs/nfs4proc.c @@ -2311,6 +2311,7 @@ static int nfs4_do_setattr(struct inode *inode, struct rpc_cred *cred, int err; do { err = _nfs4_do_setattr(inode, cred, fattr, sattr, state, ilabel, olabel); + trace_nfs4_setattr(inode, err); switch (err) { case -NFS4ERR_OPENMODE: if (!(sattr->ia_valid & ATTR_SIZE)) { @@ -3139,8 +3140,9 @@ static int nfs4_proc_access(struct inode *inode, struct nfs_access_entry *entry) struct nfs4_exception exception = { }; int err; do { - err = nfs4_handle_exception(NFS_SERVER(inode), - _nfs4_proc_access(inode, entry), + err = _nfs4_proc_access(inode, entry); + trace_nfs4_access(inode, err); + err = nfs4_handle_exception(NFS_SERVER(inode), err, &exception); } while (exception.retry); return err; @@ -3193,8 +3195,9 @@ static int nfs4_proc_readlink(struct inode *inode, struct page *page, struct nfs4_exception exception = { }; int err; do { - err = nfs4_handle_exception(NFS_SERVER(inode), - _nfs4_proc_readlink(inode, page, pgbase, pglen), + err = _nfs4_proc_readlink(inode, page, pgbase, pglen); + trace_nfs4_readlink(inode, err); + err = nfs4_handle_exception(NFS_SERVER(inode), err, &exception); } while (exception.retry); return err; @@ -3626,9 +3629,10 @@ static int nfs4_proc_readdir(struct dentry *dentry, struct rpc_cred *cred, struct nfs4_exception exception = { }; int err; do { - err = nfs4_handle_exception(NFS_SERVER(dentry->d_inode), - _nfs4_proc_readdir(dentry, cred, cookie, - pages, count, plus), + err = _nfs4_proc_readdir(dentry, cred, cookie, + pages, count, plus); + trace_nfs4_readdir(dentry->d_inode, err); + err = nfs4_handle_exception(NFS_SERVER(dentry->d_inode), err, &exception); } while (exception.retry); return err; @@ -4329,6 +4333,7 @@ static ssize_t nfs4_get_acl_uncached(struct inode *inode, void *buf, size_t bufl ssize_t ret; do { ret = __nfs4_get_acl_uncached(inode, buf, buflen); + trace_nfs4_get_acl(inode, ret); if (ret >= 0) break; ret = nfs4_handle_exception(NFS_SERVER(inode), ret, &exception); @@ -4408,8 +4413,9 @@ static int nfs4_proc_set_acl(struct inode *inode, const void *buf, size_t buflen struct nfs4_exception exception = { }; int err; do { - err = nfs4_handle_exception(NFS_SERVER(inode), - __nfs4_proc_set_acl(inode, buf, buflen), + err = __nfs4_proc_set_acl(inode, buf, buflen); + trace_nfs4_set_acl(inode, err); + err = nfs4_handle_exception(NFS_SERVER(inode), err, &exception); } while (exception.retry); return err; @@ -4462,8 +4468,9 @@ static int nfs4_get_security_label(struct inode *inode, void *buf, return -EOPNOTSUPP; do { - err = nfs4_handle_exception(NFS_SERVER(inode), - _nfs4_get_security_label(inode, buf, buflen), + err = _nfs4_get_security_label(inode, buf, buflen); + trace_nfs4_get_security_label(inode, err); + err = nfs4_handle_exception(NFS_SERVER(inode), err, &exception); } while (exception.retry); return err; @@ -4515,9 +4522,10 @@ static int nfs4_do_set_security_label(struct inode *inode, int err; do { - err = nfs4_handle_exception(NFS_SERVER(inode), - _nfs4_do_set_security_label(inode, ilabel, - fattr, olabel), + err = _nfs4_do_set_security_label(inode, ilabel, + fattr, olabel); + trace_nfs4_set_security_label(inode, err); + err = nfs4_handle_exception(NFS_SERVER(inode), err, &exception); } while (exception.retry); return err; diff --git a/fs/nfs/nfs4trace.h b/fs/nfs/nfs4trace.h index 2646a50..6bd65c2 100644 --- a/fs/nfs/nfs4trace.h +++ b/fs/nfs/nfs4trace.h @@ -461,6 +461,57 @@ DEFINE_NFS4_LOOKUP_EVENT(nfs4_remove); DEFINE_NFS4_LOOKUP_EVENT(nfs4_get_fs_locations); DEFINE_NFS4_LOOKUP_EVENT(nfs4_secinfo); +DECLARE_EVENT_CLASS(nfs4_inode_event, + TP_PROTO( + const struct inode *inode, + int error + ), + + TP_ARGS(inode, error), + + TP_STRUCT__entry( + __field(dev_t, dev) + __field(u32, fhandle) + __field(u64, fileid) + __field(int, error) + ), + + TP_fast_assign( + __entry->dev = inode->i_sb->s_dev; + __entry->fileid = NFS_FILEID(inode); + __entry->fhandle = nfs_fhandle_hash(NFS_FH(inode)); + __entry->error = error; + ), + + TP_printk( + "error=%d (%s) fileid=%02x:%02x:%llu fhandle=0x%08x", + __entry->error, + show_nfsv4_errors(__entry->error), + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->fileid, + __entry->fhandle + ) +); + +#define DEFINE_NFS4_INODE_EVENT(name) \ + DEFINE_EVENT(nfs4_inode_event, name, \ + TP_PROTO( \ + const struct inode *inode, \ + int error \ + ), \ + TP_ARGS(inode, error)) + +DEFINE_NFS4_INODE_EVENT(nfs4_setattr); +DEFINE_NFS4_INODE_EVENT(nfs4_access); +DEFINE_NFS4_INODE_EVENT(nfs4_readlink); +DEFINE_NFS4_INODE_EVENT(nfs4_readdir); +DEFINE_NFS4_INODE_EVENT(nfs4_get_acl); +DEFINE_NFS4_INODE_EVENT(nfs4_set_acl); +#ifdef CONFIG_NFS_V4_SECURITY_LABEL +DEFINE_NFS4_INODE_EVENT(nfs4_get_security_label); +DEFINE_NFS4_INODE_EVENT(nfs4_set_security_label); +#endif /* CONFIG_NFS_V4_SECURITY_LABEL */ + #endif /* _TRACE_NFS4_H */ #undef TRACE_INCLUDE_PATH -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
* [PATCH v4 14/21] NFSv4: Add tracepoints for debugging rename 2013-08-22 0:24 ` [PATCH v4 13/21] NFSv4: Add tracepoints for debugging inode manipulations Trond Myklebust @ 2013-08-22 0:24 ` Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 15/21] NFSv4: Add tracepoints for debugging delegations Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:24 UTC (permalink / raw) To: linux-nfs Add tracepoints to debug renames. Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/nfs4proc.c | 10 ++++++---- fs/nfs/nfs4trace.h | 43 +++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 49 insertions(+), 4 deletions(-) diff --git a/fs/nfs/nfs4proc.c b/fs/nfs/nfs4proc.c index 42a0b7f..3910ee6 100644 --- a/fs/nfs/nfs4proc.c +++ b/fs/nfs/nfs4proc.c @@ -3325,7 +3325,8 @@ static void nfs4_proc_rename_rpc_prepare(struct rpc_task *task, struct nfs_renam static int nfs4_proc_rename_done(struct rpc_task *task, struct inode *old_dir, struct inode *new_dir) { - struct nfs_renameres *res = task->tk_msg.rpc_resp; + struct nfs_renamedata *data = task->tk_calldata; + struct nfs_renameres *res = &data->res; if (!nfs4_sequence_done(task, &res->seq_res)) return 0; @@ -3371,9 +3372,10 @@ static int nfs4_proc_rename(struct inode *old_dir, struct qstr *old_name, struct nfs4_exception exception = { }; int err; do { - err = nfs4_handle_exception(NFS_SERVER(old_dir), - _nfs4_proc_rename(old_dir, old_name, - new_dir, new_name), + err = _nfs4_proc_rename(old_dir, old_name, + new_dir, new_name); + trace_nfs4_rename(old_dir, old_name, new_dir, new_name, err); + err = nfs4_handle_exception(NFS_SERVER(old_dir), err, &exception); } while (exception.retry); return err; diff --git a/fs/nfs/nfs4trace.h b/fs/nfs/nfs4trace.h index 6bd65c2..6388db8 100644 --- a/fs/nfs/nfs4trace.h +++ b/fs/nfs/nfs4trace.h @@ -461,6 +461,49 @@ DEFINE_NFS4_LOOKUP_EVENT(nfs4_remove); DEFINE_NFS4_LOOKUP_EVENT(nfs4_get_fs_locations); DEFINE_NFS4_LOOKUP_EVENT(nfs4_secinfo); +TRACE_EVENT(nfs4_rename, + TP_PROTO( + const struct inode *olddir, + const struct qstr *oldname, + const struct inode *newdir, + const struct qstr *newname, + int error + ), + + TP_ARGS(olddir, oldname, newdir, newname, error), + + TP_STRUCT__entry( + __field(dev_t, dev) + __field(int, error) + __field(u64, olddir) + __string(oldname, oldname->name) + __field(u64, newdir) + __string(newname, newname->name) + ), + + TP_fast_assign( + __entry->dev = olddir->i_sb->s_dev; + __entry->olddir = NFS_FILEID(olddir); + __entry->newdir = NFS_FILEID(newdir); + __entry->error = error; + __assign_str(oldname, oldname->name); + __assign_str(newname, newname->name); + ), + + TP_printk( + "error=%d (%s) oldname=%02x:%02x:%llu/%s " + "newname=%02x:%02x:%llu/%s", + __entry->error, + show_nfsv4_errors(__entry->error), + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->olddir, + __get_str(oldname), + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->newdir, + __get_str(newname) + ) +); + DECLARE_EVENT_CLASS(nfs4_inode_event, TP_PROTO( const struct inode *inode, -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
* [PATCH v4 15/21] NFSv4: Add tracepoints for debugging delegations 2013-08-22 0:24 ` [PATCH v4 14/21] NFSv4: Add tracepoints for debugging rename Trond Myklebust @ 2013-08-22 0:24 ` Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 16/21] NFSv4: Add tracepoints for debugging the idmapper Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:24 UTC (permalink / raw) To: linux-nfs Set up tracepoints to track when delegations are set, reclaimed, returned by the client, or recalled by the server. Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/callback_proc.c | 2 ++ fs/nfs/delegation.c | 3 +++ fs/nfs/nfs4proc.c | 2 ++ fs/nfs/nfs4trace.h | 72 ++++++++++++++++++++++++++++++++++++++++++++++++++ 4 files changed, 79 insertions(+) diff --git a/fs/nfs/callback_proc.c b/fs/nfs/callback_proc.c index e6ebc4c..c074930 100644 --- a/fs/nfs/callback_proc.c +++ b/fs/nfs/callback_proc.c @@ -15,6 +15,7 @@ #include "internal.h" #include "pnfs.h" #include "nfs4session.h" +#include "nfs4trace.h" #ifdef NFS_DEBUG #define NFSDBG_FACILITY NFSDBG_CALLBACK @@ -93,6 +94,7 @@ __be32 nfs4_callback_recall(struct cb_recallargs *args, void *dummy, default: res = htonl(NFS4ERR_RESOURCE); } + trace_nfs4_recall_delegation(inode, -ntohl(res)); iput(inode); out: dprintk("%s: exit with status = %d\n", __func__, ntohl(res)); diff --git a/fs/nfs/delegation.c b/fs/nfs/delegation.c index 7ec4814..ef792f2 100644 --- a/fs/nfs/delegation.c +++ b/fs/nfs/delegation.c @@ -20,6 +20,7 @@ #include "nfs4_fs.h" #include "delegation.h" #include "internal.h" +#include "nfs4trace.h" static void nfs_free_delegation(struct nfs_delegation *delegation) { @@ -160,6 +161,7 @@ void nfs_inode_reclaim_delegation(struct inode *inode, struct rpc_cred *cred, spin_unlock(&delegation->lock); put_rpccred(oldcred); rcu_read_unlock(); + trace_nfs4_reclaim_delegation(inode, res->delegation_type); } else { /* We appear to have raced with a delegation return. */ spin_unlock(&delegation->lock); @@ -344,6 +346,7 @@ int nfs_inode_set_delegation(struct inode *inode, struct rpc_cred *cred, struct spin_lock(&inode->i_lock); nfsi->cache_validity |= NFS_INO_REVAL_FORCED; spin_unlock(&inode->i_lock); + trace_nfs4_set_delegation(inode, res->delegation_type); out: spin_unlock(&clp->cl_lock); diff --git a/fs/nfs/nfs4proc.c b/fs/nfs/nfs4proc.c index 3910ee6..e3ac877 100644 --- a/fs/nfs/nfs4proc.c +++ b/fs/nfs/nfs4proc.c @@ -4798,6 +4798,7 @@ static void nfs4_delegreturn_done(struct rpc_task *task, void *calldata) if (!nfs4_sequence_done(task, &data->res.seq_res)) return; + trace_nfs4_delegreturn_exit(&data->args, &data->res, task->tk_status); switch (task->tk_status) { case -NFS4ERR_STALE_STATEID: case -NFS4ERR_EXPIRED: @@ -4901,6 +4902,7 @@ int nfs4_proc_delegreturn(struct inode *inode, struct rpc_cred *cred, const nfs4 int err; do { err = _nfs4_proc_delegreturn(inode, cred, stateid, issync); + trace_nfs4_delegreturn(inode, err); switch (err) { case -NFS4ERR_STALE_STATEID: case -NFS4ERR_EXPIRED: diff --git a/fs/nfs/nfs4trace.h b/fs/nfs/nfs4trace.h index 6388db8..900f233 100644 --- a/fs/nfs/nfs4trace.h +++ b/fs/nfs/nfs4trace.h @@ -411,6 +411,76 @@ DEFINE_NFS4_LOCK_EVENT(nfs4_lock_reclaim); DEFINE_NFS4_LOCK_EVENT(nfs4_lock_expired); DEFINE_NFS4_LOCK_EVENT(nfs4_unlock); +DECLARE_EVENT_CLASS(nfs4_set_delegation_event, + TP_PROTO( + const struct inode *inode, + fmode_t fmode + ), + + TP_ARGS(inode, fmode), + + TP_STRUCT__entry( + __field(dev_t, dev) + __field(u32, fhandle) + __field(u64, fileid) + __field(unsigned int, fmode) + ), + + TP_fast_assign( + __entry->dev = inode->i_sb->s_dev; + __entry->fileid = NFS_FILEID(inode); + __entry->fhandle = nfs_fhandle_hash(NFS_FH(inode)); + __entry->fmode = (__force unsigned int)fmode; + ), + + TP_printk( + "fmode=%s fileid=%02x:%02x:%llu fhandle=0x%08x", + show_fmode_flags(__entry->fmode), + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->fileid, + __entry->fhandle + ) +); +#define DEFINE_NFS4_SET_DELEGATION_EVENT(name) \ + DEFINE_EVENT(nfs4_set_delegation_event, name, \ + TP_PROTO( \ + const struct inode *inode, \ + fmode_t fmode \ + ), \ + TP_ARGS(inode, fmode)) +DEFINE_NFS4_SET_DELEGATION_EVENT(nfs4_set_delegation); +DEFINE_NFS4_SET_DELEGATION_EVENT(nfs4_reclaim_delegation); + +TRACE_EVENT(nfs4_delegreturn_exit, + TP_PROTO( + const struct nfs4_delegreturnargs *args, + const struct nfs4_delegreturnres *res, + int error + ), + + TP_ARGS(args, res, error), + + TP_STRUCT__entry( + __field(dev_t, dev) + __field(u32, fhandle) + __field(int, error) + ), + + TP_fast_assign( + __entry->dev = res->server->s_dev; + __entry->fhandle = nfs_fhandle_hash(args->fhandle); + __entry->error = error; + ), + + TP_printk( + "error=%d (%s) dev=%02x:%02x fhandle=0x%08x", + __entry->error, + show_nfsv4_errors(__entry->error), + MAJOR(__entry->dev), MINOR(__entry->dev), + __entry->fhandle + ) +); + DECLARE_EVENT_CLASS(nfs4_lookup_event, TP_PROTO( const struct inode *dir, @@ -554,6 +624,8 @@ DEFINE_NFS4_INODE_EVENT(nfs4_set_acl); DEFINE_NFS4_INODE_EVENT(nfs4_get_security_label); DEFINE_NFS4_INODE_EVENT(nfs4_set_security_label); #endif /* CONFIG_NFS_V4_SECURITY_LABEL */ +DEFINE_NFS4_INODE_EVENT(nfs4_recall_delegation); +DEFINE_NFS4_INODE_EVENT(nfs4_delegreturn); #endif /* _TRACE_NFS4_H */ -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
* [PATCH v4 16/21] NFSv4: Add tracepoints for debugging the idmapper 2013-08-22 0:24 ` [PATCH v4 15/21] NFSv4: Add tracepoints for debugging delegations Trond Myklebust @ 2013-08-22 0:24 ` Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 17/21] NFSv4: Add tracepoints for debugging getattr Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:24 UTC (permalink / raw) To: linux-nfs Add tracepoints to help debug uid/gid mappings to username/group. Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/idmap.c | 5 +++++ fs/nfs/nfs4trace.h | 46 ++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 51 insertions(+) diff --git a/fs/nfs/idmap.c b/fs/nfs/idmap.c index 65c7d91..e9b0c59 100644 --- a/fs/nfs/idmap.c +++ b/fs/nfs/idmap.c @@ -49,6 +49,7 @@ #include "internal.h" #include "netns.h" +#include "nfs4trace.h" #define NFS_UINT_MAXLEN 11 @@ -849,6 +850,7 @@ int nfs_map_name_to_uid(const struct nfs_server *server, const char *name, size_ if (!uid_valid(*uid)) ret = -ERANGE; } + trace_nfs4_map_name_to_uid(name, namelen, id, ret); return ret; } @@ -865,6 +867,7 @@ int nfs_map_group_to_gid(const struct nfs_server *server, const char *name, size if (!gid_valid(*gid)) ret = -ERANGE; } + trace_nfs4_map_group_to_gid(name, namelen, id, ret); return ret; } @@ -879,6 +882,7 @@ int nfs_map_uid_to_name(const struct nfs_server *server, kuid_t uid, char *buf, ret = nfs_idmap_lookup_name(id, "user", buf, buflen, idmap); if (ret < 0) ret = nfs_map_numeric_to_string(id, buf, buflen); + trace_nfs4_map_uid_to_name(buf, ret, id, ret); return ret; } int nfs_map_gid_to_group(const struct nfs_server *server, kgid_t gid, char *buf, size_t buflen) @@ -892,5 +896,6 @@ int nfs_map_gid_to_group(const struct nfs_server *server, kgid_t gid, char *buf, ret = nfs_idmap_lookup_name(id, "group", buf, buflen, idmap); if (ret < 0) ret = nfs_map_numeric_to_string(id, buf, buflen); + trace_nfs4_map_gid_to_group(buf, ret, id, ret); return ret; } diff --git a/fs/nfs/nfs4trace.h b/fs/nfs/nfs4trace.h index 900f233..f58edcf 100644 --- a/fs/nfs/nfs4trace.h +++ b/fs/nfs/nfs4trace.h @@ -627,6 +627,52 @@ DEFINE_NFS4_INODE_EVENT(nfs4_set_security_label); DEFINE_NFS4_INODE_EVENT(nfs4_recall_delegation); DEFINE_NFS4_INODE_EVENT(nfs4_delegreturn); +DECLARE_EVENT_CLASS(nfs4_idmap_event, + TP_PROTO( + const char *name, + int len, + u32 id, + int error + ), + + TP_ARGS(name, len, id, error), + + TP_STRUCT__entry( + __field(int, error) + __field(u32, id) + __dynamic_array(char, name, len > 0 ? len + 1 : 1) + ), + + TP_fast_assign( + if (len < 0) + len = 0; + __entry->error = error < 0 ? error : 0; + __entry->id = id; + memcpy(__get_dynamic_array(name), name, len); + ((char *)__get_dynamic_array(name))[len] = 0; + ), + + TP_printk( + "error=%d id=%u name=%s", + __entry->error, + __entry->id, + __get_str(name) + ) +); +#define DEFINE_NFS4_IDMAP_EVENT(name) \ + DEFINE_EVENT(nfs4_idmap_event, name, \ + TP_PROTO( \ + const char *name, \ + int len, \ + u32 id, \ + int error \ + ), \ + TP_ARGS(name, len, id, error)) +DEFINE_NFS4_IDMAP_EVENT(nfs4_map_name_to_uid); +DEFINE_NFS4_IDMAP_EVENT(nfs4_map_group_to_gid); +DEFINE_NFS4_IDMAP_EVENT(nfs4_map_uid_to_name); +DEFINE_NFS4_IDMAP_EVENT(nfs4_map_gid_to_group); + #endif /* _TRACE_NFS4_H */ #undef TRACE_INCLUDE_PATH -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
* [PATCH v4 17/21] NFSv4: Add tracepoints for debugging getattr 2013-08-22 0:24 ` [PATCH v4 16/21] NFSv4: Add tracepoints for debugging the idmapper Trond Myklebust @ 2013-08-22 0:24 ` Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 18/21] NFSv4: Add tracepoints for debugging reads and writes Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:24 UTC (permalink / raw) To: linux-nfs Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/nfs4proc.c | 7 ++++-- fs/nfs/nfs4trace.h | 69 ++++++++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 74 insertions(+), 2 deletions(-) diff --git a/fs/nfs/nfs4proc.c b/fs/nfs/nfs4proc.c index e3ac877..d6c98bd 100644 --- a/fs/nfs/nfs4proc.c +++ b/fs/nfs/nfs4proc.c @@ -2693,6 +2693,7 @@ static int nfs4_lookup_root(struct nfs_server *server, struct nfs_fh *fhandle, int err; do { err = _nfs4_lookup_root(server, fhandle, info); + trace_nfs4_lookup_root(server, fhandle, info->fattr, err); switch (err) { case 0: case -NFS4ERR_WRONGSEC: @@ -2902,8 +2903,9 @@ static int nfs4_proc_getattr(struct nfs_server *server, struct nfs_fh *fhandle, struct nfs4_exception exception = { }; int err; do { - err = nfs4_handle_exception(server, - _nfs4_proc_getattr(server, fhandle, fattr, label), + err = _nfs4_proc_getattr(server, fhandle, fattr, label); + trace_nfs4_getattr(server, fhandle, fattr, err); + err = nfs4_handle_exception(server, err, &exception); } while (exception.retry); return err; @@ -3756,6 +3758,7 @@ static int nfs4_do_fsinfo(struct nfs_server *server, struct nfs_fh *fhandle, str do { err = _nfs4_do_fsinfo(server, fhandle, fsinfo); + trace_nfs4_fsinfo(server, fhandle, fsinfo->fattr, err); if (err == 0) { struct nfs_client *clp = server->nfs_client; diff --git a/fs/nfs/nfs4trace.h b/fs/nfs/nfs4trace.h index f58edcf..99d1b1e 100644 --- a/fs/nfs/nfs4trace.h +++ b/fs/nfs/nfs4trace.h @@ -174,6 +174,24 @@ { ((__force unsigned long)FMODE_WRITE), "WRITE" }, \ { ((__force unsigned long)FMODE_EXEC), "EXEC" }) +#define show_nfs_fattr_flags(valid) \ + __print_flags((unsigned long)valid, "|", \ + { NFS_ATTR_FATTR_TYPE, "TYPE" }, \ + { NFS_ATTR_FATTR_MODE, "MODE" }, \ + { NFS_ATTR_FATTR_NLINK, "NLINK" }, \ + { NFS_ATTR_FATTR_OWNER, "OWNER" }, \ + { NFS_ATTR_FATTR_GROUP, "GROUP" }, \ + { NFS_ATTR_FATTR_RDEV, "RDEV" }, \ + { NFS_ATTR_FATTR_SIZE, "SIZE" }, \ + { NFS_ATTR_FATTR_FSID, "FSID" }, \ + { NFS_ATTR_FATTR_FILEID, "FILEID" }, \ + { NFS_ATTR_FATTR_ATIME, "ATIME" }, \ + { NFS_ATTR_FATTR_MTIME, "MTIME" }, \ + { NFS_ATTR_FATTR_CTIME, "CTIME" }, \ + { NFS_ATTR_FATTR_CHANGE, "CHANGE" }, \ + { NFS_ATTR_FATTR_OWNER_NAME, "OWNER_NAME" }, \ + { NFS_ATTR_FATTR_GROUP_NAME, "GROUP_NAME" }) + DECLARE_EVENT_CLASS(nfs4_clientid_event, TP_PROTO( const struct nfs_client *clp, @@ -627,6 +645,57 @@ DEFINE_NFS4_INODE_EVENT(nfs4_set_security_label); DEFINE_NFS4_INODE_EVENT(nfs4_recall_delegation); DEFINE_NFS4_INODE_EVENT(nfs4_delegreturn); +DECLARE_EVENT_CLASS(nfs4_getattr_event, + TP_PROTO( + const struct nfs_server *server, + const struct nfs_fh *fhandle, + const struct nfs_fattr *fattr, + int error + ), + + TP_ARGS(server, fhandle, fattr, error), + + TP_STRUCT__entry( + __field(dev_t, dev) + __field(u32, fhandle) + __field(u64, fileid) + __field(unsigned int, valid) + __field(int, error) + ), + + TP_fast_assign( + __entry->dev = server->s_dev; + __entry->valid = fattr->valid; + __entry->fhandle = nfs_fhandle_hash(fhandle); + __entry->fileid = (fattr->valid & NFS_ATTR_FATTR_FILEID) ? fattr->fileid : 0; + __entry->error = error; + ), + + TP_printk( + "error=%d (%s) fileid=%02x:%02x:%llu fhandle=0x%08x " + "valid=%s", + __entry->error, + show_nfsv4_errors(__entry->error), + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->fileid, + __entry->fhandle, + show_nfs_fattr_flags(__entry->valid) + ) +); + +#define DEFINE_NFS4_GETATTR_EVENT(name) \ + DEFINE_EVENT(nfs4_getattr_event, name, \ + TP_PROTO( \ + const struct nfs_server *server, \ + const struct nfs_fh *fhandle, \ + const struct nfs_fattr *fattr, \ + int error \ + ), \ + TP_ARGS(server, fhandle, fattr, error)) +DEFINE_NFS4_GETATTR_EVENT(nfs4_getattr); +DEFINE_NFS4_GETATTR_EVENT(nfs4_lookup_root); +DEFINE_NFS4_GETATTR_EVENT(nfs4_fsinfo); + DECLARE_EVENT_CLASS(nfs4_idmap_event, TP_PROTO( const char *name, -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
* [PATCH v4 18/21] NFSv4: Add tracepoints for debugging reads and writes 2013-08-22 0:24 ` [PATCH v4 17/21] NFSv4: Add tracepoints for debugging getattr Trond Myklebust @ 2013-08-22 0:24 ` Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 19/21] NFSv4.1: Add tracepoints for debugging layoutget/return/commit Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:24 UTC (permalink / raw) To: linux-nfs Set up tracepoints to track read, write and commit, as well as pNFS reads and writes and commits to the data server. Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/nfs4filelayout.c | 4 ++ fs/nfs/nfs4proc.c | 3 + fs/nfs/nfs4trace.c | 5 ++ fs/nfs/nfs4trace.h | 154 ++++++++++++++++++++++++++++++++++++++++++++++++ fs/nfs/pnfs.c | 3 + 5 files changed, 169 insertions(+) diff --git a/fs/nfs/nfs4filelayout.c b/fs/nfs/nfs4filelayout.c index 17ed87e..a70cb3a 100644 --- a/fs/nfs/nfs4filelayout.c +++ b/fs/nfs/nfs4filelayout.c @@ -39,6 +39,7 @@ #include "internal.h" #include "delegation.h" #include "nfs4filelayout.h" +#include "nfs4trace.h" #define NFSDBG_FACILITY NFSDBG_PNFS_LD @@ -247,6 +248,7 @@ static int filelayout_read_done_cb(struct rpc_task *task, struct nfs_pgio_header *hdr = data->header; int err; + trace_nfs4_pnfs_read(data, task->tk_status); err = filelayout_async_handle_error(task, data->args.context->state, data->ds_clp, hdr->lseg); @@ -363,6 +365,7 @@ static int filelayout_write_done_cb(struct rpc_task *task, struct nfs_pgio_header *hdr = data->header; int err; + trace_nfs4_pnfs_write(data, task->tk_status); err = filelayout_async_handle_error(task, data->args.context->state, data->ds_clp, hdr->lseg); @@ -395,6 +398,7 @@ static int filelayout_commit_done_cb(struct rpc_task *task, { int err; + trace_nfs4_pnfs_commit_ds(data, task->tk_status); err = filelayout_async_handle_error(task, NULL, data->ds_clp, data->lseg); diff --git a/fs/nfs/nfs4proc.c b/fs/nfs/nfs4proc.c index d6c98bd..e9551ae 100644 --- a/fs/nfs/nfs4proc.c +++ b/fs/nfs/nfs4proc.c @@ -3877,6 +3877,7 @@ static int nfs4_read_done_cb(struct rpc_task *task, struct nfs_read_data *data) { struct nfs_server *server = NFS_SERVER(data->header->inode); + trace_nfs4_read(data, task->tk_status); if (nfs4_async_handle_error(task, server, data->args.context->state) == -EAGAIN) { rpc_restart_call_prepare(task); return -EAGAIN; @@ -3938,6 +3939,7 @@ static int nfs4_write_done_cb(struct rpc_task *task, struct nfs_write_data *data { struct inode *inode = data->header->inode; + trace_nfs4_write(data, task->tk_status); if (nfs4_async_handle_error(task, NFS_SERVER(inode), data->args.context->state) == -EAGAIN) { rpc_restart_call_prepare(task); return -EAGAIN; @@ -4029,6 +4031,7 @@ static int nfs4_commit_done_cb(struct rpc_task *task, struct nfs_commit_data *da { struct inode *inode = data->inode; + trace_nfs4_commit(data, task->tk_status); if (nfs4_async_handle_error(task, NFS_SERVER(inode), NULL) == -EAGAIN) { rpc_restart_call_prepare(task); return -EAGAIN; diff --git a/fs/nfs/nfs4trace.c b/fs/nfs/nfs4trace.c index 3f02183..f840974 100644 --- a/fs/nfs/nfs4trace.c +++ b/fs/nfs/nfs4trace.c @@ -8,3 +8,8 @@ #define CREATE_TRACE_POINTS #include "nfs4trace.h" +#ifdef CONFIG_NFS_V4_1 +EXPORT_TRACEPOINT_SYMBOL_GPL(nfs4_pnfs_read); +EXPORT_TRACEPOINT_SYMBOL_GPL(nfs4_pnfs_write); +EXPORT_TRACEPOINT_SYMBOL_GPL(nfs4_pnfs_commit_ds); +#endif diff --git a/fs/nfs/nfs4trace.h b/fs/nfs/nfs4trace.h index 99d1b1e..1ea6983 100644 --- a/fs/nfs/nfs4trace.h +++ b/fs/nfs/nfs4trace.h @@ -742,6 +742,160 @@ DEFINE_NFS4_IDMAP_EVENT(nfs4_map_group_to_gid); DEFINE_NFS4_IDMAP_EVENT(nfs4_map_uid_to_name); DEFINE_NFS4_IDMAP_EVENT(nfs4_map_gid_to_group); +DECLARE_EVENT_CLASS(nfs4_read_event, + TP_PROTO( + const struct nfs_read_data *data, + int error + ), + + TP_ARGS(data, error), + + TP_STRUCT__entry( + __field(dev_t, dev) + __field(u32, fhandle) + __field(u64, fileid) + __field(loff_t, offset) + __field(size_t, count) + __field(int, error) + ), + + TP_fast_assign( + const struct inode *inode = data->header->inode; + __entry->dev = inode->i_sb->s_dev; + __entry->fileid = NFS_FILEID(inode); + __entry->fhandle = nfs_fhandle_hash(NFS_FH(inode)); + __entry->offset = data->args.offset; + __entry->count = data->args.count; + __entry->error = error; + ), + + TP_printk( + "error=%d (%s) fileid=%02x:%02x:%llu fhandle=0x%08x " + "offset=%lld count=%zu", + __entry->error, + show_nfsv4_errors(__entry->error), + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->fileid, + __entry->fhandle, + (long long)__entry->offset, + __entry->count + ) +); +#define DEFINE_NFS4_READ_EVENT(name) \ + DEFINE_EVENT(nfs4_read_event, name, \ + TP_PROTO( \ + const struct nfs_read_data *data, \ + int error \ + ), \ + TP_ARGS(data, error)) +DEFINE_NFS4_READ_EVENT(nfs4_read); +#ifdef CONFIG_NFS_V4_1 +DEFINE_NFS4_READ_EVENT(nfs4_pnfs_read); +#endif /* CONFIG_NFS_V4_1 */ + +DECLARE_EVENT_CLASS(nfs4_write_event, + TP_PROTO( + const struct nfs_write_data *data, + int error + ), + + TP_ARGS(data, error), + + TP_STRUCT__entry( + __field(dev_t, dev) + __field(u32, fhandle) + __field(u64, fileid) + __field(loff_t, offset) + __field(size_t, count) + __field(int, error) + ), + + TP_fast_assign( + const struct inode *inode = data->header->inode; + __entry->dev = inode->i_sb->s_dev; + __entry->fileid = NFS_FILEID(inode); + __entry->fhandle = nfs_fhandle_hash(NFS_FH(inode)); + __entry->offset = data->args.offset; + __entry->count = data->args.count; + __entry->error = error; + ), + + TP_printk( + "error=%d (%s) fileid=%02x:%02x:%llu fhandle=0x%08x " + "offset=%lld count=%zu", + __entry->error, + show_nfsv4_errors(__entry->error), + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->fileid, + __entry->fhandle, + (long long)__entry->offset, + __entry->count + ) +); + +#define DEFINE_NFS4_WRITE_EVENT(name) \ + DEFINE_EVENT(nfs4_write_event, name, \ + TP_PROTO( \ + const struct nfs_write_data *data, \ + int error \ + ), \ + TP_ARGS(data, error)) +DEFINE_NFS4_WRITE_EVENT(nfs4_write); +#ifdef CONFIG_NFS_V4_1 +DEFINE_NFS4_WRITE_EVENT(nfs4_pnfs_write); +#endif /* CONFIG_NFS_V4_1 */ + +DECLARE_EVENT_CLASS(nfs4_commit_event, + TP_PROTO( + const struct nfs_commit_data *data, + int error + ), + + TP_ARGS(data, error), + + TP_STRUCT__entry( + __field(dev_t, dev) + __field(u32, fhandle) + __field(u64, fileid) + __field(loff_t, offset) + __field(size_t, count) + __field(int, error) + ), + + TP_fast_assign( + const struct inode *inode = data->inode; + __entry->dev = inode->i_sb->s_dev; + __entry->fileid = NFS_FILEID(inode); + __entry->fhandle = nfs_fhandle_hash(NFS_FH(inode)); + __entry->offset = data->args.offset; + __entry->count = data->args.count; + __entry->error = error; + ), + + TP_printk( + "error=%d (%s) fileid=%02x:%02x:%llu fhandle=0x%08x " + "offset=%lld count=%zu", + __entry->error, + show_nfsv4_errors(__entry->error), + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->fileid, + __entry->fhandle, + (long long)__entry->offset, + __entry->count + ) +); +#define DEFINE_NFS4_COMMIT_EVENT(name) \ + DEFINE_EVENT(nfs4_commit_event, name, \ + TP_PROTO( \ + const struct nfs_commit_data *data, \ + int error \ + ), \ + TP_ARGS(data, error)) +DEFINE_NFS4_COMMIT_EVENT(nfs4_commit); +#ifdef CONFIG_NFS_V4_1 +DEFINE_NFS4_COMMIT_EVENT(nfs4_pnfs_commit_ds); +#endif /* CONFIG_NFS_V4_1 */ + #endif /* _TRACE_NFS4_H */ #undef TRACE_INCLUDE_PATH diff --git a/fs/nfs/pnfs.c b/fs/nfs/pnfs.c index 3a3a79d..d75d938 100644 --- a/fs/nfs/pnfs.c +++ b/fs/nfs/pnfs.c @@ -33,6 +33,7 @@ #include "internal.h" #include "pnfs.h" #include "iostat.h" +#include "nfs4trace.h" #define NFSDBG_FACILITY NFSDBG_PNFS #define PNFS_LAYOUTGET_RETRY_TIMEOUT (120*HZ) @@ -1526,6 +1527,7 @@ void pnfs_ld_write_done(struct nfs_write_data *data) { struct nfs_pgio_header *hdr = data->header; + trace_nfs4_pnfs_write(data, hdr->pnfs_error); if (!hdr->pnfs_error) { pnfs_set_layoutcommit(data); hdr->mds_ops->rpc_call_done(&data->task, data); @@ -1680,6 +1682,7 @@ void pnfs_ld_read_done(struct nfs_read_data *data) { struct nfs_pgio_header *hdr = data->header; + trace_nfs4_pnfs_read(data, hdr->pnfs_error); if (likely(!hdr->pnfs_error)) { __nfs4_read_done_cb(data); hdr->mds_ops->rpc_call_done(&data->task, data); -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
* [PATCH v4 19/21] NFSv4.1: Add tracepoints for debugging layoutget/return/commit 2013-08-22 0:24 ` [PATCH v4 18/21] NFSv4: Add tracepoints for debugging reads and writes Trond Myklebust @ 2013-08-22 0:24 ` Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 20/21] NFSv4.1: Add tracepoints for debugging slot table operations Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:24 UTC (permalink / raw) To: linux-nfs Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/nfs4proc.c | 6 ++++++ fs/nfs/nfs4trace.h | 55 ++++++++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 61 insertions(+) diff --git a/fs/nfs/nfs4proc.c b/fs/nfs/nfs4proc.c index e9551ae..156a86b 100644 --- a/fs/nfs/nfs4proc.c +++ b/fs/nfs/nfs4proc.c @@ -6856,6 +6856,10 @@ nfs4_proc_layoutget(struct nfs4_layoutget *lgp, gfp_t gfp_flags) status = nfs4_wait_for_completion_rpc_task(task); if (status == 0) status = task->tk_status; + trace_nfs4_layoutget(lgp->args.ctx, + &lgp->args.range, + &lgp->res.range, + status); /* if layoutp->len is 0, nfs4_layoutget_prepare called rpc_exit */ if (status == 0 && lgp->res.layoutp->len) lseg = pnfs_layout_process(lgp); @@ -6941,6 +6945,7 @@ int nfs4_proc_layoutreturn(struct nfs4_layoutreturn *lrp) if (IS_ERR(task)) return PTR_ERR(task); status = task->tk_status; + trace_nfs4_layoutreturn(lrp->args.inode, status); dprintk("<-- %s status=%d\n", __func__, status); rpc_put_task(task); return status; @@ -7127,6 +7132,7 @@ nfs4_proc_layoutcommit(struct nfs4_layoutcommit_data *data, bool sync) if (status != 0) goto out; status = task->tk_status; + trace_nfs4_layoutcommit(data->args.inode, status); out: dprintk("%s: status %d\n", __func__, status); rpc_put_task(task); diff --git a/fs/nfs/nfs4trace.h b/fs/nfs/nfs4trace.h index 1ea6983..b2a2d8a 100644 --- a/fs/nfs/nfs4trace.h +++ b/fs/nfs/nfs4trace.h @@ -894,6 +894,61 @@ DECLARE_EVENT_CLASS(nfs4_commit_event, DEFINE_NFS4_COMMIT_EVENT(nfs4_commit); #ifdef CONFIG_NFS_V4_1 DEFINE_NFS4_COMMIT_EVENT(nfs4_pnfs_commit_ds); + +#define show_pnfs_iomode(iomode) \ + __print_symbolic(iomode, \ + { IOMODE_READ, "READ" }, \ + { IOMODE_RW, "RW" }, \ + { IOMODE_ANY, "ANY" }) + +TRACE_EVENT(nfs4_layoutget, + TP_PROTO( + const struct nfs_open_context *ctx, + const struct pnfs_layout_range *args, + const struct pnfs_layout_range *res, + int error + ), + + TP_ARGS(ctx, args, res, error), + + TP_STRUCT__entry( + __field(dev_t, dev) + __field(u32, fhandle) + __field(u64, fileid) + __field(u32, iomode) + __field(u64, offset) + __field(u64, count) + __field(int, error) + ), + + TP_fast_assign( + const struct inode *inode = ctx->dentry->d_inode; + __entry->dev = inode->i_sb->s_dev; + __entry->fileid = NFS_FILEID(inode); + __entry->fhandle = nfs_fhandle_hash(NFS_FH(inode)); + __entry->iomode = args->iomode; + __entry->offset = args->offset; + __entry->count = args->length; + __entry->error = error; + ), + + TP_printk( + "error=%d (%s) fileid=%02x:%02x:%llu fhandle=0x%08x " + "iomode=%s offset=%llu count=%llu", + __entry->error, + show_nfsv4_errors(__entry->error), + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->fileid, + __entry->fhandle, + show_pnfs_iomode(__entry->iomode), + (unsigned long long)__entry->offset, + (unsigned long long)__entry->count + ) +); + +DEFINE_NFS4_INODE_EVENT(nfs4_layoutcommit); +DEFINE_NFS4_INODE_EVENT(nfs4_layoutreturn); + #endif /* CONFIG_NFS_V4_1 */ #endif /* _TRACE_NFS4_H */ -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
* [PATCH v4 20/21] NFSv4.1: Add tracepoints for debugging slot table operations 2013-08-22 0:24 ` [PATCH v4 19/21] NFSv4.1: Add tracepoints for debugging layoutget/return/commit Trond Myklebust @ 2013-08-22 0:24 ` Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 21/21] NFSv4.1: Add tracepoints for debugging test_stateid events Trond Myklebust 0 siblings, 1 reply; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:24 UTC (permalink / raw) To: linux-nfs Add tracepoints to nfs41_setup_sequence and nfs41_sequence_done to track session and slot table state changes. Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/callback_proc.c | 1 + fs/nfs/nfs4proc.c | 2 + fs/nfs/nfs4session.h | 10 ++++ fs/nfs/nfs4trace.c | 2 + fs/nfs/nfs4trace.h | 139 +++++++++++++++++++++++++++++++++++++++++++++++++ 5 files changed, 154 insertions(+) diff --git a/fs/nfs/callback_proc.c b/fs/nfs/callback_proc.c index c074930..b25ed7e 100644 --- a/fs/nfs/callback_proc.c +++ b/fs/nfs/callback_proc.c @@ -464,6 +464,7 @@ out: } else res->csr_status = status; + trace_nfs4_cb_sequence(args, res, status); dprintk("%s: exit with status = %d res->csr_status %d\n", __func__, ntohl(status), ntohl(res->csr_status)); return status; diff --git a/fs/nfs/nfs4proc.c b/fs/nfs/nfs4proc.c index 156a86b..44ba5eb 100644 --- a/fs/nfs/nfs4proc.c +++ b/fs/nfs/nfs4proc.c @@ -508,6 +508,7 @@ static int nfs41_sequence_done(struct rpc_task *task, struct nfs4_sequence_res * interrupted = true; } + trace_nfs4_sequence_done(session, res); /* Check the SEQUENCE operation status */ switch (res->sr_status) { case 0: @@ -660,6 +661,7 @@ int nfs41_setup_sequence(struct nfs4_session *session, * set to 1 if an rpc level failure occurs. */ res->sr_status = 1; + trace_nfs4_setup_sequence(session, args); out_success: rpc_call_start(task); return 0; diff --git a/fs/nfs/nfs4session.h b/fs/nfs/nfs4session.h index 86a0669..e3e6ce3 100644 --- a/fs/nfs/nfs4session.h +++ b/fs/nfs/nfs4session.h @@ -117,6 +117,16 @@ static inline int nfs4_has_persistent_session(const struct nfs_client *clp) return 0; } +#ifdef CONFIG_CRC32 +/* + * nfs_session_id_hash - calculate the crc32 hash for the session id + * @session - pointer to session + */ +#define nfs_session_id_hash(sess_id) \ + (~crc32_le(0xFFFFFFFF, &(sess_id)->data[0], sizeof((sess_id)->data))) +#else +#define nfs_session_id_hash(session) (0) +#endif #else /* defined(CONFIG_NFS_V4_1) */ static inline int nfs4_init_session(struct nfs_client *clp) diff --git a/fs/nfs/nfs4trace.c b/fs/nfs/nfs4trace.c index f840974..d774335 100644 --- a/fs/nfs/nfs4trace.c +++ b/fs/nfs/nfs4trace.c @@ -4,6 +4,8 @@ #include <linux/nfs_fs.h> #include "nfs4_fs.h" #include "internal.h" +#include "nfs4session.h" +#include "callback.h" #define CREATE_TRACE_POINTS #include "nfs4trace.h" diff --git a/fs/nfs/nfs4trace.h b/fs/nfs/nfs4trace.h index b2a2d8a..05b96a6 100644 --- a/fs/nfs/nfs4trace.h +++ b/fs/nfs/nfs4trace.h @@ -240,6 +240,145 @@ DEFINE_NFS4_CLIENTID_EVENT(nfs4_destroy_clientid); DEFINE_NFS4_CLIENTID_EVENT(nfs4_bind_conn_to_session); DEFINE_NFS4_CLIENTID_EVENT(nfs4_sequence); DEFINE_NFS4_CLIENTID_EVENT(nfs4_reclaim_complete); + +TRACE_EVENT(nfs4_setup_sequence, + TP_PROTO( + const struct nfs4_session *session, + const struct nfs4_sequence_args *args + ), + TP_ARGS(session, args), + + TP_STRUCT__entry( + __field(unsigned int, session) + __field(unsigned int, slot_nr) + __field(unsigned int, seq_nr) + __field(unsigned int, highest_used_slotid) + ), + + TP_fast_assign( + const struct nfs4_slot *sa_slot = args->sa_slot; + __entry->session = nfs_session_id_hash(&session->sess_id); + __entry->slot_nr = sa_slot->slot_nr; + __entry->seq_nr = sa_slot->seq_nr; + __entry->highest_used_slotid = + sa_slot->table->highest_used_slotid; + ), + TP_printk( + "session=0x%08x slot_nr=%u seq_nr=%u " + "highest_used_slotid=%u", + __entry->session, + __entry->slot_nr, + __entry->seq_nr, + __entry->highest_used_slotid + ) +); + +#define show_nfs4_sequence_status_flags(status) \ + __print_flags((unsigned long)status, "|", \ + { SEQ4_STATUS_CB_PATH_DOWN, "CB_PATH_DOWN" }, \ + { SEQ4_STATUS_CB_GSS_CONTEXTS_EXPIRING, \ + "CB_GSS_CONTEXTS_EXPIRING" }, \ + { SEQ4_STATUS_CB_GSS_CONTEXTS_EXPIRED, \ + "CB_GSS_CONTEXTS_EXPIRED" }, \ + { SEQ4_STATUS_EXPIRED_ALL_STATE_REVOKED, \ + "EXPIRED_ALL_STATE_REVOKED" }, \ + { SEQ4_STATUS_EXPIRED_SOME_STATE_REVOKED, \ + "EXPIRED_SOME_STATE_REVOKED" }, \ + { SEQ4_STATUS_ADMIN_STATE_REVOKED, \ + "ADMIN_STATE_REVOKED" }, \ + { SEQ4_STATUS_RECALLABLE_STATE_REVOKED, \ + "RECALLABLE_STATE_REVOKED" }, \ + { SEQ4_STATUS_LEASE_MOVED, "LEASE_MOVED" }, \ + { SEQ4_STATUS_RESTART_RECLAIM_NEEDED, \ + "RESTART_RECLAIM_NEEDED" }, \ + { SEQ4_STATUS_CB_PATH_DOWN_SESSION, \ + "CB_PATH_DOWN_SESSION" }, \ + { SEQ4_STATUS_BACKCHANNEL_FAULT, \ + "BACKCHANNEL_FAULT" }) + +TRACE_EVENT(nfs4_sequence_done, + TP_PROTO( + const struct nfs4_session *session, + const struct nfs4_sequence_res *res + ), + TP_ARGS(session, res), + + TP_STRUCT__entry( + __field(unsigned int, session) + __field(unsigned int, slot_nr) + __field(unsigned int, seq_nr) + __field(unsigned int, highest_slotid) + __field(unsigned int, target_highest_slotid) + __field(unsigned int, status_flags) + __field(int, error) + ), + + TP_fast_assign( + const struct nfs4_slot *sr_slot = res->sr_slot; + __entry->session = nfs_session_id_hash(&session->sess_id); + __entry->slot_nr = sr_slot->slot_nr; + __entry->seq_nr = sr_slot->seq_nr; + __entry->highest_slotid = res->sr_highest_slotid; + __entry->target_highest_slotid = + res->sr_target_highest_slotid; + __entry->error = res->sr_status; + ), + TP_printk( + "error=%d (%s) session=0x%08x slot_nr=%u seq_nr=%u " + "highest_slotid=%u target_highest_slotid=%u " + "status_flags=%u (%s)", + __entry->error, + show_nfsv4_errors(__entry->error), + __entry->session, + __entry->slot_nr, + __entry->seq_nr, + __entry->highest_slotid, + __entry->target_highest_slotid, + __entry->status_flags, + show_nfs4_sequence_status_flags(__entry->status_flags) + ) +); + +struct cb_sequenceargs; +struct cb_sequenceres; + +TRACE_EVENT(nfs4_cb_sequence, + TP_PROTO( + const struct cb_sequenceargs *args, + const struct cb_sequenceres *res, + __be32 status + ), + TP_ARGS(args, res, status), + + TP_STRUCT__entry( + __field(unsigned int, session) + __field(unsigned int, slot_nr) + __field(unsigned int, seq_nr) + __field(unsigned int, highest_slotid) + __field(unsigned int, cachethis) + __field(int, error) + ), + + TP_fast_assign( + __entry->session = nfs_session_id_hash(&args->csa_sessionid); + __entry->slot_nr = args->csa_slotid; + __entry->seq_nr = args->csa_sequenceid; + __entry->highest_slotid = args->csa_highestslotid; + __entry->cachethis = args->csa_cachethis; + __entry->error = -be32_to_cpu(status); + ), + + TP_printk( + "error=%d (%s) session=0x%08x slot_nr=%u seq_nr=%u " + "highest_slotid=%u", + __entry->error, + show_nfsv4_errors(__entry->error), + __entry->session, + __entry->slot_nr, + __entry->seq_nr, + __entry->highest_slotid + ) +); #endif /* CONFIG_NFS_V4_1 */ DECLARE_EVENT_CLASS(nfs4_open_event, -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
* [PATCH v4 21/21] NFSv4.1: Add tracepoints for debugging test_stateid events 2013-08-22 0:24 ` [PATCH v4 20/21] NFSv4.1: Add tracepoints for debugging slot table operations Trond Myklebust @ 2013-08-22 0:24 ` Trond Myklebust 0 siblings, 0 replies; 22+ messages in thread From: Trond Myklebust @ 2013-08-22 0:24 UTC (permalink / raw) To: linux-nfs Add tracepoints to detect issues with the TEST_STATEID operation. Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com> --- fs/nfs/nfs4proc.c | 3 +++ fs/nfs/nfs4trace.h | 49 +++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 52 insertions(+) diff --git a/fs/nfs/nfs4proc.c b/fs/nfs/nfs4proc.c index 44ba5eb..ee3bc24 100644 --- a/fs/nfs/nfs4proc.c +++ b/fs/nfs/nfs4proc.c @@ -1946,6 +1946,7 @@ static void nfs41_clear_delegation_stateid(struct nfs4_state *state) cred = get_rpccred(delegation->cred); rcu_read_unlock(); status = nfs41_test_stateid(server, stateid, cred); + trace_nfs4_test_delegation_stateid(state, NULL, status); } else rcu_read_unlock(); @@ -1988,6 +1989,7 @@ static int nfs41_check_open_stateid(struct nfs4_state *state) return -NFS4ERR_BAD_STATEID; status = nfs41_test_stateid(server, stateid, cred); + trace_nfs4_test_open_stateid(state, NULL, status); if (status != NFS_OK) { /* Free the stateid unless the server explicitly * informs us the stateid is unrecognized. */ @@ -5468,6 +5470,7 @@ static int nfs41_check_expired_locks(struct nfs4_state *state) status = nfs41_test_stateid(server, &lsp->ls_stateid, cred); + trace_nfs4_test_lock_stateid(state, lsp, status); if (status != NFS_OK) { /* Free the stateid unless the server * informs us the stateid is unrecognized. */ diff --git a/fs/nfs/nfs4trace.h b/fs/nfs/nfs4trace.h index 05b96a6..849cf14 100644 --- a/fs/nfs/nfs4trace.h +++ b/fs/nfs/nfs4trace.h @@ -638,6 +638,55 @@ TRACE_EVENT(nfs4_delegreturn_exit, ) ); +#ifdef CONFIG_NFS_V4_1 +DECLARE_EVENT_CLASS(nfs4_test_stateid_event, + TP_PROTO( + const struct nfs4_state *state, + const struct nfs4_lock_state *lsp, + int error + ), + + TP_ARGS(state, lsp, error), + + TP_STRUCT__entry( + __field(int, error) + __field(dev_t, dev) + __field(u32, fhandle) + __field(u64, fileid) + ), + + TP_fast_assign( + const struct inode *inode = state->inode; + + __entry->error = error; + __entry->dev = inode->i_sb->s_dev; + __entry->fileid = NFS_FILEID(inode); + __entry->fhandle = nfs_fhandle_hash(NFS_FH(inode)); + ), + + TP_printk( + "error=%d (%s) fileid=%02x:%02x:%llu fhandle=0x%08x", + __entry->error, + show_nfsv4_errors(__entry->error), + MAJOR(__entry->dev), MINOR(__entry->dev), + (unsigned long long)__entry->fileid, + __entry->fhandle + ) +); + +#define DEFINE_NFS4_TEST_STATEID_EVENT(name) \ + DEFINE_EVENT(nfs4_test_stateid_event, name, \ + TP_PROTO( \ + const struct nfs4_state *state, \ + const struct nfs4_lock_state *lsp, \ + int error \ + ), \ + TP_ARGS(state, lsp, error)) +DEFINE_NFS4_TEST_STATEID_EVENT(nfs4_test_delegation_stateid); +DEFINE_NFS4_TEST_STATEID_EVENT(nfs4_test_open_stateid); +DEFINE_NFS4_TEST_STATEID_EVENT(nfs4_test_lock_stateid); +#endif /* CONFIG_NFS_V4_1 */ + DECLARE_EVENT_CLASS(nfs4_lookup_event, TP_PROTO( const struct inode *dir, -- 1.8.3.1 ^ permalink raw reply related [flat|nested] 22+ messages in thread
end of thread, other threads:[~2013-08-22 0:24 UTC | newest] Thread overview: 22+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2013-08-22 0:23 [PATCH v4 00/21] NFS add tracepoints (final version) Trond Myklebust 2013-08-22 0:23 ` [PATCH v4 01/21] NFS: refactor code for calculating the crc32 hash of a filehandle Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 02/21] NFS: Add event tracing for generic NFS events Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 03/21] NFS: Pass in lookup flags from nfs_atomic_open to nfs_lookup Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 04/21] NFS: Add event tracing for generic NFS lookups Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 05/21] NFS: Add tracepoints for debugging generic file create events Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 06/21] NFS: Add tracepoints for debugging directory changes Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 07/21] NFS: Add tracepoints for debugging NFS rename and sillyrename issues Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 08/21] NFS: Add tracepoints for debugging NFS hard links Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 09/21] NFSv4: Add tracepoints for debugging state management problems Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 10/21] NFSv4: Add tracepoints for debugging file open Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 11/21] NFSv4: Add tracepoints for debugging file locking Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 12/21] NFSv4: Add tracepoints for debugging lookup/create operations Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 13/21] NFSv4: Add tracepoints for debugging inode manipulations Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 14/21] NFSv4: Add tracepoints for debugging rename Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 15/21] NFSv4: Add tracepoints for debugging delegations Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 16/21] NFSv4: Add tracepoints for debugging the idmapper Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 17/21] NFSv4: Add tracepoints for debugging getattr Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 18/21] NFSv4: Add tracepoints for debugging reads and writes Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 19/21] NFSv4.1: Add tracepoints for debugging layoutget/return/commit Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 20/21] NFSv4.1: Add tracepoints for debugging slot table operations Trond Myklebust 2013-08-22 0:24 ` [PATCH v4 21/21] NFSv4.1: Add tracepoints for debugging test_stateid events Trond Myklebust
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).