Commit 343d9c28 authored by Theodore Ts'o's avatar Theodore Ts'o

jbd2: add tracepoints which provide per-handle statistics

Handles which stay open a long time are problematic when it comes time
to close down a transaction so it can be committed.  These tracepoints
will help us determine which ones are the problematic ones, and to
validate whether changes makes things better or worse.
Signed-off-by: default avatar"Theodore Ts'o" <tytso@mit.edu>
parent 078d5039
...@@ -30,6 +30,8 @@ ...@@ -30,6 +30,8 @@
#include <linux/bug.h> #include <linux/bug.h>
#include <linux/module.h> #include <linux/module.h>
#include <trace/events/jbd2.h>
static void __jbd2_journal_temp_unlink_buffer(struct journal_head *jh); static void __jbd2_journal_temp_unlink_buffer(struct journal_head *jh);
static void __jbd2_journal_unfile_buffer(struct journal_head *jh); static void __jbd2_journal_unfile_buffer(struct journal_head *jh);
...@@ -307,6 +309,8 @@ static int start_this_handle(journal_t *journal, handle_t *handle, ...@@ -307,6 +309,8 @@ static int start_this_handle(journal_t *journal, handle_t *handle,
*/ */
update_t_max_wait(transaction, ts); update_t_max_wait(transaction, ts);
handle->h_transaction = transaction; handle->h_transaction = transaction;
handle->h_requested_credits = nblocks;
handle->h_start_jiffies = jiffies;
atomic_inc(&transaction->t_updates); atomic_inc(&transaction->t_updates);
atomic_inc(&transaction->t_handle_count); atomic_inc(&transaction->t_handle_count);
jbd_debug(4, "Handle %p given %d credits (total %d, free %d)\n", jbd_debug(4, "Handle %p given %d credits (total %d, free %d)\n",
...@@ -353,7 +357,8 @@ static handle_t *new_handle(int nblocks) ...@@ -353,7 +357,8 @@ static handle_t *new_handle(int nblocks)
* Return a pointer to a newly allocated handle, or an ERR_PTR() value * Return a pointer to a newly allocated handle, or an ERR_PTR() value
* on failure. * on failure.
*/ */
handle_t *jbd2__journal_start(journal_t *journal, int nblocks, gfp_t gfp_mask) handle_t *jbd2__journal_start(journal_t *journal, int nblocks, gfp_t gfp_mask,
unsigned int type, unsigned int line_no)
{ {
handle_t *handle = journal_current_handle(); handle_t *handle = journal_current_handle();
int err; int err;
...@@ -379,6 +384,11 @@ handle_t *jbd2__journal_start(journal_t *journal, int nblocks, gfp_t gfp_mask) ...@@ -379,6 +384,11 @@ handle_t *jbd2__journal_start(journal_t *journal, int nblocks, gfp_t gfp_mask)
current->journal_info = NULL; current->journal_info = NULL;
handle = ERR_PTR(err); handle = ERR_PTR(err);
} }
handle->h_type = type;
handle->h_line_no = line_no;
trace_jbd2_handle_start(journal->j_fs_dev->bd_dev,
handle->h_transaction->t_tid, type,
line_no, nblocks);
return handle; return handle;
} }
EXPORT_SYMBOL(jbd2__journal_start); EXPORT_SYMBOL(jbd2__journal_start);
...@@ -386,7 +396,7 @@ EXPORT_SYMBOL(jbd2__journal_start); ...@@ -386,7 +396,7 @@ EXPORT_SYMBOL(jbd2__journal_start);
handle_t *jbd2_journal_start(journal_t *journal, int nblocks) handle_t *jbd2_journal_start(journal_t *journal, int nblocks)
{ {
return jbd2__journal_start(journal, nblocks, GFP_NOFS); return jbd2__journal_start(journal, nblocks, GFP_NOFS, 0, 0);
} }
EXPORT_SYMBOL(jbd2_journal_start); EXPORT_SYMBOL(jbd2_journal_start);
...@@ -448,7 +458,14 @@ int jbd2_journal_extend(handle_t *handle, int nblocks) ...@@ -448,7 +458,14 @@ int jbd2_journal_extend(handle_t *handle, int nblocks)
goto unlock; goto unlock;
} }
trace_jbd2_handle_extend(journal->j_fs_dev->bd_dev,
handle->h_transaction->t_tid,
handle->h_type, handle->h_line_no,
handle->h_buffer_credits,
nblocks);
handle->h_buffer_credits += nblocks; handle->h_buffer_credits += nblocks;
handle->h_requested_credits += nblocks;
atomic_add(nblocks, &transaction->t_outstanding_credits); atomic_add(nblocks, &transaction->t_outstanding_credits);
result = 0; result = 0;
...@@ -1377,6 +1394,13 @@ int jbd2_journal_stop(handle_t *handle) ...@@ -1377,6 +1394,13 @@ int jbd2_journal_stop(handle_t *handle)
} }
jbd_debug(4, "Handle %p going down\n", handle); jbd_debug(4, "Handle %p going down\n", handle);
trace_jbd2_handle_stats(journal->j_fs_dev->bd_dev,
handle->h_transaction->t_tid,
handle->h_type, handle->h_line_no,
jiffies - handle->h_start_jiffies,
handle->h_sync, handle->h_requested_credits,
(handle->h_requested_credits -
handle->h_buffer_credits));
/* /*
* Implement synchronous transaction batching. If the handle * Implement synchronous transaction batching. If the handle
......
...@@ -400,6 +400,11 @@ struct jbd2_journal_handle ...@@ -400,6 +400,11 @@ struct jbd2_journal_handle
unsigned int h_sync: 1; /* sync-on-close */ unsigned int h_sync: 1; /* sync-on-close */
unsigned int h_jdata: 1; /* force data journaling */ unsigned int h_jdata: 1; /* force data journaling */
unsigned int h_aborted: 1; /* fatal error on handle */ unsigned int h_aborted: 1; /* fatal error on handle */
unsigned int h_type: 8; /* for handle statistics */
unsigned int h_line_no: 16; /* for handle statistics */
unsigned long h_start_jiffies;
unsigned int h_requested_credits;
#ifdef CONFIG_DEBUG_LOCK_ALLOC #ifdef CONFIG_DEBUG_LOCK_ALLOC
struct lockdep_map h_lockdep_map; struct lockdep_map h_lockdep_map;
...@@ -1071,7 +1076,8 @@ static inline handle_t *journal_current_handle(void) ...@@ -1071,7 +1076,8 @@ static inline handle_t *journal_current_handle(void)
*/ */
extern handle_t *jbd2_journal_start(journal_t *, int nblocks); extern handle_t *jbd2_journal_start(journal_t *, int nblocks);
extern handle_t *jbd2__journal_start(journal_t *, int nblocks, gfp_t gfp_mask); extern handle_t *jbd2__journal_start(journal_t *, int nblocks, gfp_t gfp_mask,
unsigned int type, unsigned int line_no);
extern int jbd2_journal_restart(handle_t *, int nblocks); extern int jbd2_journal_restart(handle_t *, int nblocks);
extern int jbd2__journal_restart(handle_t *, int nblocks, gfp_t gfp_mask); extern int jbd2__journal_restart(handle_t *, int nblocks, gfp_t gfp_mask);
extern int jbd2_journal_extend (handle_t *, int nblocks); extern int jbd2_journal_extend (handle_t *, int nblocks);
......
...@@ -132,6 +132,104 @@ TRACE_EVENT(jbd2_submit_inode_data, ...@@ -132,6 +132,104 @@ TRACE_EVENT(jbd2_submit_inode_data,
(unsigned long) __entry->ino) (unsigned long) __entry->ino)
); );
TRACE_EVENT(jbd2_handle_start,
TP_PROTO(dev_t dev, unsigned long tid, unsigned int type,
unsigned int line_no, int requested_blocks),
TP_ARGS(dev, tid, type, line_no, requested_blocks),
TP_STRUCT__entry(
__field( dev_t, dev )
__field( unsigned long, tid )
__field( unsigned int, type )
__field( unsigned int, line_no )
__field( int, requested_blocks)
),
TP_fast_assign(
__entry->dev = dev;
__entry->tid = tid;
__entry->type = type;
__entry->line_no = line_no;
__entry->requested_blocks = requested_blocks;
),
TP_printk("dev %d,%d tid %lu type %u line_no %u "
"requested_blocks %d",
MAJOR(__entry->dev), MINOR(__entry->dev), __entry->tid,
__entry->type, __entry->line_no, __entry->requested_blocks)
);
TRACE_EVENT(jbd2_handle_extend,
TP_PROTO(dev_t dev, unsigned long tid, unsigned int type,
unsigned int line_no, int buffer_credits,
int requested_blocks),
TP_ARGS(dev, tid, type, line_no, buffer_credits, requested_blocks),
TP_STRUCT__entry(
__field( dev_t, dev )
__field( unsigned long, tid )
__field( unsigned int, type )
__field( unsigned int, line_no )
__field( int, buffer_credits )
__field( int, requested_blocks)
),
TP_fast_assign(
__entry->dev = dev;
__entry->tid = tid;
__entry->type = type;
__entry->line_no = line_no;
__entry->buffer_credits = buffer_credits;
__entry->requested_blocks = requested_blocks;
),
TP_printk("dev %d,%d tid %lu type %u line_no %u "
"buffer_credits %d requested_blocks %d",
MAJOR(__entry->dev), MINOR(__entry->dev), __entry->tid,
__entry->type, __entry->line_no, __entry->buffer_credits,
__entry->requested_blocks)
);
TRACE_EVENT(jbd2_handle_stats,
TP_PROTO(dev_t dev, unsigned long tid, unsigned int type,
unsigned int line_no, int interval, int sync,
int requested_blocks, int dirtied_blocks),
TP_ARGS(dev, tid, type, line_no, interval, sync,
requested_blocks, dirtied_blocks),
TP_STRUCT__entry(
__field( dev_t, dev )
__field( unsigned long, tid )
__field( unsigned int, type )
__field( unsigned int, line_no )
__field( int, interval )
__field( int, sync )
__field( int, requested_blocks)
__field( int, dirtied_blocks )
),
TP_fast_assign(
__entry->dev = dev;
__entry->tid = tid;
__entry->type = type;
__entry->line_no = line_no;
__entry->interval = interval;
__entry->sync = sync;
__entry->requested_blocks = requested_blocks;
__entry->dirtied_blocks = dirtied_blocks;
),
TP_printk("dev %d,%d tid %lu type %u line_no %u interval %d "
"sync %d requested_blocks %d dirtied_blocks %d",
MAJOR(__entry->dev), MINOR(__entry->dev), __entry->tid,
__entry->type, __entry->line_no, __entry->interval,
__entry->sync, __entry->requested_blocks,
__entry->dirtied_blocks)
);
TRACE_EVENT(jbd2_run_stats, TRACE_EVENT(jbd2_run_stats,
TP_PROTO(dev_t dev, unsigned long tid, TP_PROTO(dev_t dev, unsigned long tid,
struct transaction_run_stats_s *stats), struct transaction_run_stats_s *stats),
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment