From 48716461e4cc78b239546d9047635d11d3ddf13f Mon Sep 17 00:00:00 2001 From: Zach Brown Date: Mon, 10 Jun 2024 10:57:29 -0700 Subject: [PATCH] Add tracepoint as block read returns ESTALE Block reads can return ESTALE naturally as mounts read through old cached blocks. We won't always log it as an error but we should add a tracepoint that can be inspected. Signed-off-by: Zach Brown --- kmod/src/block.c | 6 +++++- kmod/src/scoutfs_trace.h | 38 ++++++++++++++++++++++++++++++++++++++ 2 files changed, 43 insertions(+), 1 deletion(-) diff --git a/kmod/src/block.c b/kmod/src/block.c index c23764d3..7a17aa96 100644 --- a/kmod/src/block.c +++ b/kmod/src/block.c @@ -683,6 +683,7 @@ int scoutfs_block_read_ref(struct super_block *sb, struct scoutfs_block_ref *ref struct scoutfs_block_header *hdr; struct block_private *bp = NULL; bool retried = false; + __le32 crc = 0; int ret; retry: @@ -695,7 +696,9 @@ retry: /* corrupted writes might be a sign of a stale reference */ if (!test_bit(BLOCK_BIT_CRC_VALID, &bp->bits)) { - if (hdr->crc != block_calc_crc(hdr, SCOUTFS_BLOCK_LG_SIZE)) { + crc = block_calc_crc(hdr, SCOUTFS_BLOCK_LG_SIZE); + if (hdr->crc != crc) { + trace_scoutfs_block_stale(sb, ref, hdr, magic, le32_to_cpu(crc)); ret = -ESTALE; goto out; } @@ -705,6 +708,7 @@ retry: if (hdr->magic != cpu_to_le32(magic) || hdr->fsid != cpu_to_le64(sbi->fsid) || hdr->seq != ref->seq || hdr->blkno != ref->blkno) { + trace_scoutfs_block_stale(sb, ref, hdr, magic, 0); ret = -ESTALE; goto out; } diff --git a/kmod/src/scoutfs_trace.h b/kmod/src/scoutfs_trace.h index ec6ad475..0f30c513 100644 --- a/kmod/src/scoutfs_trace.h +++ b/kmod/src/scoutfs_trace.h @@ -2395,6 +2395,44 @@ TRACE_EVENT(scoutfs_block_dirty_ref, __entry->block_blkno, __entry->block_seq) ); +TRACE_EVENT(scoutfs_block_stale, + TP_PROTO(struct super_block *sb, struct scoutfs_block_ref *ref, + struct scoutfs_block_header *hdr, u32 magic, u32 crc), + + TP_ARGS(sb, ref, hdr, magic, crc), + + TP_STRUCT__entry( + SCSB_TRACE_FIELDS + __field(__u64, ref_blkno) + __field(__u64, ref_seq) + __field(__u32, hdr_crc) + __field(__u32, hdr_magic) + __field(__u64, hdr_fsid) + __field(__u64, hdr_seq) + __field(__u64, hdr_blkno) + __field(__u32, magic) + __field(__u32, crc) + ), + + TP_fast_assign( + SCSB_TRACE_ASSIGN(sb); + __entry->ref_blkno = le64_to_cpu(ref->blkno); + __entry->ref_seq = le64_to_cpu(ref->seq); + __entry->hdr_crc = le32_to_cpu(hdr->crc); + __entry->hdr_magic = le32_to_cpu(hdr->magic); + __entry->hdr_fsid = le64_to_cpu(hdr->fsid); + __entry->hdr_seq = le64_to_cpu(hdr->seq); + __entry->hdr_blkno = le64_to_cpu(hdr->blkno); + __entry->magic = magic; + __entry->crc = crc; + ), + + TP_printk(SCSBF" ref_blkno %llu ref_seq %016llx hdr_crc %08x hdr_magic %08x hdr_fsid %016llx hdr_seq %016llx hdr_blkno %llu magic %08x crc %08x", + SCSB_TRACE_ARGS, __entry->ref_blkno, __entry->ref_seq, __entry->hdr_crc, + __entry->hdr_magic, __entry->hdr_fsid, __entry->hdr_seq, __entry->hdr_blkno, + __entry->magic, __entry->crc) +); + DECLARE_EVENT_CLASS(scoutfs_block_class, TP_PROTO(struct super_block *sb, void *bp, u64 blkno, int refcount, int io_count, unsigned long bits, __u64 accessed),