Re: Metadata CRC error upon unclean unmount

Dave Chinner
2014-06-26T02:23:58Z

On Thu, Jun 26, 2014 at 10:28:59AM +1000, Dave Chinner wrote:
> On Wed, Jun 25, 2014 at 11:21:44AM +1000, Dave Chinner wrote:
> > On Tue, Jun 24, 2014 at 11:50:52PM +0200, Fanael Linithien wrote:
> > Ok, so the CRC corresponds to the version of the AGI that was logged
> > at lsn = 0x30000017e. That means the version on disk is a partial
> > update without a CRC recalculation. Ok, so how can that happen?
> >
> > Given the lsn mismatch, I suspect log recovery has played a part as
> > it will not update the LSN when replaying changes in the log. It
> > should, however, always be attaching the appropriate verifier to
> > the buffers being recovered so the CRC should be recalculated
> > correctly.
>
> Ok, I have confirmed that this is occurring and behaving correctly.
>
> [ 24.437878] XFS (vdb): Mounting V5 Filesystem
> [ 24.554429] XFS (vdb): Starting recovery (logdev: internal)
> [ 24.623466] XFS (vdb): xfs_agi_write_verify: lsn reset block 0x2
> [ 24.625263] XFS (vdb): xfs_btree_sblock_calc_crc: lsn reset block 0x8
> [ 24.627307] XFS (vdb): xfs_btree_sblock_calc_crc: lsn reset block 0x10
> [ 24.628729] XFS (vdb): xfs_btree_sblock_calc_crc: lsn reset block 0x18
> [ 24.630085] XFS (vdb): xfs_dir3_data_write_verify: lsn reset block 0x20000
> [ 24.631504] XFS (vdb): xfs_da3_node_write_verify: lsn reset block 0x20008
> [ 24.632935] XFS (vdb): xfs_dir3_data_write_verify: lsn reset block 0x20010
> [ 24.634360] XFS (vdb): xfs_dir3_data_write_verify: lsn reset block 0x20018
> [ 24.635622] XFS (vdb): xfs_dir3_free_write_verify: lsn reset block 0x201e0
> [ 24.636656] XFS (vdb): __write_verify: lsn reset block 0x201e8
> [ 24.637510] XFS (vdb): __write_verify: lsn reset block 0x201f0
> [ 24.638365] XFS (vdb): xfs_dir3_data_write_verify: lsn reset block 0x201f8
> [ 24.639378] XFS (vdb): xfs_dir3_data_write_verify: lsn reset block 0x202c0
> [ 24.640397] XFS (vdb): __write_verify: lsn reset block 0x202c8
> [ 24.641260] XFS (vdb): xfs_dir3_data_write_verify: lsn reset block 0x202d0
> [ 24.664330] XFS (vdb): Ending recovery (logdev: internal)
>
> But that also confirms that log recovery is recalculating the CRC
> after replaying changes into that block:
>
> # xfs_db -c "agi 0" -c "p lsn" -c "p crc" /dev/vdb
> lsn = 0xffffffffffffffff
> crc = 0x788c4f63 (correct)
>
> So the common log recovery path for buffers is working as it is
> designed to do.
>
> What I still don't understand yet is how changes after this recovery
> phase are getting to disk without updating the CRC. That implies
> buffers without verifiers being written....
>
> More debug to come...

Can you apply this patch and run your tests? If should spew warnings
to dmesg if a metadata buffer is ever written without an ops
structure attached to it (i.e. won't have CRCs recalculated).

Cheers,

Dave.
--
Dave Chinner
david@fromorbit.com

xfs: spew warnings on cached buffers without b_ops callbacks.

Signed-off-by: Dave Chinner <dchinner@redhat.com>
---
fs/xfs/xfs_buf.c | 6 ++++++
fs/xfs/xfs_log.c | 7 ++++++-
2 files changed, 12 insertions(+), 1 deletion(-)

diff --git a/fs/xfs/xfs_buf.c b/fs/xfs/xfs_buf.c
index a6dc83e..95e5516 100644
--- a/fs/xfs/xfs_buf.c
+++ b/fs/xfs/xfs_buf.c
@@ -1330,6 +1330,12 @@ _xfs_buf_ioapply(
SHUTDOWN_CORRUPT_INCORE);
return;
}
+ } else if (bp->b_bn != -1LL) {
+ xfs_warn(bp->b_target->bt_mount,
+ "%s: no ops on block 0x%llx/0x%llx",
+ __func__, bp->b_bn, bp->b_maps[0].bm_bn);
+ xfs_hex_dump(bp->b_addr, 64);
+ dump_stack();
}
} else if (bp->b_flags & XBF_READ_AHEAD) {
rw = READA;
diff --git a/fs/xfs/xfs_log.c b/fs/xfs/xfs_log.c
index 7647818..ecf2048 100644
--- a/fs/xfs/xfs_log.c
+++ b/fs/xfs/xfs_log.c
@@ -1369,8 +1369,13 @@ xlog_alloc_log(

xlog_get_iclog_buffer_size(mp, log);

+ /*
+ * Use a block number of -1 for the extra log buffer used during splits
+ * so that it will trigger errors if we ever try to do IO on it without
+ * first having set it up properly.
+ */
error = -ENOMEM;
- bp = xfs_buf_alloc(mp->m_logdev_targp, 0, BTOBB(log->l_iclog_size), 0);
+ bp = xfs_buf_alloc(mp->m_logdev_targp, -1LL, BTOBB(log->l_iclog_size), 0);
if (!bp)
goto out_free_log;