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@xxxxxxxxxxxxx> Signed-off-by: Ritesh Harjani (IBM) <ritesh.list@xxxxxxxxx> --- 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" } + +DECLARE_EVENT_CLASS(iomap_dio_class, + TP_PROTO(struct kiocb *iocb, struct iov_iter *iter, + unsigned int dio_flags, u64 done_before, int ret), + TP_ARGS(iocb, iter, dio_flags, done_before, ret), + TP_STRUCT__entry( + __field(dev_t, dev) + __field(ino_t, ino) + __field(loff_t, isize) + __field(loff_t, pos) + __field(u64, count) + __field(u64, done_before) + __field(int, ki_flags) + __field(unsigned int, dio_flags) + __field(bool, aio) + __field(int, 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->count = iov_iter_count(iter); + __entry->done_before = done_before; + __entry->dio_flags = dio_flags; + __entry->ki_flags = iocb->ki_flags; + __entry->aio = !is_sync_kiocb(iocb); + __entry->ret = ret; + ), + TP_printk("dev %d:%d ino 0x%lx isize 0x%llx pos 0x%llx count %llu " + "flags %s dio_flags %s done_before %llu aio %d ret %d", + MAJOR(__entry->dev), MINOR(__entry->dev), + __entry->ino, + __entry->isize, + __entry->pos, + __entry->count, + __print_flags(__entry->ki_flags, "|", TRACE_IOCB_STRINGS), + __print_flags(__entry->dio_flags, "|", TRACE_IOMAP_DIO_STRINGS), + __entry->done_before, + __entry->aio, + __entry->ret) +) + +#define DEFINE_DIO_RW_EVENT(name) \ +DEFINE_EVENT(iomap_dio_class, name, \ + TP_PROTO(struct kiocb *iocb, struct iov_iter *iter, \ + unsigned int dio_flags, u64 done_before, \ + int ret), \ + TP_ARGS(iocb, iter, dio_flags, done_before, ret)) +DEFINE_DIO_RW_EVENT(iomap_dio_rw_begin); +DEFINE_DIO_RW_EVENT(iomap_dio_rw_end); + +TRACE_EVENT(iomap_dio_complete, + TP_PROTO(struct kiocb *iocb, int error, int 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(int, 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 isize 0x%llx pos 0x%llx flags %s aio %d error %d ret %d", + 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 -- 2.39.2