You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
{{ message }}
Repository navigation
Cold start: single VssStore serves all Cashu + LDK reads synchronously — 19s vs 0.56s local (34x) #90
Measurement (signet + Cashu, same config, only storage differs)
Storage
OrangeWallet::new
StorageConfig::Vss
19,050 ms
local SQLite
557 ms
Traced with RUST_LOG=info,cdk=debug,reqwest=debug,hyper=debug,rustls=debug: ~8s in the VSS store build (build_with_sigs_auth) + Cashu::init (the Cashu DB is VSS-backed), then ~10s in ldk_nodebuild_with_store reading LDK state — the KV reads appear serial, one network round-trip each. Feerate cache (288ms) and chain sync are minor. fetch_mint_info is a background task and not implicated (earlier misattribution, corrected).
OrangeWallet builds one VssStore and passes it as the single store to both CashuKvDatabase and LdkNodeStore (src/lib.rs), so every cold start rebuilds all state over the network.
Fix directions (in rough order of ambition)
Batch/parallelize the VSS reads during node build — likely the low-risk win; today's serial per-key round-trips dominate.
Local-primary with async VSS replication (read local when the on-disk store is warm; write-through to VSS; reconcile in background). ⚠️ This one needs design care: VSS-at-boot is what catches newer remote state after a restore-on-another-device, so a naive local-first read risks resurrecting stale channel state. A safe shape might be: local-first only when a VSS version/etag check (one round-trip) confirms local is current.
Happy to test candidate branches against our staging VSS (Caddy-fronted, https://…/vss) — the 34× gap makes wins easy to verify. Repro recipe and full logs in our downstream issue: emergent-money/graduated-wallet#247.
Additional evidence that this is per-operation, not just cold start: receive-URI generation shows the same signature. The trusted-tier quote flow (get_single_use_receive_uri → cashu mint quote) measured across three configurations, same mint:
Configuration
get-invoice wall clock
local-store wallet (wallet-cli)
103 ms
mint server alone (curl, HTTPS)
~700 ms
VSS-backed wallet (Android, mobile network, LSP connected)
16,650 ms
The ~16s gap is the store layer: the cashu wallet's writes during quote issuance each cost a synchronous VSS round-trip. So batching/caching in the KV path would pay off on the hot request path, not only at boot — and it strengthens the case for fix direction 1 (batch/parallelize) as the first step, since it helps both without touching the rollback-safety semantics that make direction 2 delicate.
We technically already parallelize initial reads in LDK Node for the most part, though we can surely further make some improvements there. I think some parallelization opportunities are also possible the side of Orange SDK.
However, the biggest bottleneck here seems to VSS's usage of bitreq which serializes all these reads again by making all requests through a single, non-pipelined connection, having us eat all these round-trips again. This was briefly mentioned here but I think we never followed up implementing an actual connection pool for bitreq. (cc @TheBlueMatt@tankyleo). Now tracking here: rust-bitcoin/corepc#658
However, the biggest bottleneck here seems to VSS's usage of bitreq which serializes all these reads again by making all requests through a single, non-pipelined connection, having us eat all these round-trips again.
I thought we switched Vss-client to use pipelining? That should suffice to cut parallel requests latency down substantially.
I'd really like to see trace-level logging here. 16 seconds is insanely high, even if requests are being sent serially that sounds like something else is going wrong.
Trace-level logs captured (@TheBlueMatt) — Android device, mobile network, staging VSS behind Caddy/HTTPS. We enabled TRACE for vss_client_ng/bitreq + rustls DEBUG, millisecond timestamps. Full cold start + one receive-URI generation:
The numbers:
343 VSS requests in the window (277 GetObjectRequest, 24 ListKeyVersions, 42 PutObjectRequest)
Perfectly serial: median inter-request gap 896 ms, a steady 9–10 requests per 10s for minutes
~Every request opens a fresh connection: 350 rustls client handshakes for 343 requests; 251 of 342 consecutive-request gaps contain a handshake. TLS 1.3 PSK resumption is working ("Resuming session") — but resumption still costs a new TCP connect + 1-RTT handshake per request.
Cold start on this device: Initializing orange 17:17:12 → Creating LDK node 17:19:57 (164 s in the pre-LDK phase alone, ≈ 180 serialized VSS gets) → LDK start 17:20:15. Receive-URI generation on the same run: 14.2 s ≈ 16 serialized round-trips.
So the 16 s isn't "something else" — it's arithmetic: N serialized requests × (TCP connect + TLS resume + HTTP round-trip) on a mobile-RTT path (~0.9 s each). Our earlier 19 s measurement was from a VPS near the VSS host; the phone's RTT amplifies the same per-request cost ~10×. Re: pipelining having been switched on — at our pin (orange-sdk 4e9d230 → vss-client-ng 0.5.0), the handshake-per-request pattern says each request rides a new connection, so whatever pipelining exists isn't engaging on this path.
Sample window (repeating pattern, request → fresh connection → ~900 ms → next request):
2026-07-10 17:17:12.983 TRACE [vss_client_ng::client:88] Sending GetObjectRequest 3860541630712530198 for key cZ8kPdoVXlrvfzJQS9pZ
2026-07-10 17:17:13.542 DEBUG [rustls::client::hs:73] No cached session for DnsName("lsp.emergent.money")
2026-07-10 17:17:13.542 DEBUG [rustls::client::hs:132] Not resuming any session
2026-07-10 17:17:13.741 DEBUG [rustls::client::hs:615] Using ciphersuite TLS13_AES_128_GCM_SHA256
2026-07-10 17:17:13.742 DEBUG [rustls::client::hs:472] ALPN protocol is None
2026-07-10 17:17:14.344 TRACE [vss_client_ng::client:174] Sending ListKeyVersionsRequest 4624648138170831944 for key_prefix Some("
2026-07-10 17:17:14.560 DEBUG [rustls::client::hs:130] Resuming session
2026-07-10 17:17:14.990 DEBUG [rustls::client::hs:615] Using ciphersuite TLS13_AES_128_GCM_SHA256
2026-07-10 17:17:14.991 DEBUG [rustls::client::hs:472] ALPN protocol is None
2026-07-10 17:17:15.611 TRACE [vss_client_ng::client:88] Sending GetObjectRequest 15346573794384891948 for key vQ3MSyu3cTurwbOSE7L
2026-07-10 17:17:15.802 DEBUG [rustls::client::hs:130] Resuming session
2026-07-10 17:17:15.988 DEBUG [rustls::client::hs:615] Using ciphersuite TLS13_AES_128_GCM_SHA256
2026-07-10 17:17:15.989 DEBUG [rustls::client::hs:472] ALPN protocol is None
2026-07-10 17:17:16.403 TRACE [vss_client_ng::client:88] Sending GetObjectRequest 951519899227931550 for key vQ3MSyu3cTurwbOSE7LIK
Happy to re-run the same capture against any candidate branch — the setup is scripted now.
New datapoint isolating the per-operation cost from mobile RTT: same-machine A/B (desktop, wired network, ~2 ms RTT to the Caddy-fronted VSS — not a phone), identical binary and config, only StorageConfig differs. Measured the receive/mint saga (mint-quote paid → proofs minted → PaymentReceived), 5,000-sat receive, 39 proofs:
Storage
Invoice creation
Quote paid → PaymentReceived
local SQLite
~1 s
~1 s (n=2)
VSS
10 s
60 s
Step breakdown for the VSS run: Paid notification → saga prepare10 s → execute +6 s → post_mint +3 s → PaymentReceived+41 s. That 41 s tail is entirely after the mint's HTTP response is back — it's the proof/counter/saga-state persistence batch. So even with negligible network RTT, the hot path serializes enough store round-trips to take a minute; the earlier Android numbers (~896 ms/request) are the same arithmetic with mobile RTT multiplied in.
One more observation that might sharpen fix direction 2: our production VSS store holds 1,339 keys for a store whose LDK-only baseline (measured before the Cashu tier used VSS) was ~17 keys — i.e., the Cashu WalletDatabase dominates both key count and write churn. Since Wallet::restore() already re-derives Cashu proofs from the seed on a fresh install, it's worth asking whether CashuKvDatabase needs to live in VSS at all: making the Cashu store local-primary (VSS only for LDK state, which is what actually needs the rollback-safety semantics) would take the entire trusted-tier hot path off the network without touching the delicate channel-state design in direction 2. Happy to test that shape against our staging VSS too.
I thought we switched Vss-client to use pipelining? That should suffice to cut parallel requests latency down substantially.
We pipeline reads, but refrained from pipelining writes/removes due to idempotency concerns. While it now looks like the root cause might be the insane number of cashu-related keys, it's likely still very relevant as we require quite a few writes on each event handling and IIRC we also still have interleaving writes when we deserialize channelmanager etc.? So IMO using multiple connections would help a lot here to avoid head of line blocking.
One more observation that might sharpen fix direction 2: our production VSS store holds 1,339 keys for a store whose LDK-only baseline (measured before the Cashu tier used VSS) was ~17 keys — i.e., the Cashu WalletDatabase dominates both key count and write churn.
Okay, if these 1339 keys are indeed read on startup (sequentially or even in batches) the 15 seconds start making a lot more sense.
It seems bitreq currently marks the connection as dead if no keep-alive header is set, but HTTP 1.1 doesn't require keep-alive headers, and Caddy might just omit them: rust-bitcoin/corepc#659
Can yall confirm if Caddy is returning Connection headers? Might have to just use curl to make an identical connection (or import the server private key into WireGuard, which can use that to decrypt SSL).
No Connection: and no Keep-Alive: — which HTTP/1.1 §9.3 defines as persistent-by-default, but per rust-bitcoin/corepc#659bitreq treats as connection-dead. That closes the loop on our capture: header omitted → bitreq drops the connection after every request → fresh TCP+TLS per VSS op → ~896 ms × N serialized.
(Caddy also negotiates HTTP/2 by default when offered — the bitreq path is presumably HTTP/1.1-only, which is fine once keep-alive semantics are honored.)
Standing offer stands: when the corepc fix (or a vss-client bump) is in a branch, we'll re-run the same A12 capture for before/after numbers.
One more workload datapoint with a built-in control: a trusted-tier receive's CDK issue saga made 91 VSS requests in 46s (median 634ms apart, serial) — while in the same log window, cdk's mint HTTP calls reused pooled hyper connections and completed in ~200ms each. Same process, two HTTP stacks: hyper-with-pool is fine, bitreq-without-keep-alive crawls. Nicely isolates the fix surface to the vss-client/bitreq path.
Okay but 200ms*91 is still 18 seconds which is insanely high and unacceptable. The requests need to be parallelized on the client side too. @benthecarman is that a CDK issue or something we can do?
Headline: a receive is ~30–50 serial VSS round-trips (ChannelMonitorUpdate persists are InProgress-gated, strictly one at a time), each ~300–500ms, so ~5–7s total.
Important correction to my earlier keep-alive framing: two of the three captures reused connections (0 new bitreq connections) and were just as slow — so the per-op cost is the round-trip itself (network + VSS/postgres server), not TCP/TLS handshake. Phone↔AWS RTT is ~50–150ms, so there's ~150–350ms/op of server/round-trip overhead on a warm connection to explain. A local-SQLite A/B (same ldk-node monitor persists) runs each at ~10ms, so the gap is squarely the VSS path. Happy to grab deeper timing (per-request send→response) if useful.
Can you include the namespace+key being written/read in each entry? Its hard to tell from just "we wrote something" what's going on. Maybe the LDK log as well with the same timestamps.
Added two files to the gist: captureC_full_interleaved.log (the complete raw window — LDK + VSS + rustls lines, same timestamps, unfiltered) and captureC_keymap.md.
On namespace+key: they're in the log, but post-obfuscation — VssStore obfuscates client-side (obfuscate(primary_namespace#secondary_namespace)#obfuscate(key), the schema-V1 design, so the server never learns key names), and vss_client_ng traces the obfuscated store_key it puts in the request. Since the obfuscation is deterministic, I clustered the window's 51 requests (37 Put / 9 Get / 5 List): 11 namespaces, 21 distinct keys. Highest-confidence identifications (details + evidence in the key map):
one namespace with 5 distinct keys, one per ChannelMonitorUpdate id 1–5, each written 1–2ms after its Persistence of ChannelMonitorUpdate id N line — the MonitorUpdatingPersister per-update deltas;
a separate single key at Persistence of new ChannelMonitor (the initial full monitor);
the hottest namespace: 4 keys, 20 writes, re-written throughout payment processing (event-queue / tx-metadata / manager class — inference).
If exact identities matter, would you take a small ldk-node change to trace-log the pre-obfuscation namespace+key in VssStore alongside the request id? That would make future traces self-describing. (Alternatively we can build a de-obfuscation table from our test seed, but the log-side fix helps everyone.)
Ugh, the log just says "hottest namespace — re-written throughout payment processing incl. non-channel (cdk) phases → event-queue / tx-metadata / manager class (inference)" but that's just the agent guessing. Can you not patch vss_client to simply print the raw namespace and key in each get/put?
Done — I patched VssStore (fork of ldk-node at your pinned rev 0cea341) rather than vss_client, since the obfuscation happens in VssStore and vss_client never sees a raw name. Every op now logs VSS-RAW <op> primary#secondary#key -> <obfuscated store_key>, so each line joins 1:1 with the request traces already in the gist (verified 21/21 for the hottest key).
Gist updated (same link, now with a readable front page): https://gist.github.com/hash-money/955c29b749c69e0e6c04bda24feae7cb — 00_SUMMARY.md has an annotated per-op timeline of one plain 4200-sat receive with raw keys inline; full windows in captureD_receive_raw_keys.log and captureE_coldstart_raw_keys.log (cold start).
What the raw names show — no inference this time:
The "hottest namespace" is orange_sdk##rebalance_enabled. Its obfuscated store_key is the MmTJGR9… one dominating captures A–C. Both RebalanceTrigger methods begin with an uncached KVStore::read of this flag (rebalancer.rs:65 and :147 → store.rs::get_rebalance_enabled), so it is re-fetched over the network on every trigger evaluation — 21 of the 57 round-trips in this one receive window, ~1.4s apart. It is a user-toggle boolean; caching it in memory (invalidated by set_rebalance_enabled) removes ~1/3 of the receive-window VSS traffic for free. (Side note: the same accessor panic!s on any non-NotFound store error, so each poll is also a crash surface on a flaky link.)
The receive critical path is what you suspected: serial monitor_updates#<funding_txo>#N deltas (ids 6–10 here, strictly one at a time) interleaved with ##manager rewrites (9×), one round-trip each.
Cold start is N+1 over history: cashu_wallet#transactions#<txid> ×20 and payments##<hash> ×13, all serial — 126 ops before first paint.
Happy to turn the rebalance_enabled caching into a small PR if that shape works for you.
The "hottest namespace" is orange_sdk##rebalance_enabled. Its obfuscated store_key is the MmTJGR9… one dominating captures A–C. Both RebalanceTrigger methods begin with an uncached KVStore::read of this flag (rebalancer.rs:65 and :147 → store.rs::get_rebalance_enabled), so it is re-fetched over the network on every trigger evaluation — 21 of the 57 round-trips in this one receive window, ~1.4s apart. It is a user-toggle boolean; caching it in memory (invalidated by set_rebalance_enabled) removes ~1/3 of the receive-window VSS traffic for free. (Side note: the same accessor panic!s on any non-NotFound store error, so each poll is also a crash surface on a flaky link.)
Hmm, that seems like it should be immediately addressable. (cc @benthecarman)
When you pull a log with #103, can you ask your agent to provide the full trace-log with the VssStore patch so that we get the full trace log with the additional key-level read/write info in the same log output?
Measured both. Short version: #103 is a clear win on the receive path — −44% VSS round-trips and −38% latency — and it removes a continuous ~1.5s background poll. It does not move cold start.
All numbers below are fresh captures from today; nothing is reused from the earlier A–E captures.
Build. orange-sdk pinned to a477046b (head of #103). Against our previous pin 841490c that is exactly 4 commits — Add SECURITY.md, #102, its merge, #103 — so this isolates {#102, #103} and nothing else; the two build branches differ only in that rev = line. I checked the compiled sources rather than assuming: handle.spawn(Self::init_inner(…)) is present for #102, and RebalanceTrigger reads event_queue.get_rebalance_enabled() (in-memory cell) rather than the store for #103. ldk-node unchanged at your 0cea341 with the same VssStore raw-key patch, present in both APKs — so every log has the raw keys, the vss_client_ng requests and the LDK lines in one file on one clock (VSS-RAW joins 1:1 with the requests, 32↔32 and 57↔57).
Method. Drift on this device is bigger than the effect — my first single-sample comparison against a five-day-old log looked like a regression and wasn't. So: 3 runs per build, interleaved A/B/A/B/A/B, and then the whole thing repeated as a second independent pass ~2 hours later. 18 captures. Both passes give the same conclusions; pass 2 is quoted here.
Receive — one plain 4200-sat receive, mint → LSP → phone
Ranges don't overlap. Pass 1 independently: 55.3 → 31.7 ops (−43%), 7.19 → 5.63s (−22%), also separated. The op saving is entirely the flag — baseline ops minus its own flag reads is 35.3 vs 32.7 for #103, a ~2-op residual.
Where the win comes from. Pairing monitor updates by id and splitting at PaymentReceived:
Only 1–3 of the ~23 reads land inside an open monitor-update window, so the flag was never the main cost on the commitment dance — that's still the serial monitor_updates#…#N writes, one round-trip each.
The bigger effect is that the flag is polled continuously at ~1.5s intervals and does not stop. In every baseline run 18 round-trips land after the payment is already received, and the poll was still going when we stopped capturing — last flag read 0.2–0.3s before the end of the window in all three runs, mean interval 1.50–1.60s. I'm deliberately not quoting a "tail duration" since that's bounded by how long I chose to capture rather than by the behaviour. The window-independent statement: the baseline does a VSS round-trip every ~1.5s for as long as the wallet is open; #103 does none. On a phone that's a radio wake-up every 1.5s, and for us it's worth more than the 2.9s of latency.
68 per-item reads at ~300–500ms each. Worth noting those grew from 53 in pass 1 purely because the wallet took 6 more receives in between — the cost scales with history, which is the N+1 signature. Until they're batched, or served local-first with async replication, cold start stays ~16–20s here no matter what the flag does.
On #102 specifically — treat us as no evidence either way. We run the Cashu trusted tier, not Spark. In both arms cdk work already began before Creating LDK node..., so there was no starved initializer to unblock and the difference sits inside noise. #102 wants a Spark-tier reporter; please don't read our null as a negative.
Okay, let's see, for the payment we're running in deferred write mode, so monitor writes are 2x slower. We have
One at 2026-08-23 18:37:07.873 -> 2026-08-23 18:37:08.500 -> 2026-08-23 18:37:08.882. We get the response messages out to the LSP at 2026-08-23 18:37:08.891, 9ms later.
Then we hear back from the LSP at 2026-08-23 18:37:09.116 and do a write cycle at 2026-08-23 18:37:09.118 -> 2026-08-23 18:37:09.539 -> 2026-08-23 18:37:09.942.
We then claim, with a write cycle from 2026-08-23 18:37:10.553 -> 2026-08-23 18:37:11.151 -> 2026-08-23 18:37:11.506.
We figure out the payment is up and start writing the payment state at 2026-08-23 18:37:11.513. ldk-node then writes the payment received event to its store at 2026-08-23 18:37:11.920.
After ldk-node finishes writing the payment received event, orange writes the payment claimed event at 2026-08-23 18:37:12.320.
It appears orange completes handing out the payment sent event and ldk-node and it remove their corresponding events at 2026-08-23 18:37:13.365 and 2026-08-23 18:37:13.376. However, the list of cashu_wallet#transactions at 2026-08-23 18:37:13.644 might imply orange waited an RTT before it actually handled anything - is it blocking on the payment sent event removal? @benthecarman?
There's then a few things in the cashu_wallet namespace before we get to the 7-8 second mark, so its not entirely clear to me when we got the PaymentReceived event out of orange, but maybe there's some cashu stuff in the way there too? Would be good to update the logs to include the exact time the payment event happened on the client, at least on the next round of testing @hash-money.
In lightning this means 6 RTTs to VSS + 1 RTT to the LSP after we receive the first message. There's one more RTT to VSS that we can remove with the linked PR. Then we have 2 VSS RTTs in ldk-node writing the payment state then event (@tnull can we cut this down to one at least? If the event is guaranteed to be replayed on restart from lightning why do we need to block waiting on writing the event to VSS before passing it upstream?). We then appear to wait again for an RTT to write the payment event to orange's store (@benthecarman same question as above for ldk-node).
This gives a total or 9 RTTs to VSS + 1 RTT to the LSP after PR 4981. We could make this 6 + 1 if we switched off deferred monitor writes, though I don't love that, but hopefully we can improve that with upcoming changes in future lightning versions.
All that said, the biggest issue appear to be that rustls is re-negotiating with VSS every time. That takes those 9 RTTs to VSS and makes them at least 18, or maybe 27. This is obviously the highest leverage fix as it would nearly halve our receive time.
@TheBlueMatt — next round captured, with the client-side event time stamped into the log this time. Same VSS-RAW raw-key harness, baseline fork core (pre-#103), one plain 4200-sat receive (mint → LSP → phone).
All times below are the phone wall clock (UTC). The ldk-node/orange lines are the on-device wallet.log; the one [CLIENT-APP] line is our Kotlin event drainer (RealWalletManager) logging the instant WalletEvent::PaymentReceived crossed the FFI into the app — it carries its own Instant.now(), so it joins the wallet.log clock 1:1. Payment hash f800398b…5672d, amount_msat: 4_200_000, preimage redacted.
To close the gap you flagged ("not entirely clear when we got the PaymentReceived event out of orange"):
orange gets the event at 47.223 — one ##manager write after the ldk-node ##events write at 46.708, i.e. the ~1 VSS RTT (~515 ms here) between ldk-node writing the event and orange picking it up, as you predicted.
the client app doesn't observe it until 47.758 — a further ~535 ms. In that gap: the ##orange_events write (47.224), a ##manager write (47.553), and the ##events 2-byte ack/remove (47.750). The app's waitNextEvent unblocks essentially in lockstep with that ##events ack write, and the ##orange_events ack follows at 47.763.
That last stretch looks like exactly the double-block you were raising with @tnull / @benthecarman: on this baseline core the event isn't handed upstream to the app until after the store write cycle around it completes — first on the ldk-node side (##events), then orange (##orange_events). ~535 ms of the receive is spent between "orange has the event" and "the app can render it," none of it on the wire.
For scale, HTLC-land → app-event on this run: 03:37:42.333 (first commitment_signed) → 03:37:47.758 = 5.42 s, in line with your baseline pass (6.9–8.2 s; a touch faster here, device/liquidity state).
The [CLIENT-APP] line is a one-liner in our FFI event drainer, kept out of main (DO-NOT-MERGE trace build) — I can leave it in for future rounds. Happy to drop the full raw window (VSS keys intact, preimage redacted) in a gist to join against your request log 1:1 if that's useful.
@TheBlueMatt — measured corepc#661 on the Lightning receive path you traced, plus a root cause underneath it that turned out to be the bigger story.
Setup. Same A12 / VSS-RAW harness / [CLIENT-APP] stamp as the 09-09 round, one plain 4200-sat receive per run, mint → LSP → phone, interleaved A/B/A/B/A/B with each arm reinstalled between runs. A = our current core (crates.io bitreq 0.3.4, rustls 0.21 on the VSS path). B = A with [patch.crates-io] bitreq → corepc#661 head f46ab3a (which also moves that path to rustls 0.23.38, the PR's minimum — disclosed as a confound). Per-op durations come from a VSS-RAW done <op> in <ms> line added to the trace fork.
Receive — first commitment_signed from the LSP → PaymentReceived observed by the app
A (bitreq 0.3.4)
B (#661)
HTLC → app event
5.51 / 5.19 / 5.03 s (5.24 s)
1.91 / 2.25 / 2.12 s (2.09 s)
VSS ops in the window
15 / 16 / 14
13 / 13 / 13
TLS handshakes in the window
13 / 14 / 13
0 / 0 / 0
per-op median (ms)
395 / 477 / 387 (420)
153 / 159 / 150 (154)
Ranges don't overlap on any row; pay-request → app event is 7.73 / 7.32 / 7.71 s vs 3.64 / 4.54 / 4.42 s. Every op on A opens a new TLS session (the "Resuming session … PSK" you saw — in the 6 h main-build log before this run: 1,978 requests, 2,185 handshakes). On B the connection persists, so #661 removes the handshake and the cold congestion window from every op: the per-op cost drops ~2.5× and the receive more than halves. Your "would nearly halve" estimate was conservative.
The bigger finding: large VSS writes hang until the timeout — a missing flush() in bitreq
While driving the runs, every receive that landed inside a certain 5-minute window after app start took ~2 minutes instead of 5 s. The cause: 60 s after start the BP persists the network graph (##network_graph, 1,038,424 B on Mutinynet) to VSS, and on the phone that write times out at vss-client's hard 10 s, 13 times in a row, then fails after ldk-node's max_total_delay(180 s) — 304 s in total — while every queued store write (##manager, monitor_updates) waits behind it. It repeats hourly (NETWORK_PRUNE_TIMER); the main build log shows the same 13-attempt streak at 18:48, 19:28, 20:33, 21:38.
It is not bandwidth and not the server:
phone → LAN host, 1 MB: 0.80 s; a 253 KB bdk_wallet##local_chain write completes in ~850 ms on the same phone;
a standalone client (vss-client-ng 0.6.0 + bitreq 0.3.4, fresh SigsAuth key, single attempt) run on the server host straight to vss-server over HTTP: 12/12 OK in 10–20 ms for both 1 MB and 253 KB;
the same binary from a wired desktop through Caddy/TLS: hangs in streaks regardless of size (one run: 6/6 × 253 KB hung), Caddy logging each as readfrom tcp caddy→vss: unexpected EOF — the client closed at its 10 s timer before the body was complete;
ss -tni on the client during a hang: bytes_sent ≈ bytes_acked ≈ 195–203 KB (≈ cwnd × MSS), unacked 0, notsent 0, lastsnd climbing. The kernel had nothing left to send; the application never handed over the last ~50 KB.
The code: bitreq's async request path does write.write_all(&request.as_bytes()).await and goes straight to reading the response, with no flush() (0.3.4 connection.rs:487; same on #661 at :517, and the sync path at :793). tokio-rustls' poll_write buffers the plaintext into the rustls session and only opportunistically pushes ciphertext (while wants_write { write_io → Ready(Ok(0)) | Pending => break }, then Ready(Ok(n))), so whenever the socket is full on the last write the tail of the request stays buffered forever. Small requests never hit it; anything larger than what the socket accepts in one go — a fresh connection's cwnd — hangs.
Fix is one line in each path:
let write_res = Self::timeout(request.timeout_at,async{
write.write_all(&request.as_bytes()).await?;
write.flush().await}).await;// sync path:self.stream.write_all(&request.as_bytes())?;self.stream.flush()?;
Same desktop → Caddy matrix, single attempt each:
stack
253 KB × 12
1 MB × 6
bitreq 0.3.4
6/6, 5/6 and 1/1 hung across three runs
2/8 hung
bitreq 0.3.4 + flush
12/12 OK, ~0.53 s
6/6 OK, ~0.8 s
#661 f46ab3a
first 4 hung (fresh connections), then 8/8 OK at 0.09 s once warm
6/6 OK at 0.12 s warm
#661 + flush
8/8 OK (0.64 s fresh, 0.09 s warm)
4/4 OK, 0.12–0.23 s
So #661 masks the bug once a connection is warm (the warm cwnd swallows the whole body) but every fresh connection can still hang — which is exactly what the phone's B arm did: 10 hung graph attempts, then a lucky 11th (121.8 s / 124.7 s in two runs) where A gives up at 304 s. With the flush, the phone-side 1 MB write should be a ~1 s affair. On-device check: a third arm C = #661 + the flush, installed twice — the post-launch 1 MB graph write completed on the first attempt in 1.10 s and 1.22 s (0 retries), where the same write took 304 s to fail on A and ~123 s / 11 attempts on B; its receives were 1.90 / 1.66 s, matching B.
Happy to open the flush as a PR against corepc (on top of #661 or standalone — @tnull, your call), and to put the standalone repro + the ss traces in the gist. Two smaller observations from the raw keys, for whoever owns them: the graph is persisted to the remote store hourly although it is a rebuildable cache (1 MB up every hour on a phone), and bdk_wallet##local_chain (253 KB) was re-uploaded whole roughly every 30–80 s during the runs.
The bitreq flush fix is up as a PR against corepc master on Forgejo, with unit tests through a buffering writer (both fail without the flush): https://git.rust-bitcoin.org/rust-bitcoin/corepc/pulls/705 — it applies cleanly on top of #661 as well.
Okay! Now we're getting more reasonable. #107 might cut out another RTT or two and https://git.rust-bitcoin.org/lightningdevkit/rust-lightning/pulls/4981 will cut at least one out, so it'll probably be relatively reliably under 2s. That's not perfect, but seems more tolerable than 6-10s and might be what we have to live with in the short term.
There's long-term reworks of the LDK channel persistence flow that are making progress and will cut out a bit less than half of the RTTs we see here but they're a ways away. At that point we'd be almost bound by LN protocol, basically.
Activity
hash-money commentedon Jul 10, 2026
Additional evidence that this is per-operation, not just cold start: receive-URI generation shows the same signature. The trusted-tier quote flow (
get_single_use_receive_uri→ cashu mint quote) measured across three configurations, same mint:The ~16s gap is the store layer: the cashu wallet's writes during quote issuance each cost a synchronous VSS round-trip. So batching/caching in the KV path would pay off on the hot request path, not only at boot — and it strengthens the case for fix direction 1 (batch/parallelize) as the first step, since it helps both without touching the rollback-safety semantics that make direction 2 delicate.
tnull commentedon Jul 10, 2026
Good callout!
We technically already parallelize initial reads in LDK Node for the most part, though we can surely further make some improvements there. I think some parallelization opportunities are also possible the side of Orange SDK.
However, the biggest bottleneck here seems to VSS's usage of
bitreqwhich serializes all these reads again by making all requests through a single, non-pipelined connection, having us eat all these round-trips again. This was briefly mentioned here but I think we never followed up implementing an actual connection pool forbitreq. (cc @TheBlueMatt @tankyleo). Now tracking here: rust-bitcoin/corepc#658TheBlueMatt commentedon Jul 10, 2026
I thought we switched Vss-client to use pipelining? That should suffice to cut parallel requests latency down substantially.
TheBlueMatt commentedon Jul 10, 2026
I'd really like to see trace-level logging here. 16 seconds is insanely high, even if requests are being sent serially that sounds like something else is going wrong.
hash-money commentedon Jul 10, 2026
Trace-level logs captured (@TheBlueMatt) — Android device, mobile network, staging VSS behind Caddy/HTTPS. We enabled TRACE for
vss_client_ng/bitreq+ rustls DEBUG, millisecond timestamps. Full cold start + one receive-URI generation:The numbers:
GetObjectRequest, 24ListKeyVersions, 42PutObjectRequest)Initializing orange17:17:12 →Creating LDK node17:19:57 (164 s in the pre-LDK phase alone, ≈ 180 serialized VSS gets) → LDK start 17:20:15. Receive-URI generation on the same run: 14.2 s ≈ 16 serialized round-trips.So the 16 s isn't "something else" — it's arithmetic: N serialized requests × (TCP connect + TLS resume + HTTP round-trip) on a mobile-RTT path (~0.9 s each). Our earlier 19 s measurement was from a VPS near the VSS host; the phone's RTT amplifies the same per-request cost ~10×. Re: pipelining having been switched on — at our pin (orange-sdk
4e9d230→ vss-client-ng 0.5.0), the handshake-per-request pattern says each request rides a new connection, so whatever pipelining exists isn't engaging on this path.Sample window (repeating pattern, request → fresh connection → ~900 ms → next request):
Happy to re-run the same capture against any candidate branch — the setup is scripted now.
hash-money commentedon Jul 11, 2026
New datapoint isolating the per-operation cost from mobile RTT: same-machine A/B (desktop, wired network, ~2 ms RTT to the Caddy-fronted VSS — not a phone), identical binary and config, only
StorageConfigdiffers. Measured the receive/mint saga (mint-quote paid → proofs minted →PaymentReceived), 5,000-sat receive, 39 proofs:PaymentReceivedStep breakdown for the VSS run:
Paidnotification → sagaprepare10 s →execute+6 s →post_mint+3 s →PaymentReceived+41 s. That 41 s tail is entirely after the mint's HTTP response is back — it's the proof/counter/saga-state persistence batch. So even with negligible network RTT, the hot path serializes enough store round-trips to take a minute; the earlier Android numbers (~896 ms/request) are the same arithmetic with mobile RTT multiplied in.One more observation that might sharpen fix direction 2: our production VSS store holds 1,339 keys for a store whose LDK-only baseline (measured before the Cashu tier used VSS) was ~17 keys — i.e., the Cashu
WalletDatabasedominates both key count and write churn. SinceWallet::restore()already re-derives Cashu proofs from the seed on a fresh install, it's worth asking whetherCashuKvDatabaseneeds to live in VSS at all: making the Cashu store local-primary (VSS only for LDK state, which is what actually needs the rollback-safety semantics) would take the entire trusted-tier hot path off the network without touching the delicate channel-state design in direction 2. Happy to test that shape against our staging VSS too.tnull commentedon Jul 11, 2026
We pipeline reads, but refrained from pipelining writes/removes due to idempotency concerns. While it now looks like the root cause might be the insane number of cashu-related keys, it's likely still very relevant as we require quite a few writes on each event handling and IIRC we also still have interleaving writes when we deserialize channelmanager etc.? So IMO using multiple connections would help a lot here to avoid head of line blocking.
tnull commentedon Jul 11, 2026
Okay, if these 1339 keys are indeed read on startup (sequentially or even in batches) the 15 seconds start making a lot more sense.
tnull commentedon Jul 11, 2026
It seems
bitreqcurrently marks the connection as dead if no keep-alive header is set, but HTTP 1.1 doesn't require keep-alive headers, and Caddy might just omit them: rust-bitcoin/corepc#659TheBlueMatt commentedon Jul 11, 2026
Can yall confirm if Caddy is returning Connection headers? Might have to just use curl to make an identical connection (or import the server private key into WireGuard, which can use that to decrypt SSL).
hash-money commentedon Jul 11, 2026
Confirmed (@TheBlueMatt): Caddy omits the
Connectionheader entirely on our VSS endpoint. Forced HTTP/1.1 againsthttps://lsp.emergent.money/vss/getObject:No
Connection:and noKeep-Alive:— which HTTP/1.1 §9.3 defines as persistent-by-default, but per rust-bitcoin/corepc#659bitreqtreats as connection-dead. That closes the loop on our capture: header omitted → bitreq drops the connection after every request → fresh TCP+TLS per VSS op → ~896 ms × N serialized.(Caddy also negotiates HTTP/2 by default when offered — the
bitreqpath is presumably HTTP/1.1-only, which is fine once keep-alive semantics are honored.)Standing offer stands: when the corepc fix (or a vss-client bump) is in a branch, we'll re-run the same A12 capture for before/after numbers.
hash-money commentedon Jul 11, 2026
One more workload datapoint with a built-in control: a trusted-tier receive's CDK issue saga made 91 VSS requests in 46s (median 634ms apart, serial) — while in the same log window, cdk's mint HTTP calls reused pooled hyper connections and completed in ~200ms each. Same process, two HTTP stacks: hyper-with-pool is fine, bitreq-without-keep-alive crawls. Nicely isolates the fix surface to the vss-client/bitreq path.
TheBlueMatt commentedon Jul 11, 2026
Okay but 200ms*91 is still 18 seconds which is insanely high and unacceptable. The requests need to be parallelized on the client side too. @benthecarman is that a CDK issue or something we can do?
benthecarman commentedon Jul 11, 2026
This might be more of a cdk issue but we have our own storage impl to work with vss. I'll see if we can parallelize or reduce the number of keys.
cc @thesimplekid might be relevant for you too
benthecarman commentedon Jul 13, 2026
@hash-money can you try #93 ? This should fix for cashu hopefully
12 remaining items
hash-money commentedon Jul 27, 2026
Full read/write traces from three independent receives (device-to-device, VSS-backed A12): https://gist.github.com/hash-money/955c29b749c69e0e6c04bda24feae7cb
Headline: a receive is ~30–50 serial VSS round-trips (
ChannelMonitorUpdatepersists areInProgress-gated, strictly one at a time), each ~300–500ms, so ~5–7s total.Important correction to my earlier keep-alive framing: two of the three captures reused connections (0 new
bitreqconnections) and were just as slow — so the per-op cost is the round-trip itself (network + VSS/postgres server), not TCP/TLS handshake. Phone↔AWS RTT is ~50–150ms, so there's ~150–350ms/op of server/round-trip overhead on a warm connection to explain. A local-SQLite A/B (same ldk-node monitor persists) runs each at ~10ms, so the gap is squarely the VSS path. Happy to grab deeper timing (per-request send→response) if useful.TheBlueMatt commentedon Jul 28, 2026
Can you include the namespace+key being written/read in each entry? Its hard to tell from just "we wrote something" what's going on. Maybe the LDK log as well with the same timestamps.
hash-money commentedon Jul 28, 2026
Added two files to the gist:
captureC_full_interleaved.log(the complete raw window — LDK + VSS + rustls lines, same timestamps, unfiltered) andcaptureC_keymap.md.On namespace+key: they're in the log, but post-obfuscation —
VssStoreobfuscates client-side (obfuscate(primary_namespace#secondary_namespace)#obfuscate(key), the schema-V1 design, so the server never learns key names), andvss_client_ngtraces the obfuscatedstore_keyit puts in the request. Since the obfuscation is deterministic, I clustered the window's 51 requests (37 Put / 9 Get / 5 List): 11 namespaces, 21 distinct keys. Highest-confidence identifications (details + evidence in the key map):ChannelMonitorUpdateid 1–5, each written 1–2ms after itsPersistence of ChannelMonitorUpdate id Nline — theMonitorUpdatingPersisterper-update deltas;Persistence of new ChannelMonitor(the initial full monitor);If exact identities matter, would you take a small ldk-node change to trace-log the pre-obfuscation namespace+key in
VssStorealongside the request id? That would make future traces self-describing. (Alternatively we can build a de-obfuscation table from our test seed, but the log-side fix helps everyone.)TheBlueMatt commentedon Aug 17, 2026
Ugh, the log just says "hottest namespace — re-written throughout payment processing incl. non-channel (cdk) phases → event-queue / tx-metadata / manager class (inference)" but that's just the agent guessing. Can you not patch vss_client to simply print the raw namespace and key in each get/put?
hash-money commentedon Aug 18, 2026
Done — I patched
VssStore(fork of ldk-node at your pinned rev0cea341) rather thanvss_client, since the obfuscation happens inVssStoreandvss_clientnever sees a raw name. Every op now logsVSS-RAW <op> primary#secondary#key -> <obfuscated store_key>, so each line joins 1:1 with the request traces already in the gist (verified 21/21 for the hottest key).Gist updated (same link, now with a readable front page): https://gist.github.com/hash-money/955c29b749c69e0e6c04bda24feae7cb —
00_SUMMARY.mdhas an annotated per-op timeline of one plain 4200-sat receive with raw keys inline; full windows incaptureD_receive_raw_keys.logandcaptureE_coldstart_raw_keys.log(cold start).What the raw names show — no inference this time:
orange_sdk##rebalance_enabled. Its obfuscated store_key is theMmTJGR9…one dominating captures A–C. BothRebalanceTriggermethods begin with an uncachedKVStore::readof this flag (rebalancer.rs:65and:147→store.rs::get_rebalance_enabled), so it is re-fetched over the network on every trigger evaluation — 21 of the 57 round-trips in this one receive window, ~1.4s apart. It is a user-toggle boolean; caching it in memory (invalidated byset_rebalance_enabled) removes ~1/3 of the receive-window VSS traffic for free. (Side note: the same accessorpanic!s on any non-NotFound store error, so each poll is also a crash surface on a flaky link.)monitor_updates#<funding_txo>#Ndeltas (ids 6–10 here, strictly one at a time) interleaved with##managerrewrites (9×), one round-trip each.cashu_wallet#transactions#<txid>×20 andpayments##<hash>×13, all serial — 126 ops before first paint.Happy to turn the
rebalance_enabledcaching into a small PR if that shape works for you.tnull commentedon Aug 19, 2026
Hmm, that seems like it should be immediately addressable. (cc @benthecarman)
benthecarman commentedon Aug 19, 2026
Made #103 ! @hash-money lmk how much that improves
TheBlueMatt commentedon Aug 19, 2026
When you pull a log with #103, can you ask your agent to provide the full trace-log with the
VssStorepatch so that we get the full trace log with the additional key-level read/write info in the same log output?TheBlueMatt commentedon Aug 19, 2026
Also maybe test with #102 at the same time, at least for init.
hash-money commentedon Aug 23, 2026
Measured both. Short version: #103 is a clear win on the receive path — −44% VSS round-trips and −38% latency — and it removes a continuous ~1.5s background poll. It does not move cold start.
All numbers below are fresh captures from today; nothing is reused from the earlier A–E captures.
Build. orange-sdk pinned to
a477046b(head of #103). Against our previous pin841490cthat is exactly 4 commits —Add SECURITY.md, #102, its merge, #103 — so this isolates{#102, #103}and nothing else; the two build branches differ only in thatrev =line. I checked the compiled sources rather than assuming:handle.spawn(Self::init_inner(…))is present for #102, andRebalanceTriggerreadsevent_queue.get_rebalance_enabled()(in-memory cell) rather than the store for #103. ldk-node unchanged at your0cea341with the sameVssStoreraw-key patch, present in both APKs — so every log has the raw keys, thevss_client_ngrequests and the LDK lines in one file on one clock (VSS-RAW joins 1:1 with the requests, 32↔32 and 57↔57).Method. Drift on this device is bigger than the effect — my first single-sample comparison against a five-day-old log looked like a regression and wasn't. So: 3 runs per build, interleaved A/B/A/B/A/B, and then the whole thing repeated as a second independent pass ~2 hours later. 18 captures. Both passes give the same conclusions; pass 2 is quoted here.
Receive — one plain 4200-sat receive, mint → LSP → phone
rebalance_enabledreadsPaymentReceivedRanges don't overlap. Pass 1 independently: 55.3 → 31.7 ops (−43%), 7.19 → 5.63s (−22%), also separated. The op saving is entirely the flag — baseline ops minus its own flag reads is 35.3 vs 32.7 for #103, a ~2-op residual.
Where the win comes from. Pairing monitor updates by id and splitting at
PaymentReceived:PaymentReceivedOnly 1–3 of the ~23 reads land inside an open monitor-update window, so the flag was never the main cost on the commitment dance — that's still the serial
monitor_updates#…#Nwrites, one round-trip each.The bigger effect is that the flag is polled continuously at ~1.5s intervals and does not stop. In every baseline run 18 round-trips land after the payment is already received, and the poll was still going when we stopped capturing — last flag read 0.2–0.3s before the end of the window in all three runs, mean interval 1.50–1.60s. I'm deliberately not quoting a "tail duration" since that's bounded by how long I chose to capture rather than by the behaviour. The window-independent statement: the baseline does a VSS round-trip every ~1.5s for as long as the wallet is open; #103 does none. On a phone that's a radio wake-up every 1.5s, and for us it's worth more than the 2.9s of latency.
Cold start — launch to first balance paint
rebalance_enabledreads−35% round-trips, no measurable latency change — ranges overlap heavily. Pass 1 agrees (−39% ops, 16.75 → 16.46s, overlapping).
The polls weren't gating startup. What gates it is unchanged and is still the original #90 finding — per-item serial reads before first paint:
68 per-item reads at ~300–500ms each. Worth noting those grew from 53 in pass 1 purely because the wallet took 6 more receives in between — the cost scales with history, which is the N+1 signature. Until they're batched, or served local-first with async replication, cold start stays ~16–20s here no matter what the flag does.
On #102 specifically — treat us as no evidence either way. We run the Cashu trusted tier, not Spark. In both arms cdk work already began before
Creating LDK node..., so there was no starved initializer to unblock and the difference sits inside noise. #102 wants a Spark-tier reporter; please don't read our null as a negative.Full logs — raw keys + requests + LDK lines interleaved on one clock, preimages redacted: https://gist.github.com/hash-money/955c29b749c69e0e6c04bda24feae7cb
TheBlueMatt commentedon Sep 9, 2026
Okay, let's see, for the payment we're running in deferred write mode, so monitor writes are 2x slower. We have
One at
2026-08-23 18:37:07.873->2026-08-23 18:37:08.500->2026-08-23 18:37:08.882. We get the response messages out to the LSP at2026-08-23 18:37:08.891, 9ms later.Then we hear back from the LSP at
2026-08-23 18:37:09.116and do a write cycle at2026-08-23 18:37:09.118->2026-08-23 18:37:09.539->2026-08-23 18:37:09.942.We then are ready to claim, but the BP writes the
ChannelManagerbefore processing events. This takes from2026-08-23 18:37:09.946to2026-08-23 18:37:10.547. This RTT is fixed by https://git.rust-bitcoin.org/lightningdevkit/rust-lightning/pulls/4981We then claim, with a write cycle from
2026-08-23 18:37:10.553->2026-08-23 18:37:11.151->2026-08-23 18:37:11.506.We figure out the payment is up and start writing the payment state at
2026-08-23 18:37:11.513.ldk-nodethen writes the payment received event to its store at2026-08-23 18:37:11.920.At this point LDK is continuing to complete the claim, though there's nothing in orange that cares. Still, its a bit delayed initiating the claim but that will also be fixed by https://git.rust-bitcoin.org/lightningdevkit/rust-lightning/pulls/4981.
After ldk-node finishes writing the payment received event, orange writes the payment claimed event at
2026-08-23 18:37:12.320.It appears orange completes handing out the payment sent event and ldk-node and it remove their corresponding events at
2026-08-23 18:37:13.365and2026-08-23 18:37:13.376. However, the list ofcashu_wallet#transactionsat2026-08-23 18:37:13.644might imply orange waited an RTT before it actually handled anything - is it blocking on the payment sent event removal? @benthecarman?There's then a few things in the
cashu_walletnamespace before we get to the 7-8 second mark, so its not entirely clear to me when we got the PaymentReceived event out of orange, but maybe there's some cashu stuff in the way there too? Would be good to update the logs to include the exact time the payment event happened on the client, at least on the next round of testing @hash-money.In
lightningthis means 6 RTTs to VSS + 1 RTT to the LSP after we receive the first message. There's one more RTT to VSS that we can remove with the linked PR. Then we have 2 VSS RTTs in ldk-node writing the payment state then event (@tnull can we cut this down to one at least? If the event is guaranteed to be replayed on restart fromlightningwhy do we need to block waiting on writing the event to VSS before passing it upstream?). We then appear to wait again for an RTT to write the payment event to orange's store (@benthecarman same question as above for ldk-node).This gives a total or 9 RTTs to VSS + 1 RTT to the LSP after PR 4981. We could make this 6 + 1 if we switched off deferred monitor writes, though I don't love that, but hopefully we can improve that with upcoming changes in future
lightningversions.All that said, the biggest issue appear to be that rustls is re-negotiating with VSS every time. That takes those 9 RTTs to VSS and makes them at least 18, or maybe 27. This is obviously the highest leverage fix as it would nearly halve our receive time.
hash-money commentedon Sep 9, 2026
@TheBlueMatt — next round captured, with the client-side event time stamped into the log this time. Same VSS-RAW raw-key harness, baseline fork core (pre-#103), one plain 4200-sat receive (mint → LSP → phone).
All times below are the phone wall clock (UTC). The
ldk-node/orangelines are the on-devicewallet.log; the one[CLIENT-APP]line is our Kotlin event drainer (RealWalletManager) logging the instantWalletEvent::PaymentReceivedcrossed the FFI into the app — it carries its ownInstant.now(), so it joins thewallet.logclock 1:1. Payment hashf800398b…5672d,amount_msat: 4_200_000, preimage redacted.To close the gap you flagged ("not entirely clear when we got the PaymentReceived event out of orange"):
47.223— one##managerwrite after the ldk-node##eventswrite at46.708, i.e. the ~1 VSS RTT (~515 ms here) between ldk-node writing the event and orange picking it up, as you predicted.47.758— a further ~535 ms. In that gap: the##orange_eventswrite (47.224), a##managerwrite (47.553), and the##events2-byte ack/remove (47.750). The app'swaitNextEventunblocks essentially in lockstep with that##eventsack write, and the##orange_eventsack follows at47.763.That last stretch looks like exactly the double-block you were raising with @tnull / @benthecarman: on this baseline core the event isn't handed upstream to the app until after the store write cycle around it completes — first on the ldk-node side (
##events), then orange (##orange_events). ~535 ms of the receive is spent between "orange has the event" and "the app can render it," none of it on the wire.For scale, HTLC-land → app-event on this run:
03:37:42.333(firstcommitment_signed) →03:37:47.758= 5.42 s, in line with your baseline pass (6.9–8.2 s; a touch faster here, device/liquidity state).The
[CLIENT-APP]line is a one-liner in our FFI event drainer, kept out ofmain(DO-NOT-MERGE trace build) — I can leave it in for future rounds. Happy to drop the full raw window (VSS keys intact, preimage redacted) in a gist to join against your request log 1:1 if that's useful.hash-money commentedon Sep 10, 2026
@TheBlueMatt — measured corepc#661 on the Lightning receive path you traced, plus a root cause underneath it that turned out to be the bigger story.
Setup. Same A12 / VSS-RAW harness /
[CLIENT-APP]stamp as the 09-09 round, one plain 4200-sat receive per run, mint → LSP → phone, interleaved A/B/A/B/A/B with each arm reinstalled between runs. A = our current core (crates.io bitreq 0.3.4, rustls 0.21 on the VSS path). B = A with[patch.crates-io] bitreq→ corepc#661 headf46ab3a(which also moves that path to rustls 0.23.38, the PR's minimum — disclosed as a confound). Per-op durations come from aVSS-RAW done <op> in <ms>line added to the trace fork.Receive — first
commitment_signedfrom the LSP →PaymentReceivedobserved by the appRanges don't overlap on any row; pay-request → app event is 7.73 / 7.32 / 7.71 s vs 3.64 / 4.54 / 4.42 s. Every op on A opens a new TLS session (the "Resuming session … PSK" you saw — in the 6 h main-build log before this run: 1,978 requests, 2,185 handshakes). On B the connection persists, so #661 removes the handshake and the cold congestion window from every op: the per-op cost drops ~2.5× and the receive more than halves. Your "would nearly halve" estimate was conservative.
The bigger finding: large VSS writes hang until the timeout — a missing
flush()in bitreqWhile driving the runs, every receive that landed inside a certain 5-minute window after app start took ~2 minutes instead of 5 s. The cause: 60 s after start the BP persists the network graph (
##network_graph, 1,038,424 B on Mutinynet) to VSS, and on the phone that write times out at vss-client's hard 10 s, 13 times in a row, then fails after ldk-node'smax_total_delay(180 s)— 304 s in total — while every queued store write (##manager,monitor_updates) waits behind it. It repeats hourly (NETWORK_PRUNE_TIMER); the main build log shows the same 13-attempt streak at 18:48, 19:28, 20:33, 21:38.It is not bandwidth and not the server:
bdk_wallet##local_chainwrite completes in ~850 ms on the same phone;SigsAuthkey, single attempt) run on the server host straight to vss-server over HTTP: 12/12 OK in 10–20 ms for both 1 MB and 253 KB;readfrom tcp caddy→vss: unexpected EOF— the client closed at its 10 s timer before the body was complete;ss -tnion the client during a hang:bytes_sent ≈ bytes_acked ≈ 195–203 KB(≈ cwnd × MSS),unacked 0, notsent 0,lastsndclimbing. The kernel had nothing left to send; the application never handed over the last ~50 KB.The code: bitreq's async request path does
write.write_all(&request.as_bytes()).awaitand goes straight to reading the response, with noflush()(0.3.4connection.rs:487; same on #661 at:517, and the sync path at:793). tokio-rustls'poll_writebuffers the plaintext into the rustls session and only opportunistically pushes ciphertext (while wants_write { write_io → Ready(Ok(0)) | Pending => break }, thenReady(Ok(n))), so whenever the socket is full on the last write the tail of the request stays buffered forever. Small requests never hit it; anything larger than what the socket accepts in one go — a fresh connection's cwnd — hangs.Fix is one line in each path:
Same desktop → Caddy matrix, single attempt each:
f46ab3aSo #661 masks the bug once a connection is warm (the warm cwnd swallows the whole body) but every fresh connection can still hang — which is exactly what the phone's B arm did: 10 hung graph attempts, then a lucky 11th (121.8 s / 124.7 s in two runs) where A gives up at 304 s. With the flush, the phone-side 1 MB write should be a ~1 s affair. On-device check: a third arm C = #661 + the flush, installed twice — the post-launch 1 MB graph write completed on the first attempt in 1.10 s and 1.22 s (0 retries), where the same write took 304 s to fail on A and ~123 s / 11 attempts on B; its receives were 1.90 / 1.66 s, matching B.
Happy to open the flush as a PR against corepc (on top of #661 or standalone — @tnull, your call), and to put the standalone repro + the
sstraces in the gist. Two smaller observations from the raw keys, for whoever owns them: the graph is persisted to the remote store hourly although it is a rebuildable cache (1 MB up every hour on a phone), andbdk_wallet##local_chain(253 KB) was re-uploaded whole roughly every 30–80 s during the runs.hash-money commentedon Sep 10, 2026
The bitreq flush fix is up as a PR against corepc
masteron Forgejo, with unit tests through a buffering writer (both fail without the flush): https://git.rust-bitcoin.org/rust-bitcoin/corepc/pulls/705 — it applies cleanly on top of #661 as well.TheBlueMatt commentedon Sep 14, 2026
Okay! Now we're getting more reasonable. #107 might cut out another RTT or two and https://git.rust-bitcoin.org/lightningdevkit/rust-lightning/pulls/4981 will cut at least one out, so it'll probably be relatively reliably under 2s. That's not perfect, but seems more tolerable than 6-10s and might be what we have to live with in the short term.
There's long-term reworks of the LDK channel persistence flow that are making progress and will cut out a bit less than half of the RTTs we see here but they're a ways away. At that point we'd be almost bound by LN protocol, basically.
Thanks! I left some review comments, PTAL.