bcachefs: track transaction durations

Signed-off-by: Kent Overstreet <kent.overstreet@linux.dev>

diff --git a/fs/bcachefs/bcachefs.h b/fs/bcachefs/bcachefs.h
index 53a2624176ab5fd9649101ed9da92b74e397fb30..840f605eff1f8dc693b17eacc1d7145224a843cf 100644 (file)
--- a/fs/bcachefs/bcachefs.h
+++ b/fs/bcachefs/bcachefs.h
@@ -647,6 +647,7 @@ struct btree_debug {
 #define BCH_TRANSACTIONS_NR 128
 
 struct btree_transaction_stats {
+       struct bch2_time_stats  duration;
        struct bch2_time_stats  lock_hold_times;
        struct mutex            lock;
        unsigned                nr_max_paths;

diff --git a/fs/bcachefs/btree_iter.c b/fs/bcachefs/btree_iter.c
index fa29f00e93507b00c8ae72fc18f7e0839290dbe7..7e5c797cfaf240e0258259cddae26bdb8bb3fcef 100644 (file)
--- a/fs/bcachefs/btree_iter.c
+++ b/fs/bcachefs/btree_iter.c
@@ -2894,9 +2894,15 @@ u32 bch2_trans_begin(struct btree_trans *trans)
        }
 
        now = local_clock();
+
+       if (!IS_ENABLED(CONFIG_BCACHEFS_NO_LATENCY_ACCT) &&
+           time_after64(now, trans->last_begin_time + 10))
+               __bch2_time_stats_update(&btree_trans_stats(trans)->duration,
+                                        trans->last_begin_time, now);
+
        if (!trans->restarted &&
            (need_resched() ||
-            now - trans->last_begin_time > BTREE_TRANS_MAX_LOCK_HOLD_TIME_NS)) {
+            time_after64(now, trans->last_begin_time + BTREE_TRANS_MAX_LOCK_HOLD_TIME_NS))) {
                drop_locks_do(trans, (cond_resched(), 0));
                now = local_clock();
        }
@@ -3232,6 +3238,7 @@ void bch2_fs_btree_iter_init_early(struct bch_fs *c)
        for (s = c->btree_transaction_stats;
             s < c->btree_transaction_stats + ARRAY_SIZE(c->btree_transaction_stats);
             s++) {
+               bch2_time_stats_init(&s->duration);
                bch2_time_stats_init(&s->lock_hold_times);
                mutex_init(&s->lock);
        }

diff --git a/fs/bcachefs/debug.c b/fs/bcachefs/debug.c
index c0b4d9057f29eacea1bd6574929f8d4ae4427e41..de5bfc0d46844166b3543b4bf3ee1a7a841bbc3a 100644 (file)
--- a/fs/bcachefs/debug.c
+++ b/fs/bcachefs/debug.c
@@ -693,7 +693,7 @@ static const struct file_operations journal_pins_ops = {
        .read           = bch2_journal_pins_read,
 };
 
-static int lock_held_stats_open(struct inode *inode, struct file *file)
+static int btree_transaction_stats_open(struct inode *inode, struct file *file)
 {
        struct bch_fs *c = inode->i_private;
        struct dump_iter *i;
@@ -703,7 +703,7 @@ static int lock_held_stats_open(struct inode *inode, struct file *file)
        if (!i)
                return -ENOMEM;
 
-       i->iter = 0;
+       i->iter = 1;
        i->c    = c;
        i->buf  = PRINTBUF;
        file->private_data = i;
@@ -711,7 +711,7 @@ static int lock_held_stats_open(struct inode *inode, struct file *file)
        return 0;
 }
 
-static int lock_held_stats_release(struct inode *inode, struct file *file)
+static int btree_transaction_stats_release(struct inode *inode, struct file *file)
 {
        struct dump_iter *i = file->private_data;
 
@@ -721,8 +721,8 @@ static int lock_held_stats_release(struct inode *inode, struct file *file)
        return 0;
 }
 
-static ssize_t lock_held_stats_read(struct file *file, char __user *buf,
-                                     size_t size, loff_t *ppos)
+static ssize_t btree_transaction_stats_read(struct file *file, char __user *buf,
+                                           size_t size, loff_t *ppos)
 {
        struct dump_iter        *i = file->private_data;
        struct bch_fs *c = i->c;
@@ -755,6 +755,13 @@ static ssize_t lock_held_stats_read(struct file *file, char __user *buf,
                prt_printf(&i->buf, "Max mem used: %u", s->max_mem);
                prt_newline(&i->buf);
 
+               prt_printf(&i->buf, "Transaction duration:");
+               prt_newline(&i->buf);
+
+               printbuf_indent_add(&i->buf, 2);
+               bch2_time_stats_to_text(&i->buf, &s->duration);
+               printbuf_indent_sub(&i->buf, 2);
+
                if (IS_ENABLED(CONFIG_BCACHEFS_LOCK_TIME_STATS)) {
                        prt_printf(&i->buf, "Lock hold times:");
                        prt_newline(&i->buf);
@@ -786,11 +793,11 @@ static ssize_t lock_held_stats_read(struct file *file, char __user *buf,
        return i->ret;
 }
 
-static const struct file_operations lock_held_stats_op = {
-       .owner = THIS_MODULE,
-       .open = lock_held_stats_open,
-       .release = lock_held_stats_release,
-       .read = lock_held_stats_read,
+static const struct file_operations btree_transaction_stats_op = {
+       .owner          = THIS_MODULE,
+       .open           = btree_transaction_stats_open,
+       .release        = btree_transaction_stats_release,
+       .read           = btree_transaction_stats_read,
 };
 
 static ssize_t bch2_btree_deadlock_read(struct file *file, char __user *buf,
@@ -882,7 +889,7 @@ void bch2_fs_debug_init(struct bch_fs *c)
                            c->btree_debug, &journal_pins_ops);
 
        debugfs_create_file("btree_transaction_stats", 0400, c->fs_debug_dir,
-                           c, &lock_held_stats_op);
+                           c, &btree_transaction_stats_op);
 
        debugfs_create_file("btree_deadlock", 0400, c->fs_debug_dir,
                            c->btree_debug, &btree_deadlock_ops);