writeback: trace event writeback_single_inode

It is valuable to know how the dirty inodes are iterated and their IO size.

"writeback_single_inode: bdi 8:0: ino=134246746 state=I_DIRTY_SYNC|I_SYNC age=414 index=0 to_write=1024 wrote=0"

- "state" reflects inode->i_state at the end of writeback_single_inode()
- "index" reflects mapping->writeback_index after the ->writepages() call
- "to_write" is the wbc->nr_to_write at entrance of writeback_single_inode()
- "wrote" is the number of pages actually written

v2: add trace event writeback_single_inode_requeue as proposed by Dave.

CC: Dave Chinner <david@fromorbit.com>
Signed-off-by: Wu Fengguang <fengguang.wu@intel.com>

diff --git a/fs/fs-writeback.c b/fs/fs-writeback.c
index f43c479feee9b54efe001da166efb29d9de2d16e..5185fad48b62d825cd12961eff191556f9eb5930 100644 (file)
--- a/fs/fs-writeback.c
+++ b/fs/fs-writeback.c
@@ -346,6 +346,7 @@ writeback_single_inode(struct inode *inode, struct bdi_writeback *wb,
                       struct writeback_control *wbc)
 {
        struct address_space *mapping = inode->i_mapping;
+       long nr_to_write = wbc->nr_to_write;
        unsigned dirty;
        int ret;
 
@@ -368,6 +369,8 @@ writeback_single_inode(struct inode *inode, struct bdi_writeback *wb,
                 */
                if (wbc->sync_mode != WB_SYNC_ALL) {
                        requeue_io(inode, wb);
+                       trace_writeback_single_inode_requeue(inode, wbc,
+                                                            nr_to_write);
                        return 0;
                }
 
@@ -467,6 +470,7 @@ writeback_single_inode(struct inode *inode, struct bdi_writeback *wb,
                }
        }
        inode_sync_complete(inode);
+       trace_writeback_single_inode(inode, wbc, nr_to_write);
        return ret;
 }
 

diff --git a/include/trace/events/writeback.h b/include/trace/events/writeback.h
index b2cfac5f33133627dcb4a2f7afb2665080b08791..898277bc89b4182dd30aea16230d2aff7e03acc3 100644 (file)
--- a/include/trace/events/writeback.h
+++ b/include/trace/events/writeback.h
@@ -8,6 +8,19 @@
 #include <linux/device.h>
 #include <linux/writeback.h>
 
+#define show_inode_state(state)                                        \
+       __print_flags(state, "|",                               \
+               {I_DIRTY_SYNC,          "I_DIRTY_SYNC"},        \
+               {I_DIRTY_DATASYNC,      "I_DIRTY_DATASYNC"},    \
+               {I_DIRTY_PAGES,         "I_DIRTY_PAGES"},       \
+               {I_NEW,                 "I_NEW"},               \
+               {I_WILL_FREE,           "I_WILL_FREE"},         \
+               {I_FREEING,             "I_FREEING"},           \
+               {I_CLEAR,               "I_CLEAR"},             \
+               {I_SYNC,                "I_SYNC"},              \
+               {I_REFERENCED,          "I_REFERENCED"}         \
+       )
+
 struct wb_writeback_work;
 
 DECLARE_EVENT_CLASS(writeback_work_class,
@@ -184,6 +197,63 @@ DEFINE_EVENT(writeback_congest_waited_template, writeback_wait_iff_congested,
        TP_ARGS(usec_timeout, usec_delayed)
 );
 
+DECLARE_EVENT_CLASS(writeback_single_inode_template,
+
+       TP_PROTO(struct inode *inode,
+                struct writeback_control *wbc,
+                unsigned long nr_to_write
+       ),
+
+       TP_ARGS(inode, wbc, nr_to_write),
+
+       TP_STRUCT__entry(
+               __array(char, name, 32)
+               __field(unsigned long, ino)
+               __field(unsigned long, state)
+               __field(unsigned long, age)
+               __field(unsigned long, writeback_index)
+               __field(long, nr_to_write)
+               __field(unsigned long, wrote)
+       ),
+
+       TP_fast_assign(
+               strncpy(__entry->name,
+                       dev_name(inode->i_mapping->backing_dev_info->dev), 32);
+               __entry->ino            = inode->i_ino;
+               __entry->state          = inode->i_state;
+               __entry->age            = (jiffies - inode->dirtied_when) *
+                                                               1000 / HZ;
+               __entry->writeback_index = inode->i_mapping->writeback_index;
+               __entry->nr_to_write    = nr_to_write;
+               __entry->wrote          = nr_to_write - wbc->nr_to_write;
+       ),
+
+       TP_printk("bdi %s: ino=%lu state=%s age=%lu "
+                 "index=%lu to_write=%ld wrote=%lu",
+                 __entry->name,
+                 __entry->ino,
+                 show_inode_state(__entry->state),
+                 __entry->age,
+                 __entry->writeback_index,
+                 __entry->nr_to_write,
+                 __entry->wrote
+       )
+);
+
+DEFINE_EVENT(writeback_single_inode_template, writeback_single_inode_requeue,
+       TP_PROTO(struct inode *inode,
+                struct writeback_control *wbc,
+                unsigned long nr_to_write),
+       TP_ARGS(inode, wbc, nr_to_write)
+);
+
+DEFINE_EVENT(writeback_single_inode_template, writeback_single_inode,
+       TP_PROTO(struct inode *inode,
+                struct writeback_control *wbc,
+                unsigned long nr_to_write),
+       TP_ARGS(inode, wbc, nr_to_write)
+);
+
 #endif /* _TRACE_WRITEBACK_H */
 
 /* This part must be outside protection */