-
Notifications
You must be signed in to change notification settings - Fork 353
fix(sync-service): terminate serves whose clients stop accepting data #4711
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: main
Are you sure you want to change the base?
Changes from 8 commits
ebc2319
fd747b9
3ca1bf2
877abf8
659e8ad
1d69f71
e69bb15
f66065f
7a54d42
859b16b
b20b420
d618f73
b33f6d6
9aa162a
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,5 @@ | ||
| --- | ||
| "@core/sync-service": patch | ||
| --- | ||
|
|
||
| Terminate shape response serves whose clients stop accepting data. Serves to stalled clients never complete and are invisible to request telemetry, while pinning response memory and a file descriptor each for as long as the client's connection survives — a population of them exhausted a production node. Response bodies are now written to the socket in pieces of at most 256 KiB, and a watchdog terminates the serve when a single piece fails to complete within `ELECTRIC_STALLED_SERVE_TIMEOUT` (default 60s; 0 disables). A healthy client only needs to drain roughly one OS send buffer per timeout window to stay clear of the deadline, and a terminated client can reconnect and resume from its last offset. Oversized single body elements (e.g. one very large row) no longer enter the socket driver queue whole. |
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -434,39 +434,174 @@ defmodule Electric.Shapes.Api.Response do | |
| sample_rate_attrs = Electric.Plug.TraceContextPlug.sample_rate_attrs(conn, status) | ||
|
|
||
| conn = Plug.Conn.send_chunked(conn, status) | ||
| watchdog = start_write_watchdog(stack_id, response) | ||
|
|
||
| {conn, bytes_sent} = | ||
| response.body | ||
| |> Enum.reduce_while({conn, 0}, fn chunk, {conn, bytes_sent} -> | ||
| chunk_size = IO.iodata_length(chunk) | ||
|
|
||
| OpenTelemetry.with_span( | ||
| "shape_get.plug.stream_chunk", | ||
| Map.put(sample_rate_attrs, "chunk_size", chunk_size), | ||
| stack_id, | ||
| fn -> | ||
| case Plug.Conn.chunk(conn, chunk) do | ||
| {:ok, conn} -> | ||
| {:cont, {conn, bytes_sent + chunk_size}} | ||
|
|
||
| {:error, reason} when reason in ["closed", :closed] -> | ||
| error_str = "Connection closed unexpectedly while streaming response" | ||
| conn = Plug.Conn.assign(conn, :error_str, error_str) | ||
| {:halt, {conn, bytes_sent}} | ||
|
|
||
| {:error, reason} -> | ||
| error_str = "Error while streaming response: #{inspect(reason)}" | ||
| Logger.error(error_str) | ||
| conn = Plug.Conn.assign(conn, :error_str, error_str) | ||
| {:halt, {conn, bytes_sent}} | ||
| try do | ||
| response.body | ||
| |> Enum.reduce_while({conn, 0}, fn chunk, {conn, bytes_sent} -> | ||
| chunk_size = IO.iodata_length(chunk) | ||
|
|
||
| OpenTelemetry.with_span( | ||
| "shape_get.plug.stream_chunk", | ||
| Map.put(sample_rate_attrs, "chunk_size", chunk_size), | ||
| stack_id, | ||
| fn -> | ||
| case write_in_bounded_pieces(conn, chunk, chunk_size, watchdog) do | ||
| {:ok, conn} -> | ||
| {:cont, {conn, bytes_sent + chunk_size}} | ||
|
|
||
| {:error, reason} when reason in ["closed", :closed] -> | ||
| error_str = "Connection closed unexpectedly while streaming response" | ||
| conn = Plug.Conn.assign(conn, :error_str, error_str) | ||
| {:halt, {conn, bytes_sent}} | ||
|
|
||
| {:error, reason} -> | ||
| error_str = "Error while streaming response: #{inspect(reason)}" | ||
| Logger.error(error_str) | ||
| conn = Plug.Conn.assign(conn, :error_str, error_str) | ||
| {:halt, {conn, bytes_sent}} | ||
| end | ||
| end | ||
| end | ||
| ) | ||
| end) | ||
| ) | ||
| end) | ||
| after | ||
| watchdog && Kernel.send(watchdog, :stop) | ||
| end | ||
|
|
||
| Plug.Conn.assign(conn, :streaming_bytes_sent, bytes_sent) | ||
| end | ||
|
|
||
| # Socket writes are split into pieces of at most this size. Bounding the | ||
| # write unit bounds the response data queued in the socket's driver queue | ||
| # at any moment and — because a bounded write to a live client completes | ||
| # once the transport buffers drain — gives the stall watchdog below a | ||
| # progress signal: each completed piece is proof the client accepted data. | ||
| # | ||
| # Derived from the encoder's batch cap so that ordinary body elements are | ||
| # written as-is (no flattening or splitting) and only oversized single | ||
| # items (e.g. one very large row) are split. Making pieces smaller would | ||
| # not sharpen the watchdog: write completion is quantized by the OS at up | ||
| # to a kernel send buffer of drain, which dwarfs the piece size. | ||
| @socket_write_bytes Electric.Shapes.Api.Encoder.JSON.max_batch_bytes() | ||
|
|
||
| # A serve whose client stops accepting data blocks inside the socket write | ||
| # and cannot recover on its own: the TCP send timeout only catches a write | ||
| # that is *fully* blocked for its whole window, so a client draining at a | ||
| # trickle — or a proxy buffering for a vanished client — can hold the | ||
| # serve, everything it pins, and its file descriptor forever. Such serves | ||
| # never complete, so they emit no telemetry, and they accumulate with | ||
| # connection count (reproduced in | ||
| # test/integration/stalled_serve_memory_test.exs). | ||
| # | ||
| # The watchdog is a small companion process that terminates the serve when | ||
| # a single bounded socket write (≤ @socket_write_bytes) fails to complete | ||
| # within `:stalled_serve_timeout`. Write completion is quantized by the OS: | ||
| # a blocked write may only complete after the kernel send buffer frees a | ||
| # substantial fraction of its capacity, so the effective contract is that a | ||
| # healthy client must drain roughly one OS send buffer per timeout window | ||
| # (e.g. ~10 KB/s for a megabyte-class buffer and a 60-second window, and | ||
| # far less on stacks that signal writability at finer granularity). The | ||
| # timer is armed only while a write is in flight, so a serve idling between | ||
| # 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 | ||
| # Fallback for stacks whose seed config omits the key (e.g. minimal | ||
| # unit-test stacks); Electric.Config is the single source of truth. | ||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. This comment can be removed without any loss of information.
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Gone in 7a54d42 (the surrounding block was rewritten as part of the module extraction). |
||
| case Electric.StackConfig.lookup( | ||
| stack_id, | ||
| :stalled_serve_timeout, | ||
| Electric.Config.default(:stalled_serve_timeout) | ||
| ) do | ||
| timeout when is_integer(timeout) and timeout > 0 -> | ||
| handler = self() | ||
| shape_handle = response.handle | ||
|
|
||
| {:ok, watchdog} = | ||
| Task.start(fn -> | ||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. 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?
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. 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. |
||
| # The label groups these processes under a low-cardinality | ||
| # process_type in the per-process telemetry, rather than leaving | ||
| # them anonymous — serves and their guards should be visible. | ||
| # Logger metadata is set explicitly: this process does not inherit | ||
| # the handler's, and the reap warning below is the primary signal | ||
| # an otherwise-invisible stalled serve emits, so it must carry | ||
| # enough to correlate (which stack, which shape). | ||
| Process.set_label({:serve_watchdog, shape_handle}) | ||
| Logger.metadata(stack_id: stack_id, shape_handle: shape_handle) | ||
| ref = Process.monitor(handler) | ||
| write_watchdog_loop(handler, ref, timeout, :idle) | ||
| end) | ||
|
|
||
| watchdog | ||
|
|
||
| # 0 (or any non-positive value) disables reaping. | ||
| _disabled -> | ||
| nil | ||
| end | ||
| end | ||
|
|
||
| defp write_watchdog_loop(handler, ref, timeout, writing?) do | ||
| receive do | ||
| :write_start -> | ||
| write_watchdog_loop(handler, ref, timeout, :writing) | ||
|
|
||
| :write_done -> | ||
| write_watchdog_loop(handler, ref, timeout, :idle) | ||
|
|
||
| :stop -> | ||
| :ok | ||
|
|
||
| {:DOWN, ^ref, :process, ^handler, _reason} -> | ||
| :ok | ||
| after | ||
| watchdog_wait(writing?, timeout) -> | ||
| Logger.warning( | ||
| "Terminating stalled shape response serve: client accepted no data " <> | ||
| "for #{timeout}ms" | ||
| ) | ||
|
|
||
| Process.exit(handler, :kill) | ||
| end | ||
| end | ||
|
|
||
| defp watchdog_wait(:writing, timeout), do: timeout | ||
| defp watchdog_wait(:idle, _timeout), do: :infinity | ||
|
|
||
| # Write one response body element as a sequence of bounded socket writes, | ||
| # notifying the watchdog around each one. Elements within the bound — the | ||
| # common case, as the bound is derived from the encoder's batch cap — are | ||
| # written directly without flattening. | ||
| defp write_in_bounded_pieces(conn, chunk, chunk_size, watchdog) | ||
| when chunk_size <= @socket_write_bytes do | ||
| guarded_chunk(conn, chunk, watchdog) | ||
| end | ||
|
|
||
| defp write_in_bounded_pieces(conn, chunk, _chunk_size, watchdog) do | ||
| chunk | ||
| |> IO.iodata_to_binary() | ||
| |> write_pieces(conn, watchdog) | ||
| end | ||
|
|
||
| defp write_pieces(<<piece::binary-size(@socket_write_bytes), rest::binary>>, conn, watchdog) | ||
| when byte_size(rest) > 0 do | ||
| case guarded_chunk(conn, piece, watchdog) do | ||
| {:ok, conn} -> write_pieces(rest, conn, watchdog) | ||
| error -> error | ||
| end | ||
| end | ||
|
|
||
| defp write_pieces(piece, conn, watchdog) do | ||
| guarded_chunk(conn, piece, watchdog) | ||
| end | ||
|
|
||
| defp guarded_chunk(conn, data, watchdog) do | ||
| watchdog && Kernel.send(watchdog, :write_start) | ||
| result = Plug.Conn.chunk(conn, data) | ||
| watchdog && Kernel.send(watchdog, :write_done) | ||
| result | ||
| end | ||
|
|
||
| def etag(response, opts \\ []) | ||
|
|
||
| # When response contains no changes, in order to uniquely identify it and avoid | ||
|
|
||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
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.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
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.