jbd2: Use tracepoints for history file
The /proc/fs/jbd2/<dev>/history was maintained manually; by using
tracepoints, we can get all of the existing functionality of the /proc
file plus extra capabilities thanks to the ftrace infrastructure. We
save memory as a bonus.
Signed-off-by: "Theodore Ts'o" <tytso@mit.edu>
diff --git a/fs/jbd2/checkpoint.c b/fs/jbd2/checkpoint.c
index 5d70b3e..ca0f5eb 100644
--- a/fs/jbd2/checkpoint.c
+++ b/fs/jbd2/checkpoint.c
@@ -643,6 +643,7 @@
int __jbd2_journal_remove_checkpoint(struct journal_head *jh)
{
+ struct transaction_chp_stats_s *stats;
transaction_t *transaction;
journal_t *journal;
int ret = 0;
@@ -679,6 +680,12 @@
/* OK, that was the last buffer for the transaction: we can now
safely remove this transaction from the log */
+ stats = &transaction->t_chp_stats;
+ if (stats->cs_chp_time)
+ stats->cs_chp_time = jbd2_time_diff(stats->cs_chp_time,
+ jiffies);
+ trace_jbd2_checkpoint_stats(journal->j_fs_dev->bd_dev,
+ transaction->t_tid, stats);
__jbd2_journal_drop_transaction(journal, transaction);
kfree(transaction);
diff --git a/fs/jbd2/commit.c b/fs/jbd2/commit.c
index 26d991d..d4cfd6d 100644
--- a/fs/jbd2/commit.c
+++ b/fs/jbd2/commit.c
@@ -410,10 +410,10 @@
if (commit_transaction->t_synchronous_commit)
write_op = WRITE_SYNC_PLUG;
trace_jbd2_commit_locking(journal, commit_transaction);
- stats.u.run.rs_wait = commit_transaction->t_max_wait;
- stats.u.run.rs_locked = jiffies;
- stats.u.run.rs_running = jbd2_time_diff(commit_transaction->t_start,
- stats.u.run.rs_locked);
+ stats.run.rs_wait = commit_transaction->t_max_wait;
+ stats.run.rs_locked = jiffies;
+ stats.run.rs_running = jbd2_time_diff(commit_transaction->t_start,
+ stats.run.rs_locked);
spin_lock(&commit_transaction->t_handle_lock);
while (commit_transaction->t_updates) {
@@ -486,9 +486,9 @@
jbd2_journal_switch_revoke_table(journal);
trace_jbd2_commit_flushing(journal, commit_transaction);
- stats.u.run.rs_flushing = jiffies;
- stats.u.run.rs_locked = jbd2_time_diff(stats.u.run.rs_locked,
- stats.u.run.rs_flushing);
+ stats.run.rs_flushing = jiffies;
+ stats.run.rs_locked = jbd2_time_diff(stats.run.rs_locked,
+ stats.run.rs_flushing);
commit_transaction->t_state = T_FLUSH;
journal->j_committing_transaction = commit_transaction;
@@ -523,11 +523,11 @@
spin_unlock(&journal->j_state_lock);
trace_jbd2_commit_logging(journal, commit_transaction);
- stats.u.run.rs_logging = jiffies;
- stats.u.run.rs_flushing = jbd2_time_diff(stats.u.run.rs_flushing,
- stats.u.run.rs_logging);
- stats.u.run.rs_blocks = commit_transaction->t_outstanding_credits;
- stats.u.run.rs_blocks_logged = 0;
+ stats.run.rs_logging = jiffies;
+ stats.run.rs_flushing = jbd2_time_diff(stats.run.rs_flushing,
+ stats.run.rs_logging);
+ stats.run.rs_blocks = commit_transaction->t_outstanding_credits;
+ stats.run.rs_blocks_logged = 0;
J_ASSERT(commit_transaction->t_nr_buffers <=
commit_transaction->t_outstanding_credits);
@@ -695,7 +695,7 @@
submit_bh(write_op, bh);
}
cond_resched();
- stats.u.run.rs_blocks_logged += bufs;
+ stats.run.rs_blocks_logged += bufs;
/* Force a new descriptor to be generated next
time round the loop. */
@@ -988,33 +988,30 @@
J_ASSERT(commit_transaction->t_state == T_COMMIT);
commit_transaction->t_start = jiffies;
- stats.u.run.rs_logging = jbd2_time_diff(stats.u.run.rs_logging,
- commit_transaction->t_start);
+ stats.run.rs_logging = jbd2_time_diff(stats.run.rs_logging,
+ commit_transaction->t_start);
/*
- * File the transaction for history
+ * File the transaction statistics
*/
- stats.ts_type = JBD2_STATS_RUN;
stats.ts_tid = commit_transaction->t_tid;
- stats.u.run.rs_handle_count = commit_transaction->t_handle_count;
- spin_lock(&journal->j_history_lock);
- memcpy(journal->j_history + journal->j_history_cur, &stats,
- sizeof(stats));
- if (++journal->j_history_cur == journal->j_history_max)
- journal->j_history_cur = 0;
+ stats.run.rs_handle_count = commit_transaction->t_handle_count;
+ trace_jbd2_run_stats(journal->j_fs_dev->bd_dev,
+ commit_transaction->t_tid, &stats.run);
/*
* Calculate overall stats
*/
+ spin_lock(&journal->j_history_lock);
journal->j_stats.ts_tid++;
- journal->j_stats.u.run.rs_wait += stats.u.run.rs_wait;
- journal->j_stats.u.run.rs_running += stats.u.run.rs_running;
- journal->j_stats.u.run.rs_locked += stats.u.run.rs_locked;
- journal->j_stats.u.run.rs_flushing += stats.u.run.rs_flushing;
- journal->j_stats.u.run.rs_logging += stats.u.run.rs_logging;
- journal->j_stats.u.run.rs_handle_count += stats.u.run.rs_handle_count;
- journal->j_stats.u.run.rs_blocks += stats.u.run.rs_blocks;
- journal->j_stats.u.run.rs_blocks_logged += stats.u.run.rs_blocks_logged;
+ journal->j_stats.run.rs_wait += stats.run.rs_wait;
+ journal->j_stats.run.rs_running += stats.run.rs_running;
+ journal->j_stats.run.rs_locked += stats.run.rs_locked;
+ journal->j_stats.run.rs_flushing += stats.run.rs_flushing;
+ journal->j_stats.run.rs_logging += stats.run.rs_logging;
+ journal->j_stats.run.rs_handle_count += stats.run.rs_handle_count;
+ journal->j_stats.run.rs_blocks += stats.run.rs_blocks;
+ journal->j_stats.run.rs_blocks_logged += stats.run.rs_blocks_logged;
spin_unlock(&journal->j_history_lock);
commit_transaction->t_state = T_FINISHED;
diff --git a/fs/jbd2/journal.c b/fs/jbd2/journal.c
index 977a8da..761af77 100644
--- a/fs/jbd2/journal.c
+++ b/fs/jbd2/journal.c
@@ -676,153 +676,6 @@
int max;
};
-static void *jbd2_history_skip_empty(struct jbd2_stats_proc_session *s,
- struct transaction_stats_s *ts,
- int first)
-{
- if (ts == s->stats + s->max)
- ts = s->stats;
- if (!first && ts == s->stats + s->start)
- return NULL;
- while (ts->ts_type == 0) {
- ts++;
- if (ts == s->stats + s->max)
- ts = s->stats;
- if (ts == s->stats + s->start)
- return NULL;
- }
- return ts;
-
-}
-
-static void *jbd2_seq_history_start(struct seq_file *seq, loff_t *pos)
-{
- struct jbd2_stats_proc_session *s = seq->private;
- struct transaction_stats_s *ts;
- int l = *pos;
-
- if (l == 0)
- return SEQ_START_TOKEN;
- ts = jbd2_history_skip_empty(s, s->stats + s->start, 1);
- if (!ts)
- return NULL;
- l--;
- while (l) {
- ts = jbd2_history_skip_empty(s, ++ts, 0);
- if (!ts)
- break;
- l--;
- }
- return ts;
-}
-
-static void *jbd2_seq_history_next(struct seq_file *seq, void *v, loff_t *pos)
-{
- struct jbd2_stats_proc_session *s = seq->private;
- struct transaction_stats_s *ts = v;
-
- ++*pos;
- if (v == SEQ_START_TOKEN)
- return jbd2_history_skip_empty(s, s->stats + s->start, 1);
- else
- return jbd2_history_skip_empty(s, ++ts, 0);
-}
-
-static int jbd2_seq_history_show(struct seq_file *seq, void *v)
-{
- struct transaction_stats_s *ts = v;
- if (v == SEQ_START_TOKEN) {
- seq_printf(seq, "%-4s %-5s %-5s %-5s %-5s %-5s %-5s %-6s %-5s "
- "%-5s %-5s %-5s %-5s %-5s\n", "R/C", "tid",
- "wait", "run", "lock", "flush", "log", "hndls",
- "block", "inlog", "ctime", "write", "drop",
- "close");
- return 0;
- }
- if (ts->ts_type == JBD2_STATS_RUN)
- seq_printf(seq, "%-4s %-5lu %-5u %-5u %-5u %-5u %-5u "
- "%-6lu %-5lu %-5lu\n", "R", ts->ts_tid,
- jiffies_to_msecs(ts->u.run.rs_wait),
- jiffies_to_msecs(ts->u.run.rs_running),
- jiffies_to_msecs(ts->u.run.rs_locked),
- jiffies_to_msecs(ts->u.run.rs_flushing),
- jiffies_to_msecs(ts->u.run.rs_logging),
- ts->u.run.rs_handle_count,
- ts->u.run.rs_blocks,
- ts->u.run.rs_blocks_logged);
- else if (ts->ts_type == JBD2_STATS_CHECKPOINT)
- seq_printf(seq, "%-4s %-5lu %48s %-5u %-5lu %-5lu %-5lu\n",
- "C", ts->ts_tid, " ",
- jiffies_to_msecs(ts->u.chp.cs_chp_time),
- ts->u.chp.cs_written, ts->u.chp.cs_dropped,
- ts->u.chp.cs_forced_to_close);
- else
- J_ASSERT(0);
- return 0;
-}
-
-static void jbd2_seq_history_stop(struct seq_file *seq, void *v)
-{
-}
-
-static const struct seq_operations jbd2_seq_history_ops = {
- .start = jbd2_seq_history_start,
- .next = jbd2_seq_history_next,
- .stop = jbd2_seq_history_stop,
- .show = jbd2_seq_history_show,
-};
-
-static int jbd2_seq_history_open(struct inode *inode, struct file *file)
-{
- journal_t *journal = PDE(inode)->data;
- struct jbd2_stats_proc_session *s;
- int rc, size;
-
- s = kmalloc(sizeof(*s), GFP_KERNEL);
- if (s == NULL)
- return -ENOMEM;
- size = sizeof(struct transaction_stats_s) * journal->j_history_max;
- s->stats = kmalloc(size, GFP_KERNEL);
- if (s->stats == NULL) {
- kfree(s);
- return -ENOMEM;
- }
- spin_lock(&journal->j_history_lock);
- memcpy(s->stats, journal->j_history, size);
- s->max = journal->j_history_max;
- s->start = journal->j_history_cur % s->max;
- spin_unlock(&journal->j_history_lock);
-
- rc = seq_open(file, &jbd2_seq_history_ops);
- if (rc == 0) {
- struct seq_file *m = file->private_data;
- m->private = s;
- } else {
- kfree(s->stats);
- kfree(s);
- }
- return rc;
-
-}
-
-static int jbd2_seq_history_release(struct inode *inode, struct file *file)
-{
- struct seq_file *seq = file->private_data;
- struct jbd2_stats_proc_session *s = seq->private;
-
- kfree(s->stats);
- kfree(s);
- return seq_release(inode, file);
-}
-
-static struct file_operations jbd2_seq_history_fops = {
- .owner = THIS_MODULE,
- .open = jbd2_seq_history_open,
- .read = seq_read,
- .llseek = seq_lseek,
- .release = jbd2_seq_history_release,
-};
-
static void *jbd2_seq_info_start(struct seq_file *seq, loff_t *pos)
{
return *pos ? NULL : SEQ_START_TOKEN;
@@ -839,29 +692,29 @@
if (v != SEQ_START_TOKEN)
return 0;
- seq_printf(seq, "%lu transaction, each upto %u blocks\n",
+ seq_printf(seq, "%lu transaction, each up to %u blocks\n",
s->stats->ts_tid,
s->journal->j_max_transaction_buffers);
if (s->stats->ts_tid == 0)
return 0;
seq_printf(seq, "average: \n %ums waiting for transaction\n",
- jiffies_to_msecs(s->stats->u.run.rs_wait / s->stats->ts_tid));
+ jiffies_to_msecs(s->stats->run.rs_wait / s->stats->ts_tid));
seq_printf(seq, " %ums running transaction\n",
- jiffies_to_msecs(s->stats->u.run.rs_running / s->stats->ts_tid));
+ jiffies_to_msecs(s->stats->run.rs_running / s->stats->ts_tid));
seq_printf(seq, " %ums transaction was being locked\n",
- jiffies_to_msecs(s->stats->u.run.rs_locked / s->stats->ts_tid));
+ jiffies_to_msecs(s->stats->run.rs_locked / s->stats->ts_tid));
seq_printf(seq, " %ums flushing data (in ordered mode)\n",
- jiffies_to_msecs(s->stats->u.run.rs_flushing / s->stats->ts_tid));
+ jiffies_to_msecs(s->stats->run.rs_flushing / s->stats->ts_tid));
seq_printf(seq, " %ums logging transaction\n",
- jiffies_to_msecs(s->stats->u.run.rs_logging / s->stats->ts_tid));
+ jiffies_to_msecs(s->stats->run.rs_logging / s->stats->ts_tid));
seq_printf(seq, " %lluus average transaction commit time\n",
div_u64(s->journal->j_average_commit_time, 1000));
seq_printf(seq, " %lu handles per transaction\n",
- s->stats->u.run.rs_handle_count / s->stats->ts_tid);
+ s->stats->run.rs_handle_count / s->stats->ts_tid);
seq_printf(seq, " %lu blocks per transaction\n",
- s->stats->u.run.rs_blocks / s->stats->ts_tid);
+ s->stats->run.rs_blocks / s->stats->ts_tid);
seq_printf(seq, " %lu logged blocks per transaction\n",
- s->stats->u.run.rs_blocks_logged / s->stats->ts_tid);
+ s->stats->run.rs_blocks_logged / s->stats->ts_tid);
return 0;
}
@@ -931,8 +784,6 @@
{
journal->j_proc_entry = proc_mkdir(journal->j_devname, proc_jbd2_stats);
if (journal->j_proc_entry) {
- proc_create_data("history", S_IRUGO, journal->j_proc_entry,
- &jbd2_seq_history_fops, journal);
proc_create_data("info", S_IRUGO, journal->j_proc_entry,
&jbd2_seq_info_fops, journal);
}
@@ -941,27 +792,9 @@
static void jbd2_stats_proc_exit(journal_t *journal)
{
remove_proc_entry("info", journal->j_proc_entry);
- remove_proc_entry("history", journal->j_proc_entry);
remove_proc_entry(journal->j_devname, proc_jbd2_stats);
}
-static void journal_init_stats(journal_t *journal)
-{
- int size;
-
- if (!proc_jbd2_stats)
- return;
-
- journal->j_history_max = 100;
- size = sizeof(struct transaction_stats_s) * journal->j_history_max;
- journal->j_history = kzalloc(size, GFP_KERNEL);
- if (!journal->j_history) {
- journal->j_history_max = 0;
- return;
- }
- spin_lock_init(&journal->j_history_lock);
-}
-
/*
* Management for journal control blocks: functions to create and
* destroy journal_t structures, and to initialise and read existing
@@ -1006,7 +839,7 @@
goto fail;
}
- journal_init_stats(journal);
+ spin_lock_init(&journal->j_history_lock);
return journal;
fail:
diff --git a/include/linux/jbd2.h b/include/linux/jbd2.h
index 52695d3..f1011f7 100644
--- a/include/linux/jbd2.h
+++ b/include/linux/jbd2.h
@@ -464,9 +464,9 @@
*/
struct transaction_chp_stats_s {
unsigned long cs_chp_time;
- unsigned long cs_forced_to_close;
- unsigned long cs_written;
- unsigned long cs_dropped;
+ __u32 cs_forced_to_close;
+ __u32 cs_written;
+ __u32 cs_dropped;
};
/* The transaction_t type is the guts of the journaling mechanism. It
@@ -668,23 +668,16 @@
unsigned long rs_flushing;
unsigned long rs_logging;
- unsigned long rs_handle_count;
- unsigned long rs_blocks;
- unsigned long rs_blocks_logged;
+ __u32 rs_handle_count;
+ __u32 rs_blocks;
+ __u32 rs_blocks_logged;
};
struct transaction_stats_s {
- int ts_type;
unsigned long ts_tid;
- union {
- struct transaction_run_stats_s run;
- struct transaction_chp_stats_s chp;
- } u;
+ struct transaction_run_stats_s run;
};
-#define JBD2_STATS_RUN 1
-#define JBD2_STATS_CHECKPOINT 2
-
static inline unsigned long
jbd2_time_diff(unsigned long start, unsigned long end)
{
@@ -988,12 +981,6 @@
/*
* Journal statistics
*/
- struct transaction_stats_s *j_history;
- int j_history_max;
- int j_history_cur;
- /*
- * Protect the transactions statistics history
- */
spinlock_t j_history_lock;
struct proc_dir_entry *j_proc_entry;
struct transaction_stats_s j_stats;
diff --git a/include/trace/events/jbd2.h b/include/trace/events/jbd2.h
index b851f0b..3c60b75 100644
--- a/include/trace/events/jbd2.h
+++ b/include/trace/events/jbd2.h
@@ -7,6 +7,9 @@
#include <linux/jbd2.h>
#include <linux/tracepoint.h>
+struct transaction_chp_stats_s;
+struct transaction_run_stats_s;
+
TRACE_EVENT(jbd2_checkpoint,
TP_PROTO(journal_t *journal, int result),
@@ -162,6 +165,81 @@
jbd2_dev_to_name(__entry->dev), (unsigned long) __entry->ino)
);
+TRACE_EVENT(jbd2_run_stats,
+ TP_PROTO(dev_t dev, unsigned long tid,
+ struct transaction_run_stats_s *stats),
+
+ TP_ARGS(dev, tid, stats),
+
+ TP_STRUCT__entry(
+ __field( dev_t, dev )
+ __field( unsigned long, tid )
+ __field( unsigned long, wait )
+ __field( unsigned long, running )
+ __field( unsigned long, locked )
+ __field( unsigned long, flushing )
+ __field( unsigned long, logging )
+ __field( __u32, handle_count )
+ __field( __u32, blocks )
+ __field( __u32, blocks_logged )
+ ),
+
+ TP_fast_assign(
+ __entry->dev = dev;
+ __entry->tid = tid;
+ __entry->wait = stats->rs_wait;
+ __entry->running = stats->rs_running;
+ __entry->locked = stats->rs_locked;
+ __entry->flushing = stats->rs_flushing;
+ __entry->logging = stats->rs_logging;
+ __entry->handle_count = stats->rs_handle_count;
+ __entry->blocks = stats->rs_blocks;
+ __entry->blocks_logged = stats->rs_blocks_logged;
+ ),
+
+ TP_printk("dev %s tid %lu wait %u running %u locked %u flushing %u "
+ "logging %u handle_count %u blocks %u blocks_logged %u",
+ jbd2_dev_to_name(__entry->dev), __entry->tid,
+ jiffies_to_msecs(__entry->wait),
+ jiffies_to_msecs(__entry->running),
+ jiffies_to_msecs(__entry->locked),
+ jiffies_to_msecs(__entry->flushing),
+ jiffies_to_msecs(__entry->logging),
+ __entry->handle_count, __entry->blocks,
+ __entry->blocks_logged)
+);
+
+TRACE_EVENT(jbd2_checkpoint_stats,
+ TP_PROTO(dev_t dev, unsigned long tid,
+ struct transaction_chp_stats_s *stats),
+
+ TP_ARGS(dev, tid, stats),
+
+ TP_STRUCT__entry(
+ __field( dev_t, dev )
+ __field( unsigned long, tid )
+ __field( unsigned long, chp_time )
+ __field( __u32, forced_to_close )
+ __field( __u32, written )
+ __field( __u32, dropped )
+ ),
+
+ TP_fast_assign(
+ __entry->dev = dev;
+ __entry->tid = tid;
+ __entry->chp_time = stats->cs_chp_time;
+ __entry->forced_to_close= stats->cs_forced_to_close;
+ __entry->written = stats->cs_written;
+ __entry->dropped = stats->cs_dropped;
+ ),
+
+ TP_printk("dev %s tid %lu chp_time %u forced_to_close %u "
+ "written %u dropped %u",
+ jbd2_dev_to_name(__entry->dev), __entry->tid,
+ jiffies_to_msecs(__entry->chp_time),
+ __entry->forced_to_close, __entry->written, __entry->dropped)
+);
+
#endif /* _TRACE_JBD2_H */
/* This part must be outside protection */
