• Type: Task
    • Resolution: Unresolved
    • Priority: Major - P3
    • None
    • Affects Version/s: None
    • Component/s: Cache and Eviction
    • None
    • Storage Engines - Transactions
    • 25.592
    • None
    • None

      Summary

      The perf-atlas-M30-real.arm.aws.2023-11 sys-perf variant runs ycsb.out_of_cache.95read5update.2024-05 with a 2 GiB WiredTiger cache. Under this workload's write rate, the cache is too small for the working set: application threads are conscripted into eviction as a backstop far more than on other variants, and this shows up as severe write-latency stalls. It trips the ftdc_wt_dirty_ratio_check resource check (PERF-9081) as a side effect, but the dirty-ratio failure is a symptom, not the problem – the problem is the write-latency cost of running this workload against this cache size.

      This is a third, distinct population within BF-46531 (which also covers a missing WT backport and a checkpoint/history-store eviction limitation, tracked separately in WT-18765). It affects master and is unrelated to both of those.

      Evidence

      From the primary's FTDC (atlas-ip4ao3-shard-00-02, BFG-3676913, sys-perf @ fd7bf02e, run duration ~4358 s):

      • maximum bytes configured: 2 GiB (2,147,483,648 bytes), constant throughout.
      • Average write latency: 2.57 seconds/op (opLatencies.writes: 690,264,867,450 usec / 268,794 ops). Average read latency: 25 ms/op – a ~100x asymmetry.
      • globalLock.currentQueue.writers peaked at 255 during the run.
      • eviction worker thread active: pinned at 8 (the full configured pool) for the entire run – background eviction never idles.
      • Per wall-clock second, application threads spend an aggregate ~8.7s of thread-time actually evicting pages themselves (application thread time evicting) plus ~12.3s parked waiting their turn (application thread time waiting for interruptible cache eviction) – over 20 thread-seconds of eviction-related work per second of wall time.
      • application threads eviction requested with cache fill ratio >= 75%: 418/s – three-quarters of the time a write needs room, the cache is already 75%+ full, so WT routes the calling thread into eviction-assist rather than relying on the background eviction server.
      • Eviction throughput: ~3,381 modified + 959 unmodified pages evicted/sec combined, 45.2 MiB/s written from cache, 81.9 MiB/s read back into cache – all wildly disproportionate to the workload's own op rate (27 update ops/s, 482 read ops/s via opcounters). This is the signature of thrash: pages evicted and read straight back in.
      • History store dirty content is not the driver here (unlike the checkpoint/HS mechanism in WT-18765): HS share of dirty bytes was ~0% at the peak sample. This run's dirty-leaf ratio oscillates by 5-8 percentage points every single FTDC sample (90-171 MB swings within the 2 GiB budget), tracking bytes allocated for updates directly, not history-store reconciliation.
      • This is not 8.3's cursor-reuse bug (WT-17964/SERVER-130667): the affected revisions are all on sys-perf (master), which already carries the fix. It is also not the checkpoint/history-store eviction limitation in WT-18765: HS share was ~0%, versus 54-82% at peak in the WT-18765 failures.

      Reproduction

      evergreen patch -p sys-perf -f \
        -t ycsb.out_of_cache.95read5update.2024-05 \
        -v perf-atlas-M30-real.arm.aws.2023-11
      

      Recent failing runs (all ycsb.out_of_cache.95read5update.2024-05 on perf-atlas-M30-real.arm.aws.2023-11, resource_sanity_checks / ftdc_wt_dirty_ratio_check):

      • BFG-3676913, sys-perf @ fd7bf02e: Spruce – the run analysed above; FTDC data is the task's "FTDC data" artifact, node atlas-ip4ao3-shard-00-02 (primary for the run).
      • BFG-3665872, sys-perf @ 84dadab1: Spruce
      • BFG-3669887, sys-perf @ 0c5ee19f: Spruce
      • BFG-3669898, sys-perf @ 0c5ee19f: Spruce
      • BFG-3669895, sys-perf @ 59f9dfe6: Spruce

      This variant has recurred on ycsb.out_of_cache.95read5update.2024-05 and ycsb.out_of_cache.100read.2024-05 across many commits (see BF-46531 for the fuller BFG list); the peak dirty-leaf ratio clusters around 29-32% each time, i.e. the same margin over trigger every run, consistent with a fixed cache-size-vs-working-set mismatch rather than a code regression.

      To pull the same FTDC series for a new run: the task's "FTDC data" artifact, per-node subdirectory under atlas_ftdc_data/<host>-mongod/. Compare opLatencies.writes.latency/opLatencies.writes.ops against opLatencies.reads for the write/read latency asymmetry, application thread time evicting and application thread time waiting for interruptible cache eviction for the assist cost, and application threads eviction requested with cache fill ratio >= 75% for how often the cache is already full when a write arrives. A stdlib-only reader that makes this quick lives in the dsi repo at claude-plugins/performance-testing/skills/ftdc-parser/ftdc_query.py.

      Directions to evaluate

      • Whether 2 GiB is an intentional cache-size choice for this variant relative to the YCSB 95/5 dataset size, or an oversight – if the dataset is meant to exceed cache (the task name is out_of_cache), whether the current margin between working-set size and cache size produces representative "out of cache" behavior or degenerate thrash.
      • Whether the eviction-assist behavior itself (application threads picking up roughly half their eviction-related stall time doing the work themselves, half parked waiting) is expected at this level of cache pressure, or whether it should shed load / back off earlier.
      • Whether this is a workload-sizing decision for Product Performance to make (increase cache, or reduce dataset), independent of any WiredTiger code change.

      Related

      BF-46531 (where this was first noticed, alongside two unrelated causes), WT-18765 (the checkpoint/HS eviction limitation – explicitly not the same mechanism as this ticket).

            Assignee:
            [DO NOT USE] Backlog - Storage Engines Team
            Reporter:
            Chenhao Qu
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

              Created:
              Updated: