io_uring: add set of tracing events
To trace io_uring activity one can get an information from workqueue and
io trace events, but looks like some parts could be hard to identify via
this approach. Making what happens inside io_uring more transparent is
important to be able to reason about many aspects of it, hence introduce
the set of tracing events.
All such events could be roughly divided into two categories:
* those, that are helping to understand correctness (from both kernel
and an application point of view). E.g. a ring creation, file
registration, or waiting for available CQE. Proposed approach is to
get a pointer to an original structure of interest (ring context, or
request), and then find relevant events. io_uring_queue_async_work
also exposes a pointer to work_struct, to be able to track down
corresponding workqueue events.
* those, that provide performance related information. Mostly it's about
events that change the flow of requests, e.g. whether an async work
was queued, or delayed due to some dependencies. Another important
case is how io_uring optimizations (e.g. registered files) are
utilized.
Signed-off-by: Dmitrii Dolgov <9erthalion6@gmail.com>
Signed-off-by: Jens Axboe <axboe@kernel.dk>
diff --git a/fs/io_uring.c b/fs/io_uring.c
index e5564cd..f83465f 100644
--- a/fs/io_uring.c
+++ b/fs/io_uring.c
@@ -71,6 +71,9 @@
#include <linux/sizes.h>
#include <linux/hugetlb.h>
+#define CREATE_TRACE_POINTS
+#include <trace/events/io_uring.h>
+
#include <uapi/linux/io_uring.h>
#include "internal.h"
@@ -491,6 +494,7 @@ static inline void io_queue_async_work(struct io_ring_ctx *ctx,
}
}
+ trace_io_uring_queue_async_work(ctx, rw, req, &req->work, req->flags);
queue_work(ctx->sqo_wq[rw], &req->work);
}
@@ -710,6 +714,7 @@ static void io_fail_links(struct io_kiocb *req)
link = list_first_entry(&req->link_list, struct io_kiocb, list);
list_del(&link->list);
+ trace_io_uring_fail_link(req, link);
io_cqring_add_event(req->ctx, link->user_data, -ECANCELED);
__io_free_req(link);
}
@@ -2149,6 +2154,7 @@ static int io_req_defer(struct io_ring_ctx *ctx, struct io_kiocb *req,
req->submit.sqe = sqe_copy;
INIT_WORK(&req->work, io_sq_wq_submit_work);
+ trace_io_uring_defer(ctx, req, false);
list_add_tail(&req->list, &ctx->defer_list);
spin_unlock_irq(&ctx->completion_lock);
return -EIOCBQUEUED;
@@ -2410,6 +2416,8 @@ static bool io_add_to_prev_work(struct async_list *list, struct io_kiocb *req)
ret = false;
}
spin_unlock(&list->lock);
+
+ trace_io_uring_add_to_prev(req, ret);
return ret;
}
@@ -2458,6 +2466,7 @@ static int io_req_set_file(struct io_ring_ctx *ctx, const struct sqe_submit *s,
} else {
if (s->needs_fixed_file)
return -EBADF;
+ trace_io_uring_file_get(ctx, fd);
req->file = io_file_get(state, fd);
if (unlikely(!req->file))
return -EBADF;
@@ -2567,6 +2576,7 @@ static int io_queue_link_head(struct io_ring_ctx *ctx, struct io_kiocb *req,
/* Insert shadow req to defer_list, blocking next IOs */
spin_lock_irq(&ctx->completion_lock);
+ trace_io_uring_defer(ctx, shadow, true);
list_add_tail(&shadow->list, &ctx->defer_list);
spin_unlock_irq(&ctx->completion_lock);
@@ -2626,6 +2636,7 @@ static void io_submit_sqe(struct io_ring_ctx *ctx, struct sqe_submit *s,
s->sqe = sqe_copy;
memcpy(&req->submit, s, sizeof(*s));
+ trace_io_uring_link(ctx, req, prev);
list_add_tail(&req->list, &prev->link_list);
} else if (s->sqe->flags & IOSQE_IO_LINK) {
req->flags |= REQ_F_LINK;
@@ -2769,6 +2780,7 @@ static int io_submit_sqes(struct io_ring_ctx *ctx, unsigned int nr,
s.has_user = has_user;
s.in_async = true;
s.needs_fixed_file = true;
+ trace_io_uring_submit_sqe(ctx, true, true);
io_submit_sqe(ctx, &s, statep, &link);
submitted++;
}
@@ -2957,6 +2969,7 @@ static int io_ring_submit(struct io_ring_ctx *ctx, unsigned int to_submit)
s.in_async = false;
s.needs_fixed_file = false;
submit++;
+ trace_io_uring_submit_sqe(ctx, true, false);
io_submit_sqe(ctx, &s, statep, &link);
}
@@ -3039,6 +3052,7 @@ static int io_cqring_wait(struct io_ring_ctx *ctx, int min_events,
ret = 0;
iowq.nr_timeouts = atomic_read(&ctx->cq_timeouts);
+ trace_io_uring_cqring_wait(ctx, min_events);
do {
prepare_to_wait_exclusive(&ctx->wait, &iowq.wq,
TASK_INTERRUPTIBLE);
@@ -4197,6 +4211,7 @@ static int io_uring_create(unsigned entries, struct io_uring_params *p)
goto err;
p->features = IORING_FEAT_SINGLE_MMAP;
+ trace_io_uring_create(ret, ctx, p->sq_entries, p->cq_entries, p->flags);
return ret;
err:
io_ring_ctx_wait_and_kill(ctx);
@@ -4334,6 +4349,8 @@ SYSCALL_DEFINE4(io_uring_register, unsigned int, fd, unsigned int, opcode,
mutex_lock(&ctx->uring_lock);
ret = __io_uring_register(ctx, opcode, arg, nr_args);
mutex_unlock(&ctx->uring_lock);
+ trace_io_uring_register(ctx, opcode, ctx->nr_user_files, ctx->nr_user_bufs,
+ ctx->cq_ev_fd != NULL, ret);
out_fput:
fdput(f);
return ret;