1 Index: linux-2.6.16.46-0.14/include/linux/jbd.h
2 ===================================================================
3 --- linux-2.6.16.46-0.14.orig/include/linux/jbd.h
4 +++ linux-2.6.16.46-0.14/include/linux/jbd.h
5 @@ -422,6 +422,16 @@ struct handle_s
10 + * Some stats for checkpoint phase
12 +struct transaction_chp_stats_s {
13 + unsigned long cs_chp_time;
14 + unsigned long cs_forced_to_close;
15 + unsigned long cs_written;
16 + unsigned long cs_dropped;
19 /* The transaction_t type is the guts of the journaling mechanism. It
20 * tracks a compound transaction through its various states:
22 @@ -553,6 +563,21 @@ struct transaction_s
23 spinlock_t t_handle_lock;
26 + * Longest time some handle had to wait for running transaction
28 + unsigned long t_max_wait;
31 + * When transaction started
33 + unsigned long t_start;
36 + * Checkpointing stats [j_checkpoint_sem]
38 + struct transaction_chp_stats_s t_chp_stats;
41 * Number of outstanding updates running on this transaction
44 @@ -592,6 +617,57 @@ struct transaction_s
45 struct list_head t_jcb;
48 +struct transaction_run_stats_s {
49 + unsigned long rs_wait;
50 + unsigned long rs_running;
51 + unsigned long rs_locked;
52 + unsigned long rs_flushing;
53 + unsigned long rs_logging;
55 + unsigned long rs_handle_count;
56 + unsigned long rs_blocks;
57 + unsigned long rs_blocks_logged;
60 +struct transaction_stats_s
63 + unsigned long ts_tid;
65 + struct transaction_run_stats_s run;
66 + struct transaction_chp_stats_s chp;
70 +#define JBD_STATS_RUN 1
71 +#define JBD_STATS_CHECKPOINT 2
73 +#define ts_wait u.run.rs_wait
74 +#define ts_running u.run.rs_running
75 +#define ts_locked u.run.rs_locked
76 +#define ts_flushing u.run.rs_flushing
77 +#define ts_logging u.run.rs_logging
78 +#define ts_handle_count u.run.rs_handle_count
79 +#define ts_blocks u.run.rs_blocks
80 +#define ts_blocks_logged u.run.rs_blocks_logged
82 +#define ts_chp_time u.chp.cs_chp_time
83 +#define ts_forced_to_close u.chp.cs_forced_to_close
84 +#define ts_written u.chp.cs_written
85 +#define ts_dropped u.chp.cs_dropped
87 +#define CURRENT_MSECS (jiffies_to_msecs(jiffies))
89 +static inline unsigned int
90 +jbd_time_diff(unsigned int start, unsigned int end)
92 + if (unlikely(start > end))
93 + end = end + (~0UL - start);
100 * struct journal_s - The journal_s type is the concrete type associated with
102 @@ -845,6 +921,16 @@ struct journal_s
103 pid_t j_last_sync_writer;
108 + struct transaction_stats_s *j_history;
111 + spinlock_t j_history_lock;
112 + struct proc_dir_entry *j_proc_entry;
113 + struct transaction_stats_s j_stats;
116 * An opaque pointer to fs-private information. ext3 puts its
117 * superblock pointer here
119 Index: linux-2.6.16.46-0.14/fs/jbd/transaction.c
120 ===================================================================
121 --- linux-2.6.16.46-0.14.orig/fs/jbd/transaction.c
122 +++ linux-2.6.16.46-0.14/fs/jbd/transaction.c
123 @@ -60,6 +60,8 @@ get_transaction(journal_t *journal, tran
125 J_ASSERT(journal->j_running_transaction == NULL);
126 journal->j_running_transaction = transaction;
127 + transaction->t_max_wait = 0;
128 + transaction->t_start = CURRENT_MSECS;
132 @@ -86,6 +88,7 @@ static int start_this_handle(journal_t *
133 int nblocks = handle->h_buffer_credits;
134 transaction_t *new_transaction = NULL;
136 + unsigned long ts = CURRENT_MSECS;
138 if (nblocks > journal->j_max_transaction_buffers) {
139 printk(KERN_ERR "JBD: %s wants too many credits (%d > %d)\n",
140 @@ -219,6 +222,12 @@ repeat_locked:
141 /* OK, account for the buffers that this operation expects to
142 * use and add the handle to the running transaction. */
144 + if (time_after(transaction->t_start, ts)) {
145 + ts = jbd_time_diff(ts, transaction->t_start);
146 + if (ts > transaction->t_max_wait)
147 + transaction->t_max_wait= ts;
150 handle->h_transaction = transaction;
151 transaction->t_outstanding_credits += nblocks;
152 transaction->t_updates++;
153 Index: linux-2.6.16.46-0.14/fs/jbd/journal.c
154 ===================================================================
155 --- linux-2.6.16.46-0.14.orig/fs/jbd/journal.c
156 +++ linux-2.6.16.46-0.14/fs/jbd/journal.c
158 #include <asm/uaccess.h>
159 #include <asm/page.h>
160 #include <linux/proc_fs.h>
161 +#include <linux/seq_file.h>
163 EXPORT_SYMBOL(journal_start);
164 EXPORT_SYMBOL(journal_restart);
165 @@ -637,6 +638,300 @@ struct journal_head *journal_get_descrip
166 return journal_add_journal_head(bh);
169 +struct jbd_stats_proc_session {
170 + journal_t *journal;
171 + struct transaction_stats_s *stats;
176 +static void *jbd_history_skip_empty(struct jbd_stats_proc_session *s,
177 + struct transaction_stats_s *ts,
180 + if (ts == s->stats + s->max)
182 + if (!first && ts == s->stats + s->start)
184 + while (ts->ts_type == 0) {
186 + if (ts == s->stats + s->max)
188 + if (ts == s->stats + s->start)
195 +static void *jbd_seq_history_start(struct seq_file *seq, loff_t *pos)
197 + struct jbd_stats_proc_session *s = seq->private;
198 + struct transaction_stats_s *ts;
202 + return SEQ_START_TOKEN;
203 + ts = jbd_history_skip_empty(s, s->stats + s->start, 1);
206 + while (--l && (ts = jbd_history_skip_empty(s, ++ts, 0)) != NULL);
210 +static void *jbd_seq_history_next(struct seq_file *seq, void *v, loff_t *pos)
212 + struct jbd_stats_proc_session *s = seq->private;
213 + struct transaction_stats_s *ts = v;
216 + if (v == SEQ_START_TOKEN)
217 + return jbd_history_skip_empty(s, s->stats + s->start, 1);
219 + return jbd_history_skip_empty(s, ++ts, 0);
222 +static int jbd_seq_history_show(struct seq_file *seq, void *v)
224 + struct transaction_stats_s *ts = v;
225 + if (v == SEQ_START_TOKEN) {
226 + seq_printf(seq, "%-4s %-5s %-5s %-5s %-5s %-5s %-5s %-6s %-5s "
227 + "%-5s %-5s %-5s %-5s %-5s\n", "R/C", "tid",
228 + "wait", "run", "lock", "flush", "log", "hndls",
229 + "block", "inlog", "ctime", "write", "drop",
233 + if (ts->ts_type == JBD_STATS_RUN)
234 + seq_printf(seq, "%-4s %-5lu %-5lu %-5lu %-5lu %-5lu %-5lu "
235 + "%-6lu %-5lu %-5lu\n", "R", ts->ts_tid,
236 + ts->ts_wait, ts->ts_running, ts->ts_locked,
237 + ts->ts_flushing, ts->ts_logging,
238 + ts->ts_handle_count, ts->ts_blocks,
239 + ts->ts_blocks_logged);
240 + else if (ts->ts_type == JBD_STATS_CHECKPOINT)
241 + seq_printf(seq, "%-4s %-5lu %48s %-5lu %-5lu %-5lu %-5lu\n",
242 + "C", ts->ts_tid, " ", ts->ts_chp_time,
243 + ts->ts_written, ts->ts_dropped,
244 + ts->ts_forced_to_close);
250 +static void jbd_seq_history_stop(struct seq_file *seq, void *v)
254 +static struct seq_operations jbd_seq_history_ops = {
255 + .start = jbd_seq_history_start,
256 + .next = jbd_seq_history_next,
257 + .stop = jbd_seq_history_stop,
258 + .show = jbd_seq_history_show,
261 +static int jbd_seq_history_open(struct inode *inode, struct file *file)
263 + journal_t *journal = PDE(inode)->data;
264 + struct jbd_stats_proc_session *s;
267 + s = kmalloc(sizeof(*s), GFP_KERNEL);
270 + size = sizeof(struct transaction_stats_s) * journal->j_history_max;
271 + s->stats = kmalloc(size, GFP_KERNEL);
272 + if (s->stats == NULL) {
276 + spin_lock(&journal->j_history_lock);
277 + memcpy(s->stats, journal->j_history, size);
278 + s->max = journal->j_history_max;
279 + s->start = journal->j_history_cur % s->max;
280 + spin_unlock(&journal->j_history_lock);
282 + rc = seq_open(file, &jbd_seq_history_ops);
284 + struct seq_file *m = (struct seq_file *)file->private_data;
294 +static int jbd_seq_history_release(struct inode *inode, struct file *file)
296 + struct seq_file *seq = (struct seq_file *)file->private_data;
297 + struct jbd_stats_proc_session *s = seq->private;
300 + return seq_release(inode, file);
303 +static struct file_operations jbd_seq_history_fops = {
304 + .owner = THIS_MODULE,
305 + .open = jbd_seq_history_open,
307 + .llseek = seq_lseek,
308 + .release = jbd_seq_history_release,
311 +static void *jbd_seq_info_start(struct seq_file *seq, loff_t *pos)
313 + return *pos ? NULL : SEQ_START_TOKEN;
316 +static void *jbd_seq_info_next(struct seq_file *seq, void *v, loff_t *pos)
321 +static int jbd_seq_info_show(struct seq_file *seq, void *v)
323 + struct jbd_stats_proc_session *s = seq->private;
324 + if (v != SEQ_START_TOKEN)
326 + seq_printf(seq, "%lu transaction, each upto %u blocks\n",
328 + s->journal->j_max_transaction_buffers);
329 + if (s->stats->ts_tid == 0)
331 + seq_printf(seq, "average: \n %lums waiting for transaction\n",
332 + s->stats->ts_wait / s->stats->ts_tid);
333 + seq_printf(seq, " %lums running transaction\n",
334 + s->stats->ts_running / s->stats->ts_tid);
335 + seq_printf(seq, " %lums transaction was being locked\n",
336 + s->stats->ts_locked / s->stats->ts_tid);
337 + seq_printf(seq, " %lums flushing data (in ordered mode)\n",
338 + s->stats->ts_flushing / s->stats->ts_tid);
339 + seq_printf(seq, " %lums logging transaction\n",
340 + s->stats->ts_logging / s->stats->ts_tid);
341 + seq_printf(seq, " %lu handles per transaction\n",
342 + s->stats->ts_handle_count / s->stats->ts_tid);
343 + seq_printf(seq, " %lu blocks per transaction\n",
344 + s->stats->ts_blocks / s->stats->ts_tid);
345 + seq_printf(seq, " %lu logged blocks per transaction\n",
346 + s->stats->ts_blocks_logged / s->stats->ts_tid);
350 +static void jbd_seq_info_stop(struct seq_file *seq, void *v)
354 +static struct seq_operations jbd_seq_info_ops = {
355 + .start = jbd_seq_info_start,
356 + .next = jbd_seq_info_next,
357 + .stop = jbd_seq_info_stop,
358 + .show = jbd_seq_info_show,
361 +static int jbd_seq_info_open(struct inode *inode, struct file *file)
363 + journal_t *journal = PDE(inode)->data;
364 + struct jbd_stats_proc_session *s;
367 + s = kmalloc(sizeof(*s), GFP_KERNEL);
370 + size = sizeof(struct transaction_stats_s);
371 + s->stats = kmalloc(size, GFP_KERNEL);
372 + if (s->stats == NULL) {
376 + spin_lock(&journal->j_history_lock);
377 + memcpy(s->stats, &journal->j_stats, size);
378 + s->journal = journal;
379 + spin_unlock(&journal->j_history_lock);
381 + rc = seq_open(file, &jbd_seq_info_ops);
383 + struct seq_file *m = (struct seq_file *)file->private_data;
393 +static int jbd_seq_info_release(struct inode *inode, struct file *file)
395 + struct seq_file *seq = (struct seq_file *)file->private_data;
396 + struct jbd_stats_proc_session *s = seq->private;
399 + return seq_release(inode, file);
402 +static struct file_operations jbd_seq_info_fops = {
403 + .owner = THIS_MODULE,
404 + .open = jbd_seq_info_open,
406 + .llseek = seq_lseek,
407 + .release = jbd_seq_info_release,
410 +static struct proc_dir_entry *proc_jbd_stats = NULL;
412 +static void jbd_stats_proc_init(journal_t *journal)
416 + snprintf(name, sizeof(name) - 1, "%s", bdevname(journal->j_dev, name));
417 + journal->j_proc_entry = proc_mkdir(name, proc_jbd_stats);
418 + if (journal->j_proc_entry) {
419 + struct proc_dir_entry *p;
420 + p = create_proc_entry("history", S_IRUGO,
421 + journal->j_proc_entry);
423 + p->proc_fops = &jbd_seq_history_fops;
425 + p = create_proc_entry("info", S_IRUGO,
426 + journal->j_proc_entry);
428 + p->proc_fops = &jbd_seq_info_fops;
435 +static void jbd_stats_proc_exit(journal_t *journal)
439 + snprintf(name, sizeof(name) - 1, "%s", bdevname(journal->j_dev, name));
440 + remove_proc_entry("info", journal->j_proc_entry);
441 + remove_proc_entry("history", journal->j_proc_entry);
442 + remove_proc_entry(name, proc_jbd_stats);
445 +static void journal_init_stats(journal_t *journal)
449 + if (proc_jbd_stats == NULL)
452 + journal->j_history_max = 100;
453 + size = sizeof(struct transaction_stats_s) * journal->j_history_max;
454 + journal->j_history = kmalloc(size, GFP_KERNEL);
455 + if (journal->j_history == NULL) {
456 + journal->j_history_max = 0;
459 + memset(journal->j_history, 0, size);
460 + spin_lock_init(&journal->j_history_lock);
464 * Management for journal control blocks: functions to create and
465 * destroy journal_t structures, and to initialise and read existing
466 @@ -679,6 +974,9 @@ static journal_t * journal_init_common (
471 + journal_init_stats(journal);
476 @@ -722,6 +1020,7 @@ journal_t * journal_init_dev(struct bloc
477 journal->j_blk_offset = start;
478 journal->j_maxlen = len;
479 journal->j_blocksize = blocksize;
480 + jbd_stats_proc_init(journal);
482 bh = __getblk(journal->j_dev, start, journal->j_blocksize);
483 J_ASSERT(bh != NULL);
484 @@ -771,6 +1070,7 @@ journal_t * journal_init_inode (struct i
486 journal->j_maxlen = inode->i_size >> inode->i_sb->s_blocksize_bits;
487 journal->j_blocksize = inode->i_sb->s_blocksize;
488 + jbd_stats_proc_init(journal);
490 /* journal descriptor can store up to n blocks -bzzz */
491 n = journal->j_blocksize / sizeof(journal_block_tag_t);
492 @@ -1152,6 +1452,8 @@ void journal_destroy(journal_t *journal)
493 brelse(journal->j_sb_buffer);
496 + if (journal->j_proc_entry)
497 + jbd_stats_proc_exit(journal);
498 if (journal->j_inode)
499 iput(journal->j_inode);
500 if (journal->j_revoke)
501 @@ -1920,6 +2222,28 @@ static void __exit remove_jbd_proc_entry
505 +#if defined(CONFIG_PROC_FS)
507 +#define JBD_STATS_PROC_NAME "fs/jbd"
509 +static void __init create_jbd_stats_proc_entry(void)
511 + proc_jbd_stats = proc_mkdir(JBD_STATS_PROC_NAME, NULL);
514 +static void __exit remove_jbd_stats_proc_entry(void)
516 + if (proc_jbd_stats)
517 + remove_proc_entry(JBD_STATS_PROC_NAME, NULL);
522 +#define create_jbd_stats_proc_entry() do {} while (0)
523 +#define remove_jbd_stats_proc_entry() do {} while (0)
527 kmem_cache_t *jbd_handle_cache;
529 static int __init journal_init_handle_cache(void)
530 @@ -1982,6 +2306,7 @@ static int __init journal_init(void)
532 journal_destroy_caches();
533 create_jbd_proc_entry();
534 + create_jbd_stats_proc_entry();
538 @@ -1993,6 +2318,7 @@ static void __exit journal_exit(void)
539 printk(KERN_EMERG "JBD: leaked %d journal_heads!\n", n);
541 remove_jbd_proc_entry();
542 + remove_jbd_stats_proc_entry();
543 journal_destroy_caches();
546 Index: linux-2.6.16.46-0.14/fs/jbd/checkpoint.c
547 ===================================================================
548 --- linux-2.6.16.46-0.14.orig/fs/jbd/checkpoint.c
549 +++ linux-2.6.16.46-0.14/fs/jbd/checkpoint.c
550 @@ -166,6 +166,7 @@ static int __cleanup_transaction(journal
551 transaction_t *t = jh->b_transaction;
552 tid_t tid = t->t_tid;
554 + transaction->t_chp_stats.cs_forced_to_close++;
555 spin_unlock(&journal->j_list_lock);
556 jbd_unlock_bh_state(bh);
557 log_start_commit(journal, tid);
558 @@ -226,7 +227,7 @@ __flush_batch(journal_t *journal, struct
560 static int __flush_buffer(journal_t *journal, struct journal_head *jh,
561 struct buffer_head **bhs, int *batch_count,
563 + int *drop_count, transaction_t *transaction)
565 struct buffer_head *bh = jh2bh(jh);
567 @@ -247,6 +248,7 @@ static int __flush_buffer(journal_t *jou
568 set_buffer_jwrite(bh);
569 bhs[*batch_count] = bh;
570 jbd_unlock_bh_state(bh);
571 + transaction->t_chp_stats.cs_written++;
573 if (*batch_count == NR_BATCH) {
574 __flush_batch(journal, bhs, batch_count);
575 @@ -315,6 +317,8 @@ int log_do_checkpoint(journal_t *journal
578 transaction = journal->j_checkpoint_transactions;
579 + if (transaction->t_chp_stats.cs_chp_time == 0)
580 + transaction->t_chp_stats.cs_chp_time = CURRENT_MSECS;
581 this_tid = transaction->t_tid;
582 jh = transaction->t_checkpoint_list;
583 last_jh = jh->b_cpprev;
584 @@ -331,7 +335,8 @@ int log_do_checkpoint(journal_t *journal
588 - retry = __flush_buffer(journal, jh, bhs, &batch_count, &drop_count);
589 + retry = __flush_buffer(journal, jh, bhs, &batch_count,
590 + &drop_count, transaction);
591 if (cond_resched_lock(&journal->j_list_lock)) {
594 @@ -609,6 +614,8 @@ void __journal_insert_checkpoint(struct
596 void __journal_drop_transaction(journal_t *journal, transaction_t *transaction)
598 + struct transaction_stats_s stats;
600 assert_spin_locked(&journal->j_list_lock);
601 if (transaction->t_cpnext) {
602 transaction->t_cpnext->t_cpprev = transaction->t_cpprev;
603 @@ -634,5 +641,25 @@ void __journal_drop_transaction(journal_
604 J_ASSERT(journal->j_running_transaction != transaction);
606 jbd_debug(1, "Dropping transaction %d, all done\n", transaction->t_tid);
609 + * File the transaction for history
611 + if (transaction->t_chp_stats.cs_written != 0 ||
612 + transaction->t_chp_stats.cs_chp_time != 0) {
613 + stats.ts_type = JBD_STATS_CHECKPOINT;
614 + stats.ts_tid = transaction->t_tid;
615 + stats.u.chp = transaction->t_chp_stats;
616 + if (stats.ts_chp_time)
617 + stats.ts_chp_time =
618 + jbd_time_diff(stats.ts_chp_time, CURRENT_MSECS);
619 + spin_lock(&journal->j_history_lock);
620 + memcpy(journal->j_history + journal->j_history_cur, &stats,
622 + if (++journal->j_history_cur == journal->j_history_max)
623 + journal->j_history_cur = 0;
624 + spin_unlock(&journal->j_history_lock);
629 Index: linux-2.6.16.46-0.14/fs/jbd/commit.c
630 ===================================================================
631 --- linux-2.6.16.46-0.14.orig/fs/jbd/commit.c
632 +++ linux-2.6.16.46-0.14/fs/jbd/commit.c
634 #include <linux/mm.h>
635 #include <linux/pagemap.h>
636 #include <linux/smp_lock.h>
637 +#include <linux/jiffies.h>
640 * Default IO end handler for temporary BJ_IO buffer_heads.
641 @@ -168,6 +169,7 @@ static int journal_write_commit_record(j
643 void journal_commit_transaction(journal_t *journal)
645 + struct transaction_stats_s stats;
646 transaction_t *commit_transaction;
647 struct journal_head *jh, *new_jh, *descriptor;
648 struct buffer_head **wbuf = journal->j_wbuf;
649 @@ -214,6 +216,11 @@ void journal_commit_transaction(journal_
650 spin_lock(&journal->j_state_lock);
651 commit_transaction->t_state = T_LOCKED;
653 + stats.ts_wait = commit_transaction->t_max_wait;
654 + stats.ts_locked = CURRENT_MSECS;
655 + stats.ts_running = jbd_time_diff(commit_transaction->t_start,
658 spin_lock(&commit_transaction->t_handle_lock);
659 while (commit_transaction->t_updates) {
661 @@ -284,6 +291,9 @@ void journal_commit_transaction(journal_
663 journal_switch_revoke_table(journal);
665 + stats.ts_flushing = CURRENT_MSECS;
666 + stats.ts_locked = jbd_time_diff(stats.ts_locked, stats.ts_flushing);
668 commit_transaction->t_state = T_FLUSH;
669 journal->j_committing_transaction = commit_transaction;
670 journal->j_running_transaction = NULL;
671 @@ -442,6 +452,11 @@ write_out_data:
673 commit_transaction->t_state = T_COMMIT;
675 + stats.ts_logging = CURRENT_MSECS;
676 + stats.ts_flushing = jbd_time_diff(stats.ts_flushing, stats.ts_logging);
677 + stats.ts_blocks = commit_transaction->t_outstanding_credits;
678 + stats.ts_blocks_logged = 0;
682 while (commit_transaction->t_buffers) {
683 @@ -590,6 +605,7 @@ start_journal_io:
684 submit_bh(WRITE, bh);
687 + stats.ts_blocks_logged += bufs;
689 /* Force a new descriptor to be generated next
690 time round the loop. */
691 @@ -784,6 +800,7 @@ restart_loop:
692 cp_transaction = jh->b_cp_transaction;
693 if (cp_transaction) {
694 JBUFFER_TRACE(jh, "remove from old cp transaction");
695 + cp_transaction->t_chp_stats.cs_dropped++;
696 __journal_remove_checkpoint(jh);
699 @@ -858,6 +875,36 @@ restart_loop:
701 J_ASSERT(commit_transaction->t_state == T_COMMIT);
703 + commit_transaction->t_start = CURRENT_MSECS;
704 + stats.ts_logging = jbd_time_diff(stats.ts_logging,
705 + commit_transaction->t_start);
708 + * File the transaction for history
710 + stats.ts_type = JBD_STATS_RUN;
711 + stats.ts_tid = commit_transaction->t_tid;
712 + stats.ts_handle_count = commit_transaction->t_handle_count;
713 + spin_lock(&journal->j_history_lock);
714 + memcpy(journal->j_history + journal->j_history_cur, &stats,
716 + if (++journal->j_history_cur == journal->j_history_max)
717 + journal->j_history_cur = 0;
720 + * Calculate overall stats
722 + journal->j_stats.ts_tid++;
723 + journal->j_stats.ts_wait += stats.ts_wait;
724 + journal->j_stats.ts_running += stats.ts_running;
725 + journal->j_stats.ts_locked += stats.ts_locked;
726 + journal->j_stats.ts_flushing += stats.ts_flushing;
727 + journal->j_stats.ts_logging += stats.ts_logging;
728 + journal->j_stats.ts_handle_count += stats.ts_handle_count;
729 + journal->j_stats.ts_blocks += stats.ts_blocks;
730 + journal->j_stats.ts_blocks_logged += stats.ts_blocks_logged;
731 + spin_unlock(&journal->j_history_lock);
733 commit_transaction->t_state = T_FINISHED;
734 J_ASSERT(commit_transaction == journal->j_committing_transaction);
735 journal->j_commit_sequence = commit_transaction->t_tid;