From f28494247b2f5487869eca68f3245c2691aa5e1b Mon Sep 17 00:00:00 2001 From: sh Date: Thu, 30 Jul 2026 07:50:30 +0000 Subject: [PATCH] docs: use plainer wording in leak findings --- docs/leak-findings.md | 103 ++++++++++++++++++++++-------------------- 1 file changed, 53 insertions(+), 50 deletions(-) diff --git a/docs/leak-findings.md b/docs/leak-findings.md index c962b6b90..b7f7a3813 100644 --- a/docs/leak-findings.md +++ b/docs/leak-findings.md @@ -32,7 +32,7 @@ About 20 KiB per unanswered forward. How long it is held depends on how the rela | relay behaviour | result | | --- | --- | | slow but still replies | not a leak here, the late reply deletes the entry (but see Leak 3) | -| goes fully silent | bounded, `monitor` tears the client down at ~20 min | +| goes fully silent | bounded, `monitor` closes the client at ~20 min | | replies to some, drops others | **unbounded** | The third case is the problem. Any arriving reply resets `lastReceived` and `timeoutErrorCount`, @@ -51,15 +51,15 @@ the unbounded case replies are arriving anyway, which resets the counters either ### Fix -Do not just delete on timeout. Late replies are load bearing: `processMsg` forwards them as +Do not just delete on timeout. The agent still needs late replies. `processMsg` forwards them as `STResponse` (`Client.hs:713`), and `Agent.hs:3093` acts on them. A late `OK`/`SOK` to a `SUB` calls `processSubOk`, which is what brings a connection back UP, and a late `MSG` is processed as a real message. Deleting on timeout turns both into `STUnexpectedError` (`Client.hs:702`), so the agent would report an error instead of recovering, and drop the message. -Bound the map by age instead: stamp `Request` on insert, sweep entries with `pending == False` -older than the window in which a late reply can still matter. Picking that window needs the -agent's recovery behaviour measured, which is not done here. +Delete by age instead: record the time on `Request` when it is added, and remove entries with +`pending == False` that are older than the point where a late reply is no longer useful. Choosing +that age needs the agent's recovery behaviour measured, which is not done here. Two entry points can be fixed by deleting, because no reply is ever coming. `mkTransmission_` inserts before sending (`Client.hs:1361`) and `sendRecv` returns early at `Client.hs:1366` @@ -72,7 +72,7 @@ inserts before sending (`Client.hs:1361`) and `sendRecv` returns early at `Clien ### Issue A failed connect is cached in `smpClients` as `Left (error, expiry)` (`Client/Agent.hs:275`) and -removed only on a later lookup of the same server (`:250`, `:411`). Nothing sweeps on a timer. +removed only on a later lookup of the same server (`:250`, `:411`). Nothing removes it on a timer. The other removals are `clientDisconnected` (`:311`, connected clients only) and shutdown (`:427`). @@ -85,12 +85,12 @@ Host, port and key hash come from the client, so distinct addresses are unlimite `proxy_smpClients = 300` after 300 dead addresses, ~19 KiB each, never freed while the process runs. 1000 entries created in about 1s. -That is ~19 MiB/s when the address refuses immediately. An address that blackholes waits out the -45s connect timeout, which throttles it heavily. +That is ~19 MiB/s when the address refuses the connection immediately. An address that accepts +nothing and never answers waits out the 45s connect timeout, which slows it right down. ### Fix -Sweep the map on a timer, dropping entries past their expiry. The timestamp is already stored. +Check the map on a timer and remove entries past their expiry. The timestamp is already stored. --- @@ -99,8 +99,8 @@ Sweep the map on a timer, dropping entries past their expiry. The timestamp is a ### Issue `newSMPClientAgent` creates one `msgQ` (`Client/Agent.hs:194`) and `connectClient` gives that same -queue to every relay client (`:296`). The ntf server drains its copy -(`Notifications/Server.hs:537`). The SMP server never drains its own: `receiveFromProxyAgent` +queue to every relay client (`:296`). The ntf server reads its copy +(`Notifications/Server.hs:537`). The SMP server never reads its own: `receiveFromProxyAgent` reads `agentQ` only (`Server.hs:475`). There are three `readTBQueue` sites on a `msgQ` in `src/` and none is the proxy's. @@ -121,14 +121,14 @@ then lag cleared and 3 more attempted. Only `msgQSize` differs. | 2 | 2 (at cap) | 4 and climbing | **0 of 3** | | 2048 (production) | 4 | 0 | 3 of 3 | -Two things. The queue never drains: at production size it still holds the 4 late replies at the -end of the run. And when it fills the stall is permanent, not slow: the recovery forwards ran +Two things. The queue is never emptied: at production size it still holds the 4 late replies at +the end of the run. And when it fills the stall is permanent, not slow: the recovery forwards ran with no latency at all and got nothing back. One `msgQ` per agent and one `ProxyAgent` per server, so one slow relay stalls the proxy for every relay it talks to. That part is from the code, not measured: the bench has one relay. -2048 late replies is a cheap budget for an attacker who controls the destination relay. +Someone who controls the destination relay only needs 2048 late replies to do this. This also corrects Leak 1's "slow relay is not a leak" row. That is right about `sentCommands` and wrong about the session: the late replies that clear `sentCommands` are the ones that pile up @@ -142,7 +142,7 @@ also work but still allocates and copies every batch. --- -## Bug 3: proxy concurrency limit is inert +## Bug 3: proxy concurrency limit does nothing ### Issue @@ -200,34 +200,35 @@ work before its delete: | spins 100us | 17.8% | 9.8% | | one failing `connect()` | **0%** | **0.1%** | -A spinning child does not lose the race, it starves the parent. The window closes when the child -gives up the capability: syscall, safe FFI call, or STM retry. +A child that just spins does not lose the race, it keeps the CPU from the parent. The parent only +wins when the child hands the CPU back, which happens on a syscall, a safe FFI call, or an STM +retry. Against that rule, of the three call sites: - `forkCmd` (`Server.hs:1593`) for `PFWD`/`PRXY`/`RSLV`: all do network IO, all yield. `RSLV` was checked separately since it is client driven at command rate, but `resolveName` has no cache (`Server/Names.hs:62`). -- `deliverServiceMessages` (`Server.hs:1977`): `clientServiceSubscribed` is a one-way latch - (`Server.hs:2031`), so at most once per connection. -- `sendPendingEvtsThread.queueEvts` (`Server.hs:463`): the only one that can skip yielding. The - child is `writeTBQueue sndQ` plus three `IORef` bumps, so if space appeared it commits straight - through. +- `deliverServiceMessages` (`Server.hs:1977`): `clientServiceSubscribed` is set to `True` once + (`Server.hs:2031`) and never reset, so this runs at most once per connection. +- `sendPendingEvtsThread.queueEvts` (`Server.hs:463`): the only one that can finish without + yielding. The child does `writeTBQueue sndQ` and three `IORef` updates, so if space appeared in + the queue it finishes straight away. ### Impact -Small and bounded, and not driven live. +Small, and not reproduced against a running server. -The one non-yielding path forks at most twice per client per `pendingENDInterval` (15s, -`Server/Main.hs:581`), and only for a client whose `sndQ` was full at the check and drained by the -time the child ran. `clientDisconnected` (`Server.hs:1237`) drops the whole map, so nothing -survives the session. +The one path that can skip yielding forks at most twice per client every 15s +(`pendingENDInterval`, `Server/Main.hs:581`), and only when that client's `sndQ` was full at the +check and had emptied by the time the child ran. `clientDisconnected` (`Server.hs:1237`) clears +the whole map, so nothing outlives the session. -A client can influence both preconditions by stalling and resuming socket reads, so this is not -unreachable, but winning a sub-millisecond window at two attempts per 15s was not demonstrated. +A client can affect both of those by pausing and resuming its socket reads, so this is not out of +reach, but hitting a sub-millisecond window at two tries per 15s was not shown. -Practical cost is the misleading `endThreads` counter, which mixes stale entries with genuinely -running forked commands. +The real cost is that the `endThreads` counter is misleading: it mixes stale entries with commands +that are actually still running. ### Fix @@ -252,16 +253,18 @@ atomically $ modifyTVar' endThreads $ IM.adjust (const (Just w)) tId All recovered. Also clean: 400 connect/disconnect rounds, and steady forwarding at 50ms each way. -Sample late. At +5s the middle two still read ~120 KiB per connection, which looks like a 24 MiB -leak but is teardown in progress. Falling means reclaimed, flat above baseline means leaked. +Measure well after closing. At +5s the middle two still read ~120 KiB per connection, which looks +like a 24 MiB leak but is just connections still closing. A number that keeps falling is being +freed; a number that stops above where it started is leaked. -Peaks still matter: 200 abandoned half open connections hold ~40 MiB for ~25s, unauthenticated. A -client that finishes the handshake then sends one byte holds ~265 KiB for as long as it stays -connected, since `transportTimeout` is hardcoded `Nothing` (`Transport/Server.hs:104`). +The peaks are still worth knowing. 200 abandoned half open connections hold ~40 MiB for ~25s, with +no authentication needed. A client that finishes the handshake then sends one byte holds ~265 KiB +for as long as it stays connected, because there is no read timeout: `transportTimeout` is +hardcoded `Nothing` (`Transport/Server.hs:104`). ## Clean: connectivity and sockets under latency -`BENCHLAG_MS` swept on `proxyfwd`, one way. Sockets counted from `/proc//fd`. +Latency set with `BENCHLAG_MS` on `proxyfwd`, one way. Sockets counted from `/proc//fd`. | lag each way | delivered | sockets | relay connects | reconnects | timeouts | | --- | --- | --- | --- | --- | --- | @@ -271,31 +274,31 @@ connected, since `transportTimeout` is hardcoded `Nothing` (`Transport/Server.hs | 16s | 4/4 | 8 | 1 | 0 | 0 | | 40s | 0/2 | 8 | 1 | 0 | 1 | -Nothing accumulates. Same socket count whether forwards succeed or time out, session opened once -and reused, no reconnects at any latency. +Nothing builds up. The socket count is the same whether forwards succeed or time out, the session +is opened once and reused, and there are no reconnects at any latency. -That robustness is what makes Leak 1 unbounded: the session holding the stuck entries never drops. +This is why Leak 1 has no upper bound: the session holding the stuck entries never closes. -Forwards work to 16s each way and fail at 40s, governed by the 30s RFWD timeout. The exact cutoff -is not pinned down, since the test transport delays per read/write cycle rather than per message. +Forwards work to 16s each way and fail at 40s, because of the 30s RFWD timeout. The exact cutoff is +not measured, since the test transport adds its delay per read/write rather than per message. ## Checked, not a problem: socketsLeaked accounting `closeConn` (`Transport/Server.hs:179`) removes from `active`, calls `gracefulClose conn 5000`, -then increments `closed`, and `socketsLeaked = accepted - closed - active`. That ordering leaves a -window where a closing connection is in neither bucket. +then increments `closed`, and `socketsLeaked = accepted - closed - active`. In that order there is +a moment where a closing connection is counted in neither number. -The window never opened in practice. Over 600 sequential cycles and 200 simultaneous teardowns, -read from the control port, `leaked` was 0 at every sample. The 5000 is a timeout, not a delay. +It never happened in practice. Over 600 sequential cycles and 200 connections closed at once, read +from the control port, `leaked` was 0 every time. The 5000 is a timeout, not a delay. -Listed because an earlier version of this report called it a bug on code reading alone. +Listed because an earlier version of this report called it a bug based only on reading the code. ## Already fixed: empty session variable `withGetSessVar'` (`Session.hs:65`) wraps the session var in `bracketOnError` with -`dropEmptySessVar`, so an interrupted connect drops the empty var. Fixed in `c9ebf72e`. -`SMPProxyTests` covers the proxy and agent variants and both pass. Not reproducible because it is -fixed, not because it never happened. +`dropEmptySessVar`, so an interrupted connect removes the empty var. Fixed in `c9ebf72e`. +`SMPProxyTests` covers the proxy and agent cases and both pass. It cannot be reproduced because it +is already fixed, not because it never happened. ## Running the suite