xfs
[Top] [All Lists]

Re: [PATCH] xfs: serialize iclog write of xlog_cil_push

To: Mark Tinguely <tinguely@xxxxxxx>
Subject: Re: [PATCH] xfs: serialize iclog write of xlog_cil_push
From: Dave Chinner <david@xxxxxxxxxxxxx>
Date: Tue, 8 Jan 2013 09:22:38 +1100
Cc: xfs@xxxxxxxxxxx
In-reply-to: <50EB0DE9.70808@xxxxxxx>
References: <20130105213420.307598929@xxxxxxx> <20130106000834.GM3120@dastard> <50EB0DE9.70808@xxxxxxx>
User-agent: Mutt/1.5.21 (2010-09-15)
On Mon, Jan 07, 2013 at 12:03:21PM -0600, Mark Tinguely wrote:
> On 01/05/13 18:08, Dave Chinner wrote:
> >On Sat, Jan 05, 2013 at 02:34:15PM -0600, Mark Tinguely wrote:
> >>The back-end of xlog_cil_push() allows multiple push sequences
> >>to write to the xlog at the same time.
> >
> >It does this by design, and has since day zero.
> >
> >>This will cause problems
> >>for recovery and also could cause the xlog_cil_committed() callback
> >>to be called out of sequence.
> >
> >Log recovery is supposed to be able to handle it just fine in that
> >recovery only replays up to the last checkpoint with a valid commit
> >record. Checkpoints that don't have valid commit records - no matter
> >the order they are written - will terminate recovery at the LSN of
> >the lowest entire commit.
> >
> >>This was discovered with an EFI/EFD misorder. There are several (5) active
> >>sequence pushes and 3 completed pushes. The callback for the sequence (2)
> >>holding the EFD is being processed but the callback for the sequence (1)
> >>holding the EFI has not yet been processed.
> >
> >What are the symptoms shown when this problem is hit?  AFAICT, there
> >is no problem here - this comment above __xfs_efi_release() explains
> >that EFI/EFD misordering is expected:
> >
> >/*
> >  * Freeing the efi requires that we remove it from the AIL if it has already
> >  * been placed there. However, the EFI may not yet have been placed in the 
> > AIL
> >  * when called by xfs_efi_release() from EFD processing due to the ordering 
> > of
> >  * committed vs unpin operations in bulk insert operations. Hence the
> >  * test_and_clear_bit(XFS_EFI_COMMITTED) to ensure only the last caller 
> > frees
> >  * the EFI.
> >  */
> >
> >This was introduced in this commit:
> >
> >$ gl -n 1 b199c8a4
> >commit b199c8a4ba11879df87daad496ceee41fdc6aa82
> >Author: Dave Chinner<dchinner@xxxxxxxxxx>
> >Date:   Mon Dec 20 11:59:49 2010 +1100
> >
> >     xfs: Pull EFI/EFD handling out from under the AIL lock
> >
> >     EFI/EFD interactions are protected from races by the AIL lock. They
> >     are the only type of log items that require the the AIL lock to
> >     serialise internal state, so they need to be separated from the AIL
> >     lock before we can do bulk insert operations on the AIL.
> >
> >     To acheive this, convert the counter of the number of extents in the
> >     EFI to an atomic so it can be safely manipulated by EFD processing
> >     without locks. Also, convert the EFI state flag manipulations to use
> >     atomic bit operations so no locks are needed to record state
> >     changes. Finally, use the state bits to determine when it is safe to
> >     free the EFI and clean up the code to do this neatly.
> >
> >     Signed-off-by: Dave Chinner<dchinner@xxxxxxxxxx>
> >     Reviewed-by: Christoph Hellwig<hch@xxxxxx>
> >
> >Hence if there is some problem being seen as a result of allowing this
> >behaviour, I'd like to know what that problem actually is....
> >
> 
> The filesystem is in forced shutdown with the following error:
> xfs_trans_ail_delete_bulk: attempting to delete a log item that is
> not in the AIL.

That's something that should be in the commit message. But knowing
this fact, it took me less than a minute to find the bug. That tells
me you are seeing this:

        EFI             EFD
        commit
                        commit EFD
        ....            .....
                        committed
                        xfs_efi_release
                          efi refcount drops to zero
                          __xfs_efi_release
                            xfs_trans_ail_delete
                              shutdown!

> The EFI is in the CIL sequence #1, the EFD is in sequence #2.
> 
> Sequence #2 is running the cil callback but sequence #1 has not yet
> run its callback.
> 
> Normally, xfs_efi_item_committed() sets the XFS_EFI_COMMITTED bit.
> Either the xfs_efi_item_unpin() or the xfs_efi_release() could
> happen first and the comparison in __xfs_efi_release() compensates
> for that.
>
> But if the xfs_efi_item_committed() is not called before the
> xfs_efi_release() is called from the xfs_efd_item_committed(), then
> we will get the "not in the AIL" shutdown.

Doesn't that point directly to the root cause of the problem you
tripped over?  If xfs_efi_item_committed() has not been called, then
XFS_EFI_COMMITTED is not set and the item is not in the AIL so we
shouldn't ever be trying to remove it from the AIL. So why are we
trying to remove the EFI from the AIL when XFS_EFI_COMMITTED is not
actually set?

That is, what is supposed to happen is this when they are out of
order is this:

        EFI             EFD
        commit
                        commit EFD
        ....            .....
                        committed
                        xfs_efi_release
                          efi refcount drops to zero
                          __xfs_efi_release
                            XFS_EFI_COMMITTED is not set, does nothing
                        free EFD
        ....
        committed
          set XFS_EFI_COMMITTED
        insert into AIL
        unpin
          __xfs_efi_release
            clear XFS_EFI_COMMITTED
            remove from AIL
            free EFI.

>From this, it now should be pretty obvious where the bug is.....

Cheers,

Dave.
-- 
Dave Chinner
david@xxxxxxxxxxxxx

<Prev in Thread] Current Thread [Next in Thread>