writeback: show raw dirtied_when in trace writeback_single_inode
Subsystems (3)
RFC PATCH 1/1 writeback: show raw dirtied_when in trace writeback_single_inode
It looks more reasonable to save inode->dirtied_when in the raw trace output, and to show both the absolute raw value for easy scripting and the relative age in seconds for easy human reading.
The trace event was newly added in 3.1-rc1, so we still have the chance to change the format.
btw, are there ways for user space to query the HZ value of the running kernel? Which is required for converting the raw dirtied_when ticks to clock time.
--- include/trace/events/writeback.h | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-)
include/trace/events/writeback.h +5 -5
@@ -433,7 +433,7 @@ DECLARE_EVENT_CLASS(writeback_single_ino __array(char, name, 32) __field(unsigned long, ino) __field(unsigned long, state) - __field(unsigned long, age) + __field(unsigned long, dirtied_when) __field(unsigned long, writeback_index) __field(long, nr_to_write) __field(unsigned long, wrote)
@@ -444,19 +444,19 @@ DECLARE_EVENT_CLASS(writeback_single_ino 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->age = (jiffies - inode->dirtied_when) /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 " +TP_printk ("bdi %s: ino=%lu state=%s dirtied_when=%lu age=%lu " "index=%lu to_write=%ld wrote=%lu" , __entry->name, __entry->ino,show_inode_state (__entry->state), - __entry->age, + __entry->dirtied_when, + (jiffies - __entry->dirtied_when) /HZ , __entry->writeback_index, __entry->nr_to_write, __entry->wrote
Quoted 3 lines · Wu Fengguang
It looks more reasonable to save
inode->dirtied_whenin the raw trace output, and to show both the absolute raw value for easy scripting and the relative age in seconds for easy human reading.
I also hacked this in to debug the the delayed i_size updates with xfs, so:
ACK
PATCH v2 1/1 writeback: show raw dirtied_when in trace writeback_single_inode
[since v1: added Christoph's ack and make it actually work]
Save inode->dirtied_when in the raw trace output for reliable scripting, and to also show in formatted output the relative age in seconds for easy human reading.
--- include/trace/events/writeback.h | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-)
include/trace/events/writeback.h +5 -5
@@ -433,7 +433,7 @@ DECLARE_EVENT_CLASS(writeback_single_ino __array(char, name, 32) __field(unsigned long, ino) __field(unsigned long, state) - __field(unsigned long, age) + __field(unsigned long, dirtied_when) __field(unsigned long, writeback_index) __field(long, nr_to_write) __field(unsigned long, wrote)
@@ -444,19 +444,19 @@ DECLARE_EVENT_CLASS(writeback_single_ino 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->dirtied_when = inode->dirtied_when; __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 " +TP_printk ("bdi %s: ino=%lu state=%s dirtied_when=%lu age=%lu " "index=%lu to_write=%ld wrote=%lu" , __entry->name, __entry->ino,show_inode_state (__entry->state), - __entry->age, + __entry->dirtied_when, + (jiffies - __entry->dirtied_when) /HZ , __entry->writeback_index, __entry->nr_to_write, __entry->wrote