Deferred checkpoint pickup logs a benign adoption race at ERROR

XMLWordPrintableJSON

    • Type: Bug
    • Resolution: Unresolved
    • Priority: Major - P3
    • None
    • Affects Version/s: None
    • Component/s: Checkpoints
    • None
    • Storage Engines, Storage Engines - Transactions
    • 0.011
    • SE Transactions - 2026-08-14
    • 2

      On a disaggregated follower, when the background deferred-pickup server loses an adoption race to an inline pickup, the resulting rejection is emitted to the event handler at [ERROR] even though the caller treats it as an expected outcome and swallows it.

      checkpoint-pick-up: [WT_VERB_DEFAULT][ERROR]: __disagg_pick_up_checkpoint, 1421:
      Attempting to pick up an older checkpoint: current metadata LSN = 5062, new metadata LSN = 5058: Invalid argument
      

      Mechanism

      WT-18156 made checkpoint adoption asynchronous: a checkpoint delivered while a snapshot predating it is active is queued and drained by the pickup server. The server's adoption can race an inline adoption of a newer checkpoint. That race is correctness-safe — the loser is rejected with EINVAL/EBUSY and the deferred queue pruned in __wti_disagg_deferred_pickup_retry (src/conn/conn_layered_checkpoint_pick_up.c:1291-1300) — but the rejection is raised with WT_RET_MSG at src/conn/conn_layered_checkpoint_pick_up.c:1421, so the message reaches the event handler before the caller classifies it as benign.

      Impact

      • Python tests that assert on unexpected error output fail intermittently. Observed in 3 of 300 stressed runs of test_layered_follower10 (10 parallel workers), independent of the (1, 0) != (0, 0) GC-timing failure tracked as WT-18294.
      • Operators reading production logs see an ERROR for an event that is normal and handled.

      Suggested fix

      The force parameter of __wti_disagg_pick_up_checkpoint_meta is shared by startup/step-up and the deferred retry, so it cannot distinguish them today. Two options:

      1. Plumb a separate flag so the older-LSN rejection stays loud for startup/step-up, where it is a genuine operator error, and is quiet on the deferred-retry path. Preferred: it keeps the diagnostics. Changes the signature across four call sites plus regenerated prototypes.
      2. Demote the message at line 1421 to a verbose warning. One line, but a genuinely bad step-up pickup then reports only "Invalid argument" through the reconfigure error path, without the LSNs.

      Reproduction

      Runs 300x with 10 parallel workers on an 8-core host:

      for w in $(seq 1 10); do
        ( for i in $(seq 1 30); do
            python3 ../test/suite/run.py -D /tmp/wt_w$w test_layered_follower10 > /tmp/o_w${w}_$i.log 2>&1
          done ) &
      done; wait
      grep -l "Attempting to pick up an older checkpoint" /tmp/o_*.log
      

            Assignee:
            Chenhao Qu
            Reporter:
            Chenhao Qu
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Created:
              Updated: