Skip to content

Commit

Permalink
io_uring: add set of tracing events
Browse files Browse the repository at this point in the history
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>
  • Loading branch information
Dmitrii Dolgov authored and Jens Axboe committed Oct 29, 2019
1 parent 1136504 commit c826bd7
Showing 3 changed files with 367 additions and 0 deletions.
17 changes: 17 additions & 0 deletions fs/io_uring.c
Original file line number Diff line number Diff line change
@@ -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;
1 change: 1 addition & 0 deletions include/Kbuild
Original file line number Diff line number Diff line change
@@ -1028,6 +1028,7 @@ header-test- += trace/events/fsi_master_gpio.h
header-test- += trace/events/huge_memory.h
header-test- += trace/events/ib_mad.h
header-test- += trace/events/ib_umad.h
header-test- += trace/events/io_uring.h
header-test- += trace/events/iscsi.h
header-test- += trace/events/jbd2.h
header-test- += trace/events/kvm.h
Loading

0 comments on commit c826bd7

Please sign in to comment.