-
Type:
Task
-
Resolution: Unresolved
-
Priority:
Major - P3
-
None
-
Affects Version/s: None
-
Component/s: Checkpoints
-
None
-
Storage Engines - Persistence
-
646.586
-
None
-
None
Context
During checkpoint, dirty pages are reconciled in sync file via wt reconcile with WT REC CHECKPOINT. A single heavily modified page can dominate checkpoint time (large memory footprint, high page state mod count, long history-store wrapup).
There is already a post-hoc eviction warning when eviction exceeds one minute:
Eviction took more than 1 minute (N us). Building disk image took X us. History store wrapup took Y us.
That message is eviction-only (WT VERB EVICTION in evict page.c). Checkpoint reconcile of a hot page does not emit it. Checkpoint progress heartbeats also stay silent until that page finishes.
wt reconcile already buckets pages by footprint and mod count for stats (rec pages size *, rec page mods *) and tracks reconcile timeline stages (image build, HS wrapup).
Motivation
When checkpoint progress stops advancing for tens of seconds, engineers cannot tell whether the thread is stuck in scrub, fsync, or reconciling one hot page. A checkpoint-scoped hot-page log (before and/or after) makes that attributable without enabling noisy WT VERB RECONCILE debug.
Suggestions
- For checkpoint reconciles only, log when a page looks expensive before reconcile starts. Threshold on footprint and/or page state (align with existing size/mod stat buckets, e.g. >= 10 MB or >= 100 mods).
- After reconcile, if elapsed time exceeds a threshold (e.g. 5-20s or WT PROGRESS MSG PERIOD), log duration including image-build and HS-wrapup from reconcile timeline.
- Prefer WT VERB CHECKPOINT PROGRESS at info so it appears with other checkpoint progress output.
- Include enough identity to act: URI, page type, footprint, mod count; on completion also duration, split count, and HS wrapup time.
Suggested forms:
Checkpoint reconciling hot page on file:collection-X.wt (leaf, 48 MB, 312 mods) Checkpoint reconciled hot page on file:collection-X.wt in 47 seconds (leaf, 48 MB, 312 mods, split into 6 pages, HS wrapup 31 seconds)
- Optional follow-up: mid-reconcile HS wrapup heartbeat if post-hoc logs still leave long silence inside one page.
- Do not rely on the existing eviction "more than 1 minute" warning; keep that path unchanged.
Examples
Existing (eviction only, no URI):
[WT_VERB_EVICTION]: Eviction took more than 1 minute (65000000 us). Building disk image took 12000000 us. History store wrapup took 50000000 us.
Desired (checkpoint):
[WT_VERB_CHECKPOINT_PROGRESS]: Checkpoint reconciling hot page on file:collection-0-12345.wt (leaf, 48 MB, 312 mods) ... silence while that page reconciles ... [WT_VERB_CHECKPOINT_PROGRESS]: Checkpoint reconciled hot page on file:collection-0-12345.wt in 47 seconds (leaf, 48 MB, 312 mods, split into 6 pages, HS wrapup 31 seconds)