diff options
author | Theodore Ts'o <tytso@mit.edu> | 2013-02-06 22:30:23 -0500 |
---|---|---|
committer | Theodore Ts'o <tytso@mit.edu> | 2013-02-06 22:30:23 -0500 |
commit | 9fff24aa2c5c504aadead1ff9599e813604c2e53 (patch) | |
tree | 24bbb1691ec816aed648a895882526ce361ec92f /include | |
parent | 40ae3487628235e5f1eb27542cca0cdb6e5dbe16 (diff) | |
download | linux-9fff24aa2c5c504aadead1ff9599e813604c2e53.tar.gz linux-9fff24aa2c5c504aadead1ff9599e813604c2e53.tar.bz2 linux-9fff24aa2c5c504aadead1ff9599e813604c2e53.zip |
jbd2: track request delay statistics
Track the delay between when we first request that the commit begin
and when it actually begins, so we can see how much of a gap exists.
In theory, this should just be the remaining scheduling quantuum of
the thread which requested the commit (assuming it was not a
synchronous operation which triggered the commit request) plus
scheduling overhead; however, it's possible that real time processes
might get in the way of letting the kjournald thread from executing.
Signed-off-by: "Theodore Ts'o" <tytso@mit.edu>
Diffstat (limited to 'include')
-rw-r--r-- | include/linux/jbd2.h | 7 | ||||
-rw-r--r-- | include/trace/events/jbd2.h | 8 |
2 files changed, 13 insertions, 2 deletions
diff --git a/include/linux/jbd2.h b/include/linux/jbd2.h index e30b66346942..e0aafc46064f 100644 --- a/include/linux/jbd2.h +++ b/include/linux/jbd2.h @@ -581,6 +581,11 @@ struct transaction_s unsigned long t_start; /* + * When commit was requested + */ + unsigned long t_requested; + + /* * Checkpointing stats [j_checkpoint_sem] */ struct transaction_chp_stats_s t_chp_stats; @@ -637,6 +642,7 @@ struct transaction_s struct transaction_run_stats_s { unsigned long rs_wait; + unsigned long rs_request_delay; unsigned long rs_running; unsigned long rs_locked; unsigned long rs_flushing; @@ -649,6 +655,7 @@ struct transaction_run_stats_s { struct transaction_stats_s { unsigned long ts_tid; + unsigned long ts_requested; struct transaction_run_stats_s run; }; diff --git a/include/trace/events/jbd2.h b/include/trace/events/jbd2.h index 127993dbf322..5419f57beb1f 100644 --- a/include/trace/events/jbd2.h +++ b/include/trace/events/jbd2.h @@ -142,6 +142,7 @@ TRACE_EVENT(jbd2_run_stats, __field( dev_t, dev ) __field( unsigned long, tid ) __field( unsigned long, wait ) + __field( unsigned long, request_delay ) __field( unsigned long, running ) __field( unsigned long, locked ) __field( unsigned long, flushing ) @@ -155,6 +156,7 @@ TRACE_EVENT(jbd2_run_stats, __entry->dev = dev; __entry->tid = tid; __entry->wait = stats->rs_wait; + __entry->request_delay = stats->rs_request_delay; __entry->running = stats->rs_running; __entry->locked = stats->rs_locked; __entry->flushing = stats->rs_flushing; @@ -164,10 +166,12 @@ TRACE_EVENT(jbd2_run_stats, __entry->blocks_logged = stats->rs_blocks_logged; ), - TP_printk("dev %d,%d tid %lu wait %u running %u locked %u flushing %u " - "logging %u handle_count %u blocks %u blocks_logged %u", + TP_printk("dev %d,%d tid %lu wait %u request_delay %u running %u " + "locked %u flushing %u logging %u handle_count %u " + "blocks %u blocks_logged %u", MAJOR(__entry->dev), MINOR(__entry->dev), __entry->tid, jiffies_to_msecs(__entry->wait), + jiffies_to_msecs(__entry->request_delay), jiffies_to_msecs(__entry->running), jiffies_to_msecs(__entry->locked), jiffies_to_msecs(__entry->flushing), |