Skip to content

Bulk-copy send loop wedges with event-loop starvation on macOS; progresses only via watchdog reconnect cycles #656

Open

Description

@kriszyp

Summary

On macOS, a local 1 GB largeClone.test.mjs run (two loopback nodes, RocksDB) repeatedly wedges the bulk copy: data stops flowing to the clone within seconds of COPY_START, the leader's send thread logs the event-loop starvation warning, and progress only resumes when a watchdog forces a reconnect. The copy then completes over several wedge/reconnect cycles (326s for 1 GB ≈ 3 MB/s effective). Observed consistently across 3 runs on macOS 25.5.0 (main @ 160a8ea). CI's self-hosted Linux runners do not show this signature (their copies run to completion in a single connection).

Evidence (leader log)

14:24:00.904 [http/2] Requesting full copy of database data from ws://127.0.0.27:9933 (no resume cursor for this source)
14:26:00.595 [http/3] Receive watchdog: no ping from 127.0.0.27 (db: "data") for 60000ms — terminating connection and reconnecting — truth={connected: true, state: 2, liveness: 119s ago}
14:26:00.610 [http/2] JavaScript execution has taken too long and is not allowing proper event queue cycling, consider using 'await new Promise(setImmediate)' in code that will execute for a long duration

Clone side over the same window: Sync incomplete; last replication data arrived 126s ago (arrival stamps frozen), clone data directory not growing. After the reconnect the copy resumes from the cursor and advances again before wedging again.

Notes

  • The [http/2] event-loop warning is the thread running the copy send loop for data — the send loop appears to hold the event loop long enough to starve its own pings and the reverse connection's liveness (the receive watchdog that fires is for the other direction's socket).
  • Possibly macOS-specific socket backpressure interacting with the send loop's yield discipline (waitForDrain / checkpoint pacing) — 100 KB records, loopback.
  • Found while investigating Clone sync monitor is vacuous on RocksDB: clone marks itself Available mid-copy (targets all 0) #655 (the sync-monitor fix made the wedge visible: the clone now correctly stays Unavailable and logs stall countdowns instead of declaring success mid-copy).
  • Repro: HARPER_RUN_STRESS_TESTS=1 HARPER_STRESS_LARGE_DATA_GB=1 HARPER_INTEGRATION_TEST_INSTALL_PARENT_DIR=~/dev/tmp/x HARPER_INTEGRATION_TEST_LOG_DIR=~/dev/tmp/x/logs node integrationTests/run.mjs integrationTests/stress/largeClone.test.mjs on macOS.

Low priority if confirmed macOS-only (stress tests target self-hosted Linux), but the same starvation mechanism under a slow consumer might occur on production Linux under memory/CPU pressure — the send loop yield discipline deserves a look.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    Fields

    Priority

    P2

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions