On Thu, Aug 21, 2025 at 05:15:50PM -0700, Joanne Koong wrote:
> On Wed, Aug 20, 2025 at 5:51 PM Darrick J. Wong <djwong@xxxxxxxxxx> wrote:
> >
> > From: Darrick J. Wong <djwong@xxxxxxxxxx>
> >
> > The fuse_request_{send,end} tracepoints capture the value of
> > req->in.h.unique in the trace output. It would be really nice if we
> > could use this to match a request to its response for debugging and
> > latency analysis, but the call to trace_fuse_request_send occurs before
> > the unique id has been set:
> >
> > fuse_request_send: connection 8388608 req 0 opcode 1 (FUSE_LOOKUP) len 107
> > fuse_request_end: connection 8388608 req 6 len 16 error -2
> >
> > Move the callsites to trace_fuse_request_send to after the unique id has
> > been set, or right before we decide to cancel a request having not set
> > one.
> >
> > Signed-off-by: "Darrick J. Wong" <djwong@xxxxxxxxxx>
> > ---
> > fs/fuse/dev.c | 6 +++++-
> > fs/fuse/dev_uring.c | 8 +++++++-
>
> I think we'll also need to do the equivalent for virtio.
Ackpth, virtio sends commands too??
Oh, yes, it does -- judging from the fuse_get_unique calls, at least
virtio_fs_send_req and maybe virtio_fs_send_forget need to add a call to
trace_fuse_request_send?
> > 2 files changed, 12 insertions(+), 2 deletions(-)
> >
> >
> > diff --git a/fs/fuse/dev.c b/fs/fuse/dev.c
> > index 6f2b277973ca7d..05d6e7779387a4 100644
> > --- a/fs/fuse/dev.c
> > +++ b/fs/fuse/dev.c
> > @@ -376,10 +376,15 @@ static void fuse_dev_queue_req(struct fuse_iqueue *fiq, struct fuse_req *req)
> > if (fiq->connected) {
> > if (req->in.h.opcode != FUSE_NOTIFY_REPLY)
> > req->in.h.unique = fuse_get_unique_locked(fiq);
> > +
> > + /* tracepoint captures in.h.unique */
> > + trace_fuse_request_send(req);
> > +
> > list_add_tail(&req->list, &fiq->pending);
> > fuse_dev_wake_and_unlock(fiq);
> > } else {
> > spin_unlock(&fiq->lock);
> > + trace_fuse_request_send(req);
>
> Should this request still show up in the trace even though the request
> doesn't actually get sent to the server? imo that makes it
> misleading/confusing unless the trace also indicates -ENOTCONN.
Hrmm. I was thinking that it would be very nice to have
fuse_request_{send,end} bracket the start and end of a fuse request,
even if we kill it immediately.
OTOH from a tracing "efficiency" perspective it's probably ok for
never-sent requests only to ever hit the fuse_request_end tracepoint
since the id will not get reused for quite some time.
<shrug> Thoughts?
--D
> > req->out.h.error = -ENOTCONN;
> > clear_bit(FR_PENDING, &req->flags);
> > fuse_request_end(req);
> > @@ -398,7 +403,6 @@ static void fuse_send_one(struct fuse_iqueue *fiq, struct fuse_req *req)
> > req->in.h.len = sizeof(struct fuse_in_header) +
> > fuse_len_args(req->args->in_numargs,
> > (struct fuse_arg *) req->args->in_args);
> > - trace_fuse_request_send(req);
> > fiq->ops->send_req(fiq, req);
> > }
> >
> > diff --git a/fs/fuse/dev_uring.c b/fs/fuse/dev_uring.c
> > index 249b210becb1cc..14f263d4419392 100644
> > --- a/fs/fuse/dev_uring.c
> > +++ b/fs/fuse/dev_uring.c
> > @@ -7,6 +7,7 @@
> > #include "fuse_i.h"
> > #include "dev_uring_i.h"
> > #include "fuse_dev_i.h"
> > +#include "fuse_trace.h"
> >
> > #include <linux/fs.h>
> > #include <linux/io_uring/cmd.h>
> > @@ -1265,12 +1266,17 @@ void fuse_uring_queue_fuse_req(struct fuse_iqueue *fiq, struct fuse_req *req)
> >
> > err = -EINVAL;
> > queue = fuse_uring_task_to_queue(ring);
> > - if (!queue)
> > + if (!queue) {
> > + trace_fuse_request_send(req);
>
> Same question here.
>
> Thanks,
> Joanne
>
