On Mon, Apr 28, 2014 at 05:51:31PM -0600, Bob Mastors wrote:
> Log output attached.
> The xfs filesystem being mounted and unmounted is the only xfs filesystem
> on the system.
> On Mon, Apr 28, 2014 at 5:45 PM, Dave Chinner <david@xxxxxxxxxxxxx> wrote:
> > On Mon, Apr 28, 2014 at 04:29:02PM -0600, Bob Mastors wrote:
> > > Greetings,
> > >
> > > I have an xfs umount hang caused by forcing the block device to return
> > > i/o errors while copying files to the filesystem.
> > > Detailed steps to reproduce the problem on virtualbox are below.
> > >
> > > The linux version is a recent pull and reports as 3.15.0-rc3.
> > >
> > > [ 2040.248096] INFO: task umount:10303 blocked for more than 120 seconds.
> > > [ 2040.323947] Not tainted 3.15.0-rc3 #4
> > > [ 2040.343423] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> > disables
> > > this message.
> > > [ 2040.352665] umount D ffffffff8180fe40 0 10303 8691
> > > 0x00000000
> > > [ 2040.404918] ffff88001e33dd58 0000000000000086 ffff88001e33dd48
> > > ffffffff81080f82
> > > [ 2040.489901] ffff88001b311900 0000000000013180 ffff88001e33dfd8
> > > 0000000000013180
> > > [ 2040.534772] ffff88003daa3200 ffff88001b311900 ffff88002421aec0
> > > ffff88002421ae80
> > > [ 2040.587450] Call Trace:
> > > [ 2040.592176] [<ffffffff81080f82>] ? try_to_wake_up+0x232/0x2b0
> > > [ 2040.620212] [<ffffffff816c54d9>] schedule+0x29/0x70
> > > [ 2040.627685] [<ffffffffa04c4cd6>] xfs_ail_push_all_sync+0x96/0xd0
> > [xfs]
> > > [ 2040.632236] [<ffffffff81092230>] ? __wake_up_sync+0x20/0x20
> > > [ 2040.659105] [<ffffffffa04731a3>] xfs_unmountfs+0x63/0x160 [xfs]
> > > [ 2040.691774] [<ffffffffa0478f65>] ? kmem_free+0x35/0x40 [xfs]
> > > [ 2040.698610] [<ffffffffa0474cf5>] xfs_fs_put_super+0x25/0x60 [xfs]
> > > [ 2040.706838] [<ffffffff8119561e>] generic_shutdown_super+0x7e/0x100
> > > [ 2040.723958] [<ffffffff811956d0>] kill_block_super+0x30/0x80
> > > [ 2040.734963] [<ffffffff8119591d>] deactivate_locked_super+0x4d/0x80
> > > [ 2040.745485] [<ffffffff8119652e>] deactivate_super+0x4e/0x70
> > > [ 2040.751274] [<ffffffff811b1d42>] mntput_no_expire+0xd2/0x160
> > > [ 2040.755894] [<ffffffff811b2fff>] SyS_umount+0xaf/0x3b0
> > > [ 2040.761032] [<ffffffff816d1592>] system_call_fastpath+0x16/0x1b
> > > [ .060058] XFS (sdb): xfs_log_force: error 5 returned.
> > > [ 268059] XFS (sdb): xfs_log_force: error 5 returned.
> > >
> > > I took a look at xfs_ail_push_all_sync and it is pretty easy to see
> > > the hang. But it is not obvious to me how to fix it.
> > > Any ideas would be appreciated.
> > >
> > > I am available to run additional tests or capture more logging
> > > or whatever if that would help.
> > What's the entire log output from the first shutdown message?
So what is the AIL stuck on? Can you trace the xfs_ail* trace points
when it is in shutdown like this and post the output of the report?
> [ 1318.816643] XFS (sdb): metadata I/O error: block 0x19fc80
> ("xfs_buf_iodone_callbacks") error 5 numblks 16
> [ 1318.818080] XFS (sdb): metadata I/O error: block 0x1025cf ("xlog_iodone")
> error 5 numblks 64
> [ 1318.819350] XFS (sdb): xfs_do_force_shutdown(0x2) called from line 1170 of
> file fs/xfs/xfs_log.c. Return address = 0xffffffffa04b9859
> [ 1318.821089] XFS (sdb): Log I/O Error Detected. Shutting down filesystem
> [ 1318.822301] XFS (sdb): xfs_log_force: error 5 returned.
> [ 1318.822308] XFS (sdb): xfs_log_force: error 5 returned.
> [ 1318.822311] XFS (sdb): Detected failing async write on buffer block
> 0x19fca0. Retrying async write.
That's the only thing that is unusual about the hang. Does this
always appear when a hang occurs?