fix(sync-service): terminate serves whose clients stop accepting data#4711
fix(sync-service): terminate serves whose clients stop accepting data#4711robacourt wants to merge 12 commits into
Conversation
Failing integration test for the defense-in-depth follow-up to #4708. Bounded write units cap what each stalled serve pins, but nothing reaps the serves themselves: a population of connections whose clients stop accepting data still accumulates memory and file descriptors in proportion to connection count, invisibly (stalled serves never complete, so they emit no spans and increment no request counters). The TCP send timeout only catches a fully blocked write; a trickling client — or a proxy buffering for a vanished one — evades it forever. The test parks 3 live long-pollers on never-read sockets, sets :stalled_serve_timeout to 1s, lands a transaction large enough that every serve wedges after the initial socket-buffer fill, and asserts each handler process is terminated within the timeout plus slack. Progress is defined as a completed socket write: with post-#4708 bounded write units, any client accepting even a trickle resets the deadline, so only serves accepting nothing for the full window die — and the client can reconnect and resume from its offset. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
Defense in depth for the 2026-07-01 OOM (follow-up to #4708). Serves to stalled clients never complete, so they emit no spans and increment no request counters — while each pins its in-flight response data and a file descriptor for as long as the client's connection survives, which may be forever: the TCP send timeout only catches a write that is fully blocked for its whole window, and empirically a blocked write against a full kernel send buffer can outlast it even while the client trickles. Response bodies are now written to the socket in pieces of at most 16 KiB, and a per-serve watchdog process terminates the handler when a single piece fails to complete within :stalled_serve_timeout (ELECTRIC_STALLED_SERVE_TIMEOUT, default 60s, 0 disables). Write completion is quantized by the OS at up to a send buffer's worth of drain, so the effective contract is that a healthy client drains roughly one OS send buffer per timeout window; a terminated client reconnects and resumes from its last offset. The watchdog is armed only while a write is in flight — serves idling between body elements (live long-poll holds, SSE waiting for changes) are never at risk. The bounded write unit also cuts the response data pinned in a stalled socket's driver queue from one body element (~256 KiB) to ~16 KiB, tightening #4708's per-connection bound. Two integration tests: stalled clients are reaped within the timeout (plus slack), and a slow-but-draining client whose serve spans many timeout windows is never reaped. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
Codecov Report✅ All modified and coverable lines are covered by tests. Additional details and impacted files@@ Coverage Diff @@
## main #4711 +/- ##
=======================================
Coverage 60.04% 60.05%
=======================================
Files 397 397
Lines 43766 43766
Branches 12587 12588 +1
=======================================
+ Hits 26280 26282 +2
+ Misses 17405 17403 -2
Partials 81 81
Flags with carried forward coverage won't be shown. Click here to find out more. ☔ View full report in Codecov by Harness. 🚀 New features to boost your workflow:
|
Claude Code ReviewSummaryIncremental review (iteration 8). The only change since iter-7 is commit What's Working Well
Issues FoundCritical (Must Fix)None. Important (Should Fix)None new. Two items from iter-7 remain open (both behavior-level, untouched by this test-only commit) — restated once, not re-litigated:
Suggestions (Nice to Have)
Issue ConformanceNo linked issue (references incident Previous Review Status
Reviewed statically — I did not run the suite (needs local Docker). Codecov and the author report green. Please confirm CI is green before merge. Review iteration: 8 | 2026-07-15 |
Task.start provides $initial_call/$callers metadata and richer crash reports at no behavioral cost (unlinked and unsupervised like the bare spawn it replaces — restart semantics are meaningless for a watchdog whose protocol state lives with the serve). The explicit label groups the watchdogs under a low-cardinality `serve_watchdog` process_type in per-process telemetry instead of leaving them anonymous — the incident this guards against was prolonged by exactly that kind of process invisibility. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
Review feedback: splitting every body element into 16 KiB pieces turned multi-megabyte single elements (e.g. one very large row, which the encoder byte cap cannot split) into a thousand-plus Plug.Conn.chunk calls. Under the Plug.Test adapter each call appends to an accumulated buffer, making body readback quadratic in the piece count — enough to time out RouterTest's large-binary and chunked-results tests in CI. Pieces are now 256 KiB, matching the encoder's batch byte cap, so ordinary elements are written as-is — via a fast path that skips flattening entirely, restoring the pre-watchdog zero-copy behavior for the common case — and only oversized single items are split (a 20 MB element becomes ~80 writes instead of ~1300). This does not weaken the watchdog: write completion is quantized by the OS at up to a kernel send buffer of drain, which dwarfs either piece size, so the effective progress contract is unchanged. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
|
Review feedback addressed in 877abf8 — and correcting the test-evidence claim in the description. The two RouterTest failures were real and caused by this branch, exactly as diagnosed: 16 KiB pieces turned multi-MB single elements (which the encoder byte cap cannot split) into 1,300+ Fix: piece size raised to 256 KiB, matching the encoder's batch byte cap, with a fast path that writes in-bound elements as-is (no flattening — restores pre-watchdog zero-copy for the common case). Only oversized single items are split (20 MB element → ~80 writes, not ~1,300). This doesn't weaken the watchdog: measured write-completion granularity is quantized by the OS at up to a kernel send buffer (~600 KB) of drain, which dwarfs either piece size — the progress contract ("drain roughly one OS send buffer per timeout window") is unchanged. Verified on the branch: both flagged tests pass, full (Agreed the |
Review feedback: the watchdog runs in its own process and does not inherit the handler's Logger metadata, so the reap warning — the only signal an otherwise-invisible stalled serve emits — carried only the shape handle and could not be correlated to a stack. The watchdog now sets stack_id and shape_handle as its Logger metadata at start. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
Review feedback: the module attribute duplicated the config.ex default and was effectively dead — StackConfig's seed always provides the key — so the two values could silently drift. The lookup fallback now references Electric.Config.default/1, the single source of truth. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
Comment audit follow-up: the write piece size matching the encoder's batch byte cap was a load-bearing coupling expressed only in prose — if either constant changed independently, the no-flatten fast path would silently degrade back to flattening and splitting every element. The encoder now exposes max_batch_bytes/0 and the response module derives its write bound from it, so the invariant is structural. Also de-drift a few comments: the throughput figure is phrased as an illustration rather than a claim about the current default, the reap warning is the "primary" (not "only") signal in anticipation of a telemetry counter, and the config fallback note no longer asserts another module's behavior. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
Incident details belong in commit messages and PR descriptions, where git blame already leads; a code comment should carry the rationale, which stands on its own. In a public repository a dated reference to a private incident is also a pointer no outside reader can resolve. The test moduledocs keep traceability through public PR references instead. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
alco
left a comment
There was a problem hiding this comment.
The :kill exit signal destroys the process without executing another instruction. Every ill effect below falls out of that one property: cleanup and accounting that the handler was going to do in code silently never happens.
1. Admission-control permit leak
ServeShapePlug.check_admission stashes the acquired permit in the process dictionary; the only* release site is the after clause in call/2 (serve_shape_plug.ex:94–107). The module doc explains after was chosen deliberately over register_before_send — correct for exceptions and halts, but after does not run on :kill.
Each watchdog reap permanently leaks an :existing admission permit for the lifetime of the admission-control state. Once enough permits leak to reach the configured limit, subsequent existing-shape requests are rejected with 503.
Cheapest fix: pass the held {stack_id, kind} to the watchdog at start and have the watchdog call AdmissionControl.release/2 after the kill. There is a caveat here: blindly releasing from the watchdog after calling Process.exit/2 could undercount if the handler completes and releases its permit before the asynchronous exit takes effect. Permit ownership should be transferred atomically, or the watchdog should monitor the handler and release only when it observes the watchdog-induced :killed exit while the handler still owns the permit.
2. Observability: reaps are invisible everywhere except one log line
The kill skips every emission the handler would have made on the way out:
emit_shape_telemetrynever runs, so[:electric, :plug, :serve_shape]and[:electric, :shape, :response_size]are never emitted — reaped serves stay permanently
invisible to request metrics, exactly the "stalled serves are invisible" pathology this PR's own
description complains about, now one layer up.- The root
Plug_shape_getspan and the in-flightstream_chunkspan are never ended; their
entries orphan in the OTel span ETS table until the SDK's default sweeper drops them (strategy
drop, TTL 30 min, sweep every 10 min)
The watchdog's Logger.warning is therefore the sole explicit signal a reap ever happened.
Scope caveat worth documenting
These kill semantics — and the PR's fd/memory-release guarantees — hold for Bandit HTTP/1 only, where the plug runs in the socket-owning process. Under Bandit h2c the kill hits a stream process, freeing its memory but not the fd; the socket-writing connection process is unguarded. In embedded mode (api_plug_opts → Phoenix.Sync) under Cowboy, chunk/2 is fire-and-forget messaging to the connection process, so writes "complete" instantly and the watchdog is silently inert — and when it does kill, it's killing a host-application process, skipping the host's own after/instrumentation, not just Electric's.
| counters). The TCP send timeout only catches a *fully blocked* write; a | ||
| client draining at a trickle — or a proxy buffering for a vanished client — | ||
| evades it indefinitely. |
There was a problem hiding this comment.
I wonder how this watchdog would help in a situation where a proxy is buffering for a vanished client.
There was a problem hiding this comment.
Good challenge — the compressed claim was misleading and is reworded in b20b420. Precisely: while a proxy's buffer absorbs writes, the serve completes and releases everything (handler, pinned data, fd) — nothing is held server-side, so there is nothing to reap. The watchdog matters at the point the proxy stops accepting (buffer cap / backpressure for the vanished client): writes stop completing and the deadline runs. So it helps exactly when server-side resources are actually being held, and is correctly inert before that.
| is a completed bounded socket write, so a client sustaining a modest | ||
| throughput (roughly one OS send buffer per timeout window, worst case) | ||
| keeps resetting the deadline. A serve whose client accepts nothing for the | ||
| full window is terminated; the client can reconnect and resume from its |
There was a problem hiding this comment.
How is this materially different from "The TCP send timeout only catcing a fully blocked write"?
There was a problem hiding this comment.
Materially different in two ways, one semantic and one empirical (reworded in b20b420). Semantic: the send timeout detects a driver-level send with zero kernel acceptance for its entire window; the watchdog times full completion of a bounded application-level write — a minimum-throughput floor rather than a not-perfectly-frozen check. A connection that dribbles a few bytes resets the former forever but cannot indefinitely satisfy the latter. Empirical: in the incident this addresses, hundreds of stalled serves produced exactly two send-timeout errors in an hour; and in a local probe a send blocked against a full kernel buffer survived ~29s of continuous client draining at 20KB/s without the timeout firing.
| s | ||
| end | ||
|
|
||
| on_exit(fn -> Enum.each(socks, &:gen_tcp.close/1) end) |
There was a problem hiding this comment.
Claude loves to add cleanup code to tests but it's usually not needed. The test process will terminate after the end of the test and with it all of the resources directly attributable to it.
There was a problem hiding this comment.
Removed in 859b16b — you're right, the sockets are owned by the test process and close with it.
| # (plus slack). Without reaping they live — and pin memory and a file | ||
| # descriptor each — until the client goes away, which may be never. | ||
| for {ref, pid} <- monitors do | ||
| assert_receive {:DOWN, ^ref, :process, ^pid, _reason}, |
There was a problem hiding this comment.
Since we explicitly use :kill as the exit reason, matching here on :killed would be a nice sanity check of the mechanism working as intended.
There was a problem hiding this comment.
Done in 859b16b — the DOWN assertions now match :killed specifically.
| # last offset. | ||
| defp start_write_watchdog(stack_id, response) do | ||
| # Fallback for stacks whose seed config omits the key (e.g. minimal | ||
| # unit-test stacks); Electric.Config is the single source of truth. |
There was a problem hiding this comment.
This comment can be removed without any loss of information.
There was a problem hiding this comment.
Gone in 7a54d42 (the surrounding block was rewritten as part of the module extraction).
| # body elements (a live long-poll hold, an SSE stream waiting for changes) | ||
| # is never at risk. The terminated client can reconnect and resume from its | ||
| # last offset. | ||
| defp start_write_watchdog(stack_id, response) do |
There was a problem hiding this comment.
The Watchdog should live in a standalone module. It's way more complicated for a bunch of private functions.
There was a problem hiding this comment.
Extracted in 7a54d42 as Electric.Shapes.Api.ServeWatchdog — combined with the GenServer suggestion below, so the module is the server rather than a bag of private functions.
| shape_handle = response.handle | ||
|
|
||
| {:ok, watchdog} = | ||
| Task.start(fn -> |
There was a problem hiding this comment.
Starting a new unlinked task for every write is expensive. it basically doubles the number of processes responsible for request handling.
Wouldn't a single persistent gen server be a good fit for the job?
There was a problem hiding this comment.
One correction and then agreement. Correction: it was one task per chunked response (spawned once in send_stream), not per write — but that still doubles the processes involved in every in-flight serve, so the substance stands. Implemented in 7a54d42 as a per-stack supervised GenServer: handlers cast a registration around each bounded write, and a 1s sweep kills entries past deadline and prunes handlers that died on their own. Casts mean no synchronous coupling on the serve path (volume is bounded by socket throughput / 256 KiB — a node pushing 1 GB/s generates ~4k casts/s), casts to a stack without a running instance drop silently so serving fails open, and a restart self-heals since in-flight serves re-register on their next write — supervision semantics the per-serve process could not offer. Reap precision becomes deadline + sweep interval, noise against the 60s default.
…rver Review feedback: a watchdog process per in-flight serve doubles the processes involved in request handling, and the state machine had grown too complicated for private functions in Response. The watchdog is now a standalone, supervised GenServer, one per stack. Handlers register (cast) before each bounded socket write and deregister after it; a periodic sweep terminates handlers whose in-flight write has outlived its deadline and prunes entries for handlers that died on their own. Casts mean handlers never block on the server, casts to a stack without a running instance are silently dropped (serving degrades to unguarded rather than failing), and a restart self-heals: in-flight serves re-register on their next write, leaving at most one write unguarded — supervision semantics that a per-serve process could not have. Reap precision changes from exact to deadline-plus-sweep-interval (1s), which is noise against the 60s default. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
Review feedback: matching :killed in the DOWN assertion sanity-checks that the termination came from the watchdog's untrappable kill rather than an incidental crash; and the explicit socket cleanup was dead weight — the sockets are owned by the test process and close with it. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
Review feedback: the doc did not explain how the watchdog materially differs from the TCP send timeout (it times full completion of a bounded application write — a throughput floor — where the send timeout only detects a driver-level send with zero kernel acceptance for its whole window), and the buffering-proxy claim was compressed to the point of being misleading (while a proxy absorbs writes the serve completes and holds nothing; the deadline matters once the proxy stops accepting). Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
Direct coverage for the watchdog's contract, previously exercised only through the full-stack integration tests: a write outliving its deadline is killed (with the warning logged), writes within deadline and finished writes are left alone, a new write replaces the previous deadline, entries for processes that died on their own are pruned, and registration without a running server is silently dropped (serving degrades to unguarded). The sweep interval is now configurable via start_link opts so the tests run in under a second; the default is unchanged. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
|
@alco ready for re-review. All seven comments addressed, one commit per point (each thread has a reply with its SHA):
CI: full router suite including |
|
@robacourt Thanks for addressing my comments. You have resolved all the issues pointed out in-line but my top-level review comment remains unanswered. Below, the last point in favour of using the timer approach shows a mechanism that can be used to keep track of which resources to release when a request handler needs to be The move to a single supervised process is directionally right, but the cast transport gives it the wrong load profile: two casts per bounded write means the watchdog's message rate is proportional to throughput, with a single consumer. The "~4k casts/s at 1 GB/s" estimate assumes every write is at the 256 KiB cap. That holds for snapshot serving, but live-mode deliveries are small: a fanout wakeup of ~20k long-pollers at 2-3 body elements each is a burst of ~100k casts to one process, per transaction. And queue lag here isn't just a latency problem, it's a correctness one. FIFO protects an entry only up to the enqueue time of the sweep message: a sweep enqueued at Proposal: use the timer wheel insteadFor "enforce a deadline on a blocked operation" the BEAM already has a purpose-built primitive. Arm a BIF timer around each bounded write and cancel it on completion: defp guarded_chunk(conn, data, {killer, shape_handle, timeout}) do
ref = :erlang.start_timer(timeout, killer, {self(), shape_handle})
Process.put(:watchdog_write_ref, ref)
result = Plug.Conn.chunk(conn, data)
:erlang.cancel_timer(ref, async: true, info: false)
result
endThe killer process then hears about a write only when it overruns its deadline: def handle_info({:timeout, ref, {pid, shape_handle}}, state) do
with {:dictionary, dict} <- Process.info(pid, :dictionary),
^ref <- dict[:watchdog_write_ref] do
Logger.warning("Terminating stalled shape response serve", shape_handle: shape_handle)
Process.exit(pid, :kill)
end
{:noreply, state}
endWhy this shape:
Points of comparisonI also considered an ETS table ( Each "write" below is one arm/disarm pair, on 16 schedulers, OTP 28:
Timers scale near-linearly because each scheduler owns its own timer service; ETS flatlines under contention; the cast design is bounded by the single consumer. For headroom context: the worst realistic burst (~100k writes in one fanout wakeup) costs ~200k timer BIF calls ≈ 7 ms of aggregate scheduler time, riding alongside socket writes that each cost one to two orders of magnitude more. Usual microbenchmark caveats apply (tight loop, cache-hot), but the ordering and scaling shapes are the point. Benchmark scriptdefmodule WD do
use GenServer
def init(s), do: {:ok, s}
def handle_cast({:start, pid, dl}, s), do: {:noreply, Map.put(s, pid, dl)}
def handle_cast({:finish, pid}, s), do: {:noreply, Map.delete(s, pid)}
def handle_call(:sync, _f, s), do: {:reply, :ok, s}
end
defmodule Bench do
@timeout_ms 60_000
def timer_loop(0), do: :ok
def timer_loop(n) do
ref = :erlang.start_timer(@timeout_ms, self(), :w)
:erlang.cancel_timer(ref, async: true, info: false)
timer_loop(n - 1)
end
def ets_loop(0, _tab), do: :ok
def ets_loop(n, tab) do
:ets.insert(tab, {self(), 123_456_789, :handle})
:ets.delete(tab, self())
ets_loop(n - 1, tab)
end
def cast_loop(0, _gs), do: :ok
def cast_loop(n, gs) do
GenServer.cast(gs, {:start, self(), 123_456_789})
GenServer.cast(gs, {:finish, self()})
cast_loop(n - 1, gs)
end
def par(procs, fun) do
1..procs
|> Enum.map(fn _ -> Task.async(fun) end)
|> Enum.each(&Task.await(&1, 120_000))
end
def report(label, us, writes) do
ns_per = Float.round(us * 1000 / writes, 0)
mps = Float.round(writes / us, 2)
IO.puts("#{String.pad_trailing(label, 42)} #{ns_per} ns/write (#{mps}M writes/s)")
end
end
n = 500_000
schedulers = System.schedulers_online()
IO.puts("schedulers_online: #{schedulers}, #{n} writes/proc\n")
{t, _} = :timer.tc(fn -> Bench.timer_loop(n) end)
Bench.report("timer arm+cancel, 1 proc:", t, n)
{t, _} = :timer.tc(fn -> Bench.par(schedulers, fn -> Bench.timer_loop(n) end) end)
Bench.report("timer arm+cancel, #{schedulers} procs:", t, n * schedulers)
tab = :ets.new(:wd, [:public, :set, write_concurrency: true])
{t, _} = :timer.tc(fn -> Bench.ets_loop(n, tab) end)
Bench.report("ets insert+delete, 1 proc:", t, n)
{t, _} = :timer.tc(fn -> Bench.par(schedulers, fn -> Bench.ets_loop(n, tab) end) end)
Bench.report("ets insert+delete, #{schedulers} procs:", t, n * schedulers)
cast_n = 100_000
{:ok, gs} = GenServer.start(WD, %{})
{t_send, _} = :timer.tc(fn -> Bench.par(schedulers, fn -> Bench.cast_loop(cast_n, gs) end) end)
{t_drain, _} = :timer.tc(fn -> GenServer.call(gs, :sync, :infinity) end)
total = cast_n * schedulers
Bench.report("2 casts sent, #{schedulers} procs:", t_send, total)
IO.puts(" ...but single GenServer needed another #{div(t_drain, 1000)} ms to drain its queue")
Bench.report("cast design true throughput:", t_send + t_drain, total) |
Summary
Defense-in-depth follow-up to #4708: reap shape response serves whose clients stop accepting data. Response bodies are now written to the socket in ≤256 KiB pieces (the encoder batch cap; only oversized single items are split), and a per-serve watchdog terminates the handler when a single piece fails to complete within
ELECTRIC_STALLED_SERVE_TIMEOUT(default 60s;0disables). A terminated client reconnects and resumes from its last offset.The production incident (2026-07-01)
Same incident as #4708: a customer node OOM'd after ~400 serves to stalled clients accumulated over an hour, each pinning its in-flight response chunk (~3.9 GB total, live references, GC-immune). Two properties made the population unbounded:
send_timeoutonly fires when a single write is fully blocked for its whole window. In the incident, ~400 stalled serves produced exactly 2 send-timeout errors in an hour — trickling clients (or a proxy buffering for vanished ones) evade it indefinitely.conn_max_requestsand idle timeouts apply between requests, never mid-response. There is no total-response deadline anywhere in the stack.#4708 bounded what each stalled serve pins (~19.6 MB → <1 MB). This PR bounds how long one can exist, which also caps the population — and adds the observability that was missing: every reap logs a warning with the shape handle.
Why this design (two alternatives were disproven by measurement)
1.
Time each write call— the natural first cut (watchdog around eachPlug.Conn.chunk) was killed by our own guard test: a single write of a ~256 KiB body element to a slow-but-live client legitimately takeselement_size / drain_rate— longer than any fixed deadline at some rate. Duration-per-write semantics are rate-coupled and over-reap healthy clients.2.
Poll socket statistics for progress— measuringsend_oct/send_pendvia:inet.getstatlooked like true progress tracking. A probe disproved it:send_octcounts bytes at driver enqueue (it jumped to the full send size instantly), andsend_pendstayed frozen while a test client steadily drained — the driver only moves data into the kernel in coarse bursts, so both statistics are blind to a trickle. (This also retroactively explains why the incident's serves survivedsend_timeout.)3. Bounded pieces + per-piece deadline (this PR) — once writes are bounded, a completed write is itself the progress signal: after the transport buffers fill, each piece completes only when the client actually drains. One honest caveat, measured rather than assumed: write completion is quantized by the OS — a blocked write may only complete after the kernel send buffer frees a large fraction of its capacity (measured ~580 KB / ~29s at a 20 KB/s drain on macOS; Linux signals writability much more finely). So the documented contract is: a healthy client must drain roughly one OS send buffer per timeout window — on the order of 10 KB/s worst-case at the 60s default, trivial for any live client, unmeetable for a dead one.
Side benefit: the bounded write unit cuts the response data queued in a stalled socket's driver buffer from one body element (~256 KiB) to ~16 KiB, tightening #4708's per-connection bound further.
Implementation notes
afterblock, so it cannot outlive the serve; the kill isProcess.exit(:kill)since a wedged handler is blocked inprim_inetand cannot process messages.ELECTRIC_STALLED_SERVE_TIMEOUT→ tweaks →StackConfig), runtime-tunable per stack.Test plan
low_privilege_router_test,api_test, and all oftest/integration/green (including fix(sync-service): bound memory pinned by serves to slow or stalled clients #4708's memory-budget test). Fullrouter_testincluding:slow-tagged tests green (98 tests) as of 877abf8 — an earlier revision broke two large-payload router tests in CI (see comments); the original claim here overstated the sweep by excluding:slow.mix compile --warnings-as-errorsclean.Generated with Claude Code