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@linux.dev>

fs/bcachefs/btree_cache.c

@@ -732,6 +732,7 @@ struct btree *bch2_btree_node_get(struct bch_fs *c, struct btree_iter *iter,
 			if (bch2_btree_node_relock(iter, level + 1))
 				goto retry;
 
+			trans_restart();
 			return ERR_PTR(-EINTR);
 		}
 	}

fs/bcachefs/btree_iter.c

@@ -263,6 +263,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;
 }
 
@@ -1646,7 +1649,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)
@@ -1759,8 +1767,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;
@@ -1787,7 +1797,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;
 
@@ -1801,10 +1811,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;
@@ -1821,6 +1829,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;

fs/bcachefs/btree_iter.h

@@ -305,10 +305,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 */

fs/bcachefs/btree_types.h

@@ -269,6 +269,7 @@ struct btree_insert_entry {
 
 struct btree_trans {
 	struct bch_fs		*c;
+	size_t			nr_restarts;
 
 	u8			nr_iters;
 	u8			iters_live;

fs/bcachefs/btree_update_leaf.c

@@ -333,6 +333,7 @@ static inline int do_btree_insert_at(struct btree_insert *trans,
 
 	if (race_fault()) {
 		ret = -EINTR;
+		trans_restart(" (race)");
 		goto out;
 	}
 
@@ -456,7 +457,12 @@ int __bch2_btree_insert_at(struct btree_insert *trans)
 	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;
 		}
@@ -529,8 +535,10 @@ int __bch2_btree_insert_at(struct btree_insert *trans)
 		 * 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) {
@@ -545,13 +553,16 @@ int __bch2_btree_insert_at(struct btree_insert *trans)
 	}
 
 	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;
 			}
 
@@ -564,6 +575,8 @@ int __bch2_btree_insert_at(struct btree_insert *trans)
 		 */
 		if (!(flags & BTREE_INSERT_ATOMIC))
 			goto retry;
+
+		trans_restart(" (atomic)");
 	}
 
 	goto out;