XFS long delays on disk full

XFS long delays on disk full

[Andi Kleen]

Hi,

I was doing some testing on a 4.18-rc1 kernel, and a single threaded
test wrote a fairly large file to a XFS file system, causing it to
fill up.

After that the process hung in D state for a long time, and only
recovered after several minutes. Here's the backtrace during
the hang:

[<0>] wb_wait_for_completion+0x5e/0x90
[<0>] sync_inodes_sb+0xc9/0x290
[<0>] xfs_flush_inodes+0x25/0x30 [xfs]
[<0>] xfs_file_buffered_aio_write+0x2be/0x300 [xfs]
[<0>] __vfs_write+0x114/0x1a0
[<0>] vfs_write+0xad/0x1a0
[<0>] ksys_write+0x52/0xc0
[<0>] do_syscall_64+0x5b/0x160
[<0>] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[<0>] 0xffffffffffffffff

There were no IO errors or similar.

Expected? Already fixed?

Thanks,
-Andi

Re: XFS long delays on disk full

[Darrick J. Wong]

On Wed, Jul 18, 2018 at 02:22:40PM -0700, Andi Kleen wrote:
> Hi,
> 
> I was doing some testing on a 4.18-rc1 kernel, and a single threaded
> test wrote a fairly large file to a XFS file system, causing it to
> fill up.
> 
> After that the process hung in D state for a long time, and only
> recovered after several minutes. Here's the backtrace during
> the hang:
> 
> [<0>] wb_wait_for_completion+0x5e/0x90
> [<0>] sync_inodes_sb+0xc9/0x290

Hmm, these two:

> [<0>] xfs_flush_inodes+0x25/0x30 [xfs]
> [<0>] xfs_file_buffered_aio_write+0x2be/0x300 [xfs]

Offhand I'd guess (while awayish at OSCON) that the fs hit ENOSPC while
trying to write() the file so now we're scanning the fs like mad trying
to free up space preallocations from any open file in the fs.

How big is the fs, how big is the file, how many inodes, how many are
open, which kernel?

--D

> [<0>] __vfs_write+0x114/0x1a0
> [<0>] vfs_write+0xad/0x1a0
> [<0>] ksys_write+0x52/0xc0
> [<0>] do_syscall_64+0x5b/0x160
> [<0>] entry_SYSCALL_64_after_hwframe+0x44/0xa9
> [<0>] 0xffffffffffffffff
> 
> There were no IO errors or similar.
> 
> Expected? Already fixed?
> 
> Thanks,
> -Andi
> 
> --
> To unsubscribe from this list: send the line "unsubscribe linux-xfs" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: XFS long delays on disk full

[Andi Kleen]

On Wed, Jul 18, 2018 at 04:25:33PM -0700, Darrick J. Wong wrote:
> On Wed, Jul 18, 2018 at 02:22:40PM -0700, Andi Kleen wrote:
> > Hi,
> > 
> > I was doing some testing on a 4.18-rc1 kernel, and a single threaded
> > test wrote a fairly large file to a XFS file system, causing it to
> > fill up.
> > 
> > After that the process hung in D state for a long time, and only
> > recovered after several minutes. Here's the backtrace during
> > the hang:
> > 
> > [<0>] wb_wait_for_completion+0x5e/0x90
> > [<0>] sync_inodes_sb+0xc9/0x290
> 
> Hmm, these two:
> 
> > [<0>] xfs_flush_inodes+0x25/0x30 [xfs]
> > [<0>] xfs_file_buffered_aio_write+0x2be/0x300 [xfs]
> 
> Offhand I'd guess (while awayish at OSCON) that the fs hit ENOSPC while
> trying to write() the file so now we're scanning the fs like mad trying
> to free up space preallocations from any open file in the fs.
> 
> How big is the fs, how big is the file, how many inodes, how many are
> open, which kernel?

Kernel 2.18-rc1

/dev/sdb1       233G  211G   23G  91% /data
Filesystem     Inodes IUsed IFree IUse% Mounted on
/dev/sdb1         90M   59K   89M    1% /data

Very few files were open. The file was ~23G as it filled up
the file (I now deleted it)

-Andi

Re: XFS long delays on disk full

[Darrick J. Wong]

On Fri, Jul 20, 2018 at 10:58:37AM -0700, Andi Kleen wrote:
> On Wed, Jul 18, 2018 at 04:25:33PM -0700, Darrick J. Wong wrote:
> > On Wed, Jul 18, 2018 at 02:22:40PM -0700, Andi Kleen wrote:
> > > Hi,
> > > 
> > > I was doing some testing on a 4.18-rc1 kernel, and a single threaded
> > > test wrote a fairly large file to a XFS file system, causing it to
> > > fill up.
> > > 
> > > After that the process hung in D state for a long time, and only
> > > recovered after several minutes. Here's the backtrace during
> > > the hang:
> > > 
> > > [<0>] wb_wait_for_completion+0x5e/0x90
> > > [<0>] sync_inodes_sb+0xc9/0x290
> > 
> > Hmm, these two:
> > 
> > > [<0>] xfs_flush_inodes+0x25/0x30 [xfs]
> > > [<0>] xfs_file_buffered_aio_write+0x2be/0x300 [xfs]
> > 
> > Offhand I'd guess (while awayish at OSCON) that the fs hit ENOSPC while
> > trying to write() the file so now we're scanning the fs like mad trying
> > to free up space preallocations from any open file in the fs.
> > 
> > How big is the fs, how big is the file, how many inodes, how many are
> > open, which kernel?
> 
> Kernel 2.18-rc1
> 
> /dev/sdb1       233G  211G   23G  91% /data
> Filesystem     Inodes IUsed IFree IUse% Mounted on
> /dev/sdb1         90M   59K   89M    1% /data
> 
> Very few files were open. The file was ~23G as it filled up
> the file (I now deleted it)

Yep, that looks like xfs scraping around trying to find space when the
fs is nearly full.

--D

> 
> -Andi
> 
> --
> To unsubscribe from this list: send the line "unsubscribe linux-xfs" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: XFS long delays on disk full

[Andi Kleen]

> Yep, that looks like xfs scraping around trying to find space when the
> fs is nearly full.

Okay. Not sure what it is doing. The disk isn't that large after all,
and it's not clear why it takes that long to check a few AGs.

Can something be done about it?

It would be good enough for me if it was interruptible, so that 
Ctrl-C just worked.

-Andi