1 [PATCH] jbd2 stats through procfs
3 The patch below updates the jbd stats patch to 2.6.20/jbd2.
4 The initial patch was posted by Alex Tomas in December 2005
5 (http://marc.info/?l=linux-ext4&m=113538565128617&w=2).
6 It provides statistics via procfs such as transaction lifetime and size.
8 [ This probably should be rewritten to use debugfs? -- Ted]
10 Signed-off-by: Johann Lombardi <johann.lombardi@bull.net>
13 Index: linux-2.6.22-rc4/include/linux/jbd2.h
14 ===================================================================
15 --- linux-2.6.22-rc4.orig/include/linux/jbd2.h 2007-06-11 17:28:17.000000000 -0700
16 +++ linux-2.6.22-rc4/include/linux/jbd2.h 2007-06-13 10:45:21.000000000 -0700
22 + * Some stats for checkpoint phase
24 +struct transaction_chp_stats_s {
25 + unsigned long cs_chp_time;
26 + unsigned long cs_forced_to_close;
27 + unsigned long cs_written;
28 + unsigned long cs_dropped;
31 /* The transaction_t type is the guts of the journaling mechanism. It
32 * tracks a compound transaction through its various states:
35 spinlock_t t_handle_lock;
38 + * Longest time some handle had to wait for running transaction
40 + unsigned long t_max_wait;
43 + * When transaction started
45 + unsigned long t_start;
48 + * Checkpointing stats [j_checkpoint_sem]
50 + struct transaction_chp_stats_s t_chp_stats;
53 * Number of outstanding updates running on this transaction
60 +struct transaction_run_stats_s {
61 + unsigned long rs_wait;
62 + unsigned long rs_running;
63 + unsigned long rs_locked;
64 + unsigned long rs_flushing;
65 + unsigned long rs_logging;
67 + unsigned long rs_handle_count;
68 + unsigned long rs_blocks;
69 + unsigned long rs_blocks_logged;
72 +struct transaction_stats_s
75 + unsigned long ts_tid;
77 + struct transaction_run_stats_s run;
78 + struct transaction_chp_stats_s chp;
82 +#define JBD2_STATS_RUN 1
83 +#define JBD2_STATS_CHECKPOINT 2
85 +#define ts_wait u.run.rs_wait
86 +#define ts_running u.run.rs_running
87 +#define ts_locked u.run.rs_locked
88 +#define ts_flushing u.run.rs_flushing
89 +#define ts_logging u.run.rs_logging
90 +#define ts_handle_count u.run.rs_handle_count
91 +#define ts_blocks u.run.rs_blocks
92 +#define ts_blocks_logged u.run.rs_blocks_logged
94 +#define ts_chp_time u.chp.cs_chp_time
95 +#define ts_forced_to_close u.chp.cs_forced_to_close
96 +#define ts_written u.chp.cs_written
97 +#define ts_dropped u.chp.cs_dropped
99 +#define CURRENT_MSECS (jiffies_to_msecs(jiffies))
101 +static inline unsigned int
102 +jbd2_time_diff(unsigned int start, unsigned int end)
104 + if (unlikely(start > end))
105 + end = end + (~0UL - start);
112 * struct journal_s - The journal_s type is the concrete type associated with
115 * @j_wbufsize: maximum number of buffer_heads allowed in j_wbuf, the
116 * number that will fit in j_blocksize
117 * @j_last_sync_writer: most recent pid which did a synchronous write
118 + * @j_history: Buffer storing the transactions statistics history
119 + * @j_history_max: Maximum number of transactions in the statistics history
120 + * @j_history_cur: Current number of transactions in the statistics history
121 + * @j_history_lock: Protect the transactions statistics history
122 + * @j_proc_entry: procfs entry for the jbd statistics directory
123 + * @j_stats: Overall statistics
124 * @j_private: An opaque pointer to fs-private information.
128 pid_t j_last_sync_writer;
131 + * Journal statistics
133 + struct transaction_stats_s *j_history;
136 + spinlock_t j_history_lock;
137 + struct proc_dir_entry *j_proc_entry;
138 + struct transaction_stats_s j_stats;
141 * An opaque pointer to fs-private information. ext3 puts its
142 * superblock pointer here
144 Index: linux-2.6.22-rc4/fs/jbd2/transaction.c
145 ===================================================================
146 --- linux-2.6.22-rc4.orig/fs/jbd2/transaction.c 2007-06-11 17:22:14.000000000 -0700
147 +++ linux-2.6.22-rc4/fs/jbd2/transaction.c 2007-06-13 10:47:56.000000000 -0700
150 J_ASSERT(journal->j_running_transaction == NULL);
151 journal->j_running_transaction = transaction;
152 + transaction->t_max_wait = 0;
153 + transaction->t_start = CURRENT_MSECS;
158 int nblocks = handle->h_buffer_credits;
159 transaction_t *new_transaction = NULL;
161 + unsigned long ts = CURRENT_MSECS;
163 if (nblocks > journal->j_max_transaction_buffers) {
164 printk(KERN_ERR "JBD: %s wants too many credits (%d > %d)\n",
166 /* OK, account for the buffers that this operation expects to
167 * use and add the handle to the running transaction. */
169 + if (time_after(transaction->t_start, ts)) {
170 + ts = jbd2_time_diff(ts, transaction->t_start);
171 + if (ts > transaction->t_max_wait)
172 + transaction->t_max_wait = ts;
175 handle->h_transaction = transaction;
176 transaction->t_outstanding_credits += nblocks;
177 transaction->t_updates++;
178 Index: linux-2.6.22-rc4/fs/jbd2/checkpoint.c
179 ===================================================================
180 --- linux-2.6.22-rc4.orig/fs/jbd2/checkpoint.c 2007-06-11 17:22:14.000000000 -0700
181 +++ linux-2.6.22-rc4/fs/jbd2/checkpoint.c 2007-06-13 10:48:44.000000000 -0700
183 * Called under jbd_lock_bh_state(jh2bh(jh)), and drops it
185 static int __process_buffer(journal_t *journal, struct journal_head *jh,
186 - struct buffer_head **bhs, int *batch_count)
187 + struct buffer_head **bhs, int *batch_count,
188 + transaction_t *transaction)
190 struct buffer_head *bh = jh2bh(jh);
193 transaction_t *t = jh->b_transaction;
194 tid_t tid = t->t_tid;
196 + transaction->t_chp_stats.cs_forced_to_close++;
197 spin_unlock(&journal->j_list_lock);
198 jbd_unlock_bh_state(bh);
199 jbd2_log_start_commit(journal, tid);
201 bhs[*batch_count] = bh;
202 __buffer_relink_io(jh);
203 jbd_unlock_bh_state(bh);
204 + transaction->t_chp_stats.cs_written++;
206 if (*batch_count == NR_BATCH) {
207 spin_unlock(&journal->j_list_lock);
209 if (!journal->j_checkpoint_transactions)
211 transaction = journal->j_checkpoint_transactions;
212 + if (transaction->t_chp_stats.cs_chp_time == 0)
213 + transaction->t_chp_stats.cs_chp_time = CURRENT_MSECS;
214 this_tid = transaction->t_tid;
221 - retry = __process_buffer(journal, jh, bhs,&batch_count);
222 + retry = __process_buffer(journal, jh, bhs, &batch_count,
224 if (!retry && lock_need_resched(&journal->j_list_lock)){
225 spin_unlock(&journal->j_list_lock);
229 void __jbd2_journal_drop_transaction(journal_t *journal, transaction_t *transaction)
231 + struct transaction_stats_s stats;
233 assert_spin_locked(&journal->j_list_lock);
234 if (transaction->t_cpnext) {
235 transaction->t_cpnext->t_cpprev = transaction->t_cpprev;
237 J_ASSERT(journal->j_running_transaction != transaction);
239 jbd_debug(1, "Dropping transaction %d, all done\n", transaction->t_tid);
242 + * File the transaction for history
244 + if (transaction->t_chp_stats.cs_written != 0 ||
245 + transaction->t_chp_stats.cs_chp_time != 0) {
246 + stats.ts_type = JBD2_STATS_CHECKPOINT;
247 + stats.ts_tid = transaction->t_tid;
248 + stats.u.chp = transaction->t_chp_stats;
249 + if (stats.ts_chp_time)
250 + stats.ts_chp_time =
251 + jbd2_time_diff(stats.ts_chp_time,
253 + spin_lock(&journal->j_history_lock);
254 + memcpy(journal->j_history + journal->j_history_cur, &stats,
256 + if (++journal->j_history_cur == journal->j_history_max)
257 + journal->j_history_cur = 0;
258 + spin_unlock(&journal->j_history_lock);
263 Index: linux-2.6.22-rc4/fs/jbd2/commit.c
264 ===================================================================
265 --- linux-2.6.22-rc4.orig/fs/jbd2/commit.c 2007-06-11 17:22:14.000000000 -0700
266 +++ linux-2.6.22-rc4/fs/jbd2/commit.c 2007-06-13 10:45:21.000000000 -0700
268 #include <linux/slab.h>
269 #include <linux/mm.h>
270 #include <linux/pagemap.h>
271 +#include <linux/jiffies.h>
274 * Default IO end handler for temporary BJ_IO buffer_heads.
277 void jbd2_journal_commit_transaction(journal_t *journal)
279 + struct transaction_stats_s stats;
280 transaction_t *commit_transaction;
281 struct journal_head *jh, *new_jh, *descriptor;
282 struct buffer_head **wbuf = journal->j_wbuf;
284 spin_lock(&journal->j_state_lock);
285 commit_transaction->t_state = T_LOCKED;
287 + stats.ts_wait = commit_transaction->t_max_wait;
288 + stats.ts_locked = CURRENT_MSECS;
289 + stats.ts_running = jbd2_time_diff(commit_transaction->t_start,
292 spin_lock(&commit_transaction->t_handle_lock);
293 while (commit_transaction->t_updates) {
297 jbd2_journal_switch_revoke_table(journal);
299 + stats.ts_flushing = CURRENT_MSECS;
300 + stats.ts_locked = jbd2_time_diff(stats.ts_locked, stats.ts_flushing);
302 commit_transaction->t_state = T_FLUSH;
303 journal->j_committing_transaction = commit_transaction;
304 journal->j_running_transaction = NULL;
307 commit_transaction->t_state = T_COMMIT;
309 + stats.ts_logging = CURRENT_MSECS;
310 + stats.ts_flushing = jbd2_time_diff(stats.ts_flushing, stats.ts_logging);
311 + stats.ts_blocks = commit_transaction->t_outstanding_credits;
312 + stats.ts_blocks_logged = 0;
316 while (commit_transaction->t_buffers) {
318 submit_bh(WRITE, bh);
321 + stats.ts_blocks_logged += bufs;
323 /* Force a new descriptor to be generated next
324 time round the loop. */
326 cp_transaction = jh->b_cp_transaction;
327 if (cp_transaction) {
328 JBUFFER_TRACE(jh, "remove from old cp transaction");
329 + cp_transaction->t_chp_stats.cs_dropped++;
330 __jbd2_journal_remove_checkpoint(jh);
335 J_ASSERT(commit_transaction->t_state == T_COMMIT);
337 + commit_transaction->t_start = CURRENT_MSECS;
338 + stats.ts_logging = jbd2_time_diff(stats.ts_logging,
339 + commit_transaction->t_start);
342 + * File the transaction for history
344 + stats.ts_type = JBD2_STATS_RUN;
345 + stats.ts_tid = commit_transaction->t_tid;
346 + stats.ts_handle_count = commit_transaction->t_handle_count;
347 + spin_lock(&journal->j_history_lock);
348 + memcpy(journal->j_history + journal->j_history_cur, &stats,
350 + if (++journal->j_history_cur == journal->j_history_max)
351 + journal->j_history_cur = 0;
354 + * Calculate overall stats
356 + journal->j_stats.ts_tid++;
357 + journal->j_stats.ts_wait += stats.ts_wait;
358 + journal->j_stats.ts_running += stats.ts_running;
359 + journal->j_stats.ts_locked += stats.ts_locked;
360 + journal->j_stats.ts_flushing += stats.ts_flushing;
361 + journal->j_stats.ts_logging += stats.ts_logging;
362 + journal->j_stats.ts_handle_count += stats.ts_handle_count;
363 + journal->j_stats.ts_blocks += stats.ts_blocks;
364 + journal->j_stats.ts_blocks_logged += stats.ts_blocks_logged;
365 + spin_unlock(&journal->j_history_lock);
367 commit_transaction->t_state = T_FINISHED;
368 J_ASSERT(commit_transaction == journal->j_committing_transaction);
369 journal->j_commit_sequence = commit_transaction->t_tid;
370 Index: linux-2.6.22-rc4/fs/jbd2/journal.c
371 ===================================================================
372 --- linux-2.6.22-rc4.orig/fs/jbd2/journal.c 2007-06-11 17:28:17.000000000 -0700
373 +++ linux-2.6.22-rc4/fs/jbd2/journal.c 2007-06-13 12:11:49.000000000 -0700
375 #include <linux/poison.h>
376 #include <linux/proc_fs.h>
377 #include <linux/debugfs.h>
378 +#include <linux/seq_file.h>
380 #include <asm/uaccess.h>
381 #include <asm/page.h>
382 @@ -641,6 +642,306 @@
383 return jbd2_journal_add_journal_head(bh);
386 +struct jbd2_stats_proc_session {
387 + journal_t *journal;
388 + struct transaction_stats_s *stats;
393 +static void *jbd2_history_skip_empty(struct jbd2_stats_proc_session *s,
394 + struct transaction_stats_s *ts,
397 + if (ts == s->stats + s->max)
399 + if (!first && ts == s->stats + s->start)
401 + while (ts->ts_type == 0) {
403 + if (ts == s->stats + s->max)
405 + if (ts == s->stats + s->start)
412 +static void *jbd2_seq_history_start(struct seq_file *seq, loff_t *pos)
414 + struct jbd2_stats_proc_session *s = seq->private;
415 + struct transaction_stats_s *ts;
419 + return SEQ_START_TOKEN;
420 + ts = jbd2_history_skip_empty(s, s->stats + s->start, 1);
425 + ts = jbd2_history_skip_empty(s, ++ts, 0);
433 +static void *jbd2_seq_history_next(struct seq_file *seq, void *v, loff_t *pos)
435 + struct jbd2_stats_proc_session *s = seq->private;
436 + struct transaction_stats_s *ts = v;
439 + if (v == SEQ_START_TOKEN)
440 + return jbd2_history_skip_empty(s, s->stats + s->start, 1);
442 + return jbd2_history_skip_empty(s, ++ts, 0);
445 +static int jbd2_seq_history_show(struct seq_file *seq, void *v)
447 + struct transaction_stats_s *ts = v;
448 + if (v == SEQ_START_TOKEN) {
449 + seq_printf(seq, "%-4s %-5s %-5s %-5s %-5s %-5s %-5s %-6s %-5s "
450 + "%-5s %-5s %-5s %-5s %-5s\n", "R/C", "tid",
451 + "wait", "run", "lock", "flush", "log", "hndls",
452 + "block", "inlog", "ctime", "write", "drop",
456 + if (ts->ts_type == JBD2_STATS_RUN)
457 + seq_printf(seq, "%-4s %-5lu %-5lu %-5lu %-5lu %-5lu %-5lu "
458 + "%-6lu %-5lu %-5lu\n", "R", ts->ts_tid,
459 + ts->ts_wait, ts->ts_running, ts->ts_locked,
460 + ts->ts_flushing, ts->ts_logging,
461 + ts->ts_handle_count, ts->ts_blocks,
462 + ts->ts_blocks_logged);
463 + else if (ts->ts_type == JBD2_STATS_CHECKPOINT)
464 + seq_printf(seq, "%-4s %-5lu %48s %-5lu %-5lu %-5lu %-5lu\n",
465 + "C", ts->ts_tid, " ", ts->ts_chp_time,
466 + ts->ts_written, ts->ts_dropped,
467 + ts->ts_forced_to_close);
473 +static void jbd2_seq_history_stop(struct seq_file *seq, void *v)
477 +static struct seq_operations jbd2_seq_history_ops = {
478 + .start = jbd2_seq_history_start,
479 + .next = jbd2_seq_history_next,
480 + .stop = jbd2_seq_history_stop,
481 + .show = jbd2_seq_history_show,
484 +static int jbd2_seq_history_open(struct inode *inode, struct file *file)
486 + journal_t *journal = PDE(inode)->data;
487 + struct jbd2_stats_proc_session *s;
490 + s = kmalloc(sizeof(*s), GFP_KERNEL);
493 + size = sizeof(struct transaction_stats_s) * journal->j_history_max;
494 + s->stats = kmalloc(size, GFP_KERNEL);
499 + spin_lock(&journal->j_history_lock);
500 + memcpy(s->stats, journal->j_history, size);
501 + s->max = journal->j_history_max;
502 + s->start = journal->j_history_cur % s->max;
503 + spin_unlock(&journal->j_history_lock);
505 + rc = seq_open(file, &jbd2_seq_history_ops);
507 + struct seq_file *m = (struct seq_file *)file->private_data;
517 +static int jbd2_seq_history_release(struct inode *inode, struct file *file)
519 + struct seq_file *seq = (struct seq_file *)file->private_data;
520 + struct jbd2_stats_proc_session *s = seq->private;
523 + return seq_release(inode, file);
526 +static struct file_operations jbd2_seq_history_fops = {
527 + .owner = THIS_MODULE,
528 + .open = jbd2_seq_history_open,
530 + .llseek = seq_lseek,
531 + .release = jbd2_seq_history_release,
534 +static void *jbd2_seq_info_start(struct seq_file *seq, loff_t *pos)
536 + return *pos ? NULL : SEQ_START_TOKEN;
539 +static void *jbd2_seq_info_next(struct seq_file *seq, void *v, loff_t *pos)
544 +static int jbd2_seq_info_show(struct seq_file *seq, void *v)
546 + struct jbd2_stats_proc_session *s = seq->private;
547 + if (v != SEQ_START_TOKEN)
549 + seq_printf(seq, "%lu transaction, each upto %u blocks\n",
551 + s->journal->j_max_transaction_buffers);
552 + if (s->stats->ts_tid == 0)
554 + seq_printf(seq, "average: \n %lums waiting for transaction\n",
555 + s->stats->ts_wait / s->stats->ts_tid);
556 + seq_printf(seq, " %lums running transaction\n",
557 + s->stats->ts_running / s->stats->ts_tid);
558 + seq_printf(seq, " %lums transaction was being locked\n",
559 + s->stats->ts_locked / s->stats->ts_tid);
560 + seq_printf(seq, " %lums flushing data (in ordered mode)\n",
561 + s->stats->ts_flushing / s->stats->ts_tid);
562 + seq_printf(seq, " %lums logging transaction\n",
563 + s->stats->ts_logging / s->stats->ts_tid);
564 + seq_printf(seq, " %lu handles per transaction\n",
565 + s->stats->ts_handle_count / s->stats->ts_tid);
566 + seq_printf(seq, " %lu blocks per transaction\n",
567 + s->stats->ts_blocks / s->stats->ts_tid);
568 + seq_printf(seq, " %lu logged blocks per transaction\n",
569 + s->stats->ts_blocks_logged / s->stats->ts_tid);
573 +static void jbd2_seq_info_stop(struct seq_file *seq, void *v)
577 +static struct seq_operations jbd2_seq_info_ops = {
578 + .start = jbd2_seq_info_start,
579 + .next = jbd2_seq_info_next,
580 + .stop = jbd2_seq_info_stop,
581 + .show = jbd2_seq_info_show,
584 +static int jbd2_seq_info_open(struct inode *inode, struct file *file)
586 + journal_t *journal = PDE(inode)->data;
587 + struct jbd2_stats_proc_session *s;
590 + s = kmalloc(sizeof(*s), GFP_KERNEL);
593 + size = sizeof(struct transaction_stats_s);
594 + s->stats = kmalloc(size, GFP_KERNEL);
599 + spin_lock(&journal->j_history_lock);
600 + memcpy(s->stats, &journal->j_stats, size);
601 + s->journal = journal;
602 + spin_unlock(&journal->j_history_lock);
604 + rc = seq_open(file, &jbd2_seq_info_ops);
606 + struct seq_file *m = (struct seq_file *)file->private_data;
616 +static int jbd2_seq_info_release(struct inode *inode, struct file *file)
618 + struct seq_file *seq = (struct seq_file *)file->private_data;
619 + struct jbd2_stats_proc_session *s = seq->private;
622 + return seq_release(inode, file);
625 +static struct file_operations jbd2_seq_info_fops = {
626 + .owner = THIS_MODULE,
627 + .open = jbd2_seq_info_open,
629 + .llseek = seq_lseek,
630 + .release = jbd2_seq_info_release,
633 +static struct proc_dir_entry *proc_jbd2_stats = NULL;
635 +static void jbd2_stats_proc_init(journal_t *journal)
639 + snprintf(name, sizeof(name) - 1, "%s", bdevname(journal->j_dev, name));
640 + journal->j_proc_entry = proc_mkdir(name, proc_jbd2_stats);
641 + if (journal->j_proc_entry) {
642 + struct proc_dir_entry *p;
643 + p = create_proc_entry("history", S_IRUGO,
644 + journal->j_proc_entry);
646 + p->proc_fops = &jbd2_seq_history_fops;
648 + p = create_proc_entry("info", S_IRUGO,
649 + journal->j_proc_entry);
651 + p->proc_fops = &jbd2_seq_info_fops;
658 +static void jbd2_stats_proc_exit(journal_t *journal)
662 + snprintf(name, sizeof(name) - 1, "%s", bdevname(journal->j_dev, name));
663 + remove_proc_entry("info", journal->j_proc_entry);
664 + remove_proc_entry("history", journal->j_proc_entry);
665 + remove_proc_entry(name, proc_jbd2_stats);
668 +static void journal_init_stats(journal_t *journal)
672 + if (proc_jbd2_stats == NULL)
675 + journal->j_history_max = 100;
676 + size = sizeof(struct transaction_stats_s) * journal->j_history_max;
677 + journal->j_history = kmalloc(size, GFP_KERNEL);
678 + if (journal->j_history == NULL) {
679 + journal->j_history_max = 0;
682 + memset(journal->j_history, 0, size);
683 + spin_lock_init(&journal->j_history_lock);
687 * Management for journal control blocks: functions to create and
688 * destroy journal_t structures, and to initialise and read existing
694 + journal_init_stats(journal);
703 + jbd2_stats_proc_init(journal);
704 journal->j_dev = bdev;
705 journal->j_fs_dev = fs_dev;
706 journal->j_blk_offset = start;
709 journal->j_maxlen = inode->i_size >> inode->i_sb->s_blocksize_bits;
710 journal->j_blocksize = inode->i_sb->s_blocksize;
711 + jbd2_stats_proc_init(journal);
713 /* journal descriptor can store up to n blocks -bzzz */
714 n = journal->j_blocksize / sizeof(journal_block_tag_t);
715 @@ -1162,6 +1468,8 @@
716 brelse(journal->j_sb_buffer);
719 + if (journal->j_proc_entry)
720 + jbd2_stats_proc_exit(journal);
721 if (journal->j_inode)
722 iput(journal->j_inode);
723 if (journal->j_revoke)
724 @@ -1989,6 +2297,28 @@
728 +#if defined(CONFIG_PROC_FS)
730 +#define JBD2_STATS_PROC_NAME "fs/jbd2"
732 +static void __init jbd2_create_jbd_stats_proc_entry(void)
734 + proc_jbd2_stats = proc_mkdir(JBD2_STATS_PROC_NAME, NULL);
737 +static void __exit jbd2_remove_jbd_stats_proc_entry(void)
739 + if (proc_jbd2_stats)
740 + remove_proc_entry(JBD2_STATS_PROC_NAME, NULL);
745 +#define jbd2_create_jbd_stats_proc_entry() do {} while (0)
746 +#define jbd2_remove_jbd_stats_proc_entry() do {} while (0)
750 struct kmem_cache *jbd2_handle_cache;
752 static int __init journal_init_handle_cache(void)
753 @@ -2046,6 +2376,7 @@
755 jbd2_journal_destroy_caches();
756 jbd2_create_debugfs_entry();
757 + jbd2_create_jbd_stats_proc_entry();
761 @@ -2057,6 +2388,7 @@
762 printk(KERN_EMERG "JBD: leaked %d journal_heads!\n", n);
764 jbd2_remove_debugfs_entry();
765 + jbd2_remove_jbd_stats_proc_entry();
766 jbd2_journal_destroy_caches();