Re: [PATCH 3/4] nfsd: add some stub tracepoints around key vfs functions

From: Jeff Layton
Date: Thu Mar 06 2025 - 11:36:24 EST

Next message: Kuan-Wei Chiu: "[PATCH v3 12/16] mtd: ssfdc: Replace open-coded parity calculation with parity32()"
Previous message: Kuan-Wei Chiu: "[PATCH v3 11/16] drm/bridge: dw-hdmi: Replace open-coded parity calculation with parity32()"
In reply to: Chuck Lever: "Re: [PATCH 3/4] nfsd: add some stub tracepoints around key vfs functions"
Next in thread: Chuck Lever: "Re: [PATCH 3/4] nfsd: add some stub tracepoints around key vfs functions"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

On Thu, 2025-03-06 at 09:29 -0500, Chuck Lever wrote:
> On 3/6/25 7:38 AM, Jeff Layton wrote:
> > Sargun set up kprobes to add some of these tracepoints. Convert them to
> > simple static tracepoints. These are pretty sparse for now, but they
> > could be expanded in the future as needed.
>
> I have mixed feelings about this.
>
> - Probably tracepoints should replace the existing dprintk call sites.
> dprintk is kind of useless for heavy traffic.
>

I'm fine with removing dprintks as we go.

> - Seems like other existing tracepoints could report most of the same
> information. fh_verify, for example, has a tracepoint that reports
> the file handle. There's an svc proc tracepoint, and an NFSv4 COMPOUND
> tracepoint that can report XID and procedure.
>

The problem there is the lack of context. Yes, I can see that
fh_verify() got called, but on a busy server it can be hard to tell why
it got called. I see things like the fh_verify() tracepoint working in
conjunction with these new tracepoints. IOW, you could match up the
xids and see which fh_verify() was called for which operation.

If you like, I could drop the fh hash from these tracepoints, and just
print xid and net namespace?

> - If the tracepoint is passed an @rqstp, it should also record the
> nfsd namespace number.
>

Thanks, I'll plan to add that.

> I'd like to know more about what exactly you were hoping to extract,
> and which tracepoint(s) were most helpful for you.
>

Sargun, you're probably best equipped to answer this question. What's
most useful to you in these tracepoints?

>
> > Cc: Sargun Dillon <sargun@xxxxxxxx>
> > Signed-off-by: Jeff Layton <jlayton@xxxxxxxxxx>
> > ---
> > fs/nfsd/nfs3proc.c | 3 +++
> > fs/nfsd/nfs4proc.c | 2 ++
> > fs/nfsd/nfsproc.c | 2 ++
> > fs/nfsd/trace.h | 35 +++++++++++++++++++++++++++++++++++
> > fs/nfsd/vfs.c | 26 ++++++++++++++++++++++++++
> > 5 files changed, 68 insertions(+)
> >
> > diff --git a/fs/nfsd/nfs3proc.c b/fs/nfsd/nfs3proc.c
> > index 372bdcf5e07a5c835da240ecebb02e3576eb2ca6..2a56cae4c78a7ca66d569637e9f0e7c0fdcfb826 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
> >
> > @@ -69,6 +70,8 @@ nfsd3_proc_getattr(struct svc_rqst *rqstp)
> > struct nfsd_fhandle *argp = rqstp->rq_argp;
> > struct nfsd3_attrstat *resp = rqstp->rq_resp;
> >
> > + trace_nfsd_getattr(rqstp, &argp->fh);
> > +
> > dprintk("nfsd: GETATTR(3) %s\n",
> > SVCFH_fmt(&argp->fh));
> >
> > diff --git a/fs/nfsd/nfs4proc.c b/fs/nfsd/nfs4proc.c
> > index c20f1abcb94f131b1ec898860ba2c394b22e61e1..87d241ff91920317e0122a58bf0cf71c5b28d264 100644
> > --- a/fs/nfsd/nfs4proc.c
> > +++ b/fs/nfsd/nfs4proc.c
> > @@ -876,6 +876,8 @@ nfsd4_getattr(struct svc_rqst *rqstp, struct nfsd4_compound_state *cstate,
> > struct nfsd4_getattr *getattr = &u->getattr;
> > __be32 status;
> >
> > + trace_nfsd_getattr(rqstp, &cstate->current_fh);
> > +
> > status = fh_verify(rqstp, &cstate->current_fh, 0, NFSD_MAY_NOP);
> > if (status)
> > return status;
> > diff --git a/fs/nfsd/nfsproc.c b/fs/nfsd/nfsproc.c
> > index 6dda081eb24c00b834ab0965c3a35a12115bceb7..9563372f0826b9580299144069f57664dbd2a079 100644
> > --- a/fs/nfsd/nfsproc.c
> > +++ b/fs/nfsd/nfsproc.c
> > @@ -54,6 +54,8 @@ nfsd_proc_getattr(struct svc_rqst *rqstp)
> > struct nfsd_fhandle *argp = rqstp->rq_argp;
> > struct nfsd_attrstat *resp = rqstp->rq_resp;
> >
> > + trace_nfsd_getattr(rqstp, &argp->fh);
> > +
> > dprintk("nfsd: GETATTR %s\n", SVCFH_fmt(&argp->fh));
> >
> > fh_copy(&resp->fh, &argp->fh);
> > diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
> > index 117f7e1fd66a4838a048cc44bd5bf4dd8c6db958..d4a78fe1bab24b594b96cca8611c439da9ed6926 100644
> > --- a/fs/nfsd/trace.h
> > +++ b/fs/nfsd/trace.h
> > @@ -2337,6 +2337,41 @@ DEFINE_EVENT(nfsd_copy_async_done_class, \
> > DEFINE_COPY_ASYNC_DONE_EVENT(done);
> > DEFINE_COPY_ASYNC_DONE_EVENT(cancel);
> >
> > +DECLARE_EVENT_CLASS(nfsd_vfs_class,
> > + TP_PROTO(struct svc_rqst *rqstp, struct svc_fh *fhp),
> > + TP_ARGS(rqstp, fhp),
> > + TP_STRUCT__entry(
> > + __field(u32, xid)
> > + __field(u32, fh_hash)
> > + ),
> > + TP_fast_assign(
> > + __entry->xid = be32_to_cpu(rqstp->rq_xid);
> > + __entry->fh_hash = knfsd_fh_hash(&fhp->fh_handle);
> > + ),
> > + TP_printk("xid=0x%08x fh_hash=0x%08x",
> > + __entry->xid, __entry->fh_hash)
> > +);
> > +
> > +#define DEFINE_NFSD_VFS_EVENT(name) \
> > + DEFINE_EVENT(nfsd_vfs_class, nfsd_##name, \
> > + TP_PROTO(struct svc_rqst *rqstp, struct svc_fh *fhp), \
> > + TP_ARGS(rqstp, fhp))
> > +
> > +DEFINE_NFSD_VFS_EVENT(lookup);
> > +DEFINE_NFSD_VFS_EVENT(lookup_dentry);
> > +DEFINE_NFSD_VFS_EVENT(create_locked);
> > +DEFINE_NFSD_VFS_EVENT(create);
> > +DEFINE_NFSD_VFS_EVENT(access);
> > +DEFINE_NFSD_VFS_EVENT(create_setattr);
> > +DEFINE_NFSD_VFS_EVENT(readlink);
> > +DEFINE_NFSD_VFS_EVENT(symlink);
> > +DEFINE_NFSD_VFS_EVENT(link);
> > +DEFINE_NFSD_VFS_EVENT(rename);
> > +DEFINE_NFSD_VFS_EVENT(unlink);
> > +DEFINE_NFSD_VFS_EVENT(readdir);
> > +DEFINE_NFSD_VFS_EVENT(statfs);
> > +DEFINE_NFSD_VFS_EVENT(getattr);
> > +
> > #define show_ia_valid_flags(x) \
> > __print_flags(x, "|", \
> > { ATTR_MODE, "MODE" }, \
> > diff --git a/fs/nfsd/vfs.c b/fs/nfsd/vfs.c
> > index d755cc87a8670c491e55194de266d999ba1b337d..772a4d32b09a4bd217a9258ec803c06618cf13c8 100644
> > --- a/fs/nfsd/vfs.c
> > +++ b/fs/nfsd/vfs.c
> > @@ -244,6 +244,8 @@ nfsd_lookup_dentry(struct svc_rqst *rqstp, struct svc_fh *fhp,
> > struct dentry *dentry;
> > int host_err;
> >
> > + trace_nfsd_lookup(rqstp, fhp);
> > +
> > dprintk("nfsd: nfsd_lookup(fh %s, %.*s)\n", SVCFH_fmt(fhp), len,name);
> >
> > dparent = fhp->fh_dentry;
> > @@ -313,6 +315,8 @@ nfsd_lookup(struct svc_rqst *rqstp, struct svc_fh *fhp, const char *name,
> > struct dentry *dentry;
> > __be32 err;
> >
> > + trace_nfsd_lookup(rqstp, fhp);
> > +
> > err = fh_verify(rqstp, fhp, S_IFDIR, NFSD_MAY_EXEC);
> > if (err)
> > return err;
> > @@ -794,6 +798,8 @@ nfsd_access(struct svc_rqst *rqstp, struct svc_fh *fhp, u32 *access, u32 *suppor
> > u32 query, result = 0, sresult = 0;
> > __be32 error;
> >
> > + trace_nfsd_create(rqstp, fhp);
> > +
> > error = fh_verify(rqstp, fhp, 0, NFSD_MAY_NOP);
> > if (error)
> > goto out;
> > @@ -1401,6 +1407,8 @@ nfsd_create_setattr(struct svc_rqst *rqstp, struct svc_fh *fhp,
> > struct iattr *iap = attrs->na_iattr;
> > __be32 status;
> >
> > + trace_nfsd_create_setattr(rqstp, fhp);
> > +
> > /*
> > * Mode has already been set by file creation.
> > */
> > @@ -1467,6 +1475,8 @@ nfsd_create_locked(struct svc_rqst *rqstp, struct svc_fh *fhp,
> > __be32 err;
> > int host_err;
> >
> > + trace_nfsd_create_locked(rqstp, fhp);
> > +
> > dentry = fhp->fh_dentry;
> > dirp = d_inode(dentry);
> >
> > @@ -1557,6 +1567,8 @@ nfsd_create(struct svc_rqst *rqstp, struct svc_fh *fhp,
> > __be32 err;
> > int host_err;
> >
> > + trace_nfsd_create(rqstp, fhp);
> > +
> > if (isdotent(fname, flen))
> > return nfserr_exist;
> >
> > @@ -1609,6 +1621,8 @@ nfsd_readlink(struct svc_rqst *rqstp, struct svc_fh *fhp, char *buf, int *lenp)
> > DEFINE_DELAYED_CALL(done);
> > int len;
> >
> > + trace_nfsd_readlink(rqstp, fhp);
> > +
> > err = fh_verify(rqstp, fhp, S_IFLNK, NFSD_MAY_NOP);
> > if (unlikely(err))
> > return err;
> > @@ -1657,6 +1671,8 @@ nfsd_symlink(struct svc_rqst *rqstp, struct svc_fh *fhp,
> > __be32 err, cerr;
> > int host_err;
> >
> > + trace_nfsd_symlink(rqstp, fhp);
> > +
> > err = nfserr_noent;
> > if (!flen || path[0] == '\0')
> > goto out;
> > @@ -1725,6 +1741,8 @@ nfsd_link(struct svc_rqst *rqstp, struct svc_fh *ffhp,
> > __be32 err;
> > int host_err;
> >
> > + trace_nfsd_link(rqstp, ffhp);
> > +
> > err = fh_verify(rqstp, ffhp, S_IFDIR, NFSD_MAY_CREATE);
> > if (err)
> > goto out;
> > @@ -1842,6 +1860,8 @@ nfsd_rename(struct svc_rqst *rqstp, struct svc_fh *ffhp, char *fname, int flen,
> > int host_err;
> > bool close_cached = false;
> >
> > + trace_nfsd_rename(rqstp, ffhp);
> > +
> > err = fh_verify(rqstp, ffhp, S_IFDIR, NFSD_MAY_REMOVE);
> > if (err)
> > goto out;
> > @@ -2000,6 +2020,8 @@ nfsd_unlink(struct svc_rqst *rqstp, struct svc_fh *fhp, int type,
> > __be32 err;
> > int host_err;
> >
> > + trace_nfsd_unlink(rqstp, fhp);
> > +
> > err = nfserr_acces;
> > if (!flen || isdotent(fname, flen))
> > goto out;
> > @@ -2222,6 +2244,8 @@ nfsd_readdir(struct svc_rqst *rqstp, struct svc_fh *fhp, loff_t *offsetp,
> > loff_t offset = *offsetp;
> > int may_flags = NFSD_MAY_READ;
> >
> > + trace_nfsd_readdir(rqstp, fhp);
> > +
> > err = nfsd_open(rqstp, fhp, S_IFDIR, may_flags, &file);
> > if (err)
> > goto out;
> > @@ -2288,6 +2312,8 @@ nfsd_statfs(struct svc_rqst *rqstp, struct svc_fh *fhp, struct kstatfs *stat, in
> > {
> > __be32 err;
> >
> > + trace_nfsd_statfs(rqstp, fhp);
> > +
> > err = fh_verify(rqstp, fhp, 0, NFSD_MAY_NOP | access);
> > if (!err) {
> > struct path path = {
> >
>
>

--
Jeff Layton <jlayton@xxxxxxxxxx>

Next message: Kuan-Wei Chiu: "[PATCH v3 12/16] mtd: ssfdc: Replace open-coded parity calculation with parity32()"
Previous message: Kuan-Wei Chiu: "[PATCH v3 11/16] drm/bridge: dw-hdmi: Replace open-coded parity calculation with parity32()"
In reply to: Chuck Lever: "Re: [PATCH 3/4] nfsd: add some stub tracepoints around key vfs functions"
Next in thread: Chuck Lever: "Re: [PATCH 3/4] nfsd: add some stub tracepoints around key vfs functions"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]