Commit 3fd41721 authored by Ritesh Harjani (IBM)'s avatar Ritesh Harjani (IBM) Committed by Darrick J. Wong
Browse files

iomap: Add DIO tracepoints 



Add trace_iomap_dio_rw_begin, trace_iomap_dio_rw_queued and
trace_iomap_dio_complete tracepoint.
trace_iomap_dio_rw_queued is mostly only to know that the request was
queued and -EIOCBQUEUED was returned. It is mostly trace_iomap_dio_rw_begin
& trace_iomap_dio_complete which has all the details.

<example output log>
      a.out-2073  [006]   134.225717: iomap_dio_rw_begin:   dev 7:7 ino 0xe size 0x0 offset 0x0 length 0x1000 done_before 0x0 flags DIRECT|WRITE dio_flags DIO_FORCE_WAIT aio 1
      a.out-2073  [006]   134.226234: iomap_dio_complete:   dev 7:7 ino 0xe size 0x1000 offset 0x1000 flags DIRECT|WRITE aio 1 error 0 ret 4096
      a.out-2074  [006]   136.225975: iomap_dio_rw_begin:   dev 7:7 ino 0xe size 0x1000 offset 0x0 length 0x1000 done_before 0x0 flags DIRECT dio_flags  aio 1
      a.out-2074  [006]   136.226173: iomap_dio_rw_queued:  dev 7:7 ino 0xe size 0x1000 offset 0x1000 length 0x0
ksoftirqd/3-31    [003]   136.226389: iomap_dio_complete:   dev 7:7 ino 0xe size 0x1000 offset 0x1000 flags DIRECT aio 1 error 0 ret 4096
      a.out-2075  [003]   141.674969: iomap_dio_rw_begin:   dev 7:7 ino 0xe size 0x1000 offset 0x0 length 0x1000 done_before 0x0 flags DIRECT|WRITE dio_flags  aio 1
      a.out-2075  [003]   141.676085: iomap_dio_rw_queued:  dev 7:7 ino 0xe size 0x1000 offset 0x1000 length 0x0
kworker/2:0-27    [002]   141.676432: iomap_dio_complete:   dev 7:7 ino 0xe size 0x1000 offset 0x1000 flags DIRECT|WRITE aio 1 error 0 ret 4096
      a.out-2077  [006]   143.443746: iomap_dio_rw_begin:   dev 7:7 ino 0xe size 0x1000 offset 0x0 length 0x1000 done_before 0x0 flags DIRECT dio_flags  aio 1
      a.out-2077  [006]   143.443866: iomap_dio_rw_queued:  dev 7:7 ino 0xe size 0x1000 offset 0x1000 length 0x0
ksoftirqd/5-41    [005]   143.444134: iomap_dio_complete:   dev 7:7 ino 0xe size 0x1000 offset 0x1000 flags DIRECT aio 1 error 0 ret 4096
      a.out-2078  [007]   146.716833: iomap_dio_rw_begin:   dev 7:7 ino 0xe size 0x1000 offset 0x0 length 0x1000 done_before 0x0 flags DIRECT dio_flags  aio 0
      a.out-2078  [007]   146.717639: iomap_dio_complete:   dev 7:7 ino 0xe size 0x1000 offset 0x1000 flags DIRECT aio 0 error 0 ret 4096
      a.out-2079  [006]   148.972605: iomap_dio_rw_begin:   dev 7:7 ino 0xe size 0x1000 offset 0x0 length 0x1000 done_before 0x0 flags DIRECT dio_flags  aio 0
      a.out-2079  [006]   148.973099: iomap_dio_complete:   dev 7:7 ino 0xe size 0x1000 offset 0x1000 flags DIRECT aio 0 error 0 ret 4096

Reviewed-by: default avatarChristoph Hellwig <hch@lst.de>
Signed-off-by: default avatarRitesh Harjani (IBM) <ritesh.list@gmail.com>
Reviewed-by: default avatarDarrick J. Wong <djwong@kernel.org>
[djwong: line up strings all prettylike]
Signed-off-by: default avatarDarrick J. Wong <djwong@kernel.org>
parent d3bff1fc

fs/iomap/direct-io.c

+6 −1
Original line number Diff line number Diff line
@@ -130,6 +130,7 @@ ssize_t iomap_dio_complete(struct iomap_dio *dio) 
	if (ret > 0)

		ret += dio->done_before;



	trace_iomap_dio_complete(iocb, dio->error, ret);

	kfree(dio);



	return ret;
@@ -493,6 +494,8 @@ __iomap_dio_rw(struct kiocb *iocb, struct iov_iter *iter, 
	struct blk_plug plug;

	struct iomap_dio *dio;



	trace_iomap_dio_rw_begin(iocb, iter, dio_flags, done_before);



	if (!iomi.len)

		return NULL;
@@ -650,8 +653,10 @@ __iomap_dio_rw(struct kiocb *iocb, struct iov_iter *iter, 
	 */

	dio->wait_for_completion = wait_for_completion;

	if (!atomic_dec_and_test(&dio->ref)) {

		if (!wait_for_completion)

		if (!wait_for_completion) {

			trace_iomap_dio_rw_queued(inode, iomi.pos, iomi.len);

			return ERR_PTR(-EIOCBQUEUED);

		}



		for (;;) {

			set_current_state(TASK_UNINTERRUPTIBLE);

fs/iomap/trace.c

+1 −0
Original line number Diff line number Diff line
@@ -3,6 +3,7 @@ 
 * Copyright (c) 2019 Christoph Hellwig

 */

#include <linux/iomap.h>

#include <linux/uio.h>



/*

 * We include this last to have the helpers above available for the trace

fs/iomap/trace.h

+78 −0
Original line number Diff line number Diff line
@@ -83,6 +83,7 @@ DEFINE_RANGE_EVENT(iomap_writepage); 
DEFINE_RANGE_EVENT(iomap_release_folio);

DEFINE_RANGE_EVENT(iomap_invalidate_folio);

DEFINE_RANGE_EVENT(iomap_dio_invalidate_fail);

DEFINE_RANGE_EVENT(iomap_dio_rw_queued);



#define IOMAP_TYPE_STRINGS \

	{ IOMAP_HOLE,		"HOLE" }, \
@@ -107,6 +108,11 @@ DEFINE_RANGE_EVENT(iomap_dio_invalidate_fail); 
	{ IOMAP_F_BUFFER_HEAD,	"BH" }, \

	{ IOMAP_F_SIZE_CHANGED,	"SIZE_CHANGED" }



#define IOMAP_DIO_STRINGS \

	{IOMAP_DIO_FORCE_WAIT,	"DIO_FORCE_WAIT" }, \

	{IOMAP_DIO_OVERWRITE_ONLY, "DIO_OVERWRITE_ONLY" }, \

	{IOMAP_DIO_PARTIAL,	"DIO_PARTIAL" }



DECLARE_EVENT_CLASS(iomap_class,

	TP_PROTO(struct inode *inode, struct iomap *iomap),

	TP_ARGS(inode, iomap),
@@ -183,6 +189,78 @@ TRACE_EVENT(iomap_iter, 
		   (void *)__entry->caller)

);



TRACE_EVENT(iomap_dio_rw_begin,

	TP_PROTO(struct kiocb *iocb, struct iov_iter *iter,

		 unsigned int dio_flags, size_t done_before),

	TP_ARGS(iocb, iter, dio_flags, done_before),

	TP_STRUCT__entry(

		__field(dev_t,	dev)

		__field(ino_t,	ino)

		__field(loff_t, isize)

		__field(loff_t, pos)

		__field(size_t,	count)

		__field(size_t,	done_before)

		__field(int,	ki_flags)

		__field(unsigned int,	dio_flags)

		__field(bool,	aio)

	),

	TP_fast_assign(

		__entry->dev = file_inode(iocb->ki_filp)->i_sb->s_dev;

		__entry->ino = file_inode(iocb->ki_filp)->i_ino;

		__entry->isize = file_inode(iocb->ki_filp)->i_size;

		__entry->pos = iocb->ki_pos;

		__entry->count = iov_iter_count(iter);

		__entry->done_before = done_before;

		__entry->ki_flags = iocb->ki_flags;

		__entry->dio_flags = dio_flags;

		__entry->aio = !is_sync_kiocb(iocb);

	),

	TP_printk("dev %d:%d ino 0x%lx size 0x%llx offset 0x%llx length 0x%zx done_before 0x%zx flags %s dio_flags %s aio %d",

		  MAJOR(__entry->dev), MINOR(__entry->dev),

		  __entry->ino,

		  __entry->isize,

		  __entry->pos,

		  __entry->count,

		  __entry->done_before,

		  __print_flags(__entry->ki_flags, "|", TRACE_IOCB_STRINGS),

		  __print_flags(__entry->dio_flags, "|", IOMAP_DIO_STRINGS),

		  __entry->aio)

);



TRACE_EVENT(iomap_dio_complete,

	TP_PROTO(struct kiocb *iocb, int error, ssize_t ret),

	TP_ARGS(iocb, error, ret),

	TP_STRUCT__entry(

		__field(dev_t,	dev)

		__field(ino_t,	ino)

		__field(loff_t, isize)

		__field(loff_t, pos)

		__field(int,	ki_flags)

		__field(bool,	aio)

		__field(int,	error)

		__field(ssize_t, ret)

	),

	TP_fast_assign(

		__entry->dev = file_inode(iocb->ki_filp)->i_sb->s_dev;

		__entry->ino = file_inode(iocb->ki_filp)->i_ino;

		__entry->isize = file_inode(iocb->ki_filp)->i_size;

		__entry->pos = iocb->ki_pos;

		__entry->ki_flags = iocb->ki_flags;

		__entry->aio = !is_sync_kiocb(iocb);

		__entry->error = error;

		__entry->ret = ret;

	),

	TP_printk("dev %d:%d ino 0x%lx size 0x%llx offset 0x%llx flags %s aio %d error %d ret %zd",

		  MAJOR(__entry->dev), MINOR(__entry->dev),

		  __entry->ino,

		  __entry->isize,

		  __entry->pos,

		  __print_flags(__entry->ki_flags, "|", TRACE_IOCB_STRINGS),

		  __entry->aio,

		  __entry->error,

		  __entry->ret)

);



#endif /* _IOMAP_TRACE_H */



#undef TRACE_INCLUDE_PATH