| Message ID | 20250409-nfsd-tracepoints-v2-6-cf4e084fdd9c@kernel.org (mailing list archive) |
|---|---|
| State | Changes Requested |
| Delegated to: | Chuck Lever |
| Headers | show |
| Series | nfsd: observability improvements | expand |
On 4/9/25 10:32 AM, Jeff Layton wrote: > ...and remove the legacy dprintks. > > Signed-off-by: Jeff Layton <jlayton@kernel.org> > --- > fs/nfsd/nfs3proc.c | 18 +++++------------- > fs/nfsd/nfs4proc.c | 29 +++++++++++++++++++++++++++++ > fs/nfsd/nfsproc.c | 6 +++--- > fs/nfsd/trace.h | 39 +++++++++++++++++++++++++++++++++++++++ > 4 files changed, 76 insertions(+), 16 deletions(-) > > diff --git a/fs/nfsd/nfs3proc.c b/fs/nfsd/nfs3proc.c > index 372bdcf5e07a5c835da240ecebb02e3576eb2ca6..ea1280970ea11b2a82f0de88ad0422eef7063d6d 100644 > --- a/fs/nfsd/nfs3proc.c > +++ b/fs/nfsd/nfs3proc.c > @@ -14,6 +14,7 @@ > #include "xdr3.h" > #include "vfs.h" > #include "filecache.h" > +#include "trace.h" > > #define NFSDDBG_FACILITY NFSDDBG_PROC > > @@ -380,10 +381,7 @@ nfsd3_proc_create(struct svc_rqst *rqstp) > struct nfsd3_diropres *resp = rqstp->rq_resp; > svc_fh *dirfhp, *newfhp; > > - dprintk("nfsd: CREATE(3) %s %.*s\n", > - SVCFH_fmt(&argp->fh), > - argp->len, > - argp->name); > + trace_nfsd3_proc_create(rqstp, &argp->fh, S_IFREG, argp->name, argp->len); > > dirfhp = fh_copy(&resp->dirfh, &argp->fh); > newfhp = fh_init(&resp->fh, NFS3_FHSIZE); > @@ -405,10 +403,7 @@ nfsd3_proc_mkdir(struct svc_rqst *rqstp) > .na_iattr = &argp->attrs, > }; > > - dprintk("nfsd: MKDIR(3) %s %.*s\n", > - SVCFH_fmt(&argp->fh), > - argp->len, > - argp->name); > + trace_nfsd3_proc_mkdir(rqstp, &argp->fh, S_IFDIR, argp->name, argp->len); > > argp->attrs.ia_valid &= ~ATTR_SIZE; > fh_copy(&resp->dirfh, &argp->fh); > @@ -471,13 +466,10 @@ nfsd3_proc_mknod(struct svc_rqst *rqstp) > struct nfsd_attrs attrs = { > .na_iattr = &argp->attrs, > }; > - int type; > + int type = nfs3_ftypes[argp->ftype]; > dev_t rdev = 0; > > - dprintk("nfsd: MKNOD(3) %s %.*s\n", > - SVCFH_fmt(&argp->fh), > - argp->len, > - argp->name); > + trace_nfsd3_proc_mknod(rqstp, &argp->fh, type, argp->name, argp->len); > > fh_copy(&resp->dirfh, &argp->fh); > fh_init(&resp->fh, NFS3_FHSIZE); > diff --git a/fs/nfsd/nfs4proc.c b/fs/nfsd/nfs4proc.c > index 6e23d6103010197c0316b07c189fe12ec3033812..2c795103deaa4044596bd07d90db788169a32a0c 100644 > --- a/fs/nfsd/nfs4proc.c > +++ b/fs/nfsd/nfs4proc.c > @@ -250,6 +250,8 @@ nfsd4_create_file(struct svc_rqst *rqstp, struct svc_fh *fhp, > __be32 status; > int host_err; > > + trace_nfsd4_create_file(rqstp, fhp, S_IFREG, open->op_fname, open->op_fnamelen); > + > if (isdotent(open->op_fname, open->op_fnamelen)) > return nfserr_exist; > if (!(iap->ia_valid & ATTR_MODE)) > @@ -807,6 +809,29 @@ nfsd4_commit(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, > return status; > } > > +static umode_t nfs_type_to_vfs_type(enum nfs_ftype4 nfstype) > +{ > + switch (nfstype) { > + case NF4REG: > + return S_IFREG; > + case NF4DIR: > + return S_IFDIR; > + case NF4BLK: > + return S_IFBLK; > + case NF4CHR: > + return S_IFCHR; > + case NF4LNK: > + return S_IFLNK; > + case NF4SOCK: > + return S_IFSOCK; > + case NF4FIFO: > + return S_IFIFO; > + default: > + break; > + } > + return 0; > +} > + Wondering what happens when trace points are disabled in the kernel build. Maybe this helper belongs in fs/nfsd/trace.h instead as a macro wrapper for __print_symbolic(). But see below. > static __be32 > nfsd4_create(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, > union nfsd4_op_u *u) > @@ -822,6 +847,10 @@ nfsd4_create(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, > __be32 status; > dev_t rdev; > > + trace_nfsd4_create(rqstp, &cstate->current_fh, > + nfs_type_to_vfs_type(create->cr_type), > + create->cr_name, create->cr_namelen); > + > fh_init(&resfh, NFS4_FHSIZE); > > status = fh_verify(rqstp, &cstate->current_fh, S_IFDIR, NFSD_MAY_NOP); > diff --git a/fs/nfsd/nfsproc.c b/fs/nfsd/nfsproc.c > index 6dda081eb24c00b834ab0965c3a35a12115bceb7..33d8cbf8785588d38d4ec5efd769c1d1d06c6a91 100644 > --- a/fs/nfsd/nfsproc.c > +++ b/fs/nfsd/nfsproc.c > @@ -10,6 +10,7 @@ > #include "cache.h" > #include "xdr.h" > #include "vfs.h" > +#include "trace.h" > > #define NFSDDBG_FACILITY NFSDDBG_PROC > > @@ -292,8 +293,7 @@ nfsd_proc_create(struct svc_rqst *rqstp) > int hosterr; > dev_t rdev = 0, wanted = new_decode_dev(attr->ia_size); > > - dprintk("nfsd: CREATE %s %.*s\n", > - SVCFH_fmt(dirfhp), argp->len, argp->name); > + trace_nfsd_proc_create(rqstp, dirfhp, S_IFREG, argp->name, argp->len); > > /* First verify the parent file handle */ > resp->status = fh_verify(rqstp, dirfhp, S_IFDIR, NFSD_MAY_EXEC); > @@ -548,7 +548,7 @@ nfsd_proc_mkdir(struct svc_rqst *rqstp) > .na_iattr = &argp->attrs, > }; > > - dprintk("nfsd: MKDIR %s %.*s\n", SVCFH_fmt(&argp->fh), argp->len, argp->name); > + trace_nfsd_proc_mkdir(rqstp, &argp->fh, S_IFDIR, argp->name, argp->len); > > if (resp->fh.fh_dentry) { > printk(KERN_WARNING > diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h > index 382849d7c321d6ded8213890c2e7075770aa716c..c6aff23a845f06c87e701d57ec577c2c5c5a743c 100644 > --- a/fs/nfsd/trace.h > +++ b/fs/nfsd/trace.h > @@ -2391,6 +2391,45 @@ TRACE_EVENT(nfsd_lookup_dentry, > TP_printk("xid=0x%08x fh_hash=0x%08x name=%s", > __entry->xid, __entry->fh_hash, __get_str(name)) > ); > + > +DECLARE_EVENT_CLASS(nfsd_vfs_create_class, > + TP_PROTO(struct svc_rqst *rqstp, > + struct svc_fh *fhp, > + umode_t type, > + const char *name, > + unsigned int len), > + TP_ARGS(rqstp, fhp, type, name, len), > + TP_STRUCT__entry( > + SVC_RQST_ENDPOINT_FIELDS(rqstp) > + __field(u32, fh_hash) > + __field(umode_t, type) > + __string_len(name, name, len) > + ), > + TP_fast_assign( > + SVC_RQST_ENDPOINT_ASSIGNMENTS(rqstp); > + __entry->fh_hash = knfsd_fh_hash(&fhp->fh_handle); > + __entry->type = type; > + __assign_str(name); > + ), > + TP_printk("xid=0x%08x fh_hash=0x%08x type=%s name=%s", > + __entry->xid, __entry->fh_hash, > + show_fs_file_type(__entry->type), __get_str(name)) > +); > + > +#define DEFINE_NFSD_VFS_CREATE_EVENT(__name) \ > + DEFINE_EVENT(nfsd_vfs_create_class, __name, \ > + TP_PROTO(struct svc_rqst *rqstp, struct svc_fh *fhp, \ > + umode_t type, const char *name, unsigned int len), \ > + TP_ARGS(rqstp, fhp, type, name, len)) > + > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd_proc_create); > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd_proc_mkdir); > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_create); > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_mkdir); > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_mknod); > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd4_create); > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd4_create_file); I think we would be better off with one or two new trace points in nfsd_create() and nfsd_create_setattr() instead of all of these... Unless I've missed what you are trying to observe...? > + > #endif /* _NFSD_TRACE_H */ > > #undef TRACE_INCLUDE_PATH >
On Wed, 2025-04-09 at 11:09 -0400, Chuck Lever wrote: > On 4/9/25 10:32 AM, Jeff Layton wrote: > > ...and remove the legacy dprintks. > > > > Signed-off-by: Jeff Layton <jlayton@kernel.org> > > --- > > fs/nfsd/nfs3proc.c | 18 +++++------------- > > fs/nfsd/nfs4proc.c | 29 +++++++++++++++++++++++++++++ > > fs/nfsd/nfsproc.c | 6 +++--- > > fs/nfsd/trace.h | 39 +++++++++++++++++++++++++++++++++++++++ > > 4 files changed, 76 insertions(+), 16 deletions(-) > > > > diff --git a/fs/nfsd/nfs3proc.c b/fs/nfsd/nfs3proc.c > > index 372bdcf5e07a5c835da240ecebb02e3576eb2ca6..ea1280970ea11b2a82f0de88ad0422eef7063d6d 100644 > > --- a/fs/nfsd/nfs3proc.c > > +++ b/fs/nfsd/nfs3proc.c > > @@ -14,6 +14,7 @@ > > #include "xdr3.h" > > #include "vfs.h" > > #include "filecache.h" > > +#include "trace.h" > > > > #define NFSDDBG_FACILITY NFSDDBG_PROC > > > > @@ -380,10 +381,7 @@ nfsd3_proc_create(struct svc_rqst *rqstp) > > struct nfsd3_diropres *resp = rqstp->rq_resp; > > svc_fh *dirfhp, *newfhp; > > > > - dprintk("nfsd: CREATE(3) %s %.*s\n", > > - SVCFH_fmt(&argp->fh), > > - argp->len, > > - argp->name); > > + trace_nfsd3_proc_create(rqstp, &argp->fh, S_IFREG, argp->name, argp->len); > > > > dirfhp = fh_copy(&resp->dirfh, &argp->fh); > > newfhp = fh_init(&resp->fh, NFS3_FHSIZE); > > @@ -405,10 +403,7 @@ nfsd3_proc_mkdir(struct svc_rqst *rqstp) > > .na_iattr = &argp->attrs, > > }; > > > > - dprintk("nfsd: MKDIR(3) %s %.*s\n", > > - SVCFH_fmt(&argp->fh), > > - argp->len, > > - argp->name); > > + trace_nfsd3_proc_mkdir(rqstp, &argp->fh, S_IFDIR, argp->name, argp->len); > > > > argp->attrs.ia_valid &= ~ATTR_SIZE; > > fh_copy(&resp->dirfh, &argp->fh); > > @@ -471,13 +466,10 @@ nfsd3_proc_mknod(struct svc_rqst *rqstp) > > struct nfsd_attrs attrs = { > > .na_iattr = &argp->attrs, > > }; > > - int type; > > + int type = nfs3_ftypes[argp->ftype]; > > dev_t rdev = 0; > > > > - dprintk("nfsd: MKNOD(3) %s %.*s\n", > > - SVCFH_fmt(&argp->fh), > > - argp->len, > > - argp->name); > > + trace_nfsd3_proc_mknod(rqstp, &argp->fh, type, argp->name, argp->len); > > > > fh_copy(&resp->dirfh, &argp->fh); > > fh_init(&resp->fh, NFS3_FHSIZE); > > diff --git a/fs/nfsd/nfs4proc.c b/fs/nfsd/nfs4proc.c > > index 6e23d6103010197c0316b07c189fe12ec3033812..2c795103deaa4044596bd07d90db788169a32a0c 100644 > > --- a/fs/nfsd/nfs4proc.c > > +++ b/fs/nfsd/nfs4proc.c > > @@ -250,6 +250,8 @@ nfsd4_create_file(struct svc_rqst *rqstp, struct svc_fh *fhp, > > __be32 status; > > int host_err; > > > > + trace_nfsd4_create_file(rqstp, fhp, S_IFREG, open->op_fname, open->op_fnamelen); > > + > > if (isdotent(open->op_fname, open->op_fnamelen)) > > return nfserr_exist; > > if (!(iap->ia_valid & ATTR_MODE)) > > @@ -807,6 +809,29 @@ nfsd4_commit(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, > > return status; > > } > > > > +static umode_t nfs_type_to_vfs_type(enum nfs_ftype4 nfstype) > > +{ > > + switch (nfstype) { > > + case NF4REG: > > + return S_IFREG; > > + case NF4DIR: > > + return S_IFDIR; > > + case NF4BLK: > > + return S_IFBLK; > > + case NF4CHR: > > + return S_IFCHR; > > + case NF4LNK: > > + return S_IFLNK; > > + case NF4SOCK: > > + return S_IFSOCK; > > + case NF4FIFO: > > + return S_IFIFO; > > + default: > > + break; > > + } > > + return 0; > > +} > > + > > Wondering what happens when trace points are disabled in the kernel > build. Maybe this helper belongs in fs/nfsd/trace.h instead as a > macro wrapper for __print_symbolic(). But see below. > If tracepoints are disabled, then the only caller of this static function would go away, so it should get optimized out. I don't see how you'd make this a wrapper around __print_symbolic(), since the point is to pass in a NFS version-independent constant that the tracepoint class can use as a type. > > > static __be32 > > nfsd4_create(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, > > union nfsd4_op_u *u) > > @@ -822,6 +847,10 @@ nfsd4_create(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, > > __be32 status; > > dev_t rdev; > > > > + trace_nfsd4_create(rqstp, &cstate->current_fh, > > + nfs_type_to_vfs_type(create->cr_type), > > + create->cr_name, create->cr_namelen); > > + > > fh_init(&resfh, NFS4_FHSIZE); > > > > status = fh_verify(rqstp, &cstate->current_fh, S_IFDIR, NFSD_MAY_NOP); > > diff --git a/fs/nfsd/nfsproc.c b/fs/nfsd/nfsproc.c > > index 6dda081eb24c00b834ab0965c3a35a12115bceb7..33d8cbf8785588d38d4ec5efd769c1d1d06c6a91 100644 > > --- a/fs/nfsd/nfsproc.c > > +++ b/fs/nfsd/nfsproc.c > > @@ -10,6 +10,7 @@ > > #include "cache.h" > > #include "xdr.h" > > #include "vfs.h" > > +#include "trace.h" > > > > #define NFSDDBG_FACILITY NFSDDBG_PROC > > > > @@ -292,8 +293,7 @@ nfsd_proc_create(struct svc_rqst *rqstp) > > int hosterr; > > dev_t rdev = 0, wanted = new_decode_dev(attr->ia_size); > > > > - dprintk("nfsd: CREATE %s %.*s\n", > > - SVCFH_fmt(dirfhp), argp->len, argp->name); > > + trace_nfsd_proc_create(rqstp, dirfhp, S_IFREG, argp->name, argp->len); > > > > /* First verify the parent file handle */ > > resp->status = fh_verify(rqstp, dirfhp, S_IFDIR, NFSD_MAY_EXEC); > > @@ -548,7 +548,7 @@ nfsd_proc_mkdir(struct svc_rqst *rqstp) > > .na_iattr = &argp->attrs, > > }; > > > > - dprintk("nfsd: MKDIR %s %.*s\n", SVCFH_fmt(&argp->fh), argp->len, argp->name); > > + trace_nfsd_proc_mkdir(rqstp, &argp->fh, S_IFDIR, argp->name, argp->len); > > > > if (resp->fh.fh_dentry) { > > printk(KERN_WARNING > > diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h > > index 382849d7c321d6ded8213890c2e7075770aa716c..c6aff23a845f06c87e701d57ec577c2c5c5a743c 100644 > > --- a/fs/nfsd/trace.h > > +++ b/fs/nfsd/trace.h > > @@ -2391,6 +2391,45 @@ TRACE_EVENT(nfsd_lookup_dentry, > > TP_printk("xid=0x%08x fh_hash=0x%08x name=%s", > > __entry->xid, __entry->fh_hash, __get_str(name)) > > ); > > + > > +DECLARE_EVENT_CLASS(nfsd_vfs_create_class, > > + TP_PROTO(struct svc_rqst *rqstp, > > + struct svc_fh *fhp, > > + umode_t type, > > + const char *name, > > + unsigned int len), > > + TP_ARGS(rqstp, fhp, type, name, len), > > + TP_STRUCT__entry( > > + SVC_RQST_ENDPOINT_FIELDS(rqstp) > > + __field(u32, fh_hash) > > + __field(umode_t, type) > > + __string_len(name, name, len) > > + ), > > + TP_fast_assign( > > + SVC_RQST_ENDPOINT_ASSIGNMENTS(rqstp); > > + __entry->fh_hash = knfsd_fh_hash(&fhp->fh_handle); > > + __entry->type = type; > > + __assign_str(name); > > + ), > > + TP_printk("xid=0x%08x fh_hash=0x%08x type=%s name=%s", > > + __entry->xid, __entry->fh_hash, > > + show_fs_file_type(__entry->type), __get_str(name)) > > +); > > + > > +#define DEFINE_NFSD_VFS_CREATE_EVENT(__name) \ > > + DEFINE_EVENT(nfsd_vfs_create_class, __name, \ > > + TP_PROTO(struct svc_rqst *rqstp, struct svc_fh *fhp, \ > > + umode_t type, const char *name, unsigned int len), \ > > + TP_ARGS(rqstp, fhp, type, name, len)) > > + > > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd_proc_create); > > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd_proc_mkdir); > > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_create); > > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_mkdir); > > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_mknod); > > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd4_create); > > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd4_create_file); > > I think we would be better off with one or two new trace points in > nfsd_create() and nfsd_create_setattr() instead of all of these... > > Unless I've missed what you are trying to observe...? > I'll look into doing it that way. > > > + > > #endif /* _NFSD_TRACE_H */ > > > > #undef TRACE_INCLUDE_PATH > > > >
On 4/9/25 11:36 AM, Jeff Layton wrote: > On Wed, 2025-04-09 at 11:09 -0400, Chuck Lever wrote: >> On 4/9/25 10:32 AM, Jeff Layton wrote: >>> ...and remove the legacy dprintks. >>> >>> Signed-off-by: Jeff Layton <jlayton@kernel.org> >>> --- >>> fs/nfsd/nfs3proc.c | 18 +++++------------- >>> fs/nfsd/nfs4proc.c | 29 +++++++++++++++++++++++++++++ >>> fs/nfsd/nfsproc.c | 6 +++--- >>> fs/nfsd/trace.h | 39 +++++++++++++++++++++++++++++++++++++++ >>> 4 files changed, 76 insertions(+), 16 deletions(-) >>> >>> diff --git a/fs/nfsd/nfs3proc.c b/fs/nfsd/nfs3proc.c >>> index 372bdcf5e07a5c835da240ecebb02e3576eb2ca6..ea1280970ea11b2a82f0de88ad0422eef7063d6d 100644 >>> --- a/fs/nfsd/nfs3proc.c >>> +++ b/fs/nfsd/nfs3proc.c >>> @@ -14,6 +14,7 @@ >>> #include "xdr3.h" >>> #include "vfs.h" >>> #include "filecache.h" >>> +#include "trace.h" >>> >>> #define NFSDDBG_FACILITY NFSDDBG_PROC >>> >>> @@ -380,10 +381,7 @@ nfsd3_proc_create(struct svc_rqst *rqstp) >>> struct nfsd3_diropres *resp = rqstp->rq_resp; >>> svc_fh *dirfhp, *newfhp; >>> >>> - dprintk("nfsd: CREATE(3) %s %.*s\n", >>> - SVCFH_fmt(&argp->fh), >>> - argp->len, >>> - argp->name); >>> + trace_nfsd3_proc_create(rqstp, &argp->fh, S_IFREG, argp->name, argp->len); >>> >>> dirfhp = fh_copy(&resp->dirfh, &argp->fh); >>> newfhp = fh_init(&resp->fh, NFS3_FHSIZE); >>> @@ -405,10 +403,7 @@ nfsd3_proc_mkdir(struct svc_rqst *rqstp) >>> .na_iattr = &argp->attrs, >>> }; >>> >>> - dprintk("nfsd: MKDIR(3) %s %.*s\n", >>> - SVCFH_fmt(&argp->fh), >>> - argp->len, >>> - argp->name); >>> + trace_nfsd3_proc_mkdir(rqstp, &argp->fh, S_IFDIR, argp->name, argp->len); >>> >>> argp->attrs.ia_valid &= ~ATTR_SIZE; >>> fh_copy(&resp->dirfh, &argp->fh); >>> @@ -471,13 +466,10 @@ nfsd3_proc_mknod(struct svc_rqst *rqstp) >>> struct nfsd_attrs attrs = { >>> .na_iattr = &argp->attrs, >>> }; >>> - int type; >>> + int type = nfs3_ftypes[argp->ftype]; >>> dev_t rdev = 0; >>> >>> - dprintk("nfsd: MKNOD(3) %s %.*s\n", >>> - SVCFH_fmt(&argp->fh), >>> - argp->len, >>> - argp->name); >>> + trace_nfsd3_proc_mknod(rqstp, &argp->fh, type, argp->name, argp->len); >>> >>> fh_copy(&resp->dirfh, &argp->fh); >>> fh_init(&resp->fh, NFS3_FHSIZE); >>> diff --git a/fs/nfsd/nfs4proc.c b/fs/nfsd/nfs4proc.c >>> index 6e23d6103010197c0316b07c189fe12ec3033812..2c795103deaa4044596bd07d90db788169a32a0c 100644 >>> --- a/fs/nfsd/nfs4proc.c >>> +++ b/fs/nfsd/nfs4proc.c >>> @@ -250,6 +250,8 @@ nfsd4_create_file(struct svc_rqst *rqstp, struct svc_fh *fhp, >>> __be32 status; >>> int host_err; >>> >>> + trace_nfsd4_create_file(rqstp, fhp, S_IFREG, open->op_fname, open->op_fnamelen); >>> + >>> if (isdotent(open->op_fname, open->op_fnamelen)) >>> return nfserr_exist; >>> if (!(iap->ia_valid & ATTR_MODE)) >>> @@ -807,6 +809,29 @@ nfsd4_commit(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, >>> return status; >>> } >>> >>> +static umode_t nfs_type_to_vfs_type(enum nfs_ftype4 nfstype) >>> +{ >>> + switch (nfstype) { >>> + case NF4REG: >>> + return S_IFREG; >>> + case NF4DIR: >>> + return S_IFDIR; >>> + case NF4BLK: >>> + return S_IFBLK; >>> + case NF4CHR: >>> + return S_IFCHR; >>> + case NF4LNK: >>> + return S_IFLNK; >>> + case NF4SOCK: >>> + return S_IFSOCK; >>> + case NF4FIFO: >>> + return S_IFIFO; >>> + default: >>> + break; >>> + } >>> + return 0; >>> +} >>> + >> >> Wondering what happens when trace points are disabled in the kernel >> build. Maybe this helper belongs in fs/nfsd/trace.h instead as a >> macro wrapper for __print_symbolic(). But see below. >> > > If tracepoints are disabled, then the only caller of this static > function would go away, so it should get optimized out. AIUI, the compiler will complain in that case. If we need to keep this function here, then this is a legitimate use for "inline". > I don't see how > you'd make this a wrapper around __print_symbolic(), since the point is > to pass in a NFS version-independent constant that the tracepoint class > can use as a type. > >> >>> static __be32 >>> nfsd4_create(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, >>> union nfsd4_op_u *u) >>> @@ -822,6 +847,10 @@ nfsd4_create(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, >>> __be32 status; >>> dev_t rdev; >>> >>> + trace_nfsd4_create(rqstp, &cstate->current_fh, >>> + nfs_type_to_vfs_type(create->cr_type), >>> + create->cr_name, create->cr_namelen); >>> + >>> fh_init(&resfh, NFS4_FHSIZE); >>> >>> status = fh_verify(rqstp, &cstate->current_fh, S_IFDIR, NFSD_MAY_NOP); >>> diff --git a/fs/nfsd/nfsproc.c b/fs/nfsd/nfsproc.c >>> index 6dda081eb24c00b834ab0965c3a35a12115bceb7..33d8cbf8785588d38d4ec5efd769c1d1d06c6a91 100644 >>> --- a/fs/nfsd/nfsproc.c >>> +++ b/fs/nfsd/nfsproc.c >>> @@ -10,6 +10,7 @@ >>> #include "cache.h" >>> #include "xdr.h" >>> #include "vfs.h" >>> +#include "trace.h" >>> >>> #define NFSDDBG_FACILITY NFSDDBG_PROC >>> >>> @@ -292,8 +293,7 @@ nfsd_proc_create(struct svc_rqst *rqstp) >>> int hosterr; >>> dev_t rdev = 0, wanted = new_decode_dev(attr->ia_size); >>> >>> - dprintk("nfsd: CREATE %s %.*s\n", >>> - SVCFH_fmt(dirfhp), argp->len, argp->name); >>> + trace_nfsd_proc_create(rqstp, dirfhp, S_IFREG, argp->name, argp->len); >>> >>> /* First verify the parent file handle */ >>> resp->status = fh_verify(rqstp, dirfhp, S_IFDIR, NFSD_MAY_EXEC); >>> @@ -548,7 +548,7 @@ nfsd_proc_mkdir(struct svc_rqst *rqstp) >>> .na_iattr = &argp->attrs, >>> }; >>> >>> - dprintk("nfsd: MKDIR %s %.*s\n", SVCFH_fmt(&argp->fh), argp->len, argp->name); >>> + trace_nfsd_proc_mkdir(rqstp, &argp->fh, S_IFDIR, argp->name, argp->len); >>> >>> if (resp->fh.fh_dentry) { >>> printk(KERN_WARNING >>> diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h >>> index 382849d7c321d6ded8213890c2e7075770aa716c..c6aff23a845f06c87e701d57ec577c2c5c5a743c 100644 >>> --- a/fs/nfsd/trace.h >>> +++ b/fs/nfsd/trace.h >>> @@ -2391,6 +2391,45 @@ TRACE_EVENT(nfsd_lookup_dentry, >>> TP_printk("xid=0x%08x fh_hash=0x%08x name=%s", >>> __entry->xid, __entry->fh_hash, __get_str(name)) >>> ); >>> + >>> +DECLARE_EVENT_CLASS(nfsd_vfs_create_class, >>> + TP_PROTO(struct svc_rqst *rqstp, >>> + struct svc_fh *fhp, >>> + umode_t type, >>> + const char *name, >>> + unsigned int len), >>> + TP_ARGS(rqstp, fhp, type, name, len), >>> + TP_STRUCT__entry( >>> + SVC_RQST_ENDPOINT_FIELDS(rqstp) >>> + __field(u32, fh_hash) >>> + __field(umode_t, type) >>> + __string_len(name, name, len) >>> + ), >>> + TP_fast_assign( >>> + SVC_RQST_ENDPOINT_ASSIGNMENTS(rqstp); >>> + __entry->fh_hash = knfsd_fh_hash(&fhp->fh_handle); >>> + __entry->type = type; >>> + __assign_str(name); >>> + ), >>> + TP_printk("xid=0x%08x fh_hash=0x%08x type=%s name=%s", >>> + __entry->xid, __entry->fh_hash, >>> + show_fs_file_type(__entry->type), __get_str(name)) >>> +); >>> + >>> +#define DEFINE_NFSD_VFS_CREATE_EVENT(__name) \ >>> + DEFINE_EVENT(nfsd_vfs_create_class, __name, \ >>> + TP_PROTO(struct svc_rqst *rqstp, struct svc_fh *fhp, \ >>> + umode_t type, const char *name, unsigned int len), \ >>> + TP_ARGS(rqstp, fhp, type, name, len)) >>> + >>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd_proc_create); >>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd_proc_mkdir); >>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_create); >>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_mkdir); >>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_mknod); >>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd4_create); >>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd4_create_file); >> >> I think we would be better off with one or two new trace points in >> nfsd_create() and nfsd_create_setattr() instead of all of these... >> >> Unless I've missed what you are trying to observe...? >> > > I'll look into doing it that way. > >> >>> + >>> #endif /* _NFSD_TRACE_H */ >>> >>> #undef TRACE_INCLUDE_PATH >>> >> >> >
On 4/9/25 11:38 AM, Chuck Lever wrote: > On 4/9/25 11:36 AM, Jeff Layton wrote: >> On Wed, 2025-04-09 at 11:09 -0400, Chuck Lever wrote: >>> On 4/9/25 10:32 AM, Jeff Layton wrote: >>>> ...and remove the legacy dprintks. >>>> >>>> Signed-off-by: Jeff Layton <jlayton@kernel.org> >>>> --- >>>> fs/nfsd/nfs3proc.c | 18 +++++------------- >>>> fs/nfsd/nfs4proc.c | 29 +++++++++++++++++++++++++++++ >>>> fs/nfsd/nfsproc.c | 6 +++--- >>>> fs/nfsd/trace.h | 39 +++++++++++++++++++++++++++++++++++++++ >>>> 4 files changed, 76 insertions(+), 16 deletions(-) >>>> >>>> diff --git a/fs/nfsd/nfs3proc.c b/fs/nfsd/nfs3proc.c >>>> index 372bdcf5e07a5c835da240ecebb02e3576eb2ca6..ea1280970ea11b2a82f0de88ad0422eef7063d6d 100644 >>>> --- a/fs/nfsd/nfs3proc.c >>>> +++ b/fs/nfsd/nfs3proc.c >>>> @@ -14,6 +14,7 @@ >>>> #include "xdr3.h" >>>> #include "vfs.h" >>>> #include "filecache.h" >>>> +#include "trace.h" >>>> >>>> #define NFSDDBG_FACILITY NFSDDBG_PROC >>>> >>>> @@ -380,10 +381,7 @@ nfsd3_proc_create(struct svc_rqst *rqstp) >>>> struct nfsd3_diropres *resp = rqstp->rq_resp; >>>> svc_fh *dirfhp, *newfhp; >>>> >>>> - dprintk("nfsd: CREATE(3) %s %.*s\n", >>>> - SVCFH_fmt(&argp->fh), >>>> - argp->len, >>>> - argp->name); >>>> + trace_nfsd3_proc_create(rqstp, &argp->fh, S_IFREG, argp->name, argp->len); >>>> >>>> dirfhp = fh_copy(&resp->dirfh, &argp->fh); >>>> newfhp = fh_init(&resp->fh, NFS3_FHSIZE); >>>> @@ -405,10 +403,7 @@ nfsd3_proc_mkdir(struct svc_rqst *rqstp) >>>> .na_iattr = &argp->attrs, >>>> }; >>>> >>>> - dprintk("nfsd: MKDIR(3) %s %.*s\n", >>>> - SVCFH_fmt(&argp->fh), >>>> - argp->len, >>>> - argp->name); >>>> + trace_nfsd3_proc_mkdir(rqstp, &argp->fh, S_IFDIR, argp->name, argp->len); >>>> >>>> argp->attrs.ia_valid &= ~ATTR_SIZE; >>>> fh_copy(&resp->dirfh, &argp->fh); >>>> @@ -471,13 +466,10 @@ nfsd3_proc_mknod(struct svc_rqst *rqstp) >>>> struct nfsd_attrs attrs = { >>>> .na_iattr = &argp->attrs, >>>> }; >>>> - int type; >>>> + int type = nfs3_ftypes[argp->ftype]; >>>> dev_t rdev = 0; >>>> >>>> - dprintk("nfsd: MKNOD(3) %s %.*s\n", >>>> - SVCFH_fmt(&argp->fh), >>>> - argp->len, >>>> - argp->name); >>>> + trace_nfsd3_proc_mknod(rqstp, &argp->fh, type, argp->name, argp->len); >>>> >>>> fh_copy(&resp->dirfh, &argp->fh); >>>> fh_init(&resp->fh, NFS3_FHSIZE); >>>> diff --git a/fs/nfsd/nfs4proc.c b/fs/nfsd/nfs4proc.c >>>> index 6e23d6103010197c0316b07c189fe12ec3033812..2c795103deaa4044596bd07d90db788169a32a0c 100644 >>>> --- a/fs/nfsd/nfs4proc.c >>>> +++ b/fs/nfsd/nfs4proc.c >>>> @@ -250,6 +250,8 @@ nfsd4_create_file(struct svc_rqst *rqstp, struct svc_fh *fhp, >>>> __be32 status; >>>> int host_err; >>>> >>>> + trace_nfsd4_create_file(rqstp, fhp, S_IFREG, open->op_fname, open->op_fnamelen); >>>> + >>>> if (isdotent(open->op_fname, open->op_fnamelen)) >>>> return nfserr_exist; >>>> if (!(iap->ia_valid & ATTR_MODE)) >>>> @@ -807,6 +809,29 @@ nfsd4_commit(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, >>>> return status; >>>> } >>>> >>>> +static umode_t nfs_type_to_vfs_type(enum nfs_ftype4 nfstype) >>>> +{ >>>> + switch (nfstype) { >>>> + case NF4REG: >>>> + return S_IFREG; >>>> + case NF4DIR: >>>> + return S_IFDIR; >>>> + case NF4BLK: >>>> + return S_IFBLK; >>>> + case NF4CHR: >>>> + return S_IFCHR; >>>> + case NF4LNK: >>>> + return S_IFLNK; >>>> + case NF4SOCK: >>>> + return S_IFSOCK; >>>> + case NF4FIFO: >>>> + return S_IFIFO; >>>> + default: >>>> + break; >>>> + } >>>> + return 0; >>>> +} >>>> + >>> >>> Wondering what happens when trace points are disabled in the kernel >>> build. Maybe this helper belongs in fs/nfsd/trace.h instead as a >>> macro wrapper for __print_symbolic(). But see below. >>> >> >> If tracepoints are disabled, then the only caller of this static >> function would go away, so it should get optimized out. > > AIUI, the compiler will complain in that case. If we need to keep this > function here, then this is a legitimate use for "inline". or maybe_unused. >> I don't see how >> you'd make this a wrapper around __print_symbolic(), since the point is >> to pass in a NFS version-independent constant that the tracepoint class >> can use as a type. >> >>> >>>> static __be32 >>>> nfsd4_create(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, >>>> union nfsd4_op_u *u) >>>> @@ -822,6 +847,10 @@ nfsd4_create(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, >>>> __be32 status; >>>> dev_t rdev; >>>> >>>> + trace_nfsd4_create(rqstp, &cstate->current_fh, >>>> + nfs_type_to_vfs_type(create->cr_type), >>>> + create->cr_name, create->cr_namelen); >>>> + >>>> fh_init(&resfh, NFS4_FHSIZE); >>>> >>>> status = fh_verify(rqstp, &cstate->current_fh, S_IFDIR, NFSD_MAY_NOP); >>>> diff --git a/fs/nfsd/nfsproc.c b/fs/nfsd/nfsproc.c >>>> index 6dda081eb24c00b834ab0965c3a35a12115bceb7..33d8cbf8785588d38d4ec5efd769c1d1d06c6a91 100644 >>>> --- a/fs/nfsd/nfsproc.c >>>> +++ b/fs/nfsd/nfsproc.c >>>> @@ -10,6 +10,7 @@ >>>> #include "cache.h" >>>> #include "xdr.h" >>>> #include "vfs.h" >>>> +#include "trace.h" >>>> >>>> #define NFSDDBG_FACILITY NFSDDBG_PROC >>>> >>>> @@ -292,8 +293,7 @@ nfsd_proc_create(struct svc_rqst *rqstp) >>>> int hosterr; >>>> dev_t rdev = 0, wanted = new_decode_dev(attr->ia_size); >>>> >>>> - dprintk("nfsd: CREATE %s %.*s\n", >>>> - SVCFH_fmt(dirfhp), argp->len, argp->name); >>>> + trace_nfsd_proc_create(rqstp, dirfhp, S_IFREG, argp->name, argp->len); >>>> >>>> /* First verify the parent file handle */ >>>> resp->status = fh_verify(rqstp, dirfhp, S_IFDIR, NFSD_MAY_EXEC); >>>> @@ -548,7 +548,7 @@ nfsd_proc_mkdir(struct svc_rqst *rqstp) >>>> .na_iattr = &argp->attrs, >>>> }; >>>> >>>> - dprintk("nfsd: MKDIR %s %.*s\n", SVCFH_fmt(&argp->fh), argp->len, argp->name); >>>> + trace_nfsd_proc_mkdir(rqstp, &argp->fh, S_IFDIR, argp->name, argp->len); >>>> >>>> if (resp->fh.fh_dentry) { >>>> printk(KERN_WARNING >>>> diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h >>>> index 382849d7c321d6ded8213890c2e7075770aa716c..c6aff23a845f06c87e701d57ec577c2c5c5a743c 100644 >>>> --- a/fs/nfsd/trace.h >>>> +++ b/fs/nfsd/trace.h >>>> @@ -2391,6 +2391,45 @@ TRACE_EVENT(nfsd_lookup_dentry, >>>> TP_printk("xid=0x%08x fh_hash=0x%08x name=%s", >>>> __entry->xid, __entry->fh_hash, __get_str(name)) >>>> ); >>>> + >>>> +DECLARE_EVENT_CLASS(nfsd_vfs_create_class, >>>> + TP_PROTO(struct svc_rqst *rqstp, >>>> + struct svc_fh *fhp, >>>> + umode_t type, >>>> + const char *name, >>>> + unsigned int len), >>>> + TP_ARGS(rqstp, fhp, type, name, len), >>>> + TP_STRUCT__entry( >>>> + SVC_RQST_ENDPOINT_FIELDS(rqstp) >>>> + __field(u32, fh_hash) >>>> + __field(umode_t, type) >>>> + __string_len(name, name, len) >>>> + ), >>>> + TP_fast_assign( >>>> + SVC_RQST_ENDPOINT_ASSIGNMENTS(rqstp); >>>> + __entry->fh_hash = knfsd_fh_hash(&fhp->fh_handle); >>>> + __entry->type = type; >>>> + __assign_str(name); >>>> + ), >>>> + TP_printk("xid=0x%08x fh_hash=0x%08x type=%s name=%s", >>>> + __entry->xid, __entry->fh_hash, >>>> + show_fs_file_type(__entry->type), __get_str(name)) >>>> +); >>>> + >>>> +#define DEFINE_NFSD_VFS_CREATE_EVENT(__name) \ >>>> + DEFINE_EVENT(nfsd_vfs_create_class, __name, \ >>>> + TP_PROTO(struct svc_rqst *rqstp, struct svc_fh *fhp, \ >>>> + umode_t type, const char *name, unsigned int len), \ >>>> + TP_ARGS(rqstp, fhp, type, name, len)) >>>> + >>>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd_proc_create); >>>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd_proc_mkdir); >>>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_create); >>>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_mkdir); >>>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_mknod); >>>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd4_create); >>>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd4_create_file); >>> >>> I think we would be better off with one or two new trace points in >>> nfsd_create() and nfsd_create_setattr() instead of all of these... >>> >>> Unless I've missed what you are trying to observe...? >>> >> >> I'll look into doing it that way. >> >>> >>>> + >>>> #endif /* _NFSD_TRACE_H */ >>>> >>>> #undef TRACE_INCLUDE_PATH >>>> >>> >>> >> > >
On Wed, 2025-04-09 at 11:09 -0400, Chuck Lever wrote: > On 4/9/25 10:32 AM, Jeff Layton wrote: > > ...and remove the legacy dprintks. > > > > Signed-off-by: Jeff Layton <jlayton@kernel.org> > > --- > > fs/nfsd/nfs3proc.c | 18 +++++------------- > > fs/nfsd/nfs4proc.c | 29 +++++++++++++++++++++++++++++ > > fs/nfsd/nfsproc.c | 6 +++--- > > fs/nfsd/trace.h | 39 +++++++++++++++++++++++++++++++++++++++ > > 4 files changed, 76 insertions(+), 16 deletions(-) > > > > diff --git a/fs/nfsd/nfs3proc.c b/fs/nfsd/nfs3proc.c > > index 372bdcf5e07a5c835da240ecebb02e3576eb2ca6..ea1280970ea11b2a82f0de88ad0422eef7063d6d 100644 > > --- a/fs/nfsd/nfs3proc.c > > +++ b/fs/nfsd/nfs3proc.c > > @@ -14,6 +14,7 @@ > > #include "xdr3.h" > > #include "vfs.h" > > #include "filecache.h" > > +#include "trace.h" > > > > #define NFSDDBG_FACILITY NFSDDBG_PROC > > > > @@ -380,10 +381,7 @@ nfsd3_proc_create(struct svc_rqst *rqstp) > > struct nfsd3_diropres *resp = rqstp->rq_resp; > > svc_fh *dirfhp, *newfhp; > > > > - dprintk("nfsd: CREATE(3) %s %.*s\n", > > - SVCFH_fmt(&argp->fh), > > - argp->len, > > - argp->name); > > + trace_nfsd3_proc_create(rqstp, &argp->fh, S_IFREG, argp->name, argp->len); > > > > dirfhp = fh_copy(&resp->dirfh, &argp->fh); > > newfhp = fh_init(&resp->fh, NFS3_FHSIZE); > > @@ -405,10 +403,7 @@ nfsd3_proc_mkdir(struct svc_rqst *rqstp) > > .na_iattr = &argp->attrs, > > }; > > > > - dprintk("nfsd: MKDIR(3) %s %.*s\n", > > - SVCFH_fmt(&argp->fh), > > - argp->len, > > - argp->name); > > + trace_nfsd3_proc_mkdir(rqstp, &argp->fh, S_IFDIR, argp->name, argp->len); > > > > argp->attrs.ia_valid &= ~ATTR_SIZE; > > fh_copy(&resp->dirfh, &argp->fh); > > @@ -471,13 +466,10 @@ nfsd3_proc_mknod(struct svc_rqst *rqstp) > > struct nfsd_attrs attrs = { > > .na_iattr = &argp->attrs, > > }; > > - int type; > > + int type = nfs3_ftypes[argp->ftype]; > > dev_t rdev = 0; > > > > - dprintk("nfsd: MKNOD(3) %s %.*s\n", > > - SVCFH_fmt(&argp->fh), > > - argp->len, > > - argp->name); > > + trace_nfsd3_proc_mknod(rqstp, &argp->fh, type, argp->name, argp->len); > > > > fh_copy(&resp->dirfh, &argp->fh); > > fh_init(&resp->fh, NFS3_FHSIZE); > > diff --git a/fs/nfsd/nfs4proc.c b/fs/nfsd/nfs4proc.c > > index 6e23d6103010197c0316b07c189fe12ec3033812..2c795103deaa4044596bd07d90db788169a32a0c 100644 > > --- a/fs/nfsd/nfs4proc.c > > +++ b/fs/nfsd/nfs4proc.c > > @@ -250,6 +250,8 @@ nfsd4_create_file(struct svc_rqst *rqstp, struct svc_fh *fhp, > > __be32 status; > > int host_err; > > > > + trace_nfsd4_create_file(rqstp, fhp, S_IFREG, open->op_fname, open->op_fnamelen); > > + > > if (isdotent(open->op_fname, open->op_fnamelen)) > > return nfserr_exist; > > if (!(iap->ia_valid & ATTR_MODE)) > > @@ -807,6 +809,29 @@ nfsd4_commit(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, > > return status; > > } > > > > +static umode_t nfs_type_to_vfs_type(enum nfs_ftype4 nfstype) > > +{ > > + switch (nfstype) { > > + case NF4REG: > > + return S_IFREG; > > + case NF4DIR: > > + return S_IFDIR; > > + case NF4BLK: > > + return S_IFBLK; > > + case NF4CHR: > > + return S_IFCHR; > > + case NF4LNK: > > + return S_IFLNK; > > + case NF4SOCK: > > + return S_IFSOCK; > > + case NF4FIFO: > > + return S_IFIFO; > > + default: > > + break; > > + } > > + return 0; > > +} > > + > > Wondering what happens when trace points are disabled in the kernel > build. Maybe this helper belongs in fs/nfsd/trace.h instead as a > macro wrapper for __print_symbolic(). But see below. > > > > static __be32 > > nfsd4_create(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, > > union nfsd4_op_u *u) > > @@ -822,6 +847,10 @@ nfsd4_create(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, > > __be32 status; > > dev_t rdev; > > > > + trace_nfsd4_create(rqstp, &cstate->current_fh, > > + nfs_type_to_vfs_type(create->cr_type), > > + create->cr_name, create->cr_namelen); > > + > > fh_init(&resfh, NFS4_FHSIZE); > > > > status = fh_verify(rqstp, &cstate->current_fh, S_IFDIR, NFSD_MAY_NOP); > > diff --git a/fs/nfsd/nfsproc.c b/fs/nfsd/nfsproc.c > > index 6dda081eb24c00b834ab0965c3a35a12115bceb7..33d8cbf8785588d38d4ec5efd769c1d1d06c6a91 100644 > > --- a/fs/nfsd/nfsproc.c > > +++ b/fs/nfsd/nfsproc.c > > @@ -10,6 +10,7 @@ > > #include "cache.h" > > #include "xdr.h" > > #include "vfs.h" > > +#include "trace.h" > > > > #define NFSDDBG_FACILITY NFSDDBG_PROC > > > > @@ -292,8 +293,7 @@ nfsd_proc_create(struct svc_rqst *rqstp) > > int hosterr; > > dev_t rdev = 0, wanted = new_decode_dev(attr->ia_size); > > > > - dprintk("nfsd: CREATE %s %.*s\n", > > - SVCFH_fmt(dirfhp), argp->len, argp->name); > > + trace_nfsd_proc_create(rqstp, dirfhp, S_IFREG, argp->name, argp->len); > > > > /* First verify the parent file handle */ > > resp->status = fh_verify(rqstp, dirfhp, S_IFDIR, NFSD_MAY_EXEC); > > @@ -548,7 +548,7 @@ nfsd_proc_mkdir(struct svc_rqst *rqstp) > > .na_iattr = &argp->attrs, > > }; > > > > - dprintk("nfsd: MKDIR %s %.*s\n", SVCFH_fmt(&argp->fh), argp->len, argp->name); > > + trace_nfsd_proc_mkdir(rqstp, &argp->fh, S_IFDIR, argp->name, argp->len); > > > > if (resp->fh.fh_dentry) { > > printk(KERN_WARNING > > diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h > > index 382849d7c321d6ded8213890c2e7075770aa716c..c6aff23a845f06c87e701d57ec577c2c5c5a743c 100644 > > --- a/fs/nfsd/trace.h > > +++ b/fs/nfsd/trace.h > > @@ -2391,6 +2391,45 @@ TRACE_EVENT(nfsd_lookup_dentry, > > TP_printk("xid=0x%08x fh_hash=0x%08x name=%s", > > __entry->xid, __entry->fh_hash, __get_str(name)) > > ); > > + > > +DECLARE_EVENT_CLASS(nfsd_vfs_create_class, > > + TP_PROTO(struct svc_rqst *rqstp, > > + struct svc_fh *fhp, > > + umode_t type, > > + const char *name, > > + unsigned int len), > > + TP_ARGS(rqstp, fhp, type, name, len), > > + TP_STRUCT__entry( > > + SVC_RQST_ENDPOINT_FIELDS(rqstp) > > + __field(u32, fh_hash) > > + __field(umode_t, type) > > + __string_len(name, name, len) > > + ), > > + TP_fast_assign( > > + SVC_RQST_ENDPOINT_ASSIGNMENTS(rqstp); > > + __entry->fh_hash = knfsd_fh_hash(&fhp->fh_handle); > > + __entry->type = type; > > + __assign_str(name); > > + ), > > + TP_printk("xid=0x%08x fh_hash=0x%08x type=%s name=%s", > > + __entry->xid, __entry->fh_hash, > > + show_fs_file_type(__entry->type), __get_str(name)) > > +); > > + > > +#define DEFINE_NFSD_VFS_CREATE_EVENT(__name) \ > > + DEFINE_EVENT(nfsd_vfs_create_class, __name, \ > > + TP_PROTO(struct svc_rqst *rqstp, struct svc_fh *fhp, \ > > + umode_t type, const char *name, unsigned int len), \ > > + TP_ARGS(rqstp, fhp, type, name, len)) > > + > > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd_proc_create); > > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd_proc_mkdir); > > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_create); > > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_mkdir); > > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_mknod); > > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd4_create); > > +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd4_create_file); > > I think we would be better off with one or two new trace points in > nfsd_create() and nfsd_create_setattr() instead of all of these... > > Unless I've missed what you are trying to observe...? > Now I remember why I did it this way. Doing it the way you suggest makes this all a bit messy: Most of the callers create files via nfsd_create(), but nfsd3_create_file calls vfs_create() directly. It does call nfsd_create_setattr(), but that's really not the right place for this either, since it's doing a setattr and not the create itself. Notably, it isn't passed the filename. Note too that burying this tracepoint down in nfs_create() also means that error conditions can happen before the tracepoint that may mean that it won't fire. So, if you're watching the traces to see when CREATE or MKDIR calls occur, you may miss some of them. How do you want to proceed?
On 4/9/25 12:50 PM, Jeff Layton wrote: > On Wed, 2025-04-09 at 11:09 -0400, Chuck Lever wrote: >> On 4/9/25 10:32 AM, Jeff Layton wrote: >>> ...and remove the legacy dprintks. >>> >>> Signed-off-by: Jeff Layton <jlayton@kernel.org> >>> --- >>> fs/nfsd/nfs3proc.c | 18 +++++------------- >>> fs/nfsd/nfs4proc.c | 29 +++++++++++++++++++++++++++++ >>> fs/nfsd/nfsproc.c | 6 +++--- >>> fs/nfsd/trace.h | 39 +++++++++++++++++++++++++++++++++++++++ >>> 4 files changed, 76 insertions(+), 16 deletions(-) >>> >>> diff --git a/fs/nfsd/nfs3proc.c b/fs/nfsd/nfs3proc.c >>> index 372bdcf5e07a5c835da240ecebb02e3576eb2ca6..ea1280970ea11b2a82f0de88ad0422eef7063d6d 100644 >>> --- a/fs/nfsd/nfs3proc.c >>> +++ b/fs/nfsd/nfs3proc.c >>> @@ -14,6 +14,7 @@ >>> #include "xdr3.h" >>> #include "vfs.h" >>> #include "filecache.h" >>> +#include "trace.h" >>> >>> #define NFSDDBG_FACILITY NFSDDBG_PROC >>> >>> @@ -380,10 +381,7 @@ nfsd3_proc_create(struct svc_rqst *rqstp) >>> struct nfsd3_diropres *resp = rqstp->rq_resp; >>> svc_fh *dirfhp, *newfhp; >>> >>> - dprintk("nfsd: CREATE(3) %s %.*s\n", >>> - SVCFH_fmt(&argp->fh), >>> - argp->len, >>> - argp->name); >>> + trace_nfsd3_proc_create(rqstp, &argp->fh, S_IFREG, argp->name, argp->len); >>> >>> dirfhp = fh_copy(&resp->dirfh, &argp->fh); >>> newfhp = fh_init(&resp->fh, NFS3_FHSIZE); >>> @@ -405,10 +403,7 @@ nfsd3_proc_mkdir(struct svc_rqst *rqstp) >>> .na_iattr = &argp->attrs, >>> }; >>> >>> - dprintk("nfsd: MKDIR(3) %s %.*s\n", >>> - SVCFH_fmt(&argp->fh), >>> - argp->len, >>> - argp->name); >>> + trace_nfsd3_proc_mkdir(rqstp, &argp->fh, S_IFDIR, argp->name, argp->len); >>> >>> argp->attrs.ia_valid &= ~ATTR_SIZE; >>> fh_copy(&resp->dirfh, &argp->fh); >>> @@ -471,13 +466,10 @@ nfsd3_proc_mknod(struct svc_rqst *rqstp) >>> struct nfsd_attrs attrs = { >>> .na_iattr = &argp->attrs, >>> }; >>> - int type; >>> + int type = nfs3_ftypes[argp->ftype]; >>> dev_t rdev = 0; >>> >>> - dprintk("nfsd: MKNOD(3) %s %.*s\n", >>> - SVCFH_fmt(&argp->fh), >>> - argp->len, >>> - argp->name); >>> + trace_nfsd3_proc_mknod(rqstp, &argp->fh, type, argp->name, argp->len); >>> >>> fh_copy(&resp->dirfh, &argp->fh); >>> fh_init(&resp->fh, NFS3_FHSIZE); >>> diff --git a/fs/nfsd/nfs4proc.c b/fs/nfsd/nfs4proc.c >>> index 6e23d6103010197c0316b07c189fe12ec3033812..2c795103deaa4044596bd07d90db788169a32a0c 100644 >>> --- a/fs/nfsd/nfs4proc.c >>> +++ b/fs/nfsd/nfs4proc.c >>> @@ -250,6 +250,8 @@ nfsd4_create_file(struct svc_rqst *rqstp, struct svc_fh *fhp, >>> __be32 status; >>> int host_err; >>> >>> + trace_nfsd4_create_file(rqstp, fhp, S_IFREG, open->op_fname, open->op_fnamelen); >>> + >>> if (isdotent(open->op_fname, open->op_fnamelen)) >>> return nfserr_exist; >>> if (!(iap->ia_valid & ATTR_MODE)) >>> @@ -807,6 +809,29 @@ nfsd4_commit(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, >>> return status; >>> } >>> >>> +static umode_t nfs_type_to_vfs_type(enum nfs_ftype4 nfstype) >>> +{ >>> + switch (nfstype) { >>> + case NF4REG: >>> + return S_IFREG; >>> + case NF4DIR: >>> + return S_IFDIR; >>> + case NF4BLK: >>> + return S_IFBLK; >>> + case NF4CHR: >>> + return S_IFCHR; >>> + case NF4LNK: >>> + return S_IFLNK; >>> + case NF4SOCK: >>> + return S_IFSOCK; >>> + case NF4FIFO: >>> + return S_IFIFO; >>> + default: >>> + break; >>> + } >>> + return 0; >>> +} >>> + >> >> Wondering what happens when trace points are disabled in the kernel >> build. Maybe this helper belongs in fs/nfsd/trace.h instead as a >> macro wrapper for __print_symbolic(). But see below. >> >> >>> static __be32 >>> nfsd4_create(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, >>> union nfsd4_op_u *u) >>> @@ -822,6 +847,10 @@ nfsd4_create(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, >>> __be32 status; >>> dev_t rdev; >>> >>> + trace_nfsd4_create(rqstp, &cstate->current_fh, >>> + nfs_type_to_vfs_type(create->cr_type), >>> + create->cr_name, create->cr_namelen); >>> + >>> fh_init(&resfh, NFS4_FHSIZE); >>> >>> status = fh_verify(rqstp, &cstate->current_fh, S_IFDIR, NFSD_MAY_NOP); >>> diff --git a/fs/nfsd/nfsproc.c b/fs/nfsd/nfsproc.c >>> index 6dda081eb24c00b834ab0965c3a35a12115bceb7..33d8cbf8785588d38d4ec5efd769c1d1d06c6a91 100644 >>> --- a/fs/nfsd/nfsproc.c >>> +++ b/fs/nfsd/nfsproc.c >>> @@ -10,6 +10,7 @@ >>> #include "cache.h" >>> #include "xdr.h" >>> #include "vfs.h" >>> +#include "trace.h" >>> >>> #define NFSDDBG_FACILITY NFSDDBG_PROC >>> >>> @@ -292,8 +293,7 @@ nfsd_proc_create(struct svc_rqst *rqstp) >>> int hosterr; >>> dev_t rdev = 0, wanted = new_decode_dev(attr->ia_size); >>> >>> - dprintk("nfsd: CREATE %s %.*s\n", >>> - SVCFH_fmt(dirfhp), argp->len, argp->name); >>> + trace_nfsd_proc_create(rqstp, dirfhp, S_IFREG, argp->name, argp->len); >>> >>> /* First verify the parent file handle */ >>> resp->status = fh_verify(rqstp, dirfhp, S_IFDIR, NFSD_MAY_EXEC); >>> @@ -548,7 +548,7 @@ nfsd_proc_mkdir(struct svc_rqst *rqstp) >>> .na_iattr = &argp->attrs, >>> }; >>> >>> - dprintk("nfsd: MKDIR %s %.*s\n", SVCFH_fmt(&argp->fh), argp->len, argp->name); >>> + trace_nfsd_proc_mkdir(rqstp, &argp->fh, S_IFDIR, argp->name, argp->len); >>> >>> if (resp->fh.fh_dentry) { >>> printk(KERN_WARNING >>> diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h >>> index 382849d7c321d6ded8213890c2e7075770aa716c..c6aff23a845f06c87e701d57ec577c2c5c5a743c 100644 >>> --- a/fs/nfsd/trace.h >>> +++ b/fs/nfsd/trace.h >>> @@ -2391,6 +2391,45 @@ TRACE_EVENT(nfsd_lookup_dentry, >>> TP_printk("xid=0x%08x fh_hash=0x%08x name=%s", >>> __entry->xid, __entry->fh_hash, __get_str(name)) >>> ); >>> + >>> +DECLARE_EVENT_CLASS(nfsd_vfs_create_class, >>> + TP_PROTO(struct svc_rqst *rqstp, >>> + struct svc_fh *fhp, >>> + umode_t type, >>> + const char *name, >>> + unsigned int len), >>> + TP_ARGS(rqstp, fhp, type, name, len), >>> + TP_STRUCT__entry( >>> + SVC_RQST_ENDPOINT_FIELDS(rqstp) >>> + __field(u32, fh_hash) >>> + __field(umode_t, type) >>> + __string_len(name, name, len) >>> + ), >>> + TP_fast_assign( >>> + SVC_RQST_ENDPOINT_ASSIGNMENTS(rqstp); >>> + __entry->fh_hash = knfsd_fh_hash(&fhp->fh_handle); >>> + __entry->type = type; >>> + __assign_str(name); >>> + ), >>> + TP_printk("xid=0x%08x fh_hash=0x%08x type=%s name=%s", >>> + __entry->xid, __entry->fh_hash, >>> + show_fs_file_type(__entry->type), __get_str(name)) >>> +); >>> + >>> +#define DEFINE_NFSD_VFS_CREATE_EVENT(__name) \ >>> + DEFINE_EVENT(nfsd_vfs_create_class, __name, \ >>> + TP_PROTO(struct svc_rqst *rqstp, struct svc_fh *fhp, \ >>> + umode_t type, const char *name, unsigned int len), \ >>> + TP_ARGS(rqstp, fhp, type, name, len)) >>> + >>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd_proc_create); >>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd_proc_mkdir); >>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_create); >>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_mkdir); >>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_mknod); >>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd4_create); >>> +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd4_create_file); >> >> I think we would be better off with one or two new trace points in >> nfsd_create() and nfsd_create_setattr() instead of all of these... >> >> Unless I've missed what you are trying to observe...? >> > > Now I remember why I did it this way. Doing it the way you suggest > makes this all a bit messy: > > Most of the callers create files via nfsd_create(), but > nfsd3_create_file calls vfs_create() directly. It does call > nfsd_create_setattr(), but that's really not the right place for this > either, since it's doing a setattr and not the create itself. Notably, > it isn't passed the filename. > > Note too that burying this tracepoint down in nfs_create() also means > that error conditions can happen before the tracepoint that may mean > that it won't fire. So, if you're watching the traces to see when > CREATE or MKDIR calls occur, you may miss some of them. > > How do you want to proceed? You can see incoming RPC messages via the svc_process trace point. If you want to see the arguments for the operations too, you enable the nfsd_vfs_ tracepoints. It is reasonable to add trace points in the error flows if you believe those are important to surface. For CREATE, add the new nfsd_vfs_create trace point in nfsd_create() and also in nfsd3_create_file(). How does that sound?
diff --git a/fs/nfsd/nfs3proc.c b/fs/nfsd/nfs3proc.c index 372bdcf5e07a5c835da240ecebb02e3576eb2ca6..ea1280970ea11b2a82f0de88ad0422eef7063d6d 100644 --- a/fs/nfsd/nfs3proc.c +++ b/fs/nfsd/nfs3proc.c @@ -14,6 +14,7 @@ #include "xdr3.h" #include "vfs.h" #include "filecache.h" +#include "trace.h" #define NFSDDBG_FACILITY NFSDDBG_PROC @@ -380,10 +381,7 @@ nfsd3_proc_create(struct svc_rqst *rqstp) struct nfsd3_diropres *resp = rqstp->rq_resp; svc_fh *dirfhp, *newfhp; - dprintk("nfsd: CREATE(3) %s %.*s\n", - SVCFH_fmt(&argp->fh), - argp->len, - argp->name); + trace_nfsd3_proc_create(rqstp, &argp->fh, S_IFREG, argp->name, argp->len); dirfhp = fh_copy(&resp->dirfh, &argp->fh); newfhp = fh_init(&resp->fh, NFS3_FHSIZE); @@ -405,10 +403,7 @@ nfsd3_proc_mkdir(struct svc_rqst *rqstp) .na_iattr = &argp->attrs, }; - dprintk("nfsd: MKDIR(3) %s %.*s\n", - SVCFH_fmt(&argp->fh), - argp->len, - argp->name); + trace_nfsd3_proc_mkdir(rqstp, &argp->fh, S_IFDIR, argp->name, argp->len); argp->attrs.ia_valid &= ~ATTR_SIZE; fh_copy(&resp->dirfh, &argp->fh); @@ -471,13 +466,10 @@ nfsd3_proc_mknod(struct svc_rqst *rqstp) struct nfsd_attrs attrs = { .na_iattr = &argp->attrs, }; - int type; + int type = nfs3_ftypes[argp->ftype]; dev_t rdev = 0; - dprintk("nfsd: MKNOD(3) %s %.*s\n", - SVCFH_fmt(&argp->fh), - argp->len, - argp->name); + trace_nfsd3_proc_mknod(rqstp, &argp->fh, type, argp->name, argp->len); fh_copy(&resp->dirfh, &argp->fh); fh_init(&resp->fh, NFS3_FHSIZE); diff --git a/fs/nfsd/nfs4proc.c b/fs/nfsd/nfs4proc.c index 6e23d6103010197c0316b07c189fe12ec3033812..2c795103deaa4044596bd07d90db788169a32a0c 100644 --- a/fs/nfsd/nfs4proc.c +++ b/fs/nfsd/nfs4proc.c @@ -250,6 +250,8 @@ nfsd4_create_file(struct svc_rqst *rqstp, struct svc_fh *fhp, __be32 status; int host_err; + trace_nfsd4_create_file(rqstp, fhp, S_IFREG, open->op_fname, open->op_fnamelen); + if (isdotent(open->op_fname, open->op_fnamelen)) return nfserr_exist; if (!(iap->ia_valid & ATTR_MODE)) @@ -807,6 +809,29 @@ nfsd4_commit(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, return status; } +static umode_t nfs_type_to_vfs_type(enum nfs_ftype4 nfstype) +{ + switch (nfstype) { + case NF4REG: + return S_IFREG; + case NF4DIR: + return S_IFDIR; + case NF4BLK: + return S_IFBLK; + case NF4CHR: + return S_IFCHR; + case NF4LNK: + return S_IFLNK; + case NF4SOCK: + return S_IFSOCK; + case NF4FIFO: + return S_IFIFO; + default: + break; + } + return 0; +} + static __be32 nfsd4_create(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, union nfsd4_op_u *u) @@ -822,6 +847,10 @@ nfsd4_create(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate, __be32 status; dev_t rdev; + trace_nfsd4_create(rqstp, &cstate->current_fh, + nfs_type_to_vfs_type(create->cr_type), + create->cr_name, create->cr_namelen); + fh_init(&resfh, NFS4_FHSIZE); status = fh_verify(rqstp, &cstate->current_fh, S_IFDIR, NFSD_MAY_NOP); diff --git a/fs/nfsd/nfsproc.c b/fs/nfsd/nfsproc.c index 6dda081eb24c00b834ab0965c3a35a12115bceb7..33d8cbf8785588d38d4ec5efd769c1d1d06c6a91 100644 --- a/fs/nfsd/nfsproc.c +++ b/fs/nfsd/nfsproc.c @@ -10,6 +10,7 @@ #include "cache.h" #include "xdr.h" #include "vfs.h" +#include "trace.h" #define NFSDDBG_FACILITY NFSDDBG_PROC @@ -292,8 +293,7 @@ nfsd_proc_create(struct svc_rqst *rqstp) int hosterr; dev_t rdev = 0, wanted = new_decode_dev(attr->ia_size); - dprintk("nfsd: CREATE %s %.*s\n", - SVCFH_fmt(dirfhp), argp->len, argp->name); + trace_nfsd_proc_create(rqstp, dirfhp, S_IFREG, argp->name, argp->len); /* First verify the parent file handle */ resp->status = fh_verify(rqstp, dirfhp, S_IFDIR, NFSD_MAY_EXEC); @@ -548,7 +548,7 @@ nfsd_proc_mkdir(struct svc_rqst *rqstp) .na_iattr = &argp->attrs, }; - dprintk("nfsd: MKDIR %s %.*s\n", SVCFH_fmt(&argp->fh), argp->len, argp->name); + trace_nfsd_proc_mkdir(rqstp, &argp->fh, S_IFDIR, argp->name, argp->len); if (resp->fh.fh_dentry) { printk(KERN_WARNING diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h index 382849d7c321d6ded8213890c2e7075770aa716c..c6aff23a845f06c87e701d57ec577c2c5c5a743c 100644 --- a/fs/nfsd/trace.h +++ b/fs/nfsd/trace.h @@ -2391,6 +2391,45 @@ TRACE_EVENT(nfsd_lookup_dentry, TP_printk("xid=0x%08x fh_hash=0x%08x name=%s", __entry->xid, __entry->fh_hash, __get_str(name)) ); + +DECLARE_EVENT_CLASS(nfsd_vfs_create_class, + TP_PROTO(struct svc_rqst *rqstp, + struct svc_fh *fhp, + umode_t type, + const char *name, + unsigned int len), + TP_ARGS(rqstp, fhp, type, name, len), + TP_STRUCT__entry( + SVC_RQST_ENDPOINT_FIELDS(rqstp) + __field(u32, fh_hash) + __field(umode_t, type) + __string_len(name, name, len) + ), + TP_fast_assign( + SVC_RQST_ENDPOINT_ASSIGNMENTS(rqstp); + __entry->fh_hash = knfsd_fh_hash(&fhp->fh_handle); + __entry->type = type; + __assign_str(name); + ), + TP_printk("xid=0x%08x fh_hash=0x%08x type=%s name=%s", + __entry->xid, __entry->fh_hash, + show_fs_file_type(__entry->type), __get_str(name)) +); + +#define DEFINE_NFSD_VFS_CREATE_EVENT(__name) \ + DEFINE_EVENT(nfsd_vfs_create_class, __name, \ + TP_PROTO(struct svc_rqst *rqstp, struct svc_fh *fhp, \ + umode_t type, const char *name, unsigned int len), \ + TP_ARGS(rqstp, fhp, type, name, len)) + +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd_proc_create); +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd_proc_mkdir); +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_create); +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_mkdir); +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd3_proc_mknod); +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd4_create); +DEFINE_NFSD_VFS_CREATE_EVENT(nfsd4_create_file); + #endif /* _NFSD_TRACE_H */ #undef TRACE_INCLUDE_PATH
...and remove the legacy dprintks. Signed-off-by: Jeff Layton <jlayton@kernel.org> --- fs/nfsd/nfs3proc.c | 18 +++++------------- fs/nfsd/nfs4proc.c | 29 +++++++++++++++++++++++++++++ fs/nfsd/nfsproc.c | 6 +++--- fs/nfsd/trace.h | 39 +++++++++++++++++++++++++++++++++++++++ 4 files changed, 76 insertions(+), 16 deletions(-)