extent-tree: instrument "no usable ref covers extent offset" failures

BeesBtrfsExtentNode::pread throws "no usable ref covers extent offset"
on some live systems, but the exception trace shows only the bytenr
from block_map_fetch's BEESTRACE frame -- none of the structure being
processed is visible, and the failure cannot be classified from the
log.

Blocks with no covering ref at all are expected and never reach
pread: block_map_fetch pass 1 leaves them unreachable and pass 2
skips them.  The exception therefore indicates one of two abnormal
conditions, which the log could not previously distinguish:

 - every ref covering the offset failed to open (the referencing
   files or subvols went away between the metadata fetch and the
   read), or

 - no candidate ref covers the offset at all, meaning the caller's
   coverage model disagrees with the ref list pread built from the
   same cached refs.

Distinguish the two cases with new event counters (pread_no_ref_open,
pread_no_ref_gap, plus non-fatal pread_ref_open_fail for individual
open failures that another covering ref absorbs), and report both
counts along with candidate and ref totals in the exception message.

At the throw site, dump the refs that failed to open (capped at
BEES_PREAD_REF_LOG_MAX so the dump cannot scale with ref count --
extents can carry tens of thousands of refs), and for the gap case
dump the candidates bracketing the uncovered offset.

Add BEESTRACE frames so an unwinding exception shows the structure
being processed: pread's want range, ref/candidate counts, and live
cursor; block_map_fetch's logical size, block count, pass 1
classification summary (data/prealloc block counts), and the data
run whose read failed.

Document the new counters in event-counters.md.

Assisted-by: Claude-Code:claude-fable-5

diff --git a/docs/event-counters.md b/docs/event-counters.md
index 3808804114be9076081313235e51919f64f0ef9b..06b65a0caa958ff1d627f1acf0b5d4bd64f92373 100644 (file)
--- a/docs/event-counters.md
+++ b/docs/event-counters.md
@@ -344,7 +344,10 @@ block map in `BeesBtrfsExtentLayer::block_map_fetch`.
  * `pread_bytes`: Total number of bytes read by `pread()`.
  * `pread_fail`: A `pread()` call failed with an error other than `EINTR`.
  * `pread_ms`: Total wallclock time spent in the `pread()` loop for a chunk.
+ * `pread_no_ref_gap`: A read failed because no ref covered the extent offset at all — the caller's coverage model disagreed with the ref list.  The read is abandoned with an exception.
+ * `pread_no_ref_open`: A read failed because every ref covering the extent offset failed to open — typically the referencing files or subvols were deleted between the metadata fetch and the read.  The read is abandoned with an exception.
  * `pread_ok`: A `pread()` call returned successfully.
+ * `pread_ref_open_fail`: A ref covering the current read offset failed to open.  Not fatal by itself — another covering ref may open successfully.
  * `pread_try`: A `pread()` call was attempted (including retries after `EINTR`).
 
 progress

diff --git a/src/bees-extent-layer.cc b/src/bees-extent-layer.cc
index 483a2cd1f69efdd4c6e058ecead0e7a73c104d5a..37403e8de78001cf4e4d81a0eccea8347350af39 100644 (file)
--- a/src/bees-extent-layer.cc
+++ b/src/bees-extent-layer.cc
@@ -550,6 +550,8 @@ BeesBtrfsExtentLayer::block_map_fetch(BeesBtrfsExtentNode &node,
        const auto logical_size = *node.m_logical_size;
        const auto block_count = ranged_cast<size_t>(
                (logical_size + BLOCK_SIZE_SUMS - 1) / BLOCK_SIZE_SUMS);
+       BEESTRACE("logical_size " << to_hex(logical_size)
+               << " block_count " << block_count);
 
        // Per-block intermediate state — coalesced into regions at end.
        struct BlockState {
@@ -610,6 +612,23 @@ BeesBtrfsExtentLayer::block_map_fetch(BeesBtrfsExtentNode &node,
                }
        }
 
+       // Summarize pass 1's structural classification so an exception in
+       // pass 2 shows the extent shape the failing pread was derived from.
+       size_t data_blocks = 0;
+       size_t prealloc_blocks = 0;
+       for (size_t i = 0; i < block_count; ++i) {
+               if (has_data[i]) {
+                       ++data_blocks;
+               }
+               if (blocks[i].state == BeesTreeBlockState::prealloc) {
+                       ++prealloc_blocks;
+               }
+       }
+       BEESTRACE("refs " << refs_sp->size()
+               << " data_blocks " << data_blocks
+               << " prealloc_blocks " << prealloc_blocks
+               << " of " << block_count);
+
        // Pre-compute total bytes pass 2 will pread, for the BEESNOTE
        // progress meter below.  Mirrors pass 2's run-extraction logic
        // so the total stays accurate across multiple data ranges
@@ -655,6 +674,8 @@ BeesBtrfsExtentLayer::block_map_fetch(BeesBtrfsExtentNode &node,
                const auto range_end = min<uint64_t>(
                        static_cast<uint64_t>(j) * BLOCK_SIZE_SUMS, logical_size);
                const auto range_len = range_end - range_begin;
+               BEESTRACE("data run blocks [" << i << ".." << j << ") bytes "
+                       << to_hex(range_begin) << ".." << to_hex(range_end));
                for (uint64_t chunk_off = 0; chunk_off < range_len;
                    chunk_off += BATCH_SIZE) {
                        BEESNOTE("block_map_fetch pread bytenr "

diff --git a/src/bees-extent-tree.cc b/src/bees-extent-tree.cc
index 08d6131c06da7a468b0d8f6cd7dffa0338e77560..27551be51d4f9421ee9557c38e16697571c3f664 100644 (file)
--- a/src/bees-extent-tree.cc
+++ b/src/bees-extent-tree.cc
@@ -2363,6 +2363,8 @@ BeesBtrfsExtentNode::pread(BeesExtentLayer *layerp, void *buf, size_t len,
        const auto want_off = ranged_cast<uint64_t>(logical_offset);
        const auto want_end = checked_add_u64(want_off, len,
                "BeesBtrfsExtentNode::pread end");
+       BEESTRACE("bytenr " << to_hex(m_bytenr) << " want "
+               << to_hex(want_off) << ".." << to_hex(want_end));
 
        auto refs_sp = atomic_load(&m_refs);
        if (!refs_sp) {
@@ -2401,17 +2403,23 @@ BeesBtrfsExtentNode::pread(BeesExtentLayer *layerp, void *buf, size_t len,
                [](const CoveringRef &a, const CoveringRef &b) {
                        return a.ext_begin < b.ext_begin;
                });
+       BEESTRACE("refs " << refs_sp->size()
+               << " candidates " << candidates.size());
 
        auto *dst = static_cast<uint8_t *>(buf);
        uint64_t cursor = want_off;
        const auto sectorsize = BeesContext::s_sectorsize;
        THROW_CHECK1(runtime_error, sectorsize, sectorsize > 0);
+       BEESTRACE("cursor " << cursor);
 
        while (cursor < want_end) {
                // Find the first usable ref in extent_offset order that
                // covers `cursor` and opens successfully.
                const CoveringRef *picked = nullptr;
                Fd fd;
+               size_t covering_count = 0;
+               size_t open_fail_count = 0;
+               vector<const CoveringRef *> open_fail_sample;
                for (const auto &cand : candidates) {
                        if (cand.ext_begin > cursor) {
                                break;
@@ -2419,8 +2427,14 @@ BeesBtrfsExtentNode::pread(BeesExtentLayer *layerp, void *buf, size_t len,
                        if (cand.ext_begin + cand.ref_bytes <= cursor) {
                                continue;
                        }
+                       ++covering_count;
                        Fd candidate_fd = cand.refp->open(*layerp);
                        if (!candidate_fd) {
+                               BEESCOUNT(pread_ref_open_fail);
+                               ++open_fail_count;
+                               if (open_fail_sample.size() < BEES_PREAD_REF_LOG_MAX) {
+                                       open_fail_sample.push_back(&cand);
+                               }
                                continue;
                        }
                        picked = &cand;
@@ -2428,10 +2442,58 @@ BeesBtrfsExtentNode::pread(BeesExtentLayer *layerp, void *buf, size_t len,
                        break;
                }
                if (!picked) {
+                       // Two distinct failure classes:  refs structurally cover
+                       // `cursor` but none would open (the file or subvol went
+                       // away between the ref fetch and the read), vs no ref
+                       // covering `cursor` at all (the caller's coverage model
+                       // disagrees with the candidate list).  Blocks with no
+                       // covering ref in the first place never reach pread —
+                       // block_map_fetch pass 1 leaves them unreachable.
+                       if (covering_count) {
+                               BEESCOUNT(pread_no_ref_open);
+                       } else {
+                               BEESCOUNT(pread_no_ref_gap);
+                       }
+                       for (const auto *candp : open_fail_sample) {
+                               BEESLOGDEBUG("pread bytenr " << to_hex(m_bytenr)
+                                       << " open failed: " << *candp->refp);
+                       }
+                       if (open_fail_count > open_fail_sample.size()) {
+                               BEESLOGDEBUG("pread bytenr " << to_hex(m_bytenr)
+                                       << " ... and "
+                                       << open_fail_count - open_fail_sample.size()
+                                       << " more open failures not logged");
+                       }
+                       if (!covering_count) {
+                               // Log the candidates bracketing the gap so the
+                               // coverage disagreement is visible in the log.
+                               const CoveringRef *prevp = nullptr;
+                               const CoveringRef *nextp = nullptr;
+                               for (const auto &cand : candidates) {
+                                       if (cand.ext_begin <= cursor) {
+                                               prevp = &cand;
+                                       } else {
+                                               nextp = &cand;
+                                               break;
+                                       }
+                               }
+                               if (prevp) {
+                                       BEESLOGDEBUG("pread bytenr " << to_hex(m_bytenr)
+                                               << " nearest ref below gap: " << *prevp->refp);
+                               }
+                               if (nextp) {
+                                       BEESLOGDEBUG("pread bytenr " << to_hex(m_bytenr)
+                                               << " nearest ref above gap: " << *nextp->refp);
+                               }
+                       }
                        THROW_ERROR(runtime_error,
                                "BeesBtrfsExtentNode::pread: bytenr "
                                << to_hex(m_bytenr)
-                               << " no usable ref covers extent offset " << cursor);
+                               << " no usable ref covers extent offset " << cursor
+                               << " (covering " << covering_count
+                               << " open_failed " << open_fail_count
+                               << " candidates " << candidates.size()
+                               << " refs " << refs_sp->size() << ")");
                }
 
                const auto file_begin = picked->refp->offset()

diff --git a/src/bees.h b/src/bees.h
index 12308aa6815510d77fe6b3b792542d81860da3ef..21705b1e9153cfd7906ede1189140295930ee02e 100644 (file)
--- a/src/bees.h
+++ b/src/bees.h
@@ -140,6 +140,12 @@ const size_t BEES_MAX_EXTENT_REF_COUNT =
 /// Number of bytes to prefetch ahead during scanning to improve sequential read performance.
 const size_t BEES_READAHEAD_SIZE = 1024 * 1024;
 
+/// Maximum number of refs dumped to the debug log when
+/// BeesBtrfsExtentNode::pread finds no usable ref covering an extent
+/// offset.  Extents can have tens of thousands of refs; the dump must
+/// not scale with the ref count.
+const size_t BEES_PREAD_REF_LOG_MAX = 10;
+
 /// @name open(2) flag sets used throughout bees
 /// @{
 /// Flags common to all bees open() calls: no follow symlinks, non-blocking,