Repository navigation
Outstanding-commit wedge recurs on 5.2.6/5.2.7: native commits never settle and checkOverloaded 503s every application write on the thread until restart #2450
Description
Summary
On a production Harper Fabric control-plane node running harper-pro 5.2.6, three worker threads each had a native write commit that never settled. checkOverloaded() then rejected every new application write on those threads with the 503 Outstanding write transactions have too long of queue, please try again later for ~12.5 minutes, until the process was restarted (an upgrade to 5.2.7). Nothing else was logged: no RocksDB stall, no long-reader release, no event-loop stall warning at onset, no MDB_/ERR_BUSY error. Host resources were healthy throughout (37% memory, 3.5% CPU, 18% disk).
This is the harper#2001 family recurring with the #2001 fix present: trackOutstandingCommit() correctly detected and named the stuck commits (that part of #2001 works), but a commit that never settles is still never aborted, timed out, or diagnosed — the thread stays wedged until a restart. 5.2.6 and 5.2.7 are identical on this path (rocksdb-js 2.7.1, abandonWrites present in both), so upgrading does not prevent recurrence.
Timeline (UTC, 2026-09-01)
- 20:25:03 — the three commits are submitted (each is timed from its own submission).
- 20:25:48 — the guard fires on three threads within ~100ms, one stuck commit each:
[http/9] [error]: Rejecting writes on this thread: a commit has been outstanding for 45019ms (exceeds the 45000ms limit), from table: data.Host/ (transaction 1724751), started from Host.patch. Further record updates and publishes from new application requests on this thread will be rejected with 503 until the commit settles or the process is restarted (...)
[http/10] ... from table: data.InstanceMonitoring/ (transaction 1724755), started from InstanceMonitoring.patch ...
[http/8] ... from table: data.Host/ (transaction 1724822), started from Host.patch ...
- 20:25:48 → 20:38:15 — every application write on http/8, /9, /10 is rejected. The rejection surfaced to the app as an
unhandledRejectionper write (the app's own bug, fixed separately), ~14K lines in the hour:
[http/10] [error]: unhandledRejection in worker thread 10: Error: Outstanding write transactions have too long of queue, please try again later
at DatabaseTransaction.checkOverloaded (core/resources/DatabaseTransaction.ts:718:10)
at Object.validate (core/resources/Table.ts:2343:20)
at DatabaseTransaction.save (core/resources/DatabaseTransaction.ts:858:29)
at TableResource.#saveOperation (core/resources/Table.ts:1898:33)
at TableResource.save (core/resources/Table.ts:1869:32)
at TableResource.patch (core/resources/Table.ts:2281:16)
at patch.transactional.hasContent (core/resources/Resource.ts:180:17)
at runAction (core/resources/Resource.ts:835:20) statusCode=503
- 20:38:52 — process restarted (upgrade to 5.2.7):
Harper was not properly shutdown→Replayed 23412 records in data database→ healthy since. The stuck commits were cleared by the restart, exactly as the guard's message says; nothing else would have cleared them.
The two tables are the app's host/instance monitoring rows, patched every few seconds per connected host — a write shape that had run for months on v4 and for days on 5.2.x without incident, so the trigger is rare but the writes are constant.
Ruled out
- Resource exhaustion (memory/CPU/disk healthy at onset and throughout).
- Event-loop stall: the
JavaScript execution has taken too longwarnings that day were at 14:29–14:35 and 19:10, none at 20:25. - RocksDB write stall / long-reader release: none logged in the 20:00 hour.
- harper#2368 (
@computed/@relationshipdurable writes): one of the two tables has only three scalar fields, and there were zeroattribute.seterrors. - Blob stall: neither table has blob fields.
- An app-side shared transaction: the writes are issued from a WebSocket
messagecallback. In 5.2.7 that callback runs with no ambientcontextStoragestore (native uWSmessage→ synchronousemitchain, nothingAsyncResource-bound — reproduced with a standalone uWS +AsyncLocalStorageprobe on Node 24 and 22), so each contextless staticTable.patch()resolvedcontext = {}(Resource.ts:763) and ran in its own one-shot transaction. Three independent transactions on three threads parked at the same instant — that points at something shared underneath them.
Why this is a core issue — three distinct asks
1. A submitted native commit has no deadline (the #2001 residual). trackOutstandingCommit() (DatabaseTransaction.ts:89-130 @ v5.2.7) links the commit and unlinks it only when the promise settles. checkOverloaded() (:680-721) reads the oldest and rejects new work. Nothing ever acts on the stuck commit itself: it is never aborted, its promise is never rejected, and MAX_OUTSTANDING_TXN_DURATION only gates bystanders. rocksdb-js coordinated-retry commits park on write intents held by other transactions (the comment at :975-979 says so for the retained-read-handle case that abandonWrites fixed) — so a commit can wait forever on an intent holder that never completes, and the guard turns that into a permanent per-thread outage. Ask: after the limit (or a separate storage.maxCommitSettleTime), abort/time out the parked native commit with a diagnostic naming what it was waiting on, and let the thread recover without a restart.
2. Diagnostics stop at the symptom. The one-line identity snapshot (table, native txn id, startedFrom) is a real improvement over #2001's silence, but it says nothing about why the commit is parked: which native transaction holds the conflicting intent, on which key, from which thread, and how long it has been open. Without that, a recurrence is still un-root-causable from logs — this one was. Ask: when a commit crosses the limit, dump the waited-on transaction/intent (rocksdb-js should be able to expose the lock waiter → holder relationship) and the holder's startedFrom.
3. checkOverloaded() has the wrong failure semantics for a wedge. The 503 says "please try again later", but the condition is not transient — retries cannot succeed until a restart, so clients retry-storm a dead thread (14K rejections here). And it head-of-line-blocks every unrelated write on the thread: a patch to a different table/record is rejected because one other commit hung. Related: harper#2321 reports the same guard not recovering and punishing bystanders. Ask: once a commit is past the limit by a wide margin, distinguish "wedged" from "queue overloaded" (different message/error code, non-retryable), and scope the rejection to what actually conflicts where possible.
Environment
- harper-pro 5.2.6 at the time of the incident; the process now runs 5.2.7, whose
DatabaseTransaction.ts/rocksdb-jsare identical on this path (verified by diffing the tags). - RocksDB storage; Node 24 (the harper-pro image's runtime).
- Single-container control-plane deployment (not a multitenant Fabric host); a 2-node replicated pair.
App-side workaround
The application now awaits the message handler (so the 503 lands in its catch instead of an unhandledRejection flood) and passes an explicit fresh {} context per table op so its per-call transaction scope is pinned rather than left to the ambient store. That removes the noise and hardens the app's side of the contract; it does not and cannot prevent a native commit from parking. Workaround PR: HarperFast/central-manager#763.
Metadata
Metadata
Assignees
Labels
Type
Fields
Priority
Activity
Devin-Holland commentedon Sep 2, 2026
Recurred on 5.2.7 on both production CM nodes (2026-09-02), mechanism reproduced
Field data (both nodes on harper-pro 5.2.7 / rocksdb-js 2.7.1, all from
hdb.log)data.InstanceMonitoring/fromInstanceMonitoring.patchunhandledRejection … too long of queuedata.Host/fromHost.patch, second thread 90 ms later, third at 09:02:52Both cleared only by the 13:34 UTC container restart. Ruling out the environment: RocksDB's own
LOGshows no flush/compaction/stall between 08:58 and long after 09:01 on node A (same for node B's window); sysstat shows the data disk under 0.1% util with ~1–2 ms await, CPU 99% idle, zero blocked tasks; 20% disk, 1% inodes. No job threads ran between the previous restart and either onset, and neither node logged a singleTransaction was open too long and has been abortedline, so the long-transaction monitor never reaped a holder.Two observations that locate the fault above RocksDB:
Receive watchdog: no consumer progress … for 1800000ms while paused for back-pressureevery 30 min from 04:55:01 — i.e. replication-applied writes into thedataDB stalled at the same instant as the local commit. The stall is database-wide, not thread-scoped;checkOverloaded()only reports the thread that receives new application writes.Host.patchcommits on two threads parked within 90 ms of each other.Mechanism (rocksdb-js 2.7.1,
src/binding/transaction/transaction.cppcompleteCommitWork): every Harper commit runs withcoordinatedRetry: true(DatabaseTransaction.getReadTxn). OnIsBusy, the native layer releases the commit's own VT intents and then, if any transaction currently holds a write intent on one of those slots, registers a wake callback on that holder'sLockTrackerand parks — with no deadline. The verification table is process-global and hash-addressed (128K slots,db_settings.cpp), so the holder can be a transaction on a different table whose key merely collides. If the holder never commits/aborts/closes, the parked commit never settles;trackOutstandingCommitthen ages it past 45 s andcheckOverloaded()503s every unrelated write on that thread. The holder is never logged anywhere.Reproduction (Node 24,
npm i @harperfast/rocksdb-js@2.7.1vs@2.8.0,node --expose-gc park-on-unreleased-intent.mjs):park-on-unreleased-intent.mjs
On #2466 (rocksdb-js 2.8.0 on v5.2): rocksdb-js#744 bounds the park at
ROCKSDB_JS_PARK_TIMEOUT_MS(5000 ms) and #768/#780 release dropped / env-orphaned transactions, so the thread no longer wedges and two leak classes are closed. What it does not do — and what this recurrence argues still belongs on this issue:transaction:parkTimeoutevent), so a permanently held intent now surfaces only as the initiating write failing after ~MAX_RETRIES × 5 swith the generic coordinated-retries error, and nothing names the transaction that held the slot. Ask 2 above stands: on park timeout (or whencheckOverloaded()fires) log the holder's transaction id,startedFrom, thread and age.Two adjacent observations from the same incident, filed here for triage rather than asserted as causes:
logging.stdStreams: true) went silent from the wedge onset until restart whilehdb.logkept receiving lines from every thread —docker logscontains nothing from the incident window. Either the stdio guard (harper_logger.ts, permanentdisableStdio()on EPIPE/EIO/ERR_STREAM_DESTROYED) tripped, or worker stdout stopped being drained. Unproven; worth its own issue.restartoperation, the restart job thread booted the components, HM WebSocket sessions attached to it, and once the job completed its DB handles closed while messages were still arriving:Database not open at new Transaction … getReadTxn … incomingMsgHandler. Adjacent to rocksdb-js#780, separate from the wedge.Devin-Holland commentedon Sep 2, 2026
Split the unresolved half out: #2471 — A transaction holding staged writes stays open for hours and is never reaped or identified (the holder behind the #2450 wedge). #2466 / 5.2.8 bounds the park (this issue), so #2471 tracks the holder: naming it on park timeout /
checkOverloaded(), reporting long-lived native handles, and thesourceApply/isReplayreap exemption.Bound a request-path commit's conflict retries to its queue-time budg…
Devin-Holland commentedon Sep 3, 2026
Recurred on 5.2.8 / rocksdb-js 2.8.0 (2026-09-03) — the park was not the root cause; the per-database commit lane stops
Both production CM nodes wedged again after the 5.2.8 upgrade (17:56 UTC 09-02; harper-pro 5.2.8 and rocksdb-js 2.8.0 verified inside the containers). With the park bounded at 5 s, these commits cannot have been parked:
data.InstanceMonitoringsystem.hdb_user(theaddUserat 06:54:41)data.Hostdata.PurchasedBlocksystem.hdb_sessionWhat the counters show. RocksDB's own periodic stats in
LOG.oldfreeze at onset on every affected database:rocksdb.number.keys.writtenstops advancing (node Adata: 2,152,375 from 05:16 onward; node B: 1,921,606 from 23:56), whilerocksdb.stall.microsandrocksdb.db.write.stallstay at 0. Same on 09-02 under 2.7.1 (node A frozen at 2,559,581 from 09:08, node B at 2,195,484 from 04:32). CPU ~1%, disk idle, no blocked tasks, nothing inhdb.logor RocksDBLOGat either onset. So: commits stop reaching RocksDB, RocksDB never stalls, and the whole database stops — one bug common to 2.7.1 and 2.8.0. The coordinated-retry park was only how the victims presented on 2.7.1.Per-database, staggered. rocksdb-js runs one
rocksdb-commitlane thread per database (three in/proc/<pid>/task: data, system, oauth). Each database wedges independently, at its next commit: on node Adataat 05:14 andsystemat 06:54:42, one second afterAdding user …on http/2; on node Bdataat 23:50:28 andsystemat 00:47:49 (the next session write). That is the signature of a lane thread blocking forever on the first commit that needs something a stuck thread holds — a process-global lock (the VTwriterMutex_/DBSettingsmutex taken on everyputSync/releaseIntent), a RocksDB optimistic-commit lock bucket, or a wait insideCommit(). The http workers stay alive becausecheckOverloaded()rejects their writes before they touch any of that.Main-thread stall at onset, three days running. With
logging.stdStreams: true,docker logstrackshdb.loghour by hour before and after each wedge, but receives nothing from any thread from the onset until restart (09-03: node A nothing 05h–11h; node B nothing 23h–11h), whilehdb.logkept receiving lines from every http worker. Worker stdout is drained by the main thread's event loop; file appends are not. Unproven, but consistent with the main thread being the stuck holder.What I could not do from logs: name the blocked call. The threadsafe-function calls on the lane path are all unlimited-queue (cannot block), the log-store lock orders I traced are consistent, and RocksDB reports no stall — a native stack of the wedged process is required. A read-only capture script is ready for the next occurrence (per-thread
/procwchan/syscall/kernel stacks,gdb thread apply all btif gdb is present, and an ops-API probe that tests the main thread directly). Therocksdb-js.nodein the image is unstripped, so gdb will give symbolized frames.One more variable worth knowing about: every Harper Pro worker runs
@datadog/pprof's SIGPROF wall profiler at 50 ms sampling, restarted every 60 s (analytics/profile.ts,analytics.profiling: trueby default; thev8:ProfEvntProcthreads). Signal-based sampling profilers are a documented source of infrequent deadlocks in processes that use C++ exceptions and native mutexes. Not asserted as the cause — but it is the one process-wide agent that interrupts threads at random, and disabling it on one node is a cheap discriminating experiment.Stress harness (3 workers, hot keys, coordinated retry, log entries, main-thread log reads + cooling): 12 M commits in 5 min with no wedge; a profiler-enabled variant is running. Scripts and the capture script are attached to the follow-up; #2471 (holder reporting) stands, but the fix for this issue is downstream of the stack dump.
Devin-Holland commentedon Sep 3, 2026
Root cause found from the production gdb capture (2026-09-03 17:14/17:30 UTC): RocksDB WriteBufferManager write stall. The main thread and every
rocksdb-commitlane are blocked inrocksdb::DBImpl::WriteBufferManagerStallWrites()(frames, reproduction and fix in #2490). Harper defaults the WBM on withallowStall: true(0183089, 2026-06-11 → 5.2.5–5.2.8), memtable memory across 28 column families crossed the ~660 MiB budget with no single CF near its flush trigger, RocksDB scheduled no WBM flush (flush.reason.write_buffer_manager = 0) and every writer slept forever. This is below rocksdb-js, so #2466 could not fix it; the coordinated-retry park was how the victims presented, not the cause. Reproduced deterministically withallowStall: truevs clean withallowStall: false.Resolve the cherry-pick conflicts, taking only #2556's changes
fix: redirect /login with a reason code on CSRF storage failure (#267)