Skip to content

Ingest permanently hangs under sustained sequential bulk upsert load #1785

Closed

Description

@pbrumblay

Bug Summary

Ingest permanently hangs under sustained sequential bulk upsert load: one write's response never arrives, no error is thrown, no timeout fires, and the process becomes otherwise idle (0% CPU) while continuing to answer unrelated requests normally.

Reproduction Repository (if applicable)

https://github.com/pbrumblay/harper-hang-repro

Steps to Reproduce

  1. npm install harper@5.1.18 in an empty directory.
  2. Run the attached repro.js (node repro.js). It will:
    • harper install + harper run with a dedicated ROOTPATH (and an isolated $HOME,
      since harper install tracks a single canonical install via
      $HOME/.harperdb/hdb_boot_properties.file, independent of --ROOTPATH -- worth knowing
      if you're running multiple installs on one machine).
    • Create one plain table (BulkHangRepro, id hash attribute, a few scalar columns).
    • Issue sequential {operation: 'upsert', database, table, records} calls over the plain
      Operations API, batches of 1000 synthetic records with strictly new, distinct keys each
      batch (no repeated updates to the same keys) -- one awaited batch after another, no
      concurrency.
    • Watch wall-clock time per batch; if one exceeds 90s (vs. the ~40-135ms/batch normal
      rate), flag a stall and capture diagnostics (ps, top, sample <pid> 5, lsof,
      Harper's own log tail).
  3. Wait. In our runs this took anywhere from ~20 minutes to ~1 hour of sustained load
    (not fast/deterministic, but reliable across every attempt).

Env overrides available on the script: BATCH_SIZE, TOTAL_BATCHES, STALL_MS,
OPERATIONSAPI_NETWORK_PORT. Defaults reproduced it on the first run with no tuning.

Expected Behavior

The upsert either completes, or fails with an error/timeout that the caller can detect and
act on.

Actual Behavior

The upsert call never resolves and never rejects -- indefinitely (14+ hours in one
occurrence before we intervened manually). Specifically:

  • The Harper process sits at 0% CPU, state sleeping -- not busy, not spinning.
  • A native thread sample (sample <pid> 5) taken during the hang shows every thread idle:
    the main thread parked in uv__io_poll/kevent (event loop has nothing to do), RocksDB's
    own background thread pool (6 BGThreadWrapper threads) parked on condvar wait with
    nothing queued. Nothing is executing, nothing is blocked mid-instruction.
  • Despite that, other requests to the same process keep succeeding during the hang
    (unrelated search_by_hash queries return normally) -- so this isn't a frozen event loop or
    a global deadlock. One specific write's completion signal is lost; everything else is fine.
  • Harper's own log repeats "JavaScript execution has taken too long and is not allowing proper event queue cycling..." around the stall window, then goes silent.
  • RocksDB's own internal stats (database/*/LOG) show zero write-stall
    (Cumulative stall: 0.0 percent, rocksdb.stall.micros COUNT: 0), and its periodic
    background-compaction task keeps firing on schedule -- this is not RocksDB's own
    backpressure mechanism; whatever's stuck is upstream of that.
  • A 300-second Promise.race-based timeout wrapped around the calling code's upsert call
    (independent of Harper) never fires either, which rules out "just slow" -- the call
    genuinely never settles.

Reproduced identically 3 times in application context (Harper 5.1.15) and once more
standalone with no application code (Harper 5.1.18) -- see attached BUG_REPORT.md for the
full detail on all four occurrences, including exact table/row counts at each stall.

Platform

Harper 5.1.15, 5.1.18, 5.1.19: RocksDB 2.3.0, macOS 26.5.1 (arm64), Node v24.14.0, THREAD_COUNT: 1

Console Errors

None -- that's part of what makes this bug notable. No exception, no rejected promise, no log
line indicating failure. The operation simply never completes.

Screenshots or Videos

No response

Additional Context

Reading through resources/DatabaseTransaction.ts (the transaction-commit path every
upsert goes through), a few things stood out as possibly relevant, though none fully explain
the hang on their own -- flagging for whoever's more familiar with the native binding's
internals:

  • commit() already has recently-hardened retry handling for RocksDB ERR_BUSY/
    ERR_TRY_AGAIN (git history: fix(transaction): retry ERR_TRY_AGAIN commits instead of dropping them silently #1223, Never drop source-applied writes on conflict; backpressure the apply loop #1252, referencing a prior incident Allow Map methods to be overriden with frozen intrinsics #308 where a
    similar rejection "propagated out of the unawaited onCommit() handler as an unhandled
    rejection and the write was silently dropped"). For non-sourceApply transactions (this
    repro's write path) that retry is capped at 40 attempts with a ≤1s backoff each, so a
    genuinely-retried conflict should surface a loud ServerError well under a minute -- that
    doesn't match what we observe here.
  • The most recent commit touching this method (4ba9fd9c5, "Reconcile commit() type for
    rocksdb-js 2.2.0 coordinated-retry sentinel") is a type-only cast around rocksdb-js's
    RETRY_NOW sentinel, which commit() can resolve to (not reject) when coordinatedRetry: true is passed and an IsBusy conflict occurs. That commit's own message says "Full
    RETRY_NOW handling is a separate change" -- flagging as the most recently-touched code in
    this exact path, though this repro's calls don't pass coordinatedRetry, so on paper it
    shouldn't apply.
  • There's no timeout/watchdog anywhere in commit()'s success path for the underlying native
    transaction.commit() promise itself. checkOverloaded() exists but only protects
    later, concurrent callers from queueing behind an already-slow commit
    (STORAGE_MAXTRANSACTIONQUEUETIME, default 45s) -- it does nothing for the stuck commit
    itself, and in a purely sequential single-writer ingest (this repro's exact shape), there's
    no later caller to ever trigger it.

We also traced this in a real ETL pipeline ingesting ~50-60M rows via this same in-process
operation() upsert path (batches of ~1000, sequential) -- three occurrences in one session,
each on a fresh push of an already-packed bundle, each stalling sooner than the last (~58min
→ ~20min → ~20min), which reads like something cumulative across the process's lifetime
rather than a per-request fluke.

Are you planning to fix this issue?

No, just reporting the issue

First-time contributor support

  • I'm new to contributing and would appreciate guidance on the process
  • I'd like help understanding the project structure
  • I need assistance with setting up the development environment
  • I'm comfortable contributing, but new to this project specifically

Activity

  1. pbrumblay commented on Jul 14, 2026

    @pbrumblay
    ContributorAuthor

    I recreated this problem on 5.1.19 last night. It took 2 hours 15 minutes on my M1 mac.

  2. self-assigned this
    on Jul 15, 2026
  3. ldt1996 commented on Jul 15, 2026

    @ldt1996
    Contributor

    Reproduced reliably in a CPU-throttled container

    The standalone repro.js did not reproduce on bare metal for me (ran ~383M rows clean). The trigger turned out to be periodic suspension of the process during commits, not commit volume. Every capture in this issue shows the process being suspended by macOS App Nap; the same effect comes from cgroup CPU throttling, which is exactly what CPU-limited production containers do. Running Harper under a tight CPU quota reproduces the hang.

    Steps (Docker required)

    1. Build an image with harper@5.1.19 and the load harness.

    Dockerfile:

    FROM node:24-bookworm-slim
    WORKDIR /work
    RUN npm init -y && npm install harper@5.1.19
    COPY load.mjs /work/
    ENV HOME=/work/home
    load.mjs (installs + runs Harper, drives sequential upserts, flags any commit that never returns)
    import { spawn } from 'node:child_process';
    import { setTimeout as sleep } from 'node:timers/promises';
    import fs from 'node:fs';
    
    const PORT = 9935, USER = 'admin', PASS = 'password', DB = 'data';
    const CONCURRENCY = +(process.env.CONCURRENCY || 4);
    const BATCH = +(process.env.BATCH_SIZE || 1000);
    const STALL_MS = +(process.env.STALL_MS || 90000);
    const ROOT = '/work/hdb', HOME = '/work/home';
    const auth = 'Basic ' + Buffer.from(`${USER}:${PASS}`).toString('base64');
    try { fs.mkdirSync('/logs', { recursive: true }); } catch {}
    const log = (m) => { const l = new Date().toISOString() + ' ' + m; console.log(l); try { fs.appendFileSync('/logs/progress.log', l + '\n'); } catch {} };
    
    const op = async (body) => {
    	const r = await fetch(`http://127.0.0.1:${PORT}`, { method: 'POST', headers: { Authorization: auth, 'Content-Type': 'application/json' }, body: JSON.stringify(body) });
    	return { ok: r.ok, status: r.status, text: await r.text() };
    };
    
    if (!fs.existsSync(ROOT)) {
    	log('installing harper...');
    	await new Promise((res, rej) => spawn('./node_modules/.bin/harper',
    		['install', `--ROOTPATH=${ROOT}`, `--HDB_ADMIN_USERNAME=${USER}`, `--HDB_ADMIN_PASSWORD=${PASS}`,
    			'--DEFAULTS_MODE=dev', `--OPERATIONSAPI_NETWORK_PORT=${PORT}`, '--TC_AGREEMENT=yes', '--THREADS_COUNT=1'],
    		{ stdio: 'inherit', env: { ...process.env, HOME } }).on('exit', (c) => (c === 0 ? res() : rej(new Error('install exit ' + c)))));
    }
    const harper = spawn('./node_modules/.bin/harper', ['run'], { stdio: ['ignore', 'pipe', 'pipe'], env: { ...process.env, ROOTPATH: ROOT, HOME } });
    harper.stdout.on('data', (b) => { try { fs.appendFileSync('/logs/harper.log', b); } catch {} });
    harper.stderr.on('data', (b) => { try { fs.appendFileSync('/logs/harper.log', b); } catch {} });
    
    for (let i = 0; i < 60; i++) { try { if ((await op({ operation: 'system_information' })).ok) break; } catch {} await sleep(1000); }
    for (let w = 0; w < CONCURRENCY; w++) await op({ operation: 'create_table', database: DB, table: `T${w}`, hash_attribute: 'id' });
    log(`started: concurrency=${CONCURRENCY} batch=${BATCH} stall_ms=${STALL_MS}`);
    
    let stalled = false, rows = 0;
    async function writer(w) {
    	const pad = 'x'.repeat(200);
    	for (let b = 0; !stalled; b++) {
    		const recs = Array.from({ length: BATCH }, (_, i) => ({ id: `w${w}-${b * BATCH + i}`, payload: pad }));
    		const stuckId = recs[0].id;
    		const timer = setTimeout(() => { stalled = true; log(`STALL DETECTED writer=${w} table=T${w} stuck_id=${stuckId}`); }, STALL_MS);
    		const r = await op({ operation: 'upsert', database: DB, table: `T${w}`, records: recs });
    		clearTimeout(timer);
    		if (stalled) return; // this writer's commit hung and never returned
    		if (!r.ok) { log(`upsert_fail writer=${w} status=${r.status} ${r.text.slice(0, 120)}`); return; }
    		rows += BATCH;
    		if (w === 0 && b % 500 === 0) log(`progress ~${rows} rows`);
    	}
    }
    await Promise.all(Array.from({ length: CONCURRENCY }, (_, w) => writer(w)));
    log(stalled ? 'stopped after stall' : 'completed without stall');
    docker build -t harper-hang:5.1.19 .

    2. Run it under a tight CPU quota (this is the trigger), with a raised fd limit.

    mkdir -p /tmp/hang-logs
    docker run -d --name harper-throttle \
      --cpus=0.5 -m 4g --ulimit nofile=1048576:1048576 \
      -e CONCURRENCY=4 -e BATCH_SIZE=1000 -e STALL_MS=90000 \
      -v /tmp/hang-logs:/logs \
      harper-hang:5.1.19 node load.mjs

    --cpus=0.5 makes cgroup CFS freeze the whole process mid-commit. --ulimit nofile keeps it from hitting the file-descriptor ceiling first.

    3. Wait for a stalled commit (about 1 to 2 hours of sustained load; mine hit around 24M rows).

    grep "STALL DETECTED" /tmp/hang-logs/progress.log
    # e.g. STALL DETECTED writer=0 table=T0 stuck_id=w0-6066000

    4. Confirm it is the hang and not just slowness. Lift the throttle so a merely slow commit would finish, then check the stuck row never appears (substitute the table and stuck_id from your log):

    docker update --cpus=8 harper-throttle
    docker exec harper-throttle node -e 'const a="Basic "+Buffer.from("admin:password").toString("base64");fetch("http://127.0.0.1:9935",{method:"POST",headers:{Authorization:a,"Content-Type":"application/json"},body:JSON.stringify({operation:"search_by_hash",database:"data",table:"T0",ids:["w0-6066000"]})}).then(r=>r.text()).then(console.log)'

    Confirmed when, minutes after unthrottling:

    • the stuck row stays [] (its commit never lands, while the prior batch committed fine),
    • docker stats --no-stream harper-throttle shows Harper near 0% CPU with all threads parked,
    • other operations still return 200,
    • /tmp/hang-logs/harper.log contains JavaScript execution has taken too long.

    This matches the original signature exactly: one commit's completion is lost, and the process is otherwise idle and still serving other requests. Because it reproduces under cgroup throttling, it also lines up with the real ETL pipeline hitting it in CPU-limited containers.

    Lavinia, via Claude

  4. self-assigned this
    on Jul 16, 2026
  5. kriszyp commented on Jul 17, 2026

    @kriszyp
    Member

    Fixed with #1696, released in 5.1.22

  6. pbrumblay commented on Jul 20, 2026

    @pbrumblay
    ContributorAuthor

    @kriszyp - I was able to reproduce this on 5.1.22 using https://github.com/pbrumblay/harper-hang-repro.

    Via claude:

    It reproduced — same signature, dead on. Run number 2 hit it at batch 70,245 (~70.2M rows), after ~76 minutes, right in the same range as the original occurrences. Diagnostics confirm it's the identical bug:

    top: process at 0.0% CPU, state sleeping — not spinning, not computing
    Thread sample: main thread parked in uv_run → uv__io_poll → kevent, the event loop genuinely idle with nothing queued
    Harper's own log: repeating "JavaScript execution has taken too long and is not allowing proper event queue cycling..." — the exact same warning noted in your original repro doc
    So: run number 1's clean pass was luck, not a fix. This confirms what we suspected from reading PR #1696 — it fixes a real but different bug (sourceApply/replication ERR_TRY_AGAIN wedging), and the plain in-process bulk-upsert hang you originally found is still present in 5.1.22, unresolved.

    Practical implication: the upgrade won't fix this class of stall if you hit it again in production. It's still a real, worthwhile upgrade for the sourceApply fix and whatever else landed in 5.1.19–22, but worth setting expectations that our exact incident could recur regardless of Harper version, until Harper addresses the root cause your doc's investigation section points at (the native commit-completion signal being lost).

    More detail here: https://github.com/pbrumblay/harper-hang-repro/blob/main/2026-07-20-reproduction-5.1.22.md

  7. hdbjeff commented on Jul 21, 2026

    @hdbjeff
    Contributor

    @pbrumblay I opened a draft repair for the standalone repro harness: pbrumblay/harper-hang-repro#1

    The key correction is that the historical 5.1.22 run did not capture where the request stopped. Its nominal 90-second watchdog fired 781,206 ms late on the same event loop as fetch(), then ran synchronous diagnostics without recording later settlement. The target values were visible when queried later, but the capture cannot distinguish a lost Harper/native completion from an already-completed server response whose separate client was suspended or delayed.

    The patch moves deadlines and captures to a separate process, correlates client and Harper HTTP stages with X-Repro-Id, probes attempt-specific row values, records timer lateness and late settlement, and labels an unresolved deadline neutrally until the boundaries are classified. A deterministic one-row control now demonstrates the old false-positive capability: Harper completes and the row is queryable while only the client is stopped, then the repaired harness records late settlement instead of a Harper stall.

    This does not explain away the original in-process report or the separate Linux row-absent report; those have different signatures.

    Could you please run the PR's documented one-row control first, then rerun the 5.1.22 high-volume test from a fresh root? If it crosses the deadline, please retain the correlated JSONL files and matching deadline-* directory. Those artifacts should tell us whether the last boundary is native/Harper completion, server response delivery, or the external client.

  8. kriszyp commented on Jul 21, 2026

    @kriszyp
    Member

    Closing after validating the standalone reproduction with Jeff's PR pbrumblay/harper-hang-repro PR #1, “Repair stall classification and capture request boundaries”.

    I ran both documented tests against Harper 5.1.22:

    • The deliberate client-suspension control was classified correctly as DEADLINE_EXCEEDED_BUT_SETTLED: Harper finished the response and the attempt-specific row was visible before the external deadline fired; the client received the response after it resumed.
    • A fresh sequential run completed 100,000 batches of 1,000 rows, totaling 100,000,000 rows, in 69 minutes 30 seconds.
    • All 100,000 correlated request IDs appeared in the client, Harper server, and external watchdog traces.
    • Every watchdog arm ended settled_before_deadline; every Harper request reached response finish and close.
    • There were zero deadline captures, and Harper exited with code 0.

    This validates the harness repair and leaves no reproduction of a post-5.1.22 Harper request-settlement defect on the standalone sequential path. The historical 5.1.22 capture remains unclassified because its same-event-loop 90-second watchdog ran 781,206 ms late and did not record eventual settlement.

    The original ERR_TRY_AGAIN retry defect remains fixed by HarperFast/harper PR #1696, “fix(storage): replay conflict retry on a fresh transaction after ERR_TRY_AGAIN”. The distinct in-process report and concurrent Linux row-absent report are not disproven by this run, but either would need a separately targeted reproduction with corrected boundary capture before motivating another Harper fix.

    Note that we also observed/reproduced failure cases if the maximum open file descriptors is too low on an environment. These errors should be observable in logs. We have added some mitigation for this with HarperFast/rocksdb-js#715 to handle environments that have max fds set too low. But this seems to be more pathological, and I doubt this was the case in these reproduction attempts, but might be worth a check on the logs to verify.

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

Metadata

Metadata

Labels

bugSomething isn't working

Type

No type

Fields

Priority

None yet

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions