On 8/26/25 20:52, Darrick J. Wong wrote:
> 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
>>
I really need to find time to update my related branch - as I wrote
before, I already have all of that, I think.
Thanks,
Bernd
