Re: [RFCv3 10/10] iomap: Add trace points for DIO path

[Ritesh Harjani (IBM) <ritesh.list@gmail.com>]

"Darrick J. Wong" <djwong@kernel.org> writes:

> On Fri, Apr 14, 2023 at 01:48:49AM +0530, Ritesh Harjani wrote:
>> "Darrick J. Wong" <djwong@kernel.org> writes:
>>
>> > On Thu, Apr 13, 2023 at 02:10:32PM +0530, Ritesh Harjani (IBM) wrote:
>> >> This patch adds trace point events for iomap DIO path.
>> >>
>> >> <e.g. iomap dio trace>
>> >>      xfs_io-8815  [000]   526.790418: iomap_dio_rw_begin:   dev 7:7 ino 0xc isize 0x0 pos 0x0 count 4096 flags DIRECT dio_flags DIO_FORCE_WAIT done_before 0 aio 0 ret 0
>> >>      xfs_io-8815  [000]   526.790978: iomap_dio_complete:   dev 7:7 ino 0xc isize 0x1000 pos 0x1000 flags DIRECT aio 0 error 0 ret 4096
>> >>      xfs_io-8815  [000]   526.790988: iomap_dio_rw_end:     dev 7:7 ino 0xc isize 0x1000 pos 0x1000 count 0 flags DIRECT dio_flags DIO_FORCE_WAIT done_before 0 aio 0 ret 4096
>> >>         fsx-8827  [005]   526.939345: iomap_dio_rw_begin:   dev 7:7 ino 0xc isize 0x922f8 pos 0x4f000 count 61440 flags NOWAIT|DIRECT|ALLOC_CACHE dio_flags  done_before 0 aio 1 ret 0
>> >>         fsx-8827  [005]   526.939459: iomap_dio_rw_end:     dev 7:7 ino 0xc isize 0x922f8 pos 0x4f000 count 0 flags NOWAIT|DIRECT|ALLOC_CACHE dio_flags  done_before 0 aio 1 ret -529
>> >> ksoftirqd/5-41    [005]   526.939564: iomap_dio_complete:   dev 7:7 ino 0xc isize 0x922f8 pos 0x5e000 flags NOWAIT|DIRECT|ALLOC_CACHE aio 1 error 0 ret 61440
>> >>
>> >> Tested-by: Disha Goel <disgoel@linux.ibm.com>
>> >> Signed-off-by: Ritesh Harjani (IBM) <ritesh.list@gmail.com>
>> >> ---
>> >>  fs/iomap/direct-io.c |  3 ++
>> >>  fs/iomap/trace.c     |  1 +
>> >>  fs/iomap/trace.h     | 90 ++++++++++++++++++++++++++++++++++++++++++++
>> >>  3 files changed, 94 insertions(+)
>> >>
>> >> diff --git a/fs/iomap/direct-io.c b/fs/iomap/direct-io.c
>> >> index 5871956ee880..bb7a6dfbc8b3 100644
>> >> --- a/fs/iomap/direct-io.c
>> >> +++ b/fs/iomap/direct-io.c
>> >> @@ -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;
>> >> @@ -681,6 +682,7 @@ iomap_dio_rw(struct kiocb *iocb, struct iov_iter *iter,
>> >>  	struct iomap_dio *dio;
>> >>  	ssize_t ret = 0;
>> >>
>> >> +	trace_iomap_dio_rw_begin(iocb, iter, dio_flags, done_before, ret);
>> >>  	dio = __iomap_dio_rw(iocb, iter, ops, dops, dio_flags, private,
>> >>  			     done_before);
>> >>  	if (IS_ERR_OR_NULL(dio)) {
>> >> @@ -689,6 +691,7 @@ iomap_dio_rw(struct kiocb *iocb, struct iov_iter *iter,
>> >>  	}
>> >>  	ret = iomap_dio_complete(dio);
>> >>  out:
>> >> +	trace_iomap_dio_rw_end(iocb, iter, dio_flags, done_before, ret);
>> >>  	return ret;
>> >>  }
>> >>  EXPORT_SYMBOL_GPL(iomap_dio_rw);
>> >> diff --git a/fs/iomap/trace.c b/fs/iomap/trace.c
>> >> index da217246b1a9..728d5443daf5 100644
>> >> --- a/fs/iomap/trace.c
>> >> +++ b/fs/iomap/trace.c
>> >> @@ -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
>> >> diff --git a/fs/iomap/trace.h b/fs/iomap/trace.h
>> >> index f6ea9540d082..dcb4dd4db5fb 100644
>> >> --- a/fs/iomap/trace.h
>> >> +++ b/fs/iomap/trace.h
>> >> @@ -183,6 +183,96 @@ TRACE_EVENT(iomap_iter,
>> >>  		   (void *)__entry->caller)
>> >>  );
>> >>
>> >> +#define TRACE_IOMAP_DIO_STRINGS \
>> >> +	{IOMAP_DIO_FORCE_WAIT, "DIO_FORCE_WAIT" }, \
>> >> +	{IOMAP_DIO_OVERWRITE_ONLY, "DIO_OVERWRITE_ONLY" }, \
>> >> +	{IOMAP_DIO_PARTIAL, "DIO_PARTIAL" }
>> >
>> > Can you make the strings line up too, please?
>> >
>>
>> Ok near other _STRINGS macro. Sure, will do that.
>>
>>
>> >> +
>> >> +DECLARE_EVENT_CLASS(iomap_dio_class,
>> >> +	TP_PROTO(struct kiocb *iocb, struct iov_iter *iter,
>> >> +		 unsigned int dio_flags, u64 done_before, int ret),
>> >
>> > We're passing in ssize_t values for @ret, shouldn't the types match?
>> >
>>
>> Yes, I missed to correct that. Will make it loff_t.
>> This should be fixed in ext2 trace point macro too.
>>
>> (ssize_t can vary based on 32 bit v/s 64 bit, so while printing it as
>> %llx it gives warning on 32bit. Hence will use loff_t for ret)
>
> How about %zd?

Aah yes. My bad, I wanted to look into print-format specifiers, but
missed it.

Documentation/core-api/printk-formats.rst
		size_t			%zu or %zx
		ssize_t			%zd or %zx

Will send the next revision soon with the comments addressed then.

Thanks!
-ritesh