xfs: don't sleep in xlog_cil_force_lsn on shutdown

From: Dave Chinner <[email protected]>

Reports of a shutdown hang when fsyncing a directory have surfaced, such as this:

[ 3663.394472] Call Trace:
[ 3663.397199]  [<ffffffff815f1889>] schedule+0x29/0x70
[ 3663.402743]  [<ffffffffa01feda5>] xlog_cil_force_lsn+0x185/0x1a0 [xfs]
[ 3663.416249]  [<ffffffffa01fd3af>] _xfs_log_force_lsn+0x6f/0x2f0 [xfs]
[ 3663.429271]  [<ffffffffa01a339d>] xfs_dir_fsync+0x7d/0xe0 [xfs]
[ 3663.435873]  [<ffffffff811df8c5>] do_fsync+0x65/0xa0
[ 3663.441408]  [<ffffffff811dfbc0>] SyS_fsync+0x10/0x20
[ 3663.447043]  [<ffffffff815fc7d9>] system_call_fastpath+0x16/0x1b

If we trigger a shutdown in xlog_cil_push() from xlog_write(), we will never wake waiters on the current push sequence number, so anything waiting in xlog_cil_force_lsn() for that push sequence number to come up will not get woken and hence stall the shutdown.

Fix this by ensuring we call wake_up_all(&cil->xc_commit_wait) in the push abort handling, in the log shutdown code when waking all waiters, and adding a shutdown check in the sequence completion wait loops to ensure they abort when a wakeup due to a shutdown occurs.

Reported-by Boris Ranto <[email protected]>

Reported-by Eric Sandeen <[email protected]>

Signed-off-by Dave Chinner <[email protected]>

---

 fs/xfs/xfs_log.c     |  7 +++++--
 fs/xfs/xfs_log_cil.c | 50 ++++++++++++++++++++++++++++++++++++++++++--------
 2 files changed, 47 insertions(+), 10 deletions(-)

fs/xfs/xfs_log.c +1 -0

index a5f8bd9..dbba2d7 100644
@@ -3952,11 +3952,14 @@ xfs_log_force_umount(
 		retval = xlog_state_ioerror(log);
 		spin_unlock(&log->l_icloglock);
 	}
+
 	/*

fs/xfs/xfs_log.c +0 -0

 #ifdef XFSERRORDEBUG

fs/xfs/xfs_log_cil.c +42 -8

index 7e54553..039c873 100644
@@ -385,7 +385,15 @@ xlog_cil_committed(
 	xfs_extent_busy_clear(mp, &ctx->busy_extents,
 			     (mp->m_flags & XFS_MOUNT_DISCARD) && !abort);
 
+	/*
+	 * If we are aborting the commit, wake up anyone waiting on the
+	 * committing list.  If we don't, then a shutdown we can leave processes
+	 * waiting in xlog_cil_force_lsn() waiting on a sequence commit that
+	 * will never happen because we aborted it.
+	 */
 	spin_lock(&ctx->cil->xc_push_lock);
+	if (abort)
+		wake_up_all(&ctx->cil->xc_commit_wait);
 	list_del(&ctx->committing);
 	spin_unlock(&ctx->cil->xc_push_lock);
 

@@ -564,8 +572,18 @@ restart:
 	spin_lock(&cil->xc_push_lock);
 	list_for_each_entry(new_ctx, &cil->xc_committing, committing) {
 		/*
+		 * Avoid getting stuck in this loop because we were woken by the
+		 * shutdown, but then went back to sleep once already in the
+		 * shutdown state.
+		 */
+		if (XLOG_FORCED_SHUTDOWN(log)) {
+			spin_unlock(&cil->xc_push_lock);
+			goto out_abort_free_ticket;
+		}
+
+		/*
 		 * Higher sequences will wait for this one so skip them.
-		 * Don't wait for own own sequence, either.
+		 * Don't wait for our own sequence, either.
 		 */
 		if (new_ctx->sequence >= ctx->sequence)
 			continue;

@@ -810,6 +828,13 @@ restart:
 	 */
 	spin_lock(&cil->xc_push_lock);
 	list_for_each_entry(ctx, &cil->xc_committing, committing) {
+		/*
+		 * Avoid getting stuck in this loop because we were woken by the
+		 * shutdown, but then went back to sleep once already in the
+		 * shutdown state.
+		 */
+		if (XLOG_FORCED_SHUTDOWN(log))
+			goto out_shutdown;
 		if (ctx->sequence > sequence)
 			continue;
 		if (!ctx->commit_lsn) {

@@ -833,14 +858,12 @@ restart:
 	 * push sequence after the above wait loop and the CIL still contains
 	 * dirty objects.
 	 *
-	 * When the push occurs, it will empty the CIL and
-	 * atomically increment the currect sequence past the push sequence and
-	 * move it into the committing list. Of course, if the CIL is clean at
-	 * the time of the push, it won't have pushed the CIL at all, so in that
-	 * case we should try the push for this sequence again from the start
-	 * just in case.
+	 * When the push occurs, it will empty the CIL and atomically increment
+	 * the currect sequence past the push sequence and move it into the
+	 * committing list. Of course, if the CIL is clean at the time of the
+	 * push, it won't have pushed the CIL at all, so in that case we should
+	 * try the push for this sequence again from the start just in case.
 	 */
-
 	if (sequence == cil->xc_current_sequence &&
 	    !list_empty(&cil->xc_cil)) {
 		spin_unlock(&cil->xc_push_lock);

@@ -849,6 +872,17 @@ restart:
 
 	spin_unlock(&cil->xc_push_lock);
 	return commit_lsn;
+
+	/*
+	 * We detected a shutdown in progress. We need to trigger the log force
+	 * to pass through it's iclog state machine error handling, even though
+	 * we are already in a shutdown state. Hence we can't return
+	 * NULLCOMMITLSN here as that has special meaning to log forces (i.e.
+	 * LSN is already stable), so we return a zero LSN instead.
+	 */
+out_shutdown:
+	spin_unlock(&cil->xc_push_lock);
+	return 0;
 }
 
 /*

Signature · 6 lines

1.9.0

_______________________________________________
xfs mailing list
[email protected]
http://oss.sgi.com/mailman/listinfo/xfs

Quoted 24 lines · Dave Chinner

From: Dave Chinner <[email protected]>

Reports of a shutdown hang when fsyncing a directory have surfaced, such as this:

[ 3663.394472] Call Trace:
[ 3663.397199]  [<ffffffff815f1889>] schedule+0x29/0x70
[ 3663.402743]  [<ffffffffa01feda5>] xlog_cil_force_lsn+0x185/0x1a0 [xfs]
[ 3663.416249]  [<ffffffffa01fd3af>] _xfs_log_force_lsn+0x6f/0x2f0 [xfs]
[ 3663.429271]  [<ffffffffa01a339d>] xfs_dir_fsync+0x7d/0xe0 [xfs]
[ 3663.435873]  [<ffffffff811df8c5>] do_fsync+0x65/0xa0
[ 3663.441408]  [<ffffffff811dfbc0>] SyS_fsync+0x10/0x20
[ 3663.447043]  [<ffffffff815fc7d9>] system_call_fastpath+0x16/0x1b

If we trigger a shutdown in xlog_cil_push() from xlog_write(), we will never wake waiters on the current push sequence number, so anything waiting in xlog_cil_force_lsn() for that push sequence number to come up will not get woken and hence stall the shutdown.

Fix this by ensuring we call wake_up_all(&cil->xc_commit_wait) in the push abort handling, in the log shutdown code when waking all waiters, and adding a shutdown check in the sequence completion wait loops to ensure they abort when a wakeup due to a shutdown occurs.

Quoted 4 lines

Reported-by Boris Ranto <[email protected]>

Reported-by Eric Sandeen <[email protected]>

Signed-off-by Dave Chinner <[email protected]>

---

Previously posted here, for reference:

http://oss.sgi.com/archives/xfs/2014-04/msg00801.html

Quoted 22 lines

 fs/xfs/xfs_log.c     |  7 +++++--
 fs/xfs/xfs_log_cil.c | 50 ++++++++++++++++++++++++++++++++++++++++++--------
 2 files changed, 47 insertions(+), 10 deletions(-)

fs/xfs/xfs_log.c +5 -2

index a5f8bd9..dbba2d7 100644
@@ -3952,11 +3952,14 @@ xfs_log_force_umount(
 		retval = xlog_state_ioerror(log);
 		spin_unlock(&log->l_icloglock);
 	}
+
 	/*
-	 * Wake up everybody waiting on xfs_log_force.
-	 * Callback all log item committed functions as if the
+	 * Wake up everybody waiting on xfs_log_force. This needs to wake anyone
+	 * waiting on a CIL push that is issued as part of a log force first
+	 * before running the log item committed callback functions as if the
 	 * log writes were completed.
 	 */
+	wake_up_all(&log->l_cilp->xc_commit_wait);

fs/xfs/xfs_log.c xfs_log_force_umount( · line 3964

Quoted 2 lines

fs/xfs/xfs_log.c +0 -0

 	xlog_state_do_callback(log, XFS_LI_ABORTED, NULL);
 

This looks fine to me with the defensive reasoning described in the aforementioned link, but it also looks like it could race with a force and sleep because we don't take xc_push_lock. We take the lock for the same wake up down in xlog_cil_committed(), so a hang seems unlikely at this point.

Given that the comment is kind of wordy (and unless we want to do the locking here as well), could we update the comment to reflect this? E.g., something like:

/*
* Wake up everybody waiting on a CIL push and/or log force. Wake the
* CIL push first as if the log writes were completed. The abort
* handling in the log item committed callback functions will do this
* again under lock to avoid races.
*/

Thoughts?

Quoted 56 lines · Brian Foster

Quoted 24 lines · Dave Chinner

From: Dave Chinner <[email protected]>

Reports of a shutdown hang when fsyncing a directory have surfaced, such as this:

[ 3663.394472] Call Trace:
[ 3663.397199]  [<ffffffff815f1889>] schedule+0x29/0x70
[ 3663.402743]  [<ffffffffa01feda5>] xlog_cil_force_lsn+0x185/0x1a0 [xfs]
[ 3663.416249]  [<ffffffffa01fd3af>] _xfs_log_force_lsn+0x6f/0x2f0 [xfs]
[ 3663.429271]  [<ffffffffa01a339d>] xfs_dir_fsync+0x7d/0xe0 [xfs]
[ 3663.435873]  [<ffffffff811df8c5>] do_fsync+0x65/0xa0
[ 3663.441408]  [<ffffffff811dfbc0>] SyS_fsync+0x10/0x20
[ 3663.447043]  [<ffffffff815fc7d9>] system_call_fastpath+0x16/0x1b

If we trigger a shutdown in xlog_cil_push() from xlog_write(), we will never wake waiters on the current push sequence number, so anything waiting in xlog_cil_force_lsn() for that push sequence number to come up will not get woken and hence stall the shutdown.

Fix this by ensuring we call wake_up_all(&cil->xc_commit_wait) in the push abort handling, in the log shutdown code when waking all waiters, and adding a shutdown check in the sequence completion wait loops to ensure they abort when a wakeup due to a shutdown occurs.

Quoted 4 lines

Reported-by Boris Ranto <[email protected]>

Reported-by Eric Sandeen <[email protected]>

Signed-off-by Dave Chinner <[email protected]>

---

Previously posted here, for reference:

http://oss.sgi.com/archives/xfs/2014-04/msg00801.html

Quoted 22 lines

 fs/xfs/xfs_log.c     |  7 +++++--
 fs/xfs/xfs_log_cil.c | 50 ++++++++++++++++++++++++++++++++++++++++++--------
 2 files changed, 47 insertions(+), 10 deletions(-)

fs/xfs/xfs_log.c +5 -2

index a5f8bd9..dbba2d7 100644
@@ -3952,11 +3952,14 @@ xfs_log_force_umount(
 		retval = xlog_state_ioerror(log);
 		spin_unlock(&log->l_icloglock);
 	}
+
 	/*
-	 * Wake up everybody waiting on xfs_log_force.
-	 * Callback all log item committed functions as if the
+	 * Wake up everybody waiting on xfs_log_force. This needs to wake anyone
+	 * waiting on a CIL push that is issued as part of a log force first
+	 * before running the log item committed callback functions as if the
 	 * log writes were completed.
 	 */
+	wake_up_all(&log->l_cilp->xc_commit_wait);

Quoted 8 lines

fs/xfs/xfs_log.c xfs_log_force_umount( · line 3964

Quoted 2 lines

fs/xfs/xfs_log.c +0 -0

 	xlog_state_do_callback(log, XFS_LI_ABORTED, NULL);
 

This looks fine to me with the defensive reasoning described in the aforementioned link, but it also looks like it could race with a force and sleep because we don't take xc_push_lock. We take the lock for the same wake up down in xlog_cil_committed(), so a hang seems unlikely at this point.

We can't really race in any meaningful way- the filesystem and log are already marked as shut down. Hence any new sleeper at this point will detect a shutdown before trying to sleep. Even if we do race, the xlog_cil_committed() will catch any stragglers...

Quoted 11 lines

Given that the comment is kind of wordy (and unless we want to do the locking here as well), could we update the comment to reflect this? E.g., something like:

/*
* Wake up everybody waiting on a CIL push and/or log force. Wake the
* CIL push first as if the log writes were completed. The abort
* handling in the log item committed callback functions will do this
* again under lock to avoid races.
*/

Quoted 1 line

Thoughts?

Makes sense. I'll change it.

Cheers,

Dave.

Signature · 2 lines

Dave Chinner
[email protected]