2022-07-01 16:40:23

by Brian Foster

[permalink] [raw]

Subject: Re: Multi-page folio issues in 5.19-rc4 (was [PATCH v3 25/25] xfs: Support large folios)

On Wed, Jun 29, 2022 at 01:22:06PM -0700, Darrick J. Wong wrote:
> On Wed, Jun 29, 2022 at 08:57:30AM -0400, Brian Foster wrote:
> > On Tue, Jun 28, 2022 at 04:21:55PM -0700, Darrick J. Wong wrote:
> > > On Wed, Jun 29, 2022 at 08:17:57AM +1000, Dave Chinner wrote:
> > > > On Tue, Jun 28, 2022 at 02:18:24PM +0100, Matthew Wilcox wrote:
> > > > > On Tue, Jun 28, 2022 at 12:31:55PM +0100, Matthew Wilcox wrote:
> > > > > > On Tue, Jun 28, 2022 at 12:27:40PM +0100, Matthew Wilcox wrote:
> > > > > > > On Tue, Jun 28, 2022 at 05:31:20PM +1000, Dave Chinner wrote:
> > > > > > > > So using this technique, I've discovered that there's a dirty page
> > > > > > > > accounting leak that eventually results in fsx hanging in
> > > > > > > > balance_dirty_pages().
> > > > > > >
> > > > > > > Alas, I think this is only an accounting error, and not related to
> > > > > > > the problem(s) that Darrick & Zorro are seeing. I think what you're
> > > > > > > seeing is dirty pages being dropped at truncation without the
> > > > > > > appropriate accounting. ie this should be the fix:
> > > > > >
> > > > > > Argh, try one that actually compiles.
> > > > >
> > > > > ... that one's going to underflow the accounting. Maybe I shouldn't
> > > > > be writing code at 6am?
> > > > >
> > > > > diff --git a/mm/huge_memory.c b/mm/huge_memory.c
> > > > > index f7248002dad9..4eec6ee83e44 100644
> > > > > --- a/mm/huge_memory.c
> > > > > +++ b/mm/huge_memory.c
> > > > > @@ -18,6 +18,7 @@
> > > > > #include <linux/shrinker.h>
> > > > > #include <linux/mm_inline.h>
> > > > > #include <linux/swapops.h>
> > > > > +#include <linux/backing-dev.h>
> > > > > #include <linux/dax.h>
> > > > > #include <linux/khugepaged.h>
> > > > > #include <linux/freezer.h>
> > > > > @@ -2439,11 +2440,15 @@ static void __split_huge_page(struct page *page, struct list_head *list,
> > > > > __split_huge_page_tail(head, i, lruvec, list);
> > > > > /* Some pages can be beyond EOF: drop them from page cache */
> > > > > if (head[i].index >= end) {
> > > > > - ClearPageDirty(head + i);
> > > > > - __delete_from_page_cache(head + i, NULL);
> > > > > + struct folio *tail = page_folio(head + i);
> > > > > +
> > > > > if (shmem_mapping(head->mapping))
> > > > > shmem_uncharge(head->mapping->host, 1);
> > > > > - put_page(head + i);
> > > > > + else if (folio_test_clear_dirty(tail))
> > > > > + folio_account_cleaned(tail,
> > > > > + inode_to_wb(folio->mapping->host));
> > > > > + __filemap_remove_folio(tail, NULL);
> > > > > + folio_put(tail);
> > > > > } else if (!PageAnon(page)) {
> > > > > __xa_store(&head->mapping->i_pages, head[i].index,
> > > > > head + i, 0);
> > > > >
> > > >
> > > > Yup, that fixes the leak.
> > > >
> > > > Tested-by: Dave Chinner <[email protected]>
> > >
> > > Four hours of generic/522 running is long enough to conclude that this
> > > is likely the fix for my problem and migrate long soak testing to my
> > > main g/522 rig and:
> > >
> > > Tested-by: Darrick J. Wong <[email protected]>
> > >
> >
> > Just based on Willy's earlier comment.. what I would probably be a
> > little careful/curious about here is whether the accounting fix leads to
> > an indirect behavior change that does impact reproducibility of the
> > corruption problem. For example, does artificially escalated dirty page
> > tracking lead to increased reclaim/writeback activity than might
> > otherwise occur, and thus contend with the fs workload? Clearly it has
> > some impact based on Dave's balance_dirty_pages() problem reproducer,
> > but I don't know if it extends beyond that off the top of my head. That
> > might make some sense if the workload is fsx, since that doesn't
> > typically stress cache/memory usage the way a large fsstress workload or
> > something might.
> >
> > So for example, interesting questions might be... Do your corruption
> > events happen to correspond with dirty page accounting crossing some
> > threshold based on available memory in your test environment? Does
> > reducing available memory affect reproducibility? Etc.
>
> Yeah, I wonder that too now. I managed to trace generic/522 a couple of
> times before willy's patch dropped. From what I could tell, a large
> folio X would get page P assigned to the fsx file's page cache to cover
> range R, dirtied, and written to disk. At some point later, we'd
> reflink into part of the file range adjacent to P, but not P itself.
> I /think/ that should have caused the whole folio to get invalidated?
>
> Then some more things happened (none of which dirtied R, according to
> fsx) and then suddenly writeback would trigger on some page (don't know
> which) that would write to the disk blocks backing R. I'm fairly sure
> that's where the incorrect disk contents came from.
>
> Next, we'd reflink part of the file range including R into a different
> part of the file (call it R2). fsx would read R2, bringing a new page
> into cache, and it wouldn't match the fsxgood buffer, leading to fsx
> aborting.
>
> After a umount/mount cycle, reading R and R2 would both reveal the
> incorrect contents that had caused fsx to abort.
>

FWIW, I hadn't been able to reproduce this in my default environment to
this point. With the memory leak issue in the light, I was eventually
able to by reducing dirty_bytes to something the system would be more
likely to hit sooner (i.e. 16-32MB), but I also see stalling behavior
and whatnot due to the leak that requires backing off from the specified
dirty limit every so often.

If I apply the accounting patch to avoid the leak and set
dirty_background_bytes to something notably aggressive (1kB), the test
survived 100 iterations or so before I stopped it. If I then set
dirty_bytes to something similarly aggressive (1MB), I hit the failure
on the next iteration (assuming it's the same problem). It's spinning
again at ~25 or so iterations without a failure so far, so I'd have to
wait and see how reliable the reproducer really is. Though if it doesn't
reoccur soonish, perhaps I'll try reducing dirty_bytes a bit more...

My suspicion based on these characteristics would be that the blocking
limit triggers more aggressive reclaim/invalidation, and thus helps
detect the problem sooner. If reflink is involved purely as a cache
invalidation step (i.e. so a subsequent read will hit the disk and
detect a cache inconsistency), then it might be interesting to see if it
can still be reproduced without reflink operations enabled but instead
with some combination of the -f/-X fsx flags to perform more flush
invals and on-disk data checks..

Brian

> Unfortunately the second ftrace attempt ate some trace data, so I was
> unable to figure out if the same thing happened again.
>
> At this point I really need to get on reviewing patches for 5.20, so
> I'll try to keep poking at this (examining the trace data requires a lot
> of concentration which isn't really possible while sawzall construction
> is going on at home) but at worst I can ask Linus to merge a patch for
> 5.19 final that makes setting mapping_set_large_folio a
> Kconfig/CONFIG_XFS_DEBUG option.
>
> --D
>
> >
> > Brian
> >
> > > --D
> > >
> > > > Cheers,
> > > >
> > > > Dave.
> > > > --
> > > > Dave Chinner
> > > > [email protected]
> > >
> >
>

2022-07-01 18:17:30

by Darrick J. Wong

[permalink] [raw]

Subject: Re: Multi-page folio issues in 5.19-rc4 (was [PATCH v3 25/25] xfs: Support large folios)

On Fri, Jul 01, 2022 at 12:03:23PM -0400, Brian Foster wrote:
> On Wed, Jun 29, 2022 at 01:22:06PM -0700, Darrick J. Wong wrote:
> > On Wed, Jun 29, 2022 at 08:57:30AM -0400, Brian Foster wrote:
> > > On Tue, Jun 28, 2022 at 04:21:55PM -0700, Darrick J. Wong wrote:
> > > > On Wed, Jun 29, 2022 at 08:17:57AM +1000, Dave Chinner wrote:
> > > > > On Tue, Jun 28, 2022 at 02:18:24PM +0100, Matthew Wilcox wrote:
> > > > > > On Tue, Jun 28, 2022 at 12:31:55PM +0100, Matthew Wilcox wrote:
> > > > > > > On Tue, Jun 28, 2022 at 12:27:40PM +0100, Matthew Wilcox wrote:
> > > > > > > > On Tue, Jun 28, 2022 at 05:31:20PM +1000, Dave Chinner wrote:
> > > > > > > > > So using this technique, I've discovered that there's a dirty page
> > > > > > > > > accounting leak that eventually results in fsx hanging in
> > > > > > > > > balance_dirty_pages().
> > > > > > > >
> > > > > > > > Alas, I think this is only an accounting error, and not related to
> > > > > > > > the problem(s) that Darrick & Zorro are seeing. I think what you're
> > > > > > > > seeing is dirty pages being dropped at truncation without the
> > > > > > > > appropriate accounting. ie this should be the fix:
> > > > > > >
> > > > > > > Argh, try one that actually compiles.
> > > > > >
> > > > > > ... that one's going to underflow the accounting. Maybe I shouldn't
> > > > > > be writing code at 6am?
> > > > > >
> > > > > > diff --git a/mm/huge_memory.c b/mm/huge_memory.c
> > > > > > index f7248002dad9..4eec6ee83e44 100644
> > > > > > --- a/mm/huge_memory.c
> > > > > > +++ b/mm/huge_memory.c
> > > > > > @@ -18,6 +18,7 @@
> > > > > > #include <linux/shrinker.h>
> > > > > > #include <linux/mm_inline.h>
> > > > > > #include <linux/swapops.h>
> > > > > > +#include <linux/backing-dev.h>
> > > > > > #include <linux/dax.h>
> > > > > > #include <linux/khugepaged.h>
> > > > > > #include <linux/freezer.h>
> > > > > > @@ -2439,11 +2440,15 @@ static void __split_huge_page(struct page *page, struct list_head *list,
> > > > > > __split_huge_page_tail(head, i, lruvec, list);
> > > > > > /* Some pages can be beyond EOF: drop them from page cache */
> > > > > > if (head[i].index >= end) {
> > > > > > - ClearPageDirty(head + i);
> > > > > > - __delete_from_page_cache(head + i, NULL);
> > > > > > + struct folio *tail = page_folio(head + i);
> > > > > > +
> > > > > > if (shmem_mapping(head->mapping))
> > > > > > shmem_uncharge(head->mapping->host, 1);
> > > > > > - put_page(head + i);
> > > > > > + else if (folio_test_clear_dirty(tail))
> > > > > > + folio_account_cleaned(tail,
> > > > > > + inode_to_wb(folio->mapping->host));
> > > > > > + __filemap_remove_folio(tail, NULL);
> > > > > > + folio_put(tail);
> > > > > > } else if (!PageAnon(page)) {
> > > > > > __xa_store(&head->mapping->i_pages, head[i].index,
> > > > > > head + i, 0);
> > > > > >
> > > > >
> > > > > Yup, that fixes the leak.
> > > > >
> > > > > Tested-by: Dave Chinner <[email protected]>
> > > >
> > > > Four hours of generic/522 running is long enough to conclude that this
> > > > is likely the fix for my problem and migrate long soak testing to my
> > > > main g/522 rig and:
> > > >
> > > > Tested-by: Darrick J. Wong <[email protected]>
> > > >
> > >
> > > Just based on Willy's earlier comment.. what I would probably be a
> > > little careful/curious about here is whether the accounting fix leads to
> > > an indirect behavior change that does impact reproducibility of the
> > > corruption problem. For example, does artificially escalated dirty page
> > > tracking lead to increased reclaim/writeback activity than might
> > > otherwise occur, and thus contend with the fs workload? Clearly it has
> > > some impact based on Dave's balance_dirty_pages() problem reproducer,
> > > but I don't know if it extends beyond that off the top of my head. That
> > > might make some sense if the workload is fsx, since that doesn't
> > > typically stress cache/memory usage the way a large fsstress workload or
> > > something might.
> > >
> > > So for example, interesting questions might be... Do your corruption
> > > events happen to correspond with dirty page accounting crossing some
> > > threshold based on available memory in your test environment? Does
> > > reducing available memory affect reproducibility? Etc.
> >
> > Yeah, I wonder that too now. I managed to trace generic/522 a couple of
> > times before willy's patch dropped. From what I could tell, a large
> > folio X would get page P assigned to the fsx file's page cache to cover
> > range R, dirtied, and written to disk. At some point later, we'd
> > reflink into part of the file range adjacent to P, but not P itself.
> > I /think/ that should have caused the whole folio to get invalidated?
> >
> > Then some more things happened (none of which dirtied R, according to
> > fsx) and then suddenly writeback would trigger on some page (don't know
> > which) that would write to the disk blocks backing R. I'm fairly sure
> > that's where the incorrect disk contents came from.
> >
> > Next, we'd reflink part of the file range including R into a different
> > part of the file (call it R2). fsx would read R2, bringing a new page
> > into cache, and it wouldn't match the fsxgood buffer, leading to fsx
> > aborting.
> >
> > After a umount/mount cycle, reading R and R2 would both reveal the
> > incorrect contents that had caused fsx to abort.
> >
>
> FWIW, I hadn't been able to reproduce this in my default environment to
> this point. With the memory leak issue in the light, I was eventually
> able to by reducing dirty_bytes to something the system would be more
> likely to hit sooner (i.e. 16-32MB), but I also see stalling behavior
> and whatnot due to the leak that requires backing off from the specified
> dirty limit every so often.
>
> If I apply the accounting patch to avoid the leak and set
> dirty_background_bytes to something notably aggressive (1kB), the test
> survived 100 iterations or so before I stopped it. If I then set
> dirty_bytes to something similarly aggressive (1MB), I hit the failure
> on the next iteration (assuming it's the same problem). It's spinning
> again at ~25 or so iterations without a failure so far, so I'd have to
> wait and see how reliable the reproducer really is. Though if it doesn't
> reoccur soonish, perhaps I'll try reducing dirty_bytes a bit more...
>
> My suspicion based on these characteristics would be that the blocking
> limit triggers more aggressive reclaim/invalidation, and thus helps
> detect the problem sooner. If reflink is involved purely as a cache
> invalidation step (i.e. so a subsequent read will hit the disk and
> detect a cache inconsistency), then it might be interesting to see if it
> can still be reproduced without reflink operations enabled but instead
> with some combination of the -f/-X fsx flags to perform more flush
> invals and on-disk data checks..

Hm. I didn't try -f or lowering dirty_bytes, but with the reflink
operations disabled, g522 ran for 3 hours before I gave up and killed
it. I would've thought that the fallocate zero/collapse/insert range
functions (which use the same flush/unmap helper) would have sufficed to
make the problem happen, but ... it didn't.

I think I'll try changing dirty_bytes next, to see if I can reproduce
the problem that way. I'm not surprised that you had to set dirty_bytes
to 1MB, since 522 is only ever creating a 600K file anyway.

(Hopefully willy will be back next week to help us shed some light on
this.)

--D

> Brian
>
> > Unfortunately the second ftrace attempt ate some trace data, so I was
> > unable to figure out if the same thing happened again.
> >
> > At this point I really need to get on reviewing patches for 5.20, so
> > I'll try to keep poking at this (examining the trace data requires a lot
> > of concentration which isn't really possible while sawzall construction
> > is going on at home) but at worst I can ask Linus to merge a patch for
> > 5.19 final that makes setting mapping_set_large_folio a
> > Kconfig/CONFIG_XFS_DEBUG option.
> >
> > --D
> >
> > >
> > > Brian
> > >
> > > > --D
> > > >
> > > > > Cheers,
> > > > >
> > > > > Dave.
> > > > > --
> > > > > Dave Chinner
> > > > > [email protected]
> > > >
> > >
> >
>

2022-08-17 10:32:26

by Dave Chinner

[permalink] [raw]

Subject: Re: Multi-page folio issues in 5.19-rc4 (was [PATCH v3 25/25] xfs: Support large folios)

On Wed, Jun 29, 2022 at 08:57:30AM -0400, Brian Foster wrote:
> On Tue, Jun 28, 2022 at 04:21:55PM -0700, Darrick J. Wong wrote:
> > On Wed, Jun 29, 2022 at 08:17:57AM +1000, Dave Chinner wrote:
> > > On Tue, Jun 28, 2022 at 02:18:24PM +0100, Matthew Wilcox wrote:
> > > > On Tue, Jun 28, 2022 at 12:31:55PM +0100, Matthew Wilcox wrote:
> > > > > On Tue, Jun 28, 2022 at 12:27:40PM +0100, Matthew Wilcox wrote:
> > > > > > On Tue, Jun 28, 2022 at 05:31:20PM +1000, Dave Chinner wrote:
> > > > > > > So using this technique, I've discovered that there's a dirty page
> > > > > > > accounting leak that eventually results in fsx hanging in
> > > > > > > balance_dirty_pages().
> > > > > >
> > > > > > Alas, I think this is only an accounting error, and not related to
> > > > > > the problem(s) that Darrick & Zorro are seeing. I think what you're
> > > > > > seeing is dirty pages being dropped at truncation without the
> > > > > > appropriate accounting. ie this should be the fix:
> > > > >
> > > > > Argh, try one that actually compiles.
> > > >
> > > > ... that one's going to underflow the accounting. Maybe I shouldn't
> > > > be writing code at 6am?
> > > >
> > > > diff --git a/mm/huge_memory.c b/mm/huge_memory.c
> > > > index f7248002dad9..4eec6ee83e44 100644
> > > > --- a/mm/huge_memory.c
> > > > +++ b/mm/huge_memory.c
> > > > @@ -18,6 +18,7 @@
> > > > #include <linux/shrinker.h>
> > > > #include <linux/mm_inline.h>
> > > > #include <linux/swapops.h>
> > > > +#include <linux/backing-dev.h>
> > > > #include <linux/dax.h>
> > > > #include <linux/khugepaged.h>
> > > > #include <linux/freezer.h>
> > > > @@ -2439,11 +2440,15 @@ static void __split_huge_page(struct page *page, struct list_head *list,
> > > > __split_huge_page_tail(head, i, lruvec, list);
> > > > /* Some pages can be beyond EOF: drop them from page cache */
> > > > if (head[i].index >= end) {
> > > > - ClearPageDirty(head + i);
> > > > - __delete_from_page_cache(head + i, NULL);
> > > > + struct folio *tail = page_folio(head + i);
> > > > +
> > > > if (shmem_mapping(head->mapping))
> > > > shmem_uncharge(head->mapping->host, 1);
> > > > - put_page(head + i);
> > > > + else if (folio_test_clear_dirty(tail))
> > > > + folio_account_cleaned(tail,
> > > > + inode_to_wb(folio->mapping->host));
> > > > + __filemap_remove_folio(tail, NULL);
> > > > + folio_put(tail);
> > > > } else if (!PageAnon(page)) {
> > > > __xa_store(&head->mapping->i_pages, head[i].index,
> > > > head + i, 0);
> > > >
> > >
> > > Yup, that fixes the leak.
> > >
> > > Tested-by: Dave Chinner <[email protected]>
> >
> > Four hours of generic/522 running is long enough to conclude that this
> > is likely the fix for my problem and migrate long soak testing to my
> > main g/522 rig and:
> >
> > Tested-by: Darrick J. Wong <[email protected]>
> >
>
> Just based on Willy's earlier comment.. what I would probably be a
> little careful/curious about here is whether the accounting fix leads to
> an indirect behavior change that does impact reproducibility of the
> corruption problem. For example, does artificially escalated dirty page
> tracking lead to increased reclaim/writeback activity than might
> otherwise occur, and thus contend with the fs workload?

Yeah, I think you're right, Brian. There is an underlying problem
here, and the writeback/memory pressure bugs exposed it for everyone
to see. IOWs, we do indeed have a pre-existing problem with partial
writes, iomap, unwritten extents, writeback and memory reclaim.

(Please s/page/folio/ rather than complain I'm calling things pages
and not folios, I'm juggling between RHEL-8 code and upstream
here and it's just easier to refer to everything as pages as I write
it.)

(I'm assuming people are familiar with the iomap buffered IO code
at this point.)

Let's do a partial write into a page. Let's say the second half of
the page. __iomap_begin_write() drops into iomap_adjust_read_range()
to determine the range that needs zeroing or reading from disk. We
then call iomap_block_needs_zeroing() to determine if we zero -
which we do if it's a newly allocated or unwritten extent. Otherwise
we read it from disk.

Let's put this partial write over a large unwritten extent, which
means we zero the first part of the page, and that writing it back
runs unwritten extent conversion at IO completion. This changes the
extent backing this file offset from unwritten to written.

Then, add extreme memory pressure, so writeback is already running
and soon after the page has been dirtied it gets marked for
cleaning. Therefore, we have the possibility of background IO
submission and memory reclaim occurring at the same time as new
writes are occurring to the file.

To that end, let's add a large racing write that *ends* on this same
page that we have already partially filled with data - it will fill
the start of the page that currently contains zeros with real data.

Let's start that write() just before writeback of the already
uptodate partial page starts. iomap_apply will map the entire
write (and well beyond) as a single unwritten extent. This extent is
the same extent that the original page in the page cache already
covers, and this write would end by filling the remaining part of
that write.

While that second write is running around in the page cache
copy-in loop for the unwritten extent that backs that range, IO
submission runs and completes and converts the original partially
filled page to a written extent, then marks it clean.

[ Ayup, the extent map of the file just changed to be different
to the iomap that the current write() thinks the file layout has. ]

Further, because the partially written page is now clean,
memory reclaim can snaffle it up and it gets removed from the page
cache.

The second write finally gets to the last page of it's write and
doesn't find it in the page cache because memory reclaim removed it.
So it pulls a new page into the page cache in iomap_begin_write(),
and then in __iomap_begin_write we see that the we need to fill the
second half of the page with either zeros or data from disk.

We know that this data is on disk as the extent is now in written
state. *However*, the cached iomap that we are currently using for
the write() says the range is -unwritten-, and so at that point
iomap_block_needs_zeroing() says "page needs zeroing". Hence
__iomap_begin_write zeroes the second half of the page instead of
reading it from disk, obliterating the data that the previous write
had already written there.

Ouchy, we have data corruption because the incoming write holds a
stale cached iomap......

At this point, I had a nasty feeling of deja vu.

Oh, yeah, we already infrastructure in place to avoid using stale
cached iomaps in ->writepages....

That is, iomap_writepage_map() calls ->map_block for every filesytem
block, even though the iomap_writepage_ctx has a cached iomap in it.
That's so the filesystem can check that the cached iomap is still
valid whilst the page we are writing back is held locked. This
protects writeback against races with truncate, hole punch, etc.

XFS does this via a call to xfs_imap_valid() - we keep a generation
number in the XFS extent trees that is bumped on every change so
that we can check whether a cached iomap is still valid. If the
generation numbers don't match, then we generate a new iomap for the
writepage context....

What is clear to me now is that we have the same stale cached iomap
problem with iomap_apply() because writeback can change the extent
map state in a way that influence incoming writes and those updates
are not in any way serialised against the incoming write IO path.

Hence we have to validate that the cached iomap is not stale before
we decide what to do with a new page in the page cache (zero or read
from disk), and we have to do this iomap validation when the newly
instantiated page is locked and ready for initialisation.

I have not thought past this point - I'm only *just* smart enough to
be able to dig out the root cause of this problem. No scratch that,
I'm not smart, just stubborn enough to ignore the fact I've got the
analysis wrong at least a dozen times already.

That said, this stale mapping problem existed long before we started
using unwritten extents for delayed allocation. The change to use
unwritten extents (to fix other data corruption issues) exposed us
to in-memory zeroing in this race condition case rather reading the
block of data from disk. We just hadn't armed the landmine....

I suspect we are going to need a new iomap validation operation, and
require the iomap actors to be able to handle iomap validation
failure. What that looks like, I don't know as my brain
turned to goo and dribbled out my ears about 4 hours ago....

BTW, all the credit for finding this goes to Frank Sorenson - he did
all the hard work of reproducing the issue and narrowing down the
scope of the problem to a handful of XFS commits combined with
writeback and memory reclaim interactions. Without his hard work,
we'd still have no idea what was going on.....

Cheers,

Dave.
--
Dave Chinner
[email protected]

2022-08-18 00:33:39

by Darrick J. Wong

[permalink] [raw]

Subject: Re: Multi-page folio issues in 5.19-rc4 (was [PATCH v3 25/25] xfs: Support large folios)

On Wed, Aug 17, 2022 at 07:36:27PM +1000, Dave Chinner wrote:
> On Wed, Jun 29, 2022 at 08:57:30AM -0400, Brian Foster wrote:
> > On Tue, Jun 28, 2022 at 04:21:55PM -0700, Darrick J. Wong wrote:
> > > On Wed, Jun 29, 2022 at 08:17:57AM +1000, Dave Chinner wrote:
> > > > On Tue, Jun 28, 2022 at 02:18:24PM +0100, Matthew Wilcox wrote:
> > > > > On Tue, Jun 28, 2022 at 12:31:55PM +0100, Matthew Wilcox wrote:
> > > > > > On Tue, Jun 28, 2022 at 12:27:40PM +0100, Matthew Wilcox wrote:
> > > > > > > On Tue, Jun 28, 2022 at 05:31:20PM +1000, Dave Chinner wrote:
> > > > > > > > So using this technique, I've discovered that there's a dirty page
> > > > > > > > accounting leak that eventually results in fsx hanging in
> > > > > > > > balance_dirty_pages().
> > > > > > >
> > > > > > > Alas, I think this is only an accounting error, and not related to
> > > > > > > the problem(s) that Darrick & Zorro are seeing. I think what you're
> > > > > > > seeing is dirty pages being dropped at truncation without the
> > > > > > > appropriate accounting. ie this should be the fix:
> > > > > >
> > > > > > Argh, try one that actually compiles.
> > > > >
> > > > > ... that one's going to underflow the accounting. Maybe I shouldn't
> > > > > be writing code at 6am?
> > > > >
> > > > > diff --git a/mm/huge_memory.c b/mm/huge_memory.c
> > > > > index f7248002dad9..4eec6ee83e44 100644
> > > > > --- a/mm/huge_memory.c
> > > > > +++ b/mm/huge_memory.c
> > > > > @@ -18,6 +18,7 @@
> > > > > #include <linux/shrinker.h>
> > > > > #include <linux/mm_inline.h>
> > > > > #include <linux/swapops.h>
> > > > > +#include <linux/backing-dev.h>
> > > > > #include <linux/dax.h>
> > > > > #include <linux/khugepaged.h>
> > > > > #include <linux/freezer.h>
> > > > > @@ -2439,11 +2440,15 @@ static void __split_huge_page(struct page *page, struct list_head *list,
> > > > > __split_huge_page_tail(head, i, lruvec, list);
> > > > > /* Some pages can be beyond EOF: drop them from page cache */
> > > > > if (head[i].index >= end) {
> > > > > - ClearPageDirty(head + i);
> > > > > - __delete_from_page_cache(head + i, NULL);
> > > > > + struct folio *tail = page_folio(head + i);
> > > > > +
> > > > > if (shmem_mapping(head->mapping))
> > > > > shmem_uncharge(head->mapping->host, 1);
> > > > > - put_page(head + i);
> > > > > + else if (folio_test_clear_dirty(tail))
> > > > > + folio_account_cleaned(tail,
> > > > > + inode_to_wb(folio->mapping->host));
> > > > > + __filemap_remove_folio(tail, NULL);
> > > > > + folio_put(tail);
> > > > > } else if (!PageAnon(page)) {
> > > > > __xa_store(&head->mapping->i_pages, head[i].index,
> > > > > head + i, 0);
> > > > >
> > > >
> > > > Yup, that fixes the leak.
> > > >
> > > > Tested-by: Dave Chinner <[email protected]>
> > >
> > > Four hours of generic/522 running is long enough to conclude that this
> > > is likely the fix for my problem and migrate long soak testing to my
> > > main g/522 rig and:
> > >
> > > Tested-by: Darrick J. Wong <[email protected]>
> > >
> >
> > Just based on Willy's earlier comment.. what I would probably be a
> > little careful/curious about here is whether the accounting fix leads to
> > an indirect behavior change that does impact reproducibility of the
> > corruption problem. For example, does artificially escalated dirty page
> > tracking lead to increased reclaim/writeback activity than might
> > otherwise occur, and thus contend with the fs workload?
>
> Yeah, I think you're right, Brian. There is an underlying problem
> here, and the writeback/memory pressure bugs exposed it for everyone
> to see. IOWs, we do indeed have a pre-existing problem with partial
> writes, iomap, unwritten extents, writeback and memory reclaim.
>
> (Please s/page/folio/ rather than complain I'm calling things pages
> and not folios, I'm juggling between RHEL-8 code and upstream
> here and it's just easier to refer to everything as pages as I write
> it.)
>
> (I'm assuming people are familiar with the iomap buffered IO code
> at this point.)
>
> Let's do a partial write into a page. Let's say the second half of
> the page. __iomap_begin_write() drops into iomap_adjust_read_range()
> to determine the range that needs zeroing or reading from disk. We
> then call iomap_block_needs_zeroing() to determine if we zero -
> which we do if it's a newly allocated or unwritten extent. Otherwise
> we read it from disk.
>
> Let's put this partial write over a large unwritten extent, which
> means we zero the first part of the page, and that writing it back
> runs unwritten extent conversion at IO completion. This changes the
> extent backing this file offset from unwritten to written.
>
> Then, add extreme memory pressure, so writeback is already running
> and soon after the page has been dirtied it gets marked for
> cleaning. Therefore, we have the possibility of background IO
> submission and memory reclaim occurring at the same time as new
> writes are occurring to the file.
>
> To that end, let's add a large racing write that *ends* on this same
> page that we have already partially filled with data - it will fill
> the start of the page that currently contains zeros with real data.
>
> Let's start that write() just before writeback of the already
> uptodate partial page starts. iomap_apply will map the entire
> write (and well beyond) as a single unwritten extent. This extent is
> the same extent that the original page in the page cache already
> covers, and this write would end by filling the remaining part of
> that write.
>
> While that second write is running around in the page cache
> copy-in loop for the unwritten extent that backs that range, IO
> submission runs and completes and converts the original partially
> filled page to a written extent, then marks it clean.

So if I understand this correctly --

Thread 1 fallocates 1G of contiguous space and writes 38 bytes to the
end of that gigabyte. We instantiate a folio X for the region, zero the
parts we're not going to write, and copy the bytes we did want to write
into folio X. The folio is now uptodate and dirty. Thread 1 goes away.

Thread 2 starts a (1G-38) write of that fallocated (and mostly
unwritten) space. It proceeds very slowly, one page at a time; it'll be
a while before it gets to folio X.

ramsnake.exe fires up and pushes the system hard into memory reclaim.
Reclaim initiates dirty writeback of folio X, which writes it to disk
and does the unwritten extent conversion. Reclaim then removes X from
the page cache, and frees X.

Thread 2 finally gets to the end of its 1G write. It is still using the
cached 1G unwritten mapping from before, unaware that some of the
mapping has changed to written state. It grabs a folio for (1G - 38),
but it gets folio Y instead of folio X. Y is not uptodate, so thread 2
copies bytes from userspace and zeroes the last 38 bytes.

**WRONG**

We now have folio Y with zeroes in the last 38 bytes, instead of
whatever thread 1 wrote. Writeback pushes Y to disk, clobbering those
38 bytes forever.

> [ Ayup, the extent map of the file just changed to be different
> to the iomap that the current write() thinks the file layout has. ]
>
> Further, because the partially written page is now clean,
> memory reclaim can snaffle it up and it gets removed from the page
> cache.
>
> The second write finally gets to the last page of it's write and
> doesn't find it in the page cache because memory reclaim removed it.
> So it pulls a new page into the page cache in iomap_begin_write(),
> and then in __iomap_begin_write we see that the we need to fill the
> second half of the page with either zeros or data from disk.
>
> We know that this data is on disk as the extent is now in written
> state. *However*, the cached iomap that we are currently using for
> the write() says the range is -unwritten-, and so at that point
> iomap_block_needs_zeroing() says "page needs zeroing". Hence
> __iomap_begin_write zeroes the second half of the page instead of
> reading it from disk, obliterating the data that the previous write
> had already written there.

Yup.

> Ouchy, we have data corruption because the incoming write holds a
> stale cached iomap......
>
> At this point, I had a nasty feeling of deja vu.
>
> Oh, yeah, we already infrastructure in place to avoid using stale
> cached iomaps in ->writepages....
>
> That is, iomap_writepage_map() calls ->map_block for every filesytem
> block, even though the iomap_writepage_ctx has a cached iomap in it.
> That's so the filesystem can check that the cached iomap is still
> valid whilst the page we are writing back is held locked. This
> protects writeback against races with truncate, hole punch, etc.
>
> XFS does this via a call to xfs_imap_valid() - we keep a generation
> number in the XFS extent trees that is bumped on every change so
> that we can check whether a cached iomap is still valid. If the
> generation numbers don't match, then we generate a new iomap for the
> writepage context....
>
> What is clear to me now is that we have the same stale cached iomap
> problem with iomap_apply() because writeback can change the extent
> map state in a way that influence incoming writes and those updates
> are not in any way serialised against the incoming write IO path.
>
> Hence we have to validate that the cached iomap is not stale before
> we decide what to do with a new page in the page cache (zero or read
> from disk), and we have to do this iomap validation when the newly
> instantiated page is locked and ready for initialisation.
>
> I have not thought past this point - I'm only *just* smart enough to
> be able to dig out the root cause of this problem. No scratch that,
> I'm not smart, just stubborn enough to ignore the fact I've got the
> analysis wrong at least a dozen times already.
>
> That said, this stale mapping problem existed long before we started
> using unwritten extents for delayed allocation. The change to use
> unwritten extents (to fix other data corruption issues) exposed us
> to in-memory zeroing in this race condition case rather reading the
> block of data from disk. We just hadn't armed the landmine....
>
> I suspect we are going to need a new iomap validation operation, and
> require the iomap actors to be able to handle iomap validation
> failure. What that looks like, I don't know as my brain
> turned to goo and dribbled out my ears about 4 hours ago....

Euughg. I suppose this means that ->iomap_begin has to be able to stuff
xfs_ifork.if_seq into a cookie value that we can set in struct iomap
somewhere? And then iomap has to be able to call back to XFS to
revalidate iomap.cookie? And if iomap.cookie != xfs_ifork.if_seq, then
I guess iomap will just ... unlock and put the folio, and return EAGAIN
(or something) so that its caller will return however many bytes have
been dirtied to iomap_apply so that _apply will go get a fresh mapping?

> BTW, all the credit for finding this goes to Frank Sorenson - he did
> all the hard work of reproducing the issue and narrowing down the
> scope of the problem to a handful of XFS commits combined with
> writeback and memory reclaim interactions. Without his hard work,
> we'd still have no idea what was going on.....

Thanks a bunch to him!!!

--D

> Cheers,
>
> Dave.
> --
> Dave Chinner
> [email protected]

2022-08-18 22:02:12

by Dave Chinner

[permalink] [raw]

Subject: Re: Multi-page folio issues in 5.19-rc4 (was [PATCH v3 25/25] xfs: Support large folios)

On Wed, Aug 17, 2022 at 04:53:31PM -0700, Darrick J. Wong wrote:
> On Wed, Aug 17, 2022 at 07:36:27PM +1000, Dave Chinner wrote:
> > On Wed, Jun 29, 2022 at 08:57:30AM -0400, Brian Foster wrote:
> > > Just based on Willy's earlier comment.. what I would probably be a
> > > little careful/curious about here is whether the accounting fix leads to
> > > an indirect behavior change that does impact reproducibility of the
> > > corruption problem. For example, does artificially escalated dirty page
> > > tracking lead to increased reclaim/writeback activity than might
> > > otherwise occur, and thus contend with the fs workload?
> >
> > Yeah, I think you're right, Brian. There is an underlying problem
> > here, and the writeback/memory pressure bugs exposed it for everyone
> > to see. IOWs, we do indeed have a pre-existing problem with partial
> > writes, iomap, unwritten extents, writeback and memory reclaim.
> >
> > (Please s/page/folio/ rather than complain I'm calling things pages
> > and not folios, I'm juggling between RHEL-8 code and upstream
> > here and it's just easier to refer to everything as pages as I write
> > it.)
> >
> > (I'm assuming people are familiar with the iomap buffered IO code
> > at this point.)
> >
> > Let's do a partial write into a page. Let's say the second half of
> > the page. __iomap_begin_write() drops into iomap_adjust_read_range()
> > to determine the range that needs zeroing or reading from disk. We
> > then call iomap_block_needs_zeroing() to determine if we zero -
> > which we do if it's a newly allocated or unwritten extent. Otherwise
> > we read it from disk.
> >
> > Let's put this partial write over a large unwritten extent, which
> > means we zero the first part of the page, and that writing it back
> > runs unwritten extent conversion at IO completion. This changes the
> > extent backing this file offset from unwritten to written.
> >
> > Then, add extreme memory pressure, so writeback is already running
> > and soon after the page has been dirtied it gets marked for
> > cleaning. Therefore, we have the possibility of background IO
> > submission and memory reclaim occurring at the same time as new
> > writes are occurring to the file.
> >
> > To that end, let's add a large racing write that *ends* on this same
> > page that we have already partially filled with data - it will fill
> > the start of the page that currently contains zeros with real data.
> >
> > Let's start that write() just before writeback of the already
> > uptodate partial page starts. iomap_apply will map the entire
> > write (and well beyond) as a single unwritten extent. This extent is
> > the same extent that the original page in the page cache already
> > covers, and this write would end by filling the remaining part of
> > that write.
> >
> > While that second write is running around in the page cache
> > copy-in loop for the unwritten extent that backs that range, IO
> > submission runs and completes and converts the original partially
> > filled page to a written extent, then marks it clean.
>
> So if I understand this correctly --
>
> Thread 1 fallocates 1G of contiguous space and writes 38 bytes to the
> end of that gigabyte. We instantiate a folio X for the region, zero the
> parts we're not going to write, and copy the bytes we did want to write
> into folio X. The folio is now uptodate and dirty. Thread 1 goes away.
>
> Thread 2 starts a (1G-38) write of that fallocated (and mostly
> unwritten) space. It proceeds very slowly, one page at a time; it'll be
> a while before it gets to folio X.
>
> ramsnake.exe fires up and pushes the system hard into memory reclaim.
> Reclaim initiates dirty writeback of folio X, which writes it to disk
> and does the unwritten extent conversion. Reclaim then removes X from
> the page cache, and frees X.
>
> Thread 2 finally gets to the end of its 1G write. It is still using the
> cached 1G unwritten mapping from before, unaware that some of the
> mapping has changed to written state. It grabs a folio for (1G - 38),
> but it gets folio Y instead of folio X. Y is not uptodate, so thread 2
> copies bytes from userspace and zeroes the last 38 bytes.
>
> **WRONG**
>
> We now have folio Y with zeroes in the last 38 bytes, instead of
> whatever thread 1 wrote. Writeback pushes Y to disk, clobbering those
> 38 bytes forever.

Yes, that's pretty much it.

> > [ Ayup, the extent map of the file just changed to be different
> > to the iomap that the current write() thinks the file layout has. ]
> >
> > Further, because the partially written page is now clean,
> > memory reclaim can snaffle it up and it gets removed from the page
> > cache.
> >
> > The second write finally gets to the last page of it's write and
> > doesn't find it in the page cache because memory reclaim removed it.
> > So it pulls a new page into the page cache in iomap_begin_write(),
> > and then in __iomap_begin_write we see that the we need to fill the
> > second half of the page with either zeros or data from disk.
> >
> > We know that this data is on disk as the extent is now in written
> > state. *However*, the cached iomap that we are currently using for
> > the write() says the range is -unwritten-, and so at that point
> > iomap_block_needs_zeroing() says "page needs zeroing". Hence
> > __iomap_begin_write zeroes the second half of the page instead of
> > reading it from disk, obliterating the data that the previous write
> > had already written there.
>
> Yup.
>
> > Ouchy, we have data corruption because the incoming write holds a
> > stale cached iomap......
> >
> > At this point, I had a nasty feeling of deja vu.
> >
> > Oh, yeah, we already infrastructure in place to avoid using stale
> > cached iomaps in ->writepages....
> >
> > That is, iomap_writepage_map() calls ->map_block for every filesytem
> > block, even though the iomap_writepage_ctx has a cached iomap in it.
> > That's so the filesystem can check that the cached iomap is still
> > valid whilst the page we are writing back is held locked. This
> > protects writeback against races with truncate, hole punch, etc.
> >
> > XFS does this via a call to xfs_imap_valid() - we keep a generation
> > number in the XFS extent trees that is bumped on every change so
> > that we can check whether a cached iomap is still valid. If the
> > generation numbers don't match, then we generate a new iomap for the
> > writepage context....
> >
> > What is clear to me now is that we have the same stale cached iomap
> > problem with iomap_apply() because writeback can change the extent
> > map state in a way that influence incoming writes and those updates
> > are not in any way serialised against the incoming write IO path.
> >
> > Hence we have to validate that the cached iomap is not stale before
> > we decide what to do with a new page in the page cache (zero or read
> > from disk), and we have to do this iomap validation when the newly
> > instantiated page is locked and ready for initialisation.
> >
> > I have not thought past this point - I'm only *just* smart enough to
> > be able to dig out the root cause of this problem. No scratch that,
> > I'm not smart, just stubborn enough to ignore the fact I've got the
> > analysis wrong at least a dozen times already.
> >
> > That said, this stale mapping problem existed long before we started
> > using unwritten extents for delayed allocation. The change to use
> > unwritten extents (to fix other data corruption issues) exposed us
> > to in-memory zeroing in this race condition case rather reading the
> > block of data from disk. We just hadn't armed the landmine....
> >
> > I suspect we are going to need a new iomap validation operation, and
> > require the iomap actors to be able to handle iomap validation
> > failure. What that looks like, I don't know as my brain
> > turned to goo and dribbled out my ears about 4 hours ago....
>
> Euughg. I suppose this means that ->iomap_begin has to be able to stuff
> xfs_ifork.if_seq into a cookie value that we can set in struct iomap
> somewhere? And then iomap has to be able to call back to XFS to
> revalidate iomap.cookie? And if iomap.cookie != xfs_ifork.if_seq, then
> I guess iomap will just ... unlock and put the folio, and return EAGAIN
> (or something) so that its caller will return however many bytes have
> been dirtied to iomap_apply so that _apply will go get a fresh mapping?

Yeah, something like that. I have not had time to think this through
any further than what you've just written. It does not look like it
will be trivial, though, and it points out that every filesystem
using iomap for multi-page extent maps will need to implement iomap
invalidation detection in some way.

We already have that for XFS with the sequence numbers, but I'm
betting that none of the other filesystems that use iomap have the
internal infrastructure to track racing extent map changes...

Cheers,

Dave.
--
Dave Chinner
[email protected]