bcachefs: trace transaction restarts

exceptionally crappy "tracing", but it's a start at documenting the
places restarts can be triggered

Signed-off-by: Kent Overstreet <kent.overstreet@gmail.com>

5 files changed, 54 insertions, 9 deletions

diff --git a/fs/bcachefs/btree_cache.c b/fs/bcachefs/btree_cache.c
index f15a415e37e3..db3712a83dc1 100644
--- a/fs/bcachefs/btree_cache.c
+++ b/fs/bcachefs/btree_cache.c
@@ -730,6 +730,7 @@ retry:
 			if (bch2_btree_node_relock(iter, level + 1))
 				goto retry;
 
+			trans_restart();
 			return ERR_PTR(-EINTR);
 		}
 	}
diff --git a/fs/bcachefs/btree_iter.c b/fs/bcachefs/btree_iter.c
index c34d93747ec6..a52ec12e9058 100644
--- a/fs/bcachefs/btree_iter.c
+++ b/fs/bcachefs/btree_iter.c
@@ -262,6 +262,9 @@ bool __bch2_btree_node_lock(struct btree *b, struct bpos pos,
 
 	if (ret)
 		__btree_node_lock_type(c, b, type);
+	else
+		trans_restart();
+
 	return ret;
 }
 
@@ -1655,7 +1658,12 @@ static int btree_trans_realloc_iters(struct btree_trans *trans)
 
 	btree_trans_verify(trans);
 
-	return trans->iters_live ? -EINTR : 0;
+	if (trans->iters_live) {
+		trans_restart();
+		return -EINTR;
+	}
+
+	return 0;
 }
 
 int bch2_trans_preload_iters(struct btree_trans *trans)
@@ -1768,8 +1776,10 @@ void *bch2_trans_kmalloc(struct btree_trans *trans,
 		trans->mem = new_mem;
 		trans->mem_bytes = new_bytes;
 
-		if (old_bytes)
+		if (old_bytes) {
+			trans_restart();
 			return ERR_PTR(-EINTR);
+		}
 	}
 
 	ret = trans->mem + trans->mem_top;
@@ -1796,7 +1806,7 @@ int bch2_trans_unlock(struct btree_trans *trans)
 	return ret;
 }
 
-void bch2_trans_begin(struct btree_trans *trans)
+void __bch2_trans_begin(struct btree_trans *trans)
 {
 	unsigned idx;
 
@@ -1810,10 +1820,8 @@ void bch2_trans_begin(struct btree_trans *trans)
 	 * further (allocated an iter with a higher idx) than where the iter
 	 * was originally allocated:
 	 */
-	if (!trans->iters_live)
-		return;
-
 	while (trans->iters_linked &&
+	       trans->iters_live &&
 	       (idx = __fls(trans->iters_linked)) >
 	       __fls(trans->iters_live)) {
 		trans->iters_linked ^= 1 << idx;
@@ -1830,6 +1838,7 @@ void bch2_trans_begin(struct btree_trans *trans)
 void bch2_trans_init(struct btree_trans *trans, struct bch_fs *c)
 {
 	trans->c		= c;
+	trans->nr_restarts	= 0;
 	trans->nr_iters		= 0;
 	trans->iters_live	= 0;
 	trans->iters_linked	= 0;
diff --git a/fs/bcachefs/btree_iter.h b/fs/bcachefs/btree_iter.h
index 02ec6d59a10e..d046ad71a7ba 100644
--- a/fs/bcachefs/btree_iter.h
+++ b/fs/bcachefs/btree_iter.h
@@ -306,10 +306,31 @@ bch2_trans_copy_iter(struct btree_trans *trans, struct btree_iter *src)
 	return __bch2_trans_copy_iter(trans, src, __btree_iter_id());
 }
 
+void __bch2_trans_begin(struct btree_trans *);
+
 void *bch2_trans_kmalloc(struct btree_trans *, size_t);
 int bch2_trans_unlock(struct btree_trans *);
-void bch2_trans_begin(struct btree_trans *);
 void bch2_trans_init(struct btree_trans *, struct bch_fs *);
 int bch2_trans_exit(struct btree_trans *);
 
+#ifdef TRACE_TRANSACTION_RESTARTS
+#define bch2_trans_begin(_trans)					\
+do {									\
+	if (is_power_of_2((_trans)->nr_restarts) &&			\
+	    (_trans)->nr_restarts >= 8)					\
+		pr_info("nr restarts: %zu", (_trans)->nr_restarts);	\
+									\
+	(_trans)->nr_restarts++;					\
+	__bch2_trans_begin(_trans);					\
+} while (0)
+#else
+#define bch2_trans_begin(_trans)	__bch2_trans_begin(_trans)
+#endif
+
+#ifdef TRACE_TRANSACTION_RESTARTS_ALL
+#define trans_restart(...) pr_info("transaction restart" __VA_ARGS__)
+#else
+#define trans_restart(...) no_printk("transaction restart" __VA_ARGS__)
+#endif
+
 #endif /* _BCACHEFS_BTREE_ITER_H */
diff --git a/fs/bcachefs/btree_types.h b/fs/bcachefs/btree_types.h
index ebe71de39705..39e2db757f9a 100644
--- a/fs/bcachefs/btree_types.h
+++ b/fs/bcachefs/btree_types.h
@@ -268,6 +268,7 @@ struct btree_insert_entry {
 
 struct btree_trans {
 	struct bch_fs		*c;
+	size_t			nr_restarts;
 
 	u8			nr_iters;
 	u8			iters_live;
diff --git a/fs/bcachefs/btree_update_leaf.c b/fs/bcachefs/btree_update_leaf.c
index 24d812ad4bfc..a481b0d632d9 100644
--- a/fs/bcachefs/btree_update_leaf.c
+++ b/fs/bcachefs/btree_update_leaf.c
@@ -332,6 +332,7 @@ static inline int do_btree_insert_at(struct btree_insert *trans,
 
 	if (race_fault()) {
 		ret = -EINTR;
+		trans_restart(" (race)");
 		goto out;
 	}
 
@@ -455,7 +456,12 @@ retry:
 	cycle_gc_lock = false;
 
 	trans_for_each_entry(trans, i) {
+		unsigned old_locks_want = i->iter->locks_want;
+		unsigned old_uptodate = i->iter->uptodate;
+
 		if (!bch2_btree_iter_upgrade(i->iter, 1, true)) {
+			trans_restart(" (failed upgrade, locks_want %u uptodate %u)",
+				      old_locks_want, old_uptodate);
 			ret = -EINTR;
 			goto err;
 		}
@@ -528,8 +534,10 @@ err:
 		 * don't care if we got ENOSPC because we told split it
 		 * couldn't block:
 		 */
-		if (!ret || (flags & BTREE_INSERT_NOUNLOCK))
+		if (!ret || (flags & BTREE_INSERT_NOUNLOCK)) {
+			trans_restart(" (split)");
 			ret = -EINTR;
+		}
 	}
 
 	if (cycle_gc_lock) {
@@ -544,13 +552,16 @@ err:
 	}
 
 	if (ret == -EINTR) {
-		if (flags & BTREE_INSERT_NOUNLOCK)
+		if (flags & BTREE_INSERT_NOUNLOCK) {
+			trans_restart(" (can't unlock)");
 			goto out;
+		}
 
 		trans_for_each_entry(trans, i) {
 			int ret2 = bch2_btree_iter_traverse(i->iter);
 			if (ret2) {
 				ret = ret2;
+				trans_restart(" (traverse)");
 				goto out;
 			}
 
@@ -563,6 +574,8 @@ err:
 		 */
 		if (!(flags & BTREE_INSERT_ATOMIC))
 			goto retry;
+
+		trans_restart(" (atomic)");
 	}
 
 	goto out;