[PATCH] xfs: shutdown on failure to add page to log bio

[PATCH] xfs: shutdown on failure to add page to log bio

[Brian Foster]

If the bio_add_page() call fails, we proceed to write out a
partially constructed log buffer. This corrupts the physical log
such that log recovery is not possible. Worse, persistent
occurrences of this error eventually lead to a BUG_ON() failure in
bio_split() as iclogs wrap the end of the physical log, which
triggers log recovery on subsequent mount.

Rather than warn about writing out a corrupted log buffer, shutdown
the fs as is done for any log I/O related error. This preserves the
consistency of the physical log such that log recovery succeeds on a
subsequent mount. Note that this was observed on a 64k page debug
kernel without upstream commit 59bb47985c1d ("mm, sl[aou]b:
guarantee natural alignment for kmalloc(power-of-two)"), which
demonstrated frequent iclog bio overflows due to unaligned (slab
allocated) iclog data buffers.

Signed-off-by: Brian Foster <bfoster@redhat.com>
---
 fs/xfs/xfs_log.c | 14 ++++++++++----
 1 file changed, 10 insertions(+), 4 deletions(-)

diff --git a/fs/xfs/xfs_log.c b/fs/xfs/xfs_log.c
index 2a90a483c2d6..ebb6a5c95332 100644
--- a/fs/xfs/xfs_log.c
+++ b/fs/xfs/xfs_log.c
@@ -1705,16 +1705,22 @@ xlog_bio_end_io(
 
 static void
 xlog_map_iclog_data(
-	struct bio		*bio,
-	void			*data,
+	struct xlog_in_core	*iclog,
 	size_t			count)
 {
+	struct xfs_mount	*mp = iclog->ic_log->l_mp;
+	struct bio		*bio = &iclog->ic_bio;
+	void			*data = iclog->ic_data;
+
 	do {
 		struct page	*page = kmem_to_page(data);
 		unsigned int	off = offset_in_page(data);
 		size_t		len = min_t(size_t, count, PAGE_SIZE - off);
 
-		WARN_ON_ONCE(bio_add_page(bio, page, len, off) != len);
+		if (bio_add_page(bio, page, len, off) != len) {
+			xfs_force_shutdown(mp, SHUTDOWN_LOG_IO_ERROR);
+			break;
+		}
 
 		data += len;
 		count -= len;
@@ -1762,7 +1768,7 @@ xlog_write_iclog(
 	if (need_flush)
 		iclog->ic_bio.bi_opf |= REQ_PREFLUSH;
 
-	xlog_map_iclog_data(&iclog->ic_bio, iclog->ic_data, count);
+	xlog_map_iclog_data(iclog, count);
 	if (is_vmalloc_addr(iclog->ic_data))
 		flush_kernel_vmap_range(iclog->ic_data, count);
 
-- 
2.21.1

Re: [PATCH] xfs: shutdown on failure to add page to log bio

[Darrick J. Wong]

On Tue, Mar 24, 2020 at 12:57:00PM -0400, Brian Foster wrote:
> If the bio_add_page() call fails, we proceed to write out a
> partially constructed log buffer. This corrupts the physical log
> such that log recovery is not possible. Worse, persistent
> occurrences of this error eventually lead to a BUG_ON() failure in
> bio_split() as iclogs wrap the end of the physical log, which
> triggers log recovery on subsequent mount.
> 
> Rather than warn about writing out a corrupted log buffer, shutdown
> the fs as is done for any log I/O related error. This preserves the
> consistency of the physical log such that log recovery succeeds on a
> subsequent mount. Note that this was observed on a 64k page debug
> kernel without upstream commit 59bb47985c1d ("mm, sl[aou]b:
> guarantee natural alignment for kmalloc(power-of-two)"), which
> demonstrated frequent iclog bio overflows due to unaligned (slab
> allocated) iclog data buffers.

Fixes: tag?

Otherwise, looks ok to me.

--D

> Signed-off-by: Brian Foster <bfoster@redhat.com>
> ---
>  fs/xfs/xfs_log.c | 14 ++++++++++----
>  1 file changed, 10 insertions(+), 4 deletions(-)
> 
> diff --git a/fs/xfs/xfs_log.c b/fs/xfs/xfs_log.c
> index 2a90a483c2d6..ebb6a5c95332 100644
> --- a/fs/xfs/xfs_log.c
> +++ b/fs/xfs/xfs_log.c
> @@ -1705,16 +1705,22 @@ xlog_bio_end_io(
>  
>  static void
>  xlog_map_iclog_data(
> -	struct bio		*bio,
> -	void			*data,
> +	struct xlog_in_core	*iclog,
>  	size_t			count)
>  {
> +	struct xfs_mount	*mp = iclog->ic_log->l_mp;
> +	struct bio		*bio = &iclog->ic_bio;
> +	void			*data = iclog->ic_data;
> +
>  	do {
>  		struct page	*page = kmem_to_page(data);
>  		unsigned int	off = offset_in_page(data);
>  		size_t		len = min_t(size_t, count, PAGE_SIZE - off);
>  
> -		WARN_ON_ONCE(bio_add_page(bio, page, len, off) != len);
> +		if (bio_add_page(bio, page, len, off) != len) {
> +			xfs_force_shutdown(mp, SHUTDOWN_LOG_IO_ERROR);
> +			break;
> +		}
>  
>  		data += len;
>  		count -= len;
> @@ -1762,7 +1768,7 @@ xlog_write_iclog(
>  	if (need_flush)
>  		iclog->ic_bio.bi_opf |= REQ_PREFLUSH;
>  
> -	xlog_map_iclog_data(&iclog->ic_bio, iclog->ic_data, count);
> +	xlog_map_iclog_data(iclog, count);
>  	if (is_vmalloc_addr(iclog->ic_data))
>  		flush_kernel_vmap_range(iclog->ic_data, count);
>  
> -- 
> 2.21.1
> 

Re: [PATCH] xfs: shutdown on failure to add page to log bio

[Brian Foster]

On Tue, Mar 24, 2020 at 10:18:59AM -0700, Darrick J. Wong wrote:
> On Tue, Mar 24, 2020 at 12:57:00PM -0400, Brian Foster wrote:
> > If the bio_add_page() call fails, we proceed to write out a
> > partially constructed log buffer. This corrupts the physical log
> > such that log recovery is not possible. Worse, persistent
> > occurrences of this error eventually lead to a BUG_ON() failure in
> > bio_split() as iclogs wrap the end of the physical log, which
> > triggers log recovery on subsequent mount.
> > 
> > Rather than warn about writing out a corrupted log buffer, shutdown
> > the fs as is done for any log I/O related error. This preserves the
> > consistency of the physical log such that log recovery succeeds on a
> > subsequent mount. Note that this was observed on a 64k page debug
> > kernel without upstream commit 59bb47985c1d ("mm, sl[aou]b:
> > guarantee natural alignment for kmalloc(power-of-two)"), which
> > demonstrated frequent iclog bio overflows due to unaligned (slab
> > allocated) iclog data buffers.
> 
> Fixes: tag?
> 

I suppose you could argue it fixes commit 79b54d9bfcdcd ("xfs: use bios
directly to write log buffers"), but I didn't include a tag because this
is not really fixing a reproducible bug. It's fixing up the error
handling based on a bad combination of patches in a distro kernel.
Perhaps I'm just not clear on when we do or don't want a fixes tag..?

Brian

> Otherwise, looks ok to me.
> 
> --D
> 
> > Signed-off-by: Brian Foster <bfoster@redhat.com>
> > ---
> >  fs/xfs/xfs_log.c | 14 ++++++++++----
> >  1 file changed, 10 insertions(+), 4 deletions(-)
> > 
> > diff --git a/fs/xfs/xfs_log.c b/fs/xfs/xfs_log.c
> > index 2a90a483c2d6..ebb6a5c95332 100644
> > --- a/fs/xfs/xfs_log.c
> > +++ b/fs/xfs/xfs_log.c
> > @@ -1705,16 +1705,22 @@ xlog_bio_end_io(
> >  
> >  static void
> >  xlog_map_iclog_data(
> > -	struct bio		*bio,
> > -	void			*data,
> > +	struct xlog_in_core	*iclog,
> >  	size_t			count)
> >  {
> > +	struct xfs_mount	*mp = iclog->ic_log->l_mp;
> > +	struct bio		*bio = &iclog->ic_bio;
> > +	void			*data = iclog->ic_data;
> > +
> >  	do {
> >  		struct page	*page = kmem_to_page(data);
> >  		unsigned int	off = offset_in_page(data);
> >  		size_t		len = min_t(size_t, count, PAGE_SIZE - off);
> >  
> > -		WARN_ON_ONCE(bio_add_page(bio, page, len, off) != len);
> > +		if (bio_add_page(bio, page, len, off) != len) {
> > +			xfs_force_shutdown(mp, SHUTDOWN_LOG_IO_ERROR);
> > +			break;
> > +		}
> >  
> >  		data += len;
> >  		count -= len;
> > @@ -1762,7 +1768,7 @@ xlog_write_iclog(
> >  	if (need_flush)
> >  		iclog->ic_bio.bi_opf |= REQ_PREFLUSH;
> >  
> > -	xlog_map_iclog_data(&iclog->ic_bio, iclog->ic_data, count);
> > +	xlog_map_iclog_data(iclog, count);
> >  	if (is_vmalloc_addr(iclog->ic_data))
> >  		flush_kernel_vmap_range(iclog->ic_data, count);
> >  
> > -- 
> > 2.21.1
> > 
> 

Re: [PATCH] xfs: shutdown on failure to add page to log bio

[Darrick J. Wong]

On Tue, Mar 24, 2020 at 01:29:49PM -0400, Brian Foster wrote:
> On Tue, Mar 24, 2020 at 10:18:59AM -0700, Darrick J. Wong wrote:
> > On Tue, Mar 24, 2020 at 12:57:00PM -0400, Brian Foster wrote:
> > > If the bio_add_page() call fails, we proceed to write out a
> > > partially constructed log buffer. This corrupts the physical log
> > > such that log recovery is not possible. Worse, persistent
> > > occurrences of this error eventually lead to a BUG_ON() failure in
> > > bio_split() as iclogs wrap the end of the physical log, which
> > > triggers log recovery on subsequent mount.
> > > 
> > > Rather than warn about writing out a corrupted log buffer, shutdown
> > > the fs as is done for any log I/O related error. This preserves the
> > > consistency of the physical log such that log recovery succeeds on a
> > > subsequent mount. Note that this was observed on a 64k page debug
> > > kernel without upstream commit 59bb47985c1d ("mm, sl[aou]b:
> > > guarantee natural alignment for kmalloc(power-of-two)"), which
> > > demonstrated frequent iclog bio overflows due to unaligned (slab
> > > allocated) iclog data buffers.
> > 
> > Fixes: tag?
> > 
> 
> I suppose you could argue it fixes commit 79b54d9bfcdcd ("xfs: use bios
> directly to write log buffers"), but I didn't include a tag because this
> is not really fixing a reproducible bug. It's fixing up the error
> handling based on a bad combination of patches in a distro kernel.
> Perhaps I'm just not clear on when we do or don't want a fixes tag..?

[Summarizing what I rambled about on IRC:]

From my perspective, this looks like you concluded that the WARN_ON_ONCE
wasn't sufficient to deal with the error (because the physical log got
corrupted), so you're adding branch code to shut down the log.

Granted, it should only happen if bio_add_page fails, but as that's not
part of xfs, we have to code defensively enough to avoid breaking the
filesystem.

Looks ok, will add fixes tag and send it to the testcloud...
Reviewed-by: Darrick J. Wong <darrick.wong@oracle.com>

--D

> Brian
> 
> > Otherwise, looks ok to me.
> > 
> > --D
> > 
> > > Signed-off-by: Brian Foster <bfoster@redhat.com>
> > > ---
> > >  fs/xfs/xfs_log.c | 14 ++++++++++----
> > >  1 file changed, 10 insertions(+), 4 deletions(-)
> > > 
> > > diff --git a/fs/xfs/xfs_log.c b/fs/xfs/xfs_log.c
> > > index 2a90a483c2d6..ebb6a5c95332 100644
> > > --- a/fs/xfs/xfs_log.c
> > > +++ b/fs/xfs/xfs_log.c
> > > @@ -1705,16 +1705,22 @@ xlog_bio_end_io(
> > >  
> > >  static void
> > >  xlog_map_iclog_data(
> > > -	struct bio		*bio,
> > > -	void			*data,
> > > +	struct xlog_in_core	*iclog,
> > >  	size_t			count)
> > >  {
> > > +	struct xfs_mount	*mp = iclog->ic_log->l_mp;
> > > +	struct bio		*bio = &iclog->ic_bio;
> > > +	void			*data = iclog->ic_data;
> > > +
> > >  	do {
> > >  		struct page	*page = kmem_to_page(data);
> > >  		unsigned int	off = offset_in_page(data);
> > >  		size_t		len = min_t(size_t, count, PAGE_SIZE - off);
> > >  
> > > -		WARN_ON_ONCE(bio_add_page(bio, page, len, off) != len);
> > > +		if (bio_add_page(bio, page, len, off) != len) {
> > > +			xfs_force_shutdown(mp, SHUTDOWN_LOG_IO_ERROR);
> > > +			break;
> > > +		}
> > >  
> > >  		data += len;
> > >  		count -= len;
> > > @@ -1762,7 +1768,7 @@ xlog_write_iclog(
> > >  	if (need_flush)
> > >  		iclog->ic_bio.bi_opf |= REQ_PREFLUSH;
> > >  
> > > -	xlog_map_iclog_data(&iclog->ic_bio, iclog->ic_data, count);
> > > +	xlog_map_iclog_data(iclog, count);
> > >  	if (is_vmalloc_addr(iclog->ic_data))
> > >  		flush_kernel_vmap_range(iclog->ic_data, count);
> > >  
> > > -- 
> > > 2.21.1
> > > 
> > 
> 

Re: [PATCH] xfs: shutdown on failure to add page to log bio

[Dave Chinner]

On Tue, Mar 24, 2020 at 12:57:00PM -0400, Brian Foster wrote:
> If the bio_add_page() call fails, we proceed to write out a
> partially constructed log buffer. This corrupts the physical log
> such that log recovery is not possible. Worse, persistent
> occurrences of this error eventually lead to a BUG_ON() failure in
> bio_split() as iclogs wrap the end of the physical log, which
> triggers log recovery on subsequent mount.

I'm a little unclear on how this can happen - the iclogbuf can only
be 256kB - 64 pages - and we always allocation a bio with enough
bvecs to hold 64 pages. And the ic_data buffer we are adding to the
bio is also statically allocated so I'm left to wonder exactly how
this is failing.

i.e. this looks like code that shouldn't ever fail, yet it
apparently is, and I have no idea what is causing that failure...

That said, shutting down on failure is the right thing to do, so the
code looks good. I just want to know how the bio_add_page() failure
is occurring.

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

Re: [PATCH] xfs: shutdown on failure to add page to log bio

[Christoph Hellwig]

On Tue, Mar 24, 2020 at 12:57:00PM -0400, Brian Foster wrote:
> Rather than warn about writing out a corrupted log buffer, shutdown
> the fs as is done for any log I/O related error. This preserves the
> consistency of the physical log such that log recovery succeeds on a
> subsequent mount. Note that this was observed on a 64k page debug
> kernel without upstream commit 59bb47985c1d ("mm, sl[aou]b:
> guarantee natural alignment for kmalloc(power-of-two)"), which
> demonstrated frequent iclog bio overflows due to unaligned (slab
> allocated) iclog data buffers.

Weird..

>  static void
>  xlog_map_iclog_data(
> -	struct bio		*bio,
> -	void			*data,
> +	struct xlog_in_core	*iclog,
>  	size_t			count)
>  {
> +	struct xfs_mount	*mp = iclog->ic_log->l_mp;
> +	struct bio		*bio = &iclog->ic_bio;
> +	void			*data = iclog->ic_data;
> +
>  	do {
>  		struct page	*page = kmem_to_page(data);
>  		unsigned int	off = offset_in_page(data);
>  		size_t		len = min_t(size_t, count, PAGE_SIZE - off);
>  
> -		WARN_ON_ONCE(bio_add_page(bio, page, len, off) != len);
> +		if (bio_add_page(bio, page, len, off) != len) {
> +			xfs_force_shutdown(mp, SHUTDOWN_LOG_IO_ERROR);
> +			break;
> +		}
>  
>  		data += len;
>  		count -= len;
> @@ -1762,7 +1768,7 @@ xlog_write_iclog(
>  	if (need_flush)
>  		iclog->ic_bio.bi_opf |= REQ_PREFLUSH;
>  
> -	xlog_map_iclog_data(&iclog->ic_bio, iclog->ic_data, count);
> +	xlog_map_iclog_data(iclog, count);

Can you just return an error from xlog_map_iclog_data and shut down
in the caller?  Besides keeping the abstraction levels similar I had
also hoped to lift xlog_map_iclog_data into the block layer eventually.

Re: [PATCH] xfs: shutdown on failure to add page to log bio

[Brian Foster]

On Wed, Mar 25, 2020 at 10:24:24AM +1100, Dave Chinner wrote:
> On Tue, Mar 24, 2020 at 12:57:00PM -0400, Brian Foster wrote:
> > If the bio_add_page() call fails, we proceed to write out a
> > partially constructed log buffer. This corrupts the physical log
> > such that log recovery is not possible. Worse, persistent
> > occurrences of this error eventually lead to a BUG_ON() failure in
> > bio_split() as iclogs wrap the end of the physical log, which
> > triggers log recovery on subsequent mount.
> 
> I'm a little unclear on how this can happen - the iclogbuf can only
> be 256kB - 64 pages - and we always allocation a bio with enough
> bvecs to hold 64 pages. And the ic_data buffer we are adding to the
> bio is also statically allocated so I'm left to wonder exactly how
> this is failing.
> 
> i.e. this looks like code that shouldn't ever fail, yet it
> apparently is, and I have no idea what is causing that failure...
> 

It shouldn't fail in current upstream. The problem occurred on a large
page (64k) system without commit 59bb47985c1d ("mm, sl[aou]b: guarantee
natural alignment for kmalloc(power-of-two)"). The large page config
means default sized log buffers (32k) allocate out of slab and slab
allocs are not naturally aligned due to the lack of the aforementioned
commit (plus additional mm debug options, such as slub debug, kasan).
IOW, the 32k slab looks like this:

kmalloc-32k           75     75  33792   15    8 : tunables    0    0    0 : slabdata      5      5      0

Note the 33k object size. This means that 32k slab allocations can start
at a non-32k aligned physical offset in a page. So for example if we
allocate a 32k log buffer that lands at physical offset 48k of the
underlying page, xlog_map_iclog_data() will attempt to attach 2 physical
pages (16k from each) to the bio. Meanwhile the bio was originally
allocated and initialized based on a bvec count of
howmany(log->l_iclog_size, PAGE_SIZE), which assumes a 32k log buffer
only requires a single bvec.

The primary fix for this problem was to include the slab alignment
patch. That essentially changes the object size in the above example
from 33k to 64k for reasons described in its commit log. This error
handling patch was simply based on the observation that if the
bio_add_page() call from XFS fails, for whatever reason, we fall over
rather ungracefully.

Brian

> That said, shutting down on failure is the right thing to do, so the
> code looks good. I just want to know how the bio_add_page() failure
> is occurring.
> 
> Cheers,
> 
> Dave.
> -- 
> Dave Chinner
> david@fromorbit.com
> 

Re: [PATCH] xfs: shutdown on failure to add page to log bio

[Brian Foster]

On Wed, Mar 25, 2020 at 12:12:25AM -0700, Christoph Hellwig wrote:
> On Tue, Mar 24, 2020 at 12:57:00PM -0400, Brian Foster wrote:
> > Rather than warn about writing out a corrupted log buffer, shutdown
> > the fs as is done for any log I/O related error. This preserves the
> > consistency of the physical log such that log recovery succeeds on a
> > subsequent mount. Note that this was observed on a 64k page debug
> > kernel without upstream commit 59bb47985c1d ("mm, sl[aou]b:
> > guarantee natural alignment for kmalloc(power-of-two)"), which
> > demonstrated frequent iclog bio overflows due to unaligned (slab
> > allocated) iclog data buffers.
> 
> Weird..
> 
> >  static void
> >  xlog_map_iclog_data(
> > -	struct bio		*bio,
> > -	void			*data,
> > +	struct xlog_in_core	*iclog,
> >  	size_t			count)
> >  {
> > +	struct xfs_mount	*mp = iclog->ic_log->l_mp;
> > +	struct bio		*bio = &iclog->ic_bio;
> > +	void			*data = iclog->ic_data;
> > +
> >  	do {
> >  		struct page	*page = kmem_to_page(data);
> >  		unsigned int	off = offset_in_page(data);
> >  		size_t		len = min_t(size_t, count, PAGE_SIZE - off);
> >  
> > -		WARN_ON_ONCE(bio_add_page(bio, page, len, off) != len);
> > +		if (bio_add_page(bio, page, len, off) != len) {
> > +			xfs_force_shutdown(mp, SHUTDOWN_LOG_IO_ERROR);
> > +			break;
> > +		}
> >  
> >  		data += len;
> >  		count -= len;
> > @@ -1762,7 +1768,7 @@ xlog_write_iclog(
> >  	if (need_flush)
> >  		iclog->ic_bio.bi_opf |= REQ_PREFLUSH;
> >  
> > -	xlog_map_iclog_data(&iclog->ic_bio, iclog->ic_data, count);
> > +	xlog_map_iclog_data(iclog, count);
> 
> Can you just return an error from xlog_map_iclog_data and shut down
> in the caller?  Besides keeping the abstraction levels similar I had
> also hoped to lift xlog_map_iclog_data into the block layer eventually.
> 

Sure. That's probably more appropriate now that I look again because it
looks like we still submit the current bio with this patch. Something
like the following..?

diff --git a/fs/xfs/xfs_log.c b/fs/xfs/xfs_log.c
index 2a90a483c2d6..92a58a6bc32b 100644
--- a/fs/xfs/xfs_log.c
+++ b/fs/xfs/xfs_log.c
@@ -1703,7 +1703,7 @@ xlog_bio_end_io(
 		   &iclog->ic_end_io_work);
 }
 
-static void
+static int
 xlog_map_iclog_data(
 	struct bio		*bio,
 	void			*data,
@@ -1714,11 +1714,14 @@ xlog_map_iclog_data(
 		unsigned int	off = offset_in_page(data);
 		size_t		len = min_t(size_t, count, PAGE_SIZE - off);
 
-		WARN_ON_ONCE(bio_add_page(bio, page, len, off) != len);
+		if (bio_add_page(bio, page, len, off) != len)
+			break;
 
 		data += len;
 		count -= len;
 	} while (count);
+
+	return count;
 }
 
 STATIC void
@@ -1762,7 +1765,10 @@ xlog_write_iclog(
 	if (need_flush)
 		iclog->ic_bio.bi_opf |= REQ_PREFLUSH;
 
-	xlog_map_iclog_data(&iclog->ic_bio, iclog->ic_data, count);
+	if (xlog_map_iclog_data(&iclog->ic_bio, iclog->ic_data, count)) {
+		xfs_force_shutdown(log->l_mp, SHUTDOWN_LOG_IO_ERROR);
+		return;
+	}
 	if (is_vmalloc_addr(iclog->ic_data))
 		flush_kernel_vmap_range(iclog->ic_data, count);
 

Re: [PATCH] xfs: shutdown on failure to add page to log bio

[Christoph Hellwig]

On Wed, Mar 25, 2020 at 07:25:02AM -0400, Brian Foster wrote:
> diff --git a/fs/xfs/xfs_log.c b/fs/xfs/xfs_log.c
> index 2a90a483c2d6..92a58a6bc32b 100644
> --- a/fs/xfs/xfs_log.c
> +++ b/fs/xfs/xfs_log.c
> @@ -1703,7 +1703,7 @@ xlog_bio_end_io(
>  		   &iclog->ic_end_io_work);
>  }
>  
> -static void
> +static int
>  xlog_map_iclog_data(
>  	struct bio		*bio,
>  	void			*data,
> @@ -1714,11 +1714,14 @@ xlog_map_iclog_data(
>  		unsigned int	off = offset_in_page(data);
>  		size_t		len = min_t(size_t, count, PAGE_SIZE - off);
>  
> -		WARN_ON_ONCE(bio_add_page(bio, page, len, off) != len);
> +		if (bio_add_page(bio, page, len, off) != len)
> +			break;

I'd just return -EIO here.

>  
>  		data += len;
>  		count -= len;
>  	} while (count);
> +
> +	return count;

And 0 here.  Returning the remaining count obviously works as well,
but it feels a little unintuitive to me and would warrant a comment.