[PATCH 0/5] bcachefs: journal stall fixes

[PATCH 0/5] bcachefs: journal stall fixes

[Brian Foster]

Hi Kent,

Here's a few patches related to the journal stall issue with
generic/333. Patch 1 is the prospective fix, patches 2-4 make some
smallish cleanups to the stuck checking, and patch 5 is just an RFC for
the idea I mentioned previously wrt using a timeout. It has some issues
described in the commit log, so I'm just including it here for reference
and discussion in the event it leads to any more interesting ideas. I
think the path it's currently leading down is probably a bit of overkill
for the time being.

I've pushed patches 1-4 to the CI this morning, so we'll see how that
goes. One thing that annoys me a bit about patch 1 is that the seq
zapping presumably puts all of the processed keys at the start of the
sorted list in the write buffer flush slowpath, which then means the
loop starts by walking through those already processed keys.

I was thinking about possibly using a sentinel seq value (i.e.
UINT64_MAX or some such) to land those keys at the end of the list, but
it wasn't clear to me if such a value exists or the entire u64 space are
valid seq numbers. Another idea is to count the total number of
processed && skipped keys in the fast path and just start at that index
in the slow path, but also wasn't necessarily convinced if this is
likely enough to be worth the extra code.

Anyways.. thoughts, reviews, flames appreciated.

Brian

Brian Foster (5):
  bcachefs: more aggressive fast path write buffer key flushing
  bcachefs: gracefully unwind journal res slowpath on shutdown
  bcachefs: refactor journal stuck checking into standalone helper
  bcachefs: drop unnecessary journal stuck check from space calculation
  RFC: bcachefs: use a timeout for the journal stuck condition

 fs/bcachefs/btree_write_buffer.c | 41 +++++++-------
 fs/bcachefs/journal.c            | 95 ++++++++++++++++++++++++--------
 fs/bcachefs/journal_reclaim.c    | 19 +------
 3 files changed, 95 insertions(+), 60 deletions(-)

-- 
2.39.2

[PATCH 1/5] bcachefs: more aggressive fast path write buffer key flushing

[Brian Foster]

The btree write buffer flush code is prone to causing journal
deadlock due to inefficient use and release of reservation space.
Reservation is not pre-reserved for write buffered keys (as is done
for key cache keys, for example), because the write buffer flush
side uses a fast path that attempts insertion without need for any
reservation at all.

The write buffer flush attempts to deal with this by inserting keys
using the BTREE_INSERT_JOURNAL_RECLAIM flag to return an error on
journal reservations that require blocking. Upon first error, it
falls back to a slow path that inserts in journal order and supports
moving the associated journal pin forward.

The problem is that under pathological conditions (i.e. smaller log,
larger write buffer and journal reservation pressure), we've seen
instances where the fast path fails fairly quickly without having
completed many insertions, and then the slow path is unable to push
the journal pin forward enough to free up the space it needs to
completely flush the buffer. This problem is occasionally reproduced
by fstest generic/333.

To avoid this problem, update the fast path algorithm to skip key
inserts that fail due to inability to acquire needed journal
reservation without immediately breaking out of the loop. Instead,
insert as many keys as possible, zap the sequence numbers to mark
them as processed, and then fall back to the slow path to process
the remaining set in journal order. This reduces the amount of
journal reservation that might be required to flush the entire
buffer and increases the odds that the slow path is able to move the
journal pin forward and free up space as keys are processed.

Signed-off-by: Brian Foster <bfoster@redhat.com>
---
 fs/bcachefs/btree_write_buffer.c | 41 ++++++++++++++++----------------
 1 file changed, 21 insertions(+), 20 deletions(-)

diff --git a/fs/bcachefs/btree_write_buffer.c b/fs/bcachefs/btree_write_buffer.c
index 80f4b9839bc2..32f20e631de0 100644
--- a/fs/bcachefs/btree_write_buffer.c
+++ b/fs/bcachefs/btree_write_buffer.c
@@ -111,7 +111,7 @@ int __bch2_btree_write_buffer_flush(struct btree_trans *trans, unsigned commit_f
 	struct journal_entry_pin pin;
 	struct btree_write_buffered_key *i, *dst, *keys;
 	struct btree_iter iter = { NULL };
-	size_t nr = 0, skipped = 0, fast = 0;
+	size_t nr = 0, skipped = 0, fast = 0, slowpath = 0;
 	bool write_locked = false;
 	union btree_write_buffer_state s;
 	int ret = 0;
@@ -135,15 +135,13 @@ int __bch2_btree_write_buffer_flush(struct btree_trans *trans, unsigned commit_f
 	 *
 	 * However, since we're not flushing in the order they appear in the
 	 * journal we won't be able to drop our journal pin until everything is
-	 * flushed - which means this could deadlock the journal, if we weren't
-	 * passing BTREE_INSERT_JORUNAL_RECLAIM. This causes the update to fail
+	 * flushed - which means this could deadlock the journal if we weren't
+	 * passing BTREE_INSERT_JOURNAL_RECLAIM. This causes the update to fail
 	 * if it would block taking a journal reservation.
 	 *
-	 * If that happens, we sort them by the order they appeared in the
-	 * journal - after dropping redundant entries - and then restart
-	 * flushing, this time dropping journal pins as we go.
+	 * If that happens, simply skip the key so we can optimistically insert
+	 * as many keys as possible in the fast path.
 	 */
-
 	sort(keys, nr, sizeof(keys[0]),
 	     btree_write_buffered_key_cmp, NULL);
 
@@ -152,6 +150,7 @@ int __bch2_btree_write_buffer_flush(struct btree_trans *trans, unsigned commit_f
 		    i[0].btree == i[1].btree &&
 		    bpos_eq(i[0].k.k.p, i[1].k.k.p)) {
 			skipped++;
+			i->journal_seq = 0;
 			continue;
 		}
 
@@ -177,8 +176,14 @@ int __bch2_btree_write_buffer_flush(struct btree_trans *trans, unsigned commit_f
 				bch2_trans_begin(trans);
 		} while (bch2_err_matches(ret, BCH_ERR_transaction_restart));
 
+		if (ret == -BCH_ERR_journal_reclaim_would_deadlock) {
+			slowpath++;
+			continue;
+		}
 		if (ret)
 			break;
+
+		i->journal_seq = 0;
 	}
 
 	if (write_locked)
@@ -187,7 +192,7 @@ int __bch2_btree_write_buffer_flush(struct btree_trans *trans, unsigned commit_f
 
 	trace_write_buffer_flush(trans, nr, skipped, fast, wb->size);
 
-	if (ret == -BCH_ERR_journal_reclaim_would_deadlock)
+	if (slowpath)
 		goto slowpath;
 
 	bch2_fs_fatal_err_on(ret, c, "%s: insert error %s", __func__, bch2_err_str(ret));
@@ -198,23 +203,19 @@ int __bch2_btree_write_buffer_flush(struct btree_trans *trans, unsigned commit_f
 slowpath:
 	trace_write_buffer_flush_slowpath(trans, i - keys, nr);
 
-	dst = keys;
-	for (; i < keys + nr; i++) {
-		if (i + 1 < keys + nr &&
-		    i[0].btree == i[1].btree &&
-		    bpos_eq(i[0].k.k.p, i[1].k.k.p))
-			continue;
-
-		*dst = *i;
-		dst++;
-	}
-	nr = dst - keys;
-
+	/*
+	 * Now sort the rest by journal seq and bump the journal pin as we go.
+	 * The slowpath zapped the seq of keys that were successfully flushed so
+	 * we can skip those here.
+	 */
 	sort(keys, nr, sizeof(keys[0]),
 	     btree_write_buffered_journal_cmp,
 	     NULL);
 
 	for (i = keys; i < keys + nr; i++) {
+		if (!i->journal_seq)
+			continue;
+
 		if (i->journal_seq > pin.seq) {
 			struct journal_entry_pin pin2;
 
-- 
2.39.2

[PATCH 2/5] bcachefs: gracefully unwind journal res slowpath on shutdown

[Brian Foster]

bcachefs detects journal stuck conditions in a couple different
places. If the logic in the journal reservation slow path happens to
detect the problem, I've seen instances where the filesystem remains
deadlocked even though it has been shut down. This is occasionally
reproduced by generic/333, and usually manifests as one or more
tasks stuck in the journal reservation slow path.

To help avoid this problem, repeat the journal error check in
__journal_res_get() once under spinlock to cover the case where the
previous lock holder might have triggered shutdown. This also helps
avoid spurious/duplicate stuck reports. Also, wake the journal from
the halt code to make sure blocked callers of the journal res
slowpath have a chance to wake up and observe the pending error.
This survives an overnight looping run of generic/333 without the
aforementioned lockups.

Signed-off-by: Brian Foster <bfoster@redhat.com>
---
 fs/bcachefs/journal.c | 7 +++++++
 1 file changed, 7 insertions(+)

diff --git a/fs/bcachefs/journal.c b/fs/bcachefs/journal.c
index c9c2ee9c67f6..f521f733e180 100644
--- a/fs/bcachefs/journal.c
+++ b/fs/bcachefs/journal.c
@@ -163,6 +163,7 @@ void bch2_journal_halt(struct journal *j)
 	__journal_entry_close(j, JOURNAL_ENTRY_ERROR_VAL);
 	if (!j->err_seq)
 		j->err_seq = journal_cur_seq(j);
+	journal_wake(j);
 	spin_unlock(&j->lock);
 }
 
@@ -363,6 +364,12 @@ static int __journal_res_get(struct journal *j, struct journal_res *res,
 
 	spin_lock(&j->lock);
 
+	/* check once more in case somebody else shut things down... */
+	if (bch2_journal_error(j)) {
+		spin_unlock(&j->lock);
+		return -BCH_ERR_erofs_journal_err;
+	}
+
 	/*
 	 * Recheck after taking the lock, so we don't race with another thread
 	 * that just did journal_entry_open() and call journal_entry_close()
-- 
2.39.2

[PATCH 3/5] bcachefs: refactor journal stuck checking into standalone helper

[Brian Foster]

bcachefs checks for journal stuck conditions both in the journal
space calculation code and the journal reservation slow path. The
logic in both places is rather tricky and can result in
non-deterministic failure characteristics and debug output.

In preparation to condense journal stuck handling to a single place,
refactor the __journal_res_get() logic into a standalone helper.
Since multiple callers into the reservation code can result in
duplicate reports, use the ->err_seq field as a serialization
mechanism for the debug dump. Finally, add some comments to help
explain the logic and hopefully facilitate further improvements in
the future.

Signed-off-by: Brian Foster <bfoster@redhat.com>
---
 fs/bcachefs/journal.c | 85 ++++++++++++++++++++++++++++++++-----------
 1 file changed, 63 insertions(+), 22 deletions(-)

diff --git a/fs/bcachefs/journal.c b/fs/bcachefs/journal.c
index f521f733e180..3f0e6d71aa32 100644
--- a/fs/bcachefs/journal.c
+++ b/fs/bcachefs/journal.c
@@ -76,6 +76,67 @@ static void journal_pin_list_init(struct journal_entry_pin_list *p, int count)
 	p->devs.nr = 0;
 }
 
+/*
+ * Detect stuck journal conditions and trigger shutdown. Technically the journal
+ * can end up stuck for a variety of reasons, such as a blocked I/O, journal
+ * reservation lockup, etc. Since this is a fatal error with potentially
+ * unpredictable characteristics, we want to be fairly conservative before we
+ * decide to shut things down.
+ *
+ * Consider the journal stuck when it appears full with no ability to commit
+ * btree transactions, to discard journal buckets, nor acquire priority
+ * (reserved watermark) reservation.
+ */
+static inline bool
+journal_error_check_stuck(struct journal *j, int error, unsigned flags)
+{
+	struct bch_fs *c = container_of(j, struct bch_fs, journal);
+	bool stuck = false;
+	struct printbuf buf = PRINTBUF;
+
+	if (!(error == JOURNAL_ERR_journal_full ||
+	      error == JOURNAL_ERR_journal_pin_full) ||
+	    nr_unwritten_journal_entries(j) ||
+	    (flags & JOURNAL_WATERMARK_MASK) != JOURNAL_WATERMARK_reserved)
+		return stuck;
+
+	spin_lock(&j->lock);
+
+	if (j->can_discard) {
+		spin_unlock(&j->lock);
+		return stuck;
+	}
+
+	stuck = true;
+
+	/*
+	 * The journal shutdown path will set ->err_seq, but do it here first to
+	 * serialize against concurrent failures and avoid duplicate error
+	 * reports.
+	 */
+	if (j->err_seq) {
+		spin_unlock(&j->lock);
+		return stuck;
+	}
+	j->err_seq = journal_cur_seq(j);
+	spin_unlock(&j->lock);
+
+	bch_err(c, "Journal stuck! Hava a pre-reservation but journal full (error %s)",
+		bch2_journal_errors[error]);
+	bch2_journal_debug_to_text(&buf, j);
+	bch_err(c, "%s", buf.buf);
+
+	printbuf_reset(&buf);
+	bch2_journal_pins_to_text(&buf, j);
+	bch_err(c, "Journal pins:\n%s", buf.buf);
+	printbuf_exit(&buf);
+
+	bch2_fatal_error(c);
+	dump_stack();
+
+	return stuck;
+}
+
 /* journal entry close/open: */
 
 void __bch2_journal_buf_put(struct journal *j)
@@ -417,28 +478,8 @@ static int __journal_res_get(struct journal *j, struct journal_res *res,
 
 	if (!ret)
 		goto retry;
-
-	if ((ret == JOURNAL_ERR_journal_full ||
-	     ret == JOURNAL_ERR_journal_pin_full) &&
-	    !can_discard &&
-	    !nr_unwritten_journal_entries(j) &&
-	    (flags & JOURNAL_WATERMARK_MASK) == JOURNAL_WATERMARK_reserved) {
-		struct printbuf buf = PRINTBUF;
-
-		bch_err(c, "Journal stuck! Hava a pre-reservation but journal full (ret %s)",
-			bch2_journal_errors[ret]);
-
-		bch2_journal_debug_to_text(&buf, j);
-		bch_err(c, "%s", buf.buf);
-
-		printbuf_reset(&buf);
-		bch2_journal_pins_to_text(&buf, j);
-		bch_err(c, "Journal pins:\n%s", buf.buf);
-
-		printbuf_exit(&buf);
-		bch2_fatal_error(c);
-		dump_stack();
-	}
+	if (journal_error_check_stuck(j, ret, flags))
+		ret = -BCH_ERR_journal_res_get_blocked;
 
 	/*
 	 * Journal is full - can't rely on reclaim from work item due to
-- 
2.39.2

[PATCH 4/5] bcachefs: drop unnecessary journal stuck check from space calculation

[Brian Foster]

The journal stucking check in bch2_journal_space_available() is
particularly aggressive and can lead to premature shutdown in some
rare cases. This is difficult to reproduce, but also comes along
with a fatal error and so is worthwhile to be cautious.

For example, we've seen instances where the journal is under heavy
reservation pressure, the journal allocation path transitions into
the final available journal bucket, the journal write path
immediately consumes that bucket and calls into
bch2_journal_space_available(), which then in turn flags the journal
as stuck because there is no available space and shuts down the
filesystem instead of submitting the journal write (that would have
otherwise succeeded).

To avoid this problem, simplify the journal stuck checking by just
relying on the higher level logic in the journal reservation path.
This produces more useful debug output and is a more reliable
indicator that things have bogged down.

Signed-off-by: Brian Foster <bfoster@redhat.com>
---
 fs/bcachefs/journal_reclaim.c | 19 +------------------
 1 file changed, 1 insertion(+), 18 deletions(-)

diff --git a/fs/bcachefs/journal_reclaim.c b/fs/bcachefs/journal_reclaim.c
index 8c88884c74a5..37c6846a30aa 100644
--- a/fs/bcachefs/journal_reclaim.c
+++ b/fs/bcachefs/journal_reclaim.c
@@ -210,24 +210,7 @@ void bch2_journal_space_available(struct journal *j)
 	clean		= j->space[journal_space_clean].total;
 	total		= j->space[journal_space_total].total;
 
-	if (!clean_ondisk &&
-	    journal_cur_seq(j) == j->seq_ondisk) {
-		struct printbuf buf = PRINTBUF;
-
-		__bch2_journal_debug_to_text(&buf, j);
-		bch_err(c, "journal stuck\n%s", buf.buf);
-		printbuf_exit(&buf);
-
-		/*
-		 * Hack: bch2_fatal_error() calls bch2_journal_halt() which
-		 * takes journal lock:
-		 */
-		spin_unlock(&j->lock);
-		bch2_fatal_error(c);
-		spin_lock(&j->lock);
-
-		ret = JOURNAL_ERR_journal_stuck;
-	} else if (!j->space[journal_space_discarded].next_entry)
+	if (!j->space[journal_space_discarded].next_entry)
 		ret = JOURNAL_ERR_journal_full;
 
 	if ((j->space[journal_space_clean_ondisk].next_entry <
-- 
2.39.2

[PATCH 5/5] RFC: bcachefs: use a timeout for the journal stuck condition

[Brian Foster]

This is currently just a thought/experiment on how to make the
journal checking logic a bit more reliable. I've seen this actually
still result in blocked tasks in the journal reservation slow path,
which I think is actually due to the timeout allowing tasks to wind down
long enough after a legitimate stall such that there are no more journal
wake events to allow any one of the tasks to detect the stuck condition
and shut down the fs.

This would need to be addressed somehow or another for this sort of
thing to be useful. One approach could be a timer of some sort to
monitor things as the journal becomes full, but I think that is
approaching overkill given this is a rare enough problem. This is
primarily posted for thought and discussion.

Not-Signed-off-by: Brian Foster <bfoster@redhat.com>
---
 fs/bcachefs/journal.c | 7 +++++--
 1 file changed, 5 insertions(+), 2 deletions(-)

diff --git a/fs/bcachefs/journal.c b/fs/bcachefs/journal.c
index 3f0e6d71aa32..a83b753fbc3f 100644
--- a/fs/bcachefs/journal.c
+++ b/fs/bcachefs/journal.c
@@ -85,7 +85,8 @@ static void journal_pin_list_init(struct journal_entry_pin_list *p, int count)
  *
  * Consider the journal stuck when it appears full with no ability to commit
  * btree transactions, to discard journal buckets, nor acquire priority
- * (reserved watermark) reservation.
+ * (reserved watermark) reservation, and we have not been able to open a new
+ * journal entry for at least 30s.
  */
 static inline bool
 journal_error_check_stuck(struct journal *j, int error, unsigned flags)
@@ -93,6 +94,7 @@ journal_error_check_stuck(struct journal *j, int error, unsigned flags)
 	struct bch_fs *c = container_of(j, struct bch_fs, journal);
 	bool stuck = false;
 	struct printbuf buf = PRINTBUF;
+	u64 stuck_ts;
 
 	if (!(error == JOURNAL_ERR_journal_full ||
 	      error == JOURNAL_ERR_journal_pin_full) ||
@@ -102,7 +104,8 @@ journal_error_check_stuck(struct journal *j, int error, unsigned flags)
 
 	spin_lock(&j->lock);
 
-	if (j->can_discard) {
+	stuck_ts = j->res_get_blocked_start + (NSEC_PER_SEC * 30);
+	if (j->can_discard || time_before64(local_clock(), stuck_ts)) {
 		spin_unlock(&j->lock);
 		return stuck;
 	}
-- 
2.39.2

Re: [PATCH 1/5] bcachefs: more aggressive fast path write buffer key flushing

[Brian Foster]

On Tue, Mar 21, 2023 at 09:20:10AM -0400, Brian Foster wrote:
> The btree write buffer flush code is prone to causing journal
> deadlock due to inefficient use and release of reservation space.
> Reservation is not pre-reserved for write buffered keys (as is done
> for key cache keys, for example), because the write buffer flush
> side uses a fast path that attempts insertion without need for any
> reservation at all.
> 
> The write buffer flush attempts to deal with this by inserting keys
> using the BTREE_INSERT_JOURNAL_RECLAIM flag to return an error on
> journal reservations that require blocking. Upon first error, it
> falls back to a slow path that inserts in journal order and supports
> moving the associated journal pin forward.
> 
> The problem is that under pathological conditions (i.e. smaller log,
> larger write buffer and journal reservation pressure), we've seen
> instances where the fast path fails fairly quickly without having
> completed many insertions, and then the slow path is unable to push
> the journal pin forward enough to free up the space it needs to
> completely flush the buffer. This problem is occasionally reproduced
> by fstest generic/333.
> 
> To avoid this problem, update the fast path algorithm to skip key
> inserts that fail due to inability to acquire needed journal
> reservation without immediately breaking out of the loop. Instead,
> insert as many keys as possible, zap the sequence numbers to mark
> them as processed, and then fall back to the slow path to process
> the remaining set in journal order. This reduces the amount of
> journal reservation that might be required to flush the entire
> buffer and increases the odds that the slow path is able to move the
> journal pin forward and free up space as keys are processed.
> 
> Signed-off-by: Brian Foster <bfoster@redhat.com>
> ---
>  fs/bcachefs/btree_write_buffer.c | 41 ++++++++++++++++----------------
>  1 file changed, 21 insertions(+), 20 deletions(-)
> 
> diff --git a/fs/bcachefs/btree_write_buffer.c b/fs/bcachefs/btree_write_buffer.c
> index 80f4b9839bc2..32f20e631de0 100644
> --- a/fs/bcachefs/btree_write_buffer.c
> +++ b/fs/bcachefs/btree_write_buffer.c
...
> @@ -198,23 +203,19 @@ int __bch2_btree_write_buffer_flush(struct btree_trans *trans, unsigned commit_f
>  slowpath:
>  	trace_write_buffer_flush_slowpath(trans, i - keys, nr);
>  
> -	dst = keys;
> -	for (; i < keys + nr; i++) {
> -		if (i + 1 < keys + nr &&
> -		    i[0].btree == i[1].btree &&
> -		    bpos_eq(i[0].k.k.p, i[1].k.k.p))
> -			continue;
> -
> -		*dst = *i;
> -		dst++;
> -	}
> -	nr = dst - keys;
> -

This one leaves an unused var warning. I've fixed it locally but will
wait for any further comments before reposting.

Brian

> +	/*
> +	 * Now sort the rest by journal seq and bump the journal pin as we go.
> +	 * The slowpath zapped the seq of keys that were successfully flushed so
> +	 * we can skip those here.
> +	 */
>  	sort(keys, nr, sizeof(keys[0]),
>  	     btree_write_buffered_journal_cmp,
>  	     NULL);
>  
>  	for (i = keys; i < keys + nr; i++) {
> +		if (!i->journal_seq)
> +			continue;
> +
>  		if (i->journal_seq > pin.seq) {
>  			struct journal_entry_pin pin2;
>  
> -- 
> 2.39.2
>