diff mbox series

[RFC,v1] io_uring: add io_uring_link trace event

Message ID 20191008125357.25265-1-9erthalion6@gmail.com (mailing list archive)
State New, archived
Headers show
Series [RFC,v1] io_uring: add io_uring_link trace event | expand

Commit Message

Dmitry Dolgov Oct. 8, 2019, 12:53 p.m. UTC
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.
E.g. it's not easy to figure out that one work was started after another
due to a link between them.

For that purpose introduce io_uring_link trace event, that will be fired
when a request is added to a link_list.

Signed-off-by: Dmitrii Dolgov <9erthalion6@gmail.com>
---
 fs/io_uring.c                   |  4 ++++
 include/Kbuild                  |  1 +
 include/trace/events/io_uring.h | 42 +++++++++++++++++++++++++++++++++
 3 files changed, 47 insertions(+)
 create mode 100644 include/trace/events/io_uring.h

Comments

Dmitry Dolgov Oct. 8, 2019, 12:54 p.m. UTC | #1
> On Tue, Oct 8, 2019 at 2:52 PM Dmitrii Dolgov <9erthalion6@gmail.com> wrote:
>
> 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.
> E.g. it's not easy to figure out that one work was started after another
> due to a link between them.
>
> For that purpose introduce io_uring_link trace event, that will be fired
> when a request is added to a link_list.
>
> Signed-off-by: Dmitrii Dolgov <9erthalion6@gmail.com>
> ---
>  fs/io_uring.c                   |  4 ++++
>  include/Kbuild                  |  1 +
>  include/trace/events/io_uring.h | 42 +++++++++++++++++++++++++++++++++
>  3 files changed, 47 insertions(+)
>  create mode 100644 include/trace/events/io_uring.h
>
> diff --git a/fs/io_uring.c b/fs/io_uring.c
> index bfbb7ab3c4e..63e4b592d69 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"
> @@ -2488,6 +2491,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(&req->work, &prev->work);
>                 list_add_tail(&req->list, &prev->link_list);
>         } else if (s->sqe->flags & IOSQE_IO_LINK) {
>                 req->flags |= REQ_F_LINK;
> diff --git a/include/Kbuild b/include/Kbuild
> index ffba79483cc..61b66725d25 100644
> --- a/include/Kbuild
> +++ b/include/Kbuild
> @@ -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
> diff --git a/include/trace/events/io_uring.h b/include/trace/events/io_uring.h
> new file mode 100644
> index 00000000000..56245c31a1e
> --- /dev/null
> +++ b/include/trace/events/io_uring.h
> @@ -0,0 +1,42 @@
> +/* SPDX-License-Identifier: GPL-2.0 */
> +#undef TRACE_SYSTEM
> +#define TRACE_SYSTEM io_uring
> +
> +#if !defined(_TRACE_IO_URING_H) || defined(TRACE_HEADER_MULTI_READ)
> +#define _TRACE_IO_URING_H
> +
> +#include <linux/tracepoint.h>
> +
> +/**
> + * io_uring_link - called immediately before the io_uring work added into
> + *                                link_list of the another request.
> + * @work:                      pointer to linked struct work_struct
> + * @target_work:       pointer to previous struct work_struct,
> + *                                     that would contain @work
> + *
> + * Allows to track linked requests in io_uring.
> + */
> +TRACE_EVENT(io_uring_link,
> +
> +       TP_PROTO(struct work_struct *work, struct work_struct *target_work),
> +
> +       TP_ARGS(work, target_work),
> +
> +       TP_STRUCT__entry (
> +               __field(  void *,       work                    )
> +               __field(  void *,       target_work             )
> +       ),
> +
> +       TP_fast_assign(
> +               __entry->work                   = work;
> +               __entry->target_work    = target_work;
> +       ),
> +
> +       TP_printk("io_uring work struct %p linked after %p",
> +                         __entry->work, __entry->target_work)
> +);
> +
> +#endif /* _TRACE_IO_URING_H */
> +
> +/* This part must be outside protection */
> +#include <trace/define_trace.h>
> --
> 2.21.0
>

If I'm missing something and it doesn't make sense, then I would be glad to
hear if there are any best practices or ideas, and in general how to look at
io_uring from the tracing point of view.
Jens Axboe Oct. 8, 2019, 1:01 p.m. UTC | #2
On 10/8/19 6:54 AM, Dmitry Dolgov wrote:
>> On Tue, Oct 8, 2019 at 2:52 PM Dmitrii Dolgov <9erthalion6@gmail.com> wrote:
>>
>> 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.
>> E.g. it's not easy to figure out that one work was started after another
>> due to a link between them.
>>
>> For that purpose introduce io_uring_link trace event, that will be fired
>> when a request is added to a link_list.
>>
>> Signed-off-by: Dmitrii Dolgov <9erthalion6@gmail.com>
>> ---
>>   fs/io_uring.c                   |  4 ++++
>>   include/Kbuild                  |  1 +
>>   include/trace/events/io_uring.h | 42 +++++++++++++++++++++++++++++++++
>>   3 files changed, 47 insertions(+)
>>   create mode 100644 include/trace/events/io_uring.h
>>
>> diff --git a/fs/io_uring.c b/fs/io_uring.c
>> index bfbb7ab3c4e..63e4b592d69 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"
>> @@ -2488,6 +2491,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(&req->work, &prev->work);
>>                  list_add_tail(&req->list, &prev->link_list);
>>          } else if (s->sqe->flags & IOSQE_IO_LINK) {
>>                  req->flags |= REQ_F_LINK;
>> diff --git a/include/Kbuild b/include/Kbuild
>> index ffba79483cc..61b66725d25 100644
>> --- a/include/Kbuild
>> +++ b/include/Kbuild
>> @@ -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
>> diff --git a/include/trace/events/io_uring.h b/include/trace/events/io_uring.h
>> new file mode 100644
>> index 00000000000..56245c31a1e
>> --- /dev/null
>> +++ b/include/trace/events/io_uring.h
>> @@ -0,0 +1,42 @@
>> +/* SPDX-License-Identifier: GPL-2.0 */
>> +#undef TRACE_SYSTEM
>> +#define TRACE_SYSTEM io_uring
>> +
>> +#if !defined(_TRACE_IO_URING_H) || defined(TRACE_HEADER_MULTI_READ)
>> +#define _TRACE_IO_URING_H
>> +
>> +#include <linux/tracepoint.h>
>> +
>> +/**
>> + * io_uring_link - called immediately before the io_uring work added into
>> + *                                link_list of the another request.
>> + * @work:                      pointer to linked struct work_struct
>> + * @target_work:       pointer to previous struct work_struct,
>> + *                                     that would contain @work
>> + *
>> + * Allows to track linked requests in io_uring.
>> + */
>> +TRACE_EVENT(io_uring_link,
>> +
>> +       TP_PROTO(struct work_struct *work, struct work_struct *target_work),
>> +
>> +       TP_ARGS(work, target_work),
>> +
>> +       TP_STRUCT__entry (
>> +               __field(  void *,       work                    )
>> +               __field(  void *,       target_work             )
>> +       ),
>> +
>> +       TP_fast_assign(
>> +               __entry->work                   = work;
>> +               __entry->target_work    = target_work;
>> +       ),
>> +
>> +       TP_printk("io_uring work struct %p linked after %p",
>> +                         __entry->work, __entry->target_work)
>> +);
>> +
>> +#endif /* _TRACE_IO_URING_H */
>> +
>> +/* This part must be outside protection */
>> +#include <trace/define_trace.h>
>> --
>> 2.21.0
>>
> 
> If I'm missing something and it doesn't make sense, then I would be
> glad to hear if there are any best practices or ideas, and in general
> how to look at io_uring from the tracing point of view.

I think it makes sense, and in fact I'd encourage you to expand the
tracing so we can get better insight into io_uring doing what it should
be doing.
Dmitry Dolgov Oct. 8, 2019, 1:11 p.m. UTC | #3
> On Tue, Oct 8, 2019 at 3:02 PM Jens Axboe <axboe@kernel.dk> wrote:
>
> > If I'm missing something and it doesn't make sense, then I would be
> > glad to hear if there are any best practices or ideas, and in general
> > how to look at io_uring from the tracing point of view.
>
> I think it makes sense, and in fact I'd encourage you to expand the
> tracing so we can get better insight into io_uring doing what it should
> be doing.

Sure. I was investigating this topic for some time, and hopefully soon I can
prepare a patch with more intensive tracing for most important aspects.
diff mbox series

Patch

diff --git a/fs/io_uring.c b/fs/io_uring.c
index bfbb7ab3c4e..63e4b592d69 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"
@@ -2488,6 +2491,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(&req->work, &prev->work);
 		list_add_tail(&req->list, &prev->link_list);
 	} else if (s->sqe->flags & IOSQE_IO_LINK) {
 		req->flags |= REQ_F_LINK;
diff --git a/include/Kbuild b/include/Kbuild
index ffba79483cc..61b66725d25 100644
--- a/include/Kbuild
+++ b/include/Kbuild
@@ -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
diff --git a/include/trace/events/io_uring.h b/include/trace/events/io_uring.h
new file mode 100644
index 00000000000..56245c31a1e
--- /dev/null
+++ b/include/trace/events/io_uring.h
@@ -0,0 +1,42 @@ 
+/* SPDX-License-Identifier: GPL-2.0 */
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM io_uring
+
+#if !defined(_TRACE_IO_URING_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_IO_URING_H
+
+#include <linux/tracepoint.h>
+
+/**
+ * io_uring_link - called immediately before the io_uring work added into
+ * 				   link_list of the another request.
+ * @work:			pointer to linked struct work_struct
+ * @target_work:	pointer to previous struct work_struct,
+ * 					that would contain @work
+ *
+ * Allows to track linked requests in io_uring.
+ */
+TRACE_EVENT(io_uring_link,
+
+	TP_PROTO(struct work_struct *work, struct work_struct *target_work),
+
+	TP_ARGS(work, target_work),
+
+	TP_STRUCT__entry (
+		__field(  void *,	work			)
+		__field(  void *,	target_work		)
+	),
+
+	TP_fast_assign(
+		__entry->work			= work;
+		__entry->target_work	= target_work;
+	),
+
+	TP_printk("io_uring work struct %p linked after %p",
+			  __entry->work, __entry->target_work)
+);
+
+#endif /* _TRACE_IO_URING_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>