@@ -281,7 +281,9 @@ 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);
+
+ /* enqueue, as it is send to "fiq->ops queue" */
+ trace_fuse_request_enqueue(req);
fiq->ops->send_req(fiq, req);
}
@@ -580,6 +582,8 @@ static int fuse_request_queue_background(struct fuse_req *req)
}
__set_bit(FR_ISREPLY, &req->flags);
+ trace_fuse_request_bg_enqueue(req);
+
#ifdef CONFIG_FUSE_IO_URING
if (fuse_uring_ready(fc))
return fuse_request_queue_background_uring(fc, req);
@@ -1314,6 +1318,7 @@ static ssize_t fuse_dev_do_read(struct fuse_dev *fud, struct file *file,
clear_bit(FR_PENDING, &req->flags);
list_del_init(&req->list);
spin_unlock(&fiq->lock);
+ trace_fuse_request_send(req);
args = req->args;
reqsize = req->in.h.len;
@@ -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>
@@ -678,6 +679,7 @@ static void fuse_uring_send(struct fuse_ring_ent *ent, struct io_uring_cmd *cmd,
ent->cmd = NULL;
spin_unlock(&queue->lock);
+ trace_fuse_request_send(ent->fuse_req);
io_uring_cmd_done(cmd, ret, 0, issue_flags);
}
@@ -77,30 +77,55 @@ OPCODES
#define EM(a, b) {a, b},
#define EMe(a, b) {a, b}
-TRACE_EVENT(fuse_request_send,
+#define FUSE_REQ_TRACE_FIELDS \
+ __field(dev_t, connection) \
+ __field(uint64_t, unique) \
+ __field(enum fuse_opcode, opcode) \
+ __field(uint32_t, len) \
+
+#define FUSE_REQ_TRACE_ASSIGN(req) \
+ do { \
+ __entry->connection = req->fm->fc->dev; \
+ __entry->unique = req->in.h.unique; \
+ __entry->opcode = req->in.h.opcode; \
+ __entry->len = req->in.h.len; \
+ } while (0)
+
+
+TRACE_EVENT(fuse_request_enqueue,
TP_PROTO(const struct fuse_req *req),
-
TP_ARGS(req),
-
- TP_STRUCT__entry(
- __field(dev_t, connection)
- __field(uint64_t, unique)
- __field(enum fuse_opcode, opcode)
- __field(uint32_t, len)
- ),
-
- TP_fast_assign(
- __entry->connection = req->fm->fc->dev;
- __entry->unique = req->in.h.unique;
- __entry->opcode = req->in.h.opcode;
- __entry->len = req->in.h.len;
- ),
+ TP_STRUCT__entry(FUSE_REQ_TRACE_FIELDS),
+ TP_fast_assign(FUSE_REQ_TRACE_ASSIGN(req)),
TP_printk("connection %u req %llu opcode %u (%s) len %u ",
__entry->connection, __entry->unique, __entry->opcode,
__print_symbolic(__entry->opcode, OPCODES), __entry->len)
);
+TRACE_EVENT(fuse_request_bg_enqueue,
+ TP_PROTO(const struct fuse_req *req),
+ TP_ARGS(req),
+ TP_STRUCT__entry(FUSE_REQ_TRACE_FIELDS),
+ TP_fast_assign(FUSE_REQ_TRACE_ASSIGN(req)),
+
+ TP_printk("connection %u req %llu opcode %u (%s) len %u ",
+ __entry->connection, __entry->unique, __entry->opcode,
+ __print_symbolic(__entry->opcode, OPCODES), __entry->len)
+);
+
+TRACE_EVENT(fuse_request_send,
+ TP_PROTO(const struct fuse_req *req),
+ TP_ARGS(req),
+ TP_STRUCT__entry(FUSE_REQ_TRACE_FIELDS),
+ TP_fast_assign(FUSE_REQ_TRACE_ASSIGN(req)),
+
+ TP_printk("connection %u req %llu opcode %u (%s) len %u ",
+ __entry->connection, __entry->unique, __entry->opcode,
+ __print_symbolic(__entry->opcode, OPCODES), __entry->len)
+);
+
+
TRACE_EVENT(fuse_request_end,
TP_PROTO(const struct fuse_req *req),
Rename trace_fuse_request_send to trace_fuse_request_enqueue Add trace_fuse_request_send Add trace_fuse_request_bg_enqueue Add trace_fuse_request_enqueue This helps to track entire request time and time in different queues. Signed-off-by: Bernd Schubert <bschubert@ddn.com> --- fs/fuse/dev.c | 7 ++++++- fs/fuse/dev_uring.c | 2 ++ fs/fuse/fuse_trace.h | 57 +++++++++++++++++++++++++++++++++++++--------------- 3 files changed, 49 insertions(+), 17 deletions(-)