Commit 502c87d6 authored by Stefan Roesch's avatar Stefan Roesch Committed by Jens Axboe
Browse files

io-uring: Make tracepoints consistent. 



This makes the io-uring tracepoints consistent. Where it makes sense
the tracepoints start with the following four fields:
- context (ring)
- request
- user_data
- opcode.

Signed-off-by: default avatarStefan Roesch <shr@fb.com>
Link: https://lore.kernel.org/r/20220214180430.70572-3-shr@fb.com


Signed-off-by: default avatarJens Axboe <axboe@kernel.dk>
parent d5ec1dfa

fs/io_uring.c

+13 −11
Original line number Diff line number Diff line
@@ -1603,8 +1603,8 @@ static void io_queue_async_work(struct io_kiocb *req, bool *dont_use) 
	if (WARN_ON_ONCE(!same_thread_group(req->task, current)))

		req->work.flags |= IO_WQ_WORK_CANCEL;



	trace_io_uring_queue_async_work(ctx, io_wq_is_hashed(&req->work), req,

					&req->work, req->flags);

	trace_io_uring_queue_async_work(ctx, req, req->user_data, req->opcode, req->flags,

					&req->work, io_wq_is_hashed(&req->work));

	io_wq_enqueue(tctx->io_wq, &req->work);

	if (link)

		io_queue_linked_timeout(link);
@@ -1936,7 +1936,7 @@ static inline bool __fill_cqe(struct io_ring_ctx *ctx, u64 user_data, 


static inline bool __io_fill_cqe(struct io_kiocb *req, s32 res, u32 cflags)

{

	trace_io_uring_complete(req->ctx, req->user_data, res, cflags);

	trace_io_uring_complete(req->ctx, req, req->user_data, res, cflags);

	return __fill_cqe(req->ctx, req->user_data, res, cflags);

}
@@ -1950,7 +1950,7 @@ static noinline bool io_fill_cqe_aux(struct io_ring_ctx *ctx, u64 user_data, 
				     s32 res, u32 cflags)

{

	ctx->cq_extra++;

	trace_io_uring_complete(ctx, user_data, res, cflags);

	trace_io_uring_complete(ctx, NULL, user_data, res, cflags);

	return __fill_cqe(ctx, user_data, res, cflags);

}
@@ -2202,7 +2202,9 @@ static void io_fail_links(struct io_kiocb *req) 
		nxt = link->link;

		link->link = NULL;



		trace_io_uring_fail_link(req, link);

		trace_io_uring_fail_link(req->ctx, req, req->user_data,

					req->opcode, link);



		if (!ignore_cqes) {

			link->flags &= ~REQ_F_CQE_SKIP;

			io_fill_cqe_req(link, res, 0);
@@ -5629,7 +5631,7 @@ static void __io_poll_execute(struct io_kiocb *req, int mask) 
	else

		req->io_task_work.func = io_apoll_task_func;



	trace_io_uring_task_add(req->ctx, req->opcode, req->user_data, mask);

	trace_io_uring_task_add(req->ctx, req, req->user_data, req->opcode, mask);

	io_req_task_work_add(req, false);

}
@@ -5858,7 +5860,7 @@ static int io_arm_poll_handler(struct io_kiocb *req) 
	if (ret || ipt.error)

		return ret ? IO_APOLL_READY : IO_APOLL_ABORTED;



	trace_io_uring_poll_arm(ctx, req, req->opcode, req->user_data,

	trace_io_uring_poll_arm(ctx, req, req->user_data, req->opcode,

				mask, apoll->poll.events);

	return IO_APOLL_OK;

}
@@ -6667,7 +6669,7 @@ static __cold void io_drain_req(struct io_kiocb *req) 
		goto queue;

	}



	trace_io_uring_defer(ctx, req, req->user_data);

	trace_io_uring_defer(ctx, req, req->user_data, req->opcode);

	de->req = req;

	de->seq = seq;

	list_add_tail(&de->list, &ctx->defer_list);
@@ -7001,7 +7003,7 @@ static struct file *io_file_get_normal(struct io_ring_ctx *ctx, 
{

	struct file *file = fget(fd);



	trace_io_uring_file_get(ctx, fd);

	trace_io_uring_file_get(ctx, req, req->user_data, fd);



	/* we don't allow fixed io_uring files */

	if (file && unlikely(file->f_op == &io_uring_fops))
@@ -7299,7 +7301,7 @@ static int io_submit_sqe(struct io_ring_ctx *ctx, struct io_kiocb *req, 


	ret = io_init_req(ctx, req, sqe);

	if (unlikely(ret)) {

		trace_io_uring_req_failed(sqe, ret);

		trace_io_uring_req_failed(sqe, ctx, req, ret);



		/* fail even hard links since we don't submit */

		if (link->head) {
@@ -7326,7 +7328,7 @@ static int io_submit_sqe(struct io_ring_ctx *ctx, struct io_kiocb *req, 
	}



	/* don't need @sqe from now on */

	trace_io_uring_submit_sqe(ctx, req, req->opcode, req->user_data,

	trace_io_uring_submit_sqe(ctx, req, req->user_data, req->opcode,

				  req->flags, true,

				  ctx->flags & IORING_SETUP_SQPOLL);

include/trace/events/io_uring.h

+153 −165
Original line number Diff line number Diff line
@@ -97,6 +97,8 @@ TRACE_EVENT(io_uring_register, 
 * io_uring_file_get - called before getting references to an SQE file

 *

 * @ctx:	pointer to a ring context structure

 * @req:	pointer to a submitted request

 * @user_data:	user data associated with the request

 * @fd:		SQE file descriptor

 *

 * Allows to trace out how often an SQE file reference is obtained, which can
@@ -105,59 +107,71 @@ TRACE_EVENT(io_uring_register, 
 */

TRACE_EVENT(io_uring_file_get,



	TP_PROTO(void *ctx, int fd),

	TP_PROTO(void *ctx, void *req, unsigned long long user_data, int fd),



	TP_ARGS(ctx, fd),

	TP_ARGS(ctx, req, user_data, fd),



	TP_STRUCT__entry (

		__field(  void *,	ctx		)

		__field(  void *,	req		)

		__field(  u64,		user_data	)

		__field(  int,		fd		)

	),



	TP_fast_assign(

		__entry->ctx		= ctx;

		__entry->req		= req;

		__entry->user_data	= user_data;

		__entry->fd		= fd;

	),



	TP_printk("ring %p, fd %d", __entry->ctx, __entry->fd)

	TP_printk("ring %p, req %p, user_data %llu, fd %d",

		__entry->ctx, __entry->req, __entry->user_data, __entry->fd)

);



/**

 * io_uring_queue_async_work - called before submitting a new async work

 *

 * @ctx:	pointer to a ring context structure

 * @hashed:	type of workqueue, hashed or normal

 * @req:	pointer to a submitted request

 * @user_data:	user data associated with the request

 * @opcode:	opcode of request

 * @flags	request flags

 * @work:	pointer to a submitted io_wq_work

 * @rw:		type of workqueue, hashed or normal

 *

 * Allows to trace asynchronous work submission.

 */

TRACE_EVENT(io_uring_queue_async_work,



	TP_PROTO(void *ctx, int rw, void * req, struct io_wq_work *work,

			 unsigned int flags),

	TP_PROTO(void *ctx, void * req, unsigned long long user_data, u8 opcode,

		unsigned int flags, struct io_wq_work *work, int rw),



	TP_ARGS(ctx, rw, req, work, flags),

	TP_ARGS(ctx, req, user_data, flags, opcode, work, rw),



	TP_STRUCT__entry (

		__field(  void *,			ctx		)

		__field(  int,				rw	)

		__field(  void *,			req		)

		__field(  struct io_wq_work *,		work	)

		__field(  u64,				user_data	)

		__field(  u8,				opcode		)

		__field(  unsigned int,			flags		)

		__field(  struct io_wq_work *,		work		)

		__field(  int,				rw		)

	),



	TP_fast_assign(

		__entry->ctx		= ctx;

		__entry->rw	= rw;

		__entry->req		= req;

		__entry->work	= work;

		__entry->user_data	= user_data;

		__entry->flags		= flags;

		__entry->opcode		= opcode;

		__entry->work		= work;

		__entry->rw		= rw;

	),



	TP_printk("ring %p, request %p, flags %d, %s queue, work %p",

			  __entry->ctx, __entry->req, __entry->flags,

			  __entry->rw ? "hashed" : "normal", __entry->work)

	TP_printk("ring %p, request %p, user_data %llu, opcode %d, flags %d, %s queue, work %p",

		__entry->ctx, __entry->req, __entry->user_data, __entry->opcode,

		__entry->flags, __entry->rw ? "hashed" : "normal", __entry->work)

);



/**
@@ -166,30 +180,33 @@ TRACE_EVENT(io_uring_queue_async_work, 
 * @ctx:	pointer to a ring context structure

 * @req:	pointer to a deferred request

 * @user_data:	user data associated with the request

 * @opcode:	opcode of request

 *

 * Allows to track deferred requests, to get an insight about what requests are

 * not started immediately.

 */

TRACE_EVENT(io_uring_defer,



	TP_PROTO(void *ctx, void *req, unsigned long long user_data),

	TP_PROTO(void *ctx, void *req, unsigned long long user_data, u8 opcode),



	TP_ARGS(ctx, req, user_data),

	TP_ARGS(ctx, req, user_data, opcode),



	TP_STRUCT__entry (

		__field(  void *,		ctx	)

		__field(  void *,		req	)

		__field(  unsigned long long,	data	)

		__field(  u8,			opcode	)

	),



	TP_fast_assign(

		__entry->ctx	= ctx;

		__entry->req	= req;

		__entry->data	= user_data;

		__entry->opcode	= opcode;

	),



	TP_printk("ring %p, request %p user_data %llu", __entry->ctx,

			__entry->req, __entry->data)

	TP_printk("ring %p, request %p, user_data %llu, opcode %d",

		__entry->ctx, __entry->req, __entry->data, __entry->opcode)

);



/**
@@ -257,7 +274,10 @@ TRACE_EVENT(io_uring_cqring_wait, 
/**

 * io_uring_fail_link - called before failing a linked request

 *

 * @ctx:	pointer to a ring context structure

 * @req:	request, which links were cancelled

 * @user_data:	user data associated with the request

 * @opcode:	opcode of request

 * @link:	cancelled link

 *

 * Allows to track linked requests cancellation, to see not only that some work
@@ -265,27 +285,36 @@ TRACE_EVENT(io_uring_cqring_wait, 
 */

TRACE_EVENT(io_uring_fail_link,



	TP_PROTO(void *req, void *link),

	TP_PROTO(void *ctx, void *req, unsigned long long user_data, u8 opcode, void *link),



	TP_ARGS(req, link),

	TP_ARGS(ctx, req, user_data, opcode, link),



	TP_STRUCT__entry (

		__field(  void *,		ctx		)

		__field(  void *,		req		)

		__field(  unsigned long long,	user_data	)

		__field(  u8,			opcode		)

		__field(  void *,		link		)

	),



	TP_fast_assign(

		__entry->ctx		= ctx;

		__entry->req		= req;

		__entry->user_data	= user_data;

		__entry->opcode		= opcode;

		__entry->link		= link;

	),



	TP_printk("request %p, link %p", __entry->req, __entry->link)

	TP_printk("ring %p, request %p, user_data %llu, opcode %d, link %p",

		__entry->ctx, __entry->req, __entry->user_data, __entry->opcode,

		__entry->link)

);



/**

 * io_uring_complete - called when completing an SQE

 *

 * @ctx:		pointer to a ring context structure

 * @req:		pointer to a submitted request

 * @user_data:		user data associated with the request

 * @res:		result of the request

 * @cflags:		completion flags
@@ -293,12 +322,13 @@ TRACE_EVENT(io_uring_fail_link, 
 */

TRACE_EVENT(io_uring_complete,



	TP_PROTO(void *ctx, u64 user_data, int res, unsigned cflags),

	TP_PROTO(void *ctx, void *req, u64 user_data, int res, unsigned cflags),



	TP_ARGS(ctx, user_data, res, cflags),

	TP_ARGS(ctx, req, user_data, res, cflags),



	TP_STRUCT__entry (

		__field(  void *,	ctx		)

		__field(  void *,	req		)

		__field(  u64,		user_data	)

		__field(  int,		res		)

		__field(  unsigned,	cflags		)
@@ -306,13 +336,15 @@ TRACE_EVENT(io_uring_complete, 


	TP_fast_assign(

		__entry->ctx		= ctx;

		__entry->req		= req;

		__entry->user_data	= user_data;

		__entry->res		= res;

		__entry->cflags		= cflags;

	),



	TP_printk("ring %p, user_data 0x%llx, result %d, cflags %x",

			  __entry->ctx, (unsigned long long)__entry->user_data,

	TP_printk("ring %p, req %p, user_data 0x%llx, result %d, cflags %x",

		__entry->ctx, __entry->req,

		(unsigned long long)__entry->user_data,

		__entry->res, __entry->cflags)

);
@@ -321,8 +353,8 @@ TRACE_EVENT(io_uring_complete, 
 *

 * @ctx:		pointer to a ring context structure

 * @req:		pointer to a submitted request

 * @opcode:		opcode of request

 * @user_data:		user data associated with the request

 * @opcode:		opcode of request

 * @flags		request flags

 * @force_nonblock:	whether a context blocking or not

 * @sq_thread:		true if sq_thread has submitted this SQE
@@ -332,16 +364,16 @@ TRACE_EVENT(io_uring_complete, 
 */

TRACE_EVENT(io_uring_submit_sqe,



	TP_PROTO(void *ctx, void *req, u8 opcode, u64 user_data, u32 flags,

	TP_PROTO(void *ctx, void *req, unsigned long long user_data, u8 opcode, u32 flags,

		 bool force_nonblock, bool sq_thread),



	TP_ARGS(ctx, req, opcode, user_data, flags, force_nonblock, sq_thread),

	TP_ARGS(ctx, req, user_data, opcode, flags, force_nonblock, sq_thread),



	TP_STRUCT__entry (

		__field(  void *,		ctx		)

		__field(  void *,		req		)

		__field(  unsigned long long,	user_data	)

		__field(  u8,			opcode		)

		__field(  u64,		user_data	)

		__field(  u32,			flags		)

		__field(  bool,			force_nonblock	)

		__field(  bool,			sq_thread	)
@@ -350,16 +382,16 @@ TRACE_EVENT(io_uring_submit_sqe, 
	TP_fast_assign(

		__entry->ctx		= ctx;

		__entry->req		= req;

		__entry->opcode		= opcode;

		__entry->user_data	= user_data;

		__entry->opcode		= opcode;

		__entry->flags		= flags;

		__entry->force_nonblock	= force_nonblock;

		__entry->sq_thread	= sq_thread;

	),



	TP_printk("ring %p, req %p, op %d, data 0x%llx, flags %u, "

	TP_printk("ring %p, req %p, user_data %llu, opcode %d, flags %u, "

		  "non block %d, sq_thread %d", __entry->ctx, __entry->req,

		  __entry->opcode, (unsigned long long)__entry->user_data,

		  __entry->user_data, __entry->opcode,

		  __entry->flags, __entry->force_nonblock, __entry->sq_thread)

);
@@ -368,8 +400,8 @@ TRACE_EVENT(io_uring_submit_sqe, 
 *

 * @ctx:		pointer to a ring context structure

 * @req:		pointer to the armed request

 * @opcode:		opcode of request

 * @user_data:		user data associated with the request

 * @opcode:		opcode of request

 * @mask:		request poll events mask

 * @events:		registered events of interest

 *
@@ -378,16 +410,16 @@ TRACE_EVENT(io_uring_submit_sqe, 
 */

TRACE_EVENT(io_uring_poll_arm,



	TP_PROTO(void *ctx, void *req, u8 opcode, u64 user_data,

	TP_PROTO(void *ctx, void *req, u64 user_data, u8 opcode,

		 int mask, int events),



	TP_ARGS(ctx, req, opcode, user_data, mask, events),

	TP_ARGS(ctx, req, user_data, opcode, mask, events),



	TP_STRUCT__entry (

		__field(  void *,		ctx		)

		__field(  void *,		req		)

		__field(  unsigned long long,	user_data	)

		__field(  u8,			opcode		)

		__field(  u64,		user_data	)

		__field(  int,			mask		)

		__field(  int,			events		)

	),
@@ -395,121 +427,74 @@ TRACE_EVENT(io_uring_poll_arm, 
	TP_fast_assign(

		__entry->ctx		= ctx;

		__entry->req		= req;

		__entry->opcode		= opcode;

		__entry->user_data	= user_data;

		__entry->opcode		= opcode;

		__entry->mask		= mask;

		__entry->events		= events;

	),



	TP_printk("ring %p, req %p, op %d, data 0x%llx, mask 0x%x, events 0x%x",

		  __entry->ctx, __entry->req, __entry->opcode,

		  (unsigned long long) __entry->user_data,

	TP_printk("ring %p, req %p, user_data %llu, opcode %d, mask 0x%x, events 0x%x",

		  __entry->ctx, __entry->req, __entry->user_data, __entry->opcode,

		  __entry->mask, __entry->events)

);



TRACE_EVENT(io_uring_poll_wake,



	TP_PROTO(void *ctx, u8 opcode, u64 user_data, int mask),



	TP_ARGS(ctx, opcode, user_data, mask),



	TP_STRUCT__entry (

		__field(  void *,	ctx		)

		__field(  u8,		opcode		)

		__field(  u64,		user_data	)

		__field(  int,		mask		)

	),



	TP_fast_assign(

		__entry->ctx		= ctx;

		__entry->opcode		= opcode;

		__entry->user_data	= user_data;

		__entry->mask		= mask;

	),



	TP_printk("ring %p, op %d, data 0x%llx, mask 0x%x",

			  __entry->ctx, __entry->opcode,

			  (unsigned long long) __entry->user_data,

			  __entry->mask)

);



TRACE_EVENT(io_uring_task_add,



	TP_PROTO(void *ctx, u8 opcode, u64 user_data, int mask),



	TP_ARGS(ctx, opcode, user_data, mask),



	TP_STRUCT__entry (

		__field(  void *,	ctx		)

		__field(  u8,		opcode		)

		__field(  u64,		user_data	)

		__field(  int,		mask		)

	),



	TP_fast_assign(

		__entry->ctx		= ctx;

		__entry->opcode		= opcode;

		__entry->user_data	= user_data;

		__entry->mask		= mask;

	),



	TP_printk("ring %p, op %d, data 0x%llx, mask %x",

			  __entry->ctx, __entry->opcode,

			  (unsigned long long) __entry->user_data,

			  __entry->mask)

);



/*

 * io_uring_task_run - called when task_work_run() executes the poll events

 *                     notification callbacks

 * io_uring_task_add - called after adding a task

 *

 * @ctx:		pointer to a ring context structure

 * @req:		pointer to the armed request

 * @opcode:		opcode of request

 * @req:		pointer to request

 * @user_data:		user data associated with the request

 * @opcode:		opcode of request

 * @mask:		request poll events mask

 *

 * Allows to track when notified poll events are processed

 */

TRACE_EVENT(io_uring_task_run,

TRACE_EVENT(io_uring_task_add,



	TP_PROTO(void *ctx, void *req, u8 opcode, u64 user_data),

	TP_PROTO(void *ctx, void *req, unsigned long long user_data, u8 opcode, int mask),



	TP_ARGS(ctx, req, opcode, user_data),

	TP_ARGS(ctx, req, user_data, opcode, mask),



	TP_STRUCT__entry (

		__field(  void *,		ctx		)

		__field(  void *,		req		)

		__field(  unsigned long long,	user_data	)

		__field(  u8,			opcode		)

		__field(  u64,		user_data	)

		__field(  int,			mask		)

	),



	TP_fast_assign(

		__entry->ctx		= ctx;

		__entry->req		= req;

		__entry->opcode		= opcode;

		__entry->user_data	= user_data;

		__entry->opcode		= opcode;

		__entry->mask		= mask;

	),



	TP_printk("ring %p, req %p, op %d, data 0x%llx",

		  __entry->ctx, __entry->req, __entry->opcode,

		  (unsigned long long) __entry->user_data)

	TP_printk("ring %p, req %p, user_data %llu, opcode %d, mask %x",

		__entry->ctx, __entry->req, __entry->user_data, __entry->opcode,

		__entry->mask)

);



/*

 * io_uring_req_failed - called when an sqe is errored dring submission

 *

 * @sqe:		pointer to the io_uring_sqe that failed

 * @ctx:		pointer to a ring context structure

 * @req:		pointer to request

 * @error:		error it failed with

 *

 * Allows easier diagnosing of malformed requests in production systems.

 */

TRACE_EVENT(io_uring_req_failed,



	TP_PROTO(const struct io_uring_sqe *sqe, int error),

	TP_PROTO(const struct io_uring_sqe *sqe, void *ctx, void *req, int error),



	TP_ARGS(sqe, error),

	TP_ARGS(sqe, ctx, req, error),



	TP_STRUCT__entry (

		__field(  void *,		ctx		)

		__field(  void *,		req		)

		__field(  unsigned long long,	user_data	)

		__field(  u8,			opcode		)

		__field(  u8,			flags		)

		__field(  u8,			ioprio		)
@@ -517,7 +502,6 @@ TRACE_EVENT(io_uring_req_failed, 
		__field( u64,			addr		)

		__field( u32,			len		)

		__field( u32,			op_flags	)

		__field( u64,	user_data )

		__field( u16,			buf_index	)

		__field( u16,			personality	)

		__field( u32,			file_index	)
@@ -527,6 +511,9 @@ TRACE_EVENT(io_uring_req_failed, 
	),



	TP_fast_assign(

		__entry->ctx		= ctx;

		__entry->req		= req;

		__entry->user_data	= sqe->user_data;

		__entry->opcode		= sqe->opcode;

		__entry->flags		= sqe->flags;

		__entry->ioprio		= sqe->ioprio;
@@ -534,7 +521,6 @@ TRACE_EVENT(io_uring_req_failed, 
		__entry->addr		= sqe->addr;

		__entry->len		= sqe->len;

		__entry->op_flags	= sqe->rw_flags;

		__entry->user_data	= sqe->user_data;

		__entry->buf_index	= sqe->buf_index;

		__entry->personality	= sqe->personality;

		__entry->file_index	= sqe->file_index;
@@ -543,13 +529,15 @@ TRACE_EVENT(io_uring_req_failed, 
		__entry->error		= error;

	),



	TP_printk("op %d, flags=0x%x, prio=%d, off=%llu, addr=%llu, "

		  "len=%u, rw_flags=0x%x, user_data=0x%llx, buf_index=%d, "

	TP_printk("ring %p, req %p, user_data %llu, "

		"op %d, flags=0x%x, prio=%d, off=%llu, addr=%llu, "

		  "len=%u, rw_flags=0x%x, buf_index=%d, "

		  "personality=%d, file_index=%d, pad=0x%llx/%llx, error=%d",

		  __entry->ctx, __entry->req, __entry->user_data,

		  __entry->opcode, __entry->flags, __entry->ioprio,

		  (unsigned long long)__entry->off,

		  (unsigned long long) __entry->addr, __entry->len,

		  __entry->op_flags, (unsigned long long) __entry->user_data,

		  __entry->op_flags,

		  __entry->buf_index, __entry->personality, __entry->file_index,

		  (unsigned long long) __entry->pad1,

		  (unsigned long long) __entry->pad2, __entry->error)