bcachefs: bch2_fs_emergency_read_only2()

More error message cleanup: instead of multiple printk()s per error, we
want to be building up a single error message in a printbuf, so that it
can be printed with indenting that shows grouping and avoid errors
getting interspersed or lost in the log.

This gets rid of most calls to bch2_fs_emergency_read_only(). We still
have calls to
 - bch2_fatal_error()
 - bch2_fs_fatal_error()
 - bch2_fs_fatal_err_on()

that need work.

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

fs/bcachefs/btree_io.c

@@ -1766,23 +1766,31 @@ void bch2_btree_node_read(struct btree_trans *trans, struct btree *b,
 					 NULL, &pick, -1);
 
 	if (ret <= 0) {
+		bool ratelimit = true;
 		struct printbuf buf = PRINTBUF;
+		bch2_log_msg_start(c, &buf);
 
 		prt_str(&buf, "btree node read error: no device to read from\n at ");
 		bch2_btree_pos_to_text(&buf, c, b);
 		prt_newline(&buf);
 		bch2_btree_lost_data(c, &buf, b->c.btree_id);
-		bch_err_ratelimited(c, "%s", buf.buf);
 
 		if (c->opts.recovery_passes & BIT_ULL(BCH_RECOVERY_PASS_check_topology) &&
-		    c->curr_recovery_pass > BCH_RECOVERY_PASS_check_topology)
-			bch2_fatal_error(c);
+		    c->curr_recovery_pass > BCH_RECOVERY_PASS_check_topology &&
+		    bch2_fs_emergency_read_only2(c, &buf))
+			ratelimit = false;
+
+		static DEFINE_RATELIMIT_STATE(rs,
+					      DEFAULT_RATELIMIT_INTERVAL,
+					      DEFAULT_RATELIMIT_BURST);
+		if (!ratelimit || __ratelimit(&rs))
+			bch2_print_str(c, KERN_ERR, buf.buf);
+		printbuf_exit(&buf);
 
 		set_btree_node_read_error(b);
 		clear_btree_node_read_in_flight(b);
 		smp_mb__after_atomic();
 		wake_up_bit(&b->flags, BTREE_NODE_read_in_flight);
-		printbuf_exit(&buf);
 		return;
 	}
 

fs/bcachefs/btree_iter.c

@@ -16,6 +16,7 @@
 #include "journal_io.h"
 #include "replicas.h"
 #include "snapshot.h"
+#include "super.h"
 #include "trace.h"
 
 #include <linux/random.h>
@@ -3449,29 +3450,45 @@ struct btree_trans *__bch2_trans_get(struct bch_fs *c, unsigned fn_idx)
 	return trans;
 }
 
-static void check_btree_paths_leaked(struct btree_trans *trans)
-{
 #ifdef CONFIG_BCACHEFS_DEBUG
-	struct bch_fs *c = trans->c;
+
+static bool btree_paths_leaked(struct btree_trans *trans)
+{
 	struct btree_path *path;
 	unsigned i;
 
 	trans_for_each_path(trans, path, i)
 		if (path->ref)
-			goto leaked;
-	return;
-leaked:
-	bch_err(c, "btree paths leaked from %s!", trans->fn);
-	trans_for_each_path(trans, path, i)
-		if (path->ref)
-			printk(KERN_ERR "  btree %s %pS\n",
-			       bch2_btree_id_str(path->btree_id),
-			       (void *) path->ip_allocated);
-	/* Be noisy about this: */
-	bch2_fatal_error(c);
-#endif
+			return true;
+	return false;
 }
 
+static void check_btree_paths_leaked(struct btree_trans *trans)
+{
+	if (btree_paths_leaked(trans)) {
+		struct bch_fs *c = trans->c;
+		struct btree_path *path;
+		unsigned i;
+
+		struct printbuf buf = PRINTBUF;
+		bch2_log_msg_start(c, &buf);
+
+		prt_printf(&buf, "btree paths leaked from %s!\n", trans->fn);
+		trans_for_each_path(trans, path, i)
+			if (path->ref)
+				prt_printf(&buf, "btree %s %pS\n",
+					   bch2_btree_id_str(path->btree_id),
+					   (void *) path->ip_allocated);
+
+		bch2_fs_emergency_read_only2(c, &buf);
+		bch2_print_str(c, KERN_ERR, buf.buf);
+		printbuf_exit(&buf);
+	}
+}
+#else
+static inline void check_btree_paths_leaked(struct btree_trans *trans) {}
+#endif
+
 void bch2_trans_put(struct btree_trans *trans)
 	__releases(&c->btree_trans_barrier)
 {

fs/bcachefs/btree_update_interior.c

@@ -1813,10 +1813,10 @@ static int bch2_btree_insert_node(struct btree_update *as, struct btree_trans *t
 			   __func__, b->c.level);
 		bch2_btree_update_to_text(&buf, as);
 		bch2_btree_path_to_text(&buf, trans, path_idx);
+		bch2_fs_emergency_read_only2(c, &buf);
 
 		bch2_print_str(c, KERN_ERR, buf.buf);
 		printbuf_exit(&buf);
-		bch2_fs_emergency_read_only(c);
 		return -EIO;
 	}
 

fs/bcachefs/data_update.c

@@ -348,6 +348,7 @@ static int __bch2_data_update_index_update(struct btree_trans *trans,
 						 });
 		if (invalid) {
 			struct printbuf buf = PRINTBUF;
+			bch2_log_msg_start(c, &buf);
 
 			prt_str(&buf, "about to insert invalid key in data update path");
 			prt_printf(&buf, "\nop.nonce: %u", m->op.nonce);
@@ -358,10 +359,11 @@ static int __bch2_data_update_index_update(struct btree_trans *trans,
 			prt_str(&buf, "\nnew: ");
 			bch2_bkey_val_to_text(&buf, c, bkey_i_to_s_c(insert));
 
+			bch2_fs_emergency_read_only2(c, &buf);
+
 			bch2_print_str(c, KERN_ERR, buf.buf);
 			printbuf_exit(&buf);
 
-			bch2_fatal_error(c);
 			ret = -BCH_ERR_invalid_bkey;
 			goto out;
 		}

fs/bcachefs/error.c

@@ -11,12 +11,12 @@
 
 #define FSCK_ERR_RATELIMIT_NR	10
 
-void bch2_log_msg_start(struct bch_fs *c, struct printbuf *out)
+void __bch2_log_msg_start(const char *fs_or_dev_name, struct printbuf *out)
 {
 	printbuf_indent_add_nextline(out, 2);
 
 #ifdef BCACHEFS_LOG_PREFIX
-	prt_printf(out, bch2_log_msg(c, ""));
+	prt_printf(out, "bcachefs (%s): ", fs_or_dev_name);
 #endif
 }
 
@@ -29,9 +29,7 @@ bool __bch2_inconsistent_error(struct bch_fs *c, struct printbuf *out)
 		return false;
 	case BCH_ON_ERROR_fix_safe:
 	case BCH_ON_ERROR_ro:
-		if (bch2_fs_emergency_read_only(c))
-			prt_printf(out, "inconsistency detected - emergency read only at journal seq %llu\n",
-				   journal_cur_seq(&c->journal));
+		bch2_fs_emergency_read_only2(c, out);
 		return true;
 	case BCH_ON_ERROR_panic:
 		bch2_print_str(c, KERN_ERR, out->buf);
@@ -151,14 +149,17 @@ void bch2_io_error_work(struct work_struct *work)
 
 		bool dev = !__bch2_dev_set_state(c, ca, BCH_MEMBER_STATE_ro,
 						 BCH_FORCE_IF_DEGRADED);
+		struct printbuf buf = PRINTBUF;
+		__bch2_log_msg_start(ca->name, &buf);
 
-		bch_err(ca,
-			"writes erroring for %u seconds, setting %s ro",
+		prt_printf(&buf, "writes erroring for %u seconds, setting %s ro",
 			c->opts.write_error_timeout,
 			dev ? "device" : "filesystem");
 		if (!dev)
-			bch2_fs_emergency_read_only(c);
+			bch2_fs_emergency_read_only2(c, &buf);
 
+		bch2_print_str(c, KERN_ERR, buf.buf);
+		printbuf_exit(&buf);
 	}
 out:
 	up_write(&c->state_lock);

fs/bcachefs/error.h

@@ -18,7 +18,12 @@ struct work_struct;
 
 /* Error messages: */
 
-void bch2_log_msg_start(struct bch_fs *, struct printbuf *);
+void __bch2_log_msg_start(const char *, struct printbuf *);
+
+static inline void bch2_log_msg_start(struct bch_fs *c, struct printbuf *out)
+{
+	__bch2_log_msg_start(c->name, out);
+}
 
 /*
  * Inconsistency errors: The on disk data is inconsistent. If these occur during

fs/bcachefs/fs-ioctl.c

@@ -172,7 +172,10 @@ static int bch2_ioc_goingdown(struct bch_fs *c, u32 __user *arg)
 	if (get_user(flags, arg))
 		return -EFAULT;
 
-	bch_notice(c, "shutdown by ioctl type %u", flags);
+	struct printbuf buf = PRINTBUF;
+	bch2_log_msg_start(c, &buf);
+
+	prt_printf(&buf, "shutdown by ioctl type %u", flags);
 
 	switch (flags) {
 	case FSOP_GOING_FLAGS_DEFAULT:
@@ -180,20 +183,23 @@ static int bch2_ioc_goingdown(struct bch_fs *c, u32 __user *arg)
 		if (ret)
 			break;
 		bch2_journal_flush(&c->journal);
-		bch2_fs_emergency_read_only(c);
+		bch2_fs_emergency_read_only2(c, &buf);
 		bdev_thaw(c->vfs_sb->s_bdev);
 		break;
 	case FSOP_GOING_FLAGS_LOGFLUSH:
 		bch2_journal_flush(&c->journal);
 		fallthrough;
 	case FSOP_GOING_FLAGS_NOLOGFLUSH:
-		bch2_fs_emergency_read_only(c);
+		bch2_fs_emergency_read_only2(c, &buf);
 		break;
 	default:
 		ret = -EINVAL;
-		break;
+		goto noprint;
 	}
 
+	bch2_print_str(c, KERN_ERR, buf.buf);
+noprint:
+	printbuf_exit(&buf);
 	return ret;
 }
 

fs/bcachefs/journal_io.c

@@ -1628,8 +1628,6 @@ static CLOSURE_CALLBACK(journal_write_done)
 			       : j->noflush_write_time, j->write_start_time);
 
 	if (!w->devs_written.nr) {
-		if (!bch2_journal_error(j))
-			bch_err(c, "unable to write journal to sufficient devices");
 		err = -BCH_ERR_journal_write_err;
 	} else {
 		bch2_devlist_to_replicas(&replicas.e, BCH_DATA_journal,
@@ -1637,8 +1635,20 @@ static CLOSURE_CALLBACK(journal_write_done)
 		err = bch2_mark_replicas(c, &replicas.e);
 	}
 
-	if (err)
-		bch2_fatal_error(c);
+	if (err && !bch2_journal_error(j)) {
+		struct printbuf buf = PRINTBUF;
+		bch2_log_msg_start(c, &buf);
+
+		if (err == -BCH_ERR_journal_write_err)
+			prt_printf(&buf, "unable to write journal to sufficient devices");
+		else
+			prt_printf(&buf, "journal write error marking replicas: %s", bch2_err_str(err));
+
+		bch2_fs_emergency_read_only2(c, &buf);
+
+		bch2_print_str(c, KERN_ERR, buf.buf);
+		printbuf_exit(&buf);
+	}
 
 	closure_debug_destroy(cl);
 

fs/bcachefs/recovery.c

@@ -1108,8 +1108,17 @@ int bch2_fs_recovery(struct bch_fs *c)
 	return ret;
 err:
 fsck_err:
-	bch2_fs_emergency_read_only(c);
-	goto out;
+	{
+		struct printbuf buf = PRINTBUF;
+		bch2_log_msg_start(c, &buf);
+
+		prt_printf(&buf, "error in recovery: %s", bch2_err_str(ret));
+		bch2_fs_emergency_read_only2(c, &buf);
+
+		bch2_print_str(c, KERN_ERR, buf.buf);
+		printbuf_exit(&buf);
+	}
+	return ret;
 }
 
 int bch2_fs_initialize(struct bch_fs *c)

fs/bcachefs/super.c

@@ -438,6 +438,30 @@ bool bch2_fs_emergency_read_only(struct bch_fs *c)
 	return ret;
 }
 
+static bool __bch2_fs_emergency_read_only2(struct bch_fs *c, struct printbuf *out,
+					   bool locked)
+{
+	bool ret = !test_and_set_bit(BCH_FS_emergency_ro, &c->flags);
+
+	if (!locked)
+		bch2_journal_halt(&c->journal);
+	else
+		bch2_journal_halt_locked(&c->journal);
+	bch2_fs_read_only_async(c);
+	wake_up(&bch2_read_only_wait);
+
+	if (ret)
+		prt_printf(out, "emergency read only at seq %llu\n",
+			   journal_cur_seq(&c->journal));
+
+	return ret;
+}
+
+bool bch2_fs_emergency_read_only2(struct bch_fs *c, struct printbuf *out)
+{
+	return __bch2_fs_emergency_read_only2(c, out, false);
+}
+
 bool bch2_fs_emergency_read_only_locked(struct bch_fs *c)
 {
 	bool ret = !test_and_set_bit(BCH_FS_emergency_ro, &c->flags);
@@ -2252,20 +2276,32 @@ static void bch2_fs_bdev_mark_dead(struct block_device *bdev, bool surprise)
 	if (!ca)
 		goto unlock;
 
-	if (bch2_dev_state_allowed(c, ca, BCH_MEMBER_STATE_failed, BCH_FORCE_IF_DEGRADED)) {
+	bool dev = bch2_dev_state_allowed(c, ca,
+					  BCH_MEMBER_STATE_failed,
+					  BCH_FORCE_IF_DEGRADED);
+
+	if (!dev && sb) {
+		if (!surprise)
+			sync_filesystem(sb);
+		shrink_dcache_sb(sb);
+		evict_inodes(sb);
+	}
+
+	struct printbuf buf = PRINTBUF;
+	__bch2_log_msg_start(ca->name, &buf);
+
+	prt_printf(&buf, "offline from block layer");
+
+	if (dev) {
 		__bch2_dev_offline(c, ca);
 	} else {
-		if (sb) {
-			if (!surprise)
-				sync_filesystem(sb);
-			shrink_dcache_sb(sb);
-			evict_inodes(sb);
-		}
-
 		bch2_journal_flush(&c->journal);
-		bch2_fs_emergency_read_only(c);
+		bch2_fs_emergency_read_only2(c, &buf);
 	}
 
+	bch2_print_str(c, KERN_ERR, buf.buf);
+	printbuf_exit(&buf);
+
 	bch2_dev_put(ca);
 unlock:
 	if (sb)

fs/bcachefs/super.h

@@ -32,6 +32,8 @@ int bch2_dev_resize(struct bch_fs *, struct bch_dev *, u64);
 struct bch_dev *bch2_dev_lookup(struct bch_fs *, const char *);
 
 bool bch2_fs_emergency_read_only(struct bch_fs *);
+bool bch2_fs_emergency_read_only2(struct bch_fs *, struct printbuf *);
+
 bool bch2_fs_emergency_read_only_locked(struct bch_fs *);
 void bch2_fs_read_only(struct bch_fs *);