Skip to content

A keyed Postgres sink on pgx, and the leak loops that found the demo's growth - #290

Merged
turbolytics merged 27 commits into
mainfrom
bench/component-leak-loops
Sep 14, 2026
Merged

turbolytics merged 27 commits into
mainfrom
bench/component-leak-loops

Conversation

@turbolytics

@turbolytics turbolytics commented Sep 14, 2026

Copy link
Copy Markdown
Owner

What this changes

The Bluesky demo on Render still grows after #277: from about 85 MB to about 105 MB over the 14 hours after the redeploy. The cause is the demo's write, INSERT ... ON CONFLICT into an attached Postgres through the DuckDB postgres extension, which copies the whole target table's keys into DuckDB on every flush. This branch carries the benchmarks that found it, and the fix: a keyed postgres sink on pgx that writes at the cost of the batch.

The fix, per docs/superpowers/specs/2026-09-14-postgres-sink-design.md and docs/superpowers/plans/2026-09-14-postgres-sink.md:

  • type: postgres with dsn, table, mode: upsert | append, and key for upsert. One transaction per buffered batch, in arrival order: a COPY into a session temp table, then INSERT ... SELECT DISTINCT ON (key) ... ORDER BY key, __seq DESC ON CONFLICT (key) DO UPDATE. Two rows with one key in a batch keep the last. The retry ladder wraps it.
  • A probe that checks the table exists, the key columns exist, and a non-partial unique index or constraint covers exactly the key, and warns on append onto a table with a unique index.
  • Errors coded from SQLSTATE: class 08, 53, 57 and 40 are system.sink.unreachable (exit 12, retried); 21, 23, 28, 42, 3D and 3F are user.sink.invalid (exit 10); 22, and a COPY pgx abandoned for a value it cannot encode, are user.sink.encode_failed (exit 10). That closes A window sink failure exits 1, not 12 #287 for this sink.
  • sqlflow validate refuses upsert with late_rows: reemit, warns on append with reemit, and warns on any sqlcommand sink carrying ON CONFLICT while a command attaches a Postgres.
  • The invariant sink.flush.idempotent_on_key: a second delivery of a batch leaves a keyed sink's destination holding it once. The postgres sink proves it; the six other sinks are exempt with a structural proof that they name no key.
  • bluesky.postgres.windowed.yml and kafka.postgres.sink.yml move to the sink.
  • The image sets MALLOC_ARENA_MAX=2.

The investigation:

A production worker shows growth per hour, but the growth is caused per event: per message, batch, flush, or reconnect. A fast replay changes how many of each event happen per hour, so a leak tied to flushes looks flat in a run of millions of messages. Each loop here drives one kind of event as fast as the component allows and reports growth per event of that kind.

  • internal/leakloop samples RssAnon, Go retained (Sys - HeapReleased), and duckdb_memory(), and fits bytes per event after warm-up. SQLFLOW_LEAK_SCALE scales every loop. SQLFLOW_LEAK_MALLOC_TRIM calls malloc_trim(0) before each sample. Replay cycles a capture with each post's time_us shifted forward per pass, so the stream clock keeps moving.

  • The loops build only with -tags leakloop, carry no coverage.Covers, and fail rather than skip without SQLFLOW_LEAK_POSTGRES. They report a rate and assert nothing, so they are benchmarks, not tests, and they never run in the suite.

    • internal/websocket/leakloop_test.go: per message on one connection, and per reconnect.
    • internal/handlers/structured_leakloop_test.go: StructuredBatch with the demo's nested schema and handler SELECT, per message, nothing downstream.
    • internal/managers/window_leakloop_test.go: the demo's shape through the real StructuredBatch handler, the progress row, and Watermark.Poll on the manager's connection, with a counting sink and with the demo's sqlcommand upsert into Postgres.
    • internal/sinks/sqlcommand_leakloop_test.go: per flush into a local table, and into Postgres with the demo's upsert (growing table, same keys, truncated table), a plain insert, and a read.
  • dev/bench:

    • record.py records real Jetstream posts from a cursor, about 5,000 a second.
    • replay serves a capture over a websocket, paced by each event's time_us.
    • replay-soak.sh runs a pipeline container at Render's 0.5 CPU and 512 MB and decomposes its memory once a minute.
    • bluesky/render-ca740f8.yml is the demo as deployed. render-10x.yml is the same pipeline compressed ten times in wall clock, with noop-sink and no-postgres variants.
    • leakloops.sh and leakloop.Dockerfile build the loops with the tag and run each in its own process on Linux.
  • The image sets MALLOC_ARENA_MAX=2. It costs no throughput. The Kafka benchmark container ran 2,000,000 messages at batch 5,000 in three alternating pairs:

    Run Unset, msg/s =2, msg/s Unset, peak anon =2, peak anon
    1 873,700 888,005 210 MiB 199 MiB
    2 929,028 843,946 208 MiB 198 MiB
    3 854,105 860,750 209 MiB 196 MiB

    Throughput moves within run-to-run noise. Peak anon is 10 to 13 MiB lower with =2.

Findings

Every loop ran on Linux arm64 in Docker with DuckDB v1.5.2, postgres extension c89234f, and Postgres 16, one process per loop. Loops that read posts used 2,000,000 real Jetstream posts. Native is RssAnon minus Go retained.

1. The demo's upsert through the postgres extension grows every flush

3,600 flushes of 40 rows each:

Sink statement Postgres table Native MiB Per flush after warm-up
Demo upsert, a new minute per flush grows 40 rows a flush 18.5 to 211.9 +54.7 KB
Same, MALLOC_ARENA_MAX=2 grows 40 rows a flush 17.1 to 83.4 +20.0 KB
Same, malloc_trim(0) before each sample grows 40 rows a flush 18.7 to 83.6 +29.3 KB
Demo upsert, the same minute every flush 40 rows, every row conflicts 17.9 to 98.0 +12.5 KB
Same, malloc_trim(0) 40 rows, every row conflicts 2.1 to 43.9 +8.3 KB
Demo upsert, table truncated after each flush 40 rows, nothing conflicts 18.4 to 61.2 +5.4 KB
Same, malloc_trim(0) 40 rows, nothing conflicts 2.4 to 26.9 +6.4 KB
Plain INSERT, a new minute per flush grows 40 rows a flush 18.3 to 22.8 +0.1 KB
Read one row from the table unchanged 18.4 to 26.3 +1.1 KB

duckdb_memory() stayed at 0.1 MiB and Go retained stayed flat in every row.

The extension's query log shows why a growing table costs more. This is one demo-style upsert into a 1,000-row table, with SET pg_debug_show_queries = true on the v1.5.2 CLI:

BEGIN TRANSACTION ISOLATION LEVEL REPEATABLE READ
COPY (SELECT "bucket", "lang", ctid FROM "public"."probe_upsert" WHERE ctid BETWEEN '(0,0)'::tid AND '(4294967295,0)'::tid) TO STDOUT (FORMAT "binary");
CREATE LOCAL TEMPORARY TABLE "update_data_556daa94-148d-4f69-99e6-06f63354e988"("posts" INTEGER, "updated_at" TIMESTAMP WITH TIME ZONE, __page_id_string VARCHAR) ON COMMIT DROP;
COPY "public"."probe_upsert" FROM STDIN (FORMAT BINARY)
UPDATE "public"."probe_upsert" SET "posts" = "update_data_556daa94-148d-4f69-99e6-06f63354e988"."posts", "updated_at" = "update_data_556daa94-148d-4f69-99e6-06f63354e988"."updated_at" FROM "update_data_556daa94-148d-4f69-99e6-06f63354e988" WHERE "probe_upsert".ctid=__page_id_string::TID
COMMIT

Every upsert copies the key columns and ctid of the whole target table into DuckDB and detects conflicts there. The demo's table gains one row per language every minute and is never trimmed, so every flush reads more than the last.

What the rows show:

  • ON CONFLICT is the cause. A plain insert of the same rows is flat.
  • A growing target table multiplies it.
  • Part of it is glibc holding freed memory. Against the untrimmed run of the same case, the trimmed run grew 66% less with a growing table, 48% less with the same keys, and 43% less with a truncated table. MALLOC_ARENA_MAX=2 grew 66% less with a growing table. Each row is a separate run.
  • The rest survives malloc_trim(0). It is either still referenced, or held by the jemalloc allocator inside libduckdb, which malloc_trim does not reach. These loops do not separate the two.

2. The v1.2.0 container reproduces the growth, and a noop window sink removes it

render-10x.yml on turbolytics/sql-flow:v1.2.0 at --cpus 0.5 --memory 512m. The replay covers the same 2,000,000 posts that live Jetstream sent over 11.3 hours, in 68 minutes. noop-sink is the same pipeline with the window's sink set to noop: the postgres extension stays loaded and attached, and nothing is written through it.

Minute Messages, demo Native MiB, demo Messages, noop sink Native MiB, noop sink
4 114,154 45.0 114,154 42.0
8 230,632 46.0 230,632 45.8
12 360,704 51.1 338,772 48.0
16 489,288 64.0 458,183 48.1
24 753,051 65.5 707,213 48.0
32 1,017,833 65.1 971,601 49.8
48 1,499,093 66.9 1,484,321 49.2
64 1,930,727 68.6 1,952,585 51.0
72 2,000,000 68.9 2,164,713 50.9

The demo stepped up 18 MiB between minutes 8 and 16, then grew 4.9 MiB to the end. The noop-sink run never stepped, and grew 2.8 MiB over the same minutes. While messages flowed, Go retained stayed between 20.3 and 21.7 MiB and duckdb_memory() between 0.25 and 0.81 MiB in both runs. The demo run wrote 23,403 rows to Postgres.

The noop-sink run lost its connection once, at minute 11: websocket read failed, reconnecting with connection reset by peer, then websocket reconnected a second later. The replay starts every connection at the first post, so that run consumed the first 305,192 posts twice and stopped 135,287 short of the end of the capture. It processed the posts behind the demo's step, 230,000 to 489,000, twice: at minutes 4 to 8 and again at 19 to 24. Native stayed between 45.8 and 48.3 MiB both times.

2a. Footguns 3, 4, and 5 in #268 have the same cause

The extension does not send ON CONFLICT to Postgres. DuckDB runs the upsert itself against a copy of the table's keys and writes the result back. Traced with SET pg_debug_show_queries = true on the v1.5.2 CLI.

A plain insert of three of a table's four columns:

COPY "public"."probe_upsert" ("bucket", "lang", "posts") FROM STDIN (FORMAT BINARY)

An upsert of two rows with key 1:

COPY (SELECT "k", ctid FROM "public"."probe_dupes" ) TO STDOUT (FORMAT "binary");
CREATE LOCAL TEMPORARY TABLE "update_data_2e0e54c3-8186-4069-86e2-7a2b8d0ea45c"("v" INTEGER, __page_id_string VARCHAR) ON COMMIT DROP;
COPY "public"."probe_dupes" FROM STDIN (FORMAT BINARY)
UPDATE "public"."probe_dupes" SET "v" = "update_data_2e0e54c3-8186-4069-86e2-7a2b8d0ea45c"."v" FROM "update_data_2e0e54c3-8186-4069-86e2-7a2b8d0ea45c" WHERE "probe_dupes"...

The table then held one row, (1, 10), and nothing reported an error.

Footgun What the log shows
An omitted NOT NULL DEFAULT column fails the upsert The upsert's COPY ... FROM STDIN has no column list, so it sends every column. The plain insert names its columns, and Postgres applies the default.
A unique index is not a conflict target The catalog query reads pg_constraint with contype IN ('p', 'u'). A unique index without a constraint never reaches DuckDB's binder.
Duplicate keys in one upsert keep one row Postgres never receives ON CONFLICT, so its "cannot affect row a second time" check never runs. The log does not show how DuckDB dropped the second row.
Each upsert reads the whole target table The COPY (SELECT <key columns>, ctid ...) TO STDOUT has no filter on the incoming keys.

DuckDB v1.5.5 with extension 41223e5 sends the same full-table COPY ... TO STDOUT.

3. The demo's shape through the real handler and manager

One process per loop, 2,000,000 real posts, Linux arm64, DuckDB v1.5.2. The handler alone, then the handler writing the window table with Watermark.Poll after every batch, with a counting sink and with the demo's sqlcommand upsert into Postgres on the sink's own connection:

Loop Native MiB Per message after warm-up
StructuredBatch, demo schema, SELECT only -0.7 to 32.6 +10.3 B
Handler, window table, Watermark.Poll, counting sink 0.1 to 81.6 +12.7 B
Same, sqlcommand upsert into Postgres 18.2 to 151.4 +24.1 B

The upsert adds about 11 B a message over the counting sink. At the demo's 500 posts a batch and one closed minute per flush that is about 680 flushes over 2,000,000 posts, or about 21 KB a flush, inside the 12 to 55 KB the sink loop measured on its own. The window loop through the real manager and the sink loop agree.

The handler's own rate varies between runs: the SELECT-only loop ended 2,000,000 messages at 15.0, 33.9, 37.3, and 32.6 MiB native across four runs, and at 10,000,000 messages its growth had fallen from 29 MiB in the first million to 1 MiB in the last. Compare loops within a run of this size, not a single number across runs. duckdb_memory() read 0 throughout. The existing TestStructuredInvoke_DoesNotLeakNativeMemory bounds a flat three-column schema at 8 MiB over 500,000 messages, about 17 bytes a message, so it does not see this rate.

3a. After: the postgres sink under the same loops

The per-flush loop, run together on Linux against the same Postgres 16: 3,600 flushes of one closed minute of 40 rows into a table that grows by that much every flush.

Sink Native MiB Per flush after warm-up
sqlcommand upsert through the extension 17.8 to 187.1 +42,132 B
sqlcommand plain insert through the extension 1.9 to 6.3 +110 B
postgres sink, upsert -3.2 to -3.4 -62 B
postgres sink, append -3.4 to -3.3 +17 B

Native reads negative for the pgx sink because its buffers are Go heap: Go retained exceeds RssAnon by the heap the runtime holds and has not touched.

The window loop through the real manager, 2,000,000 posts, one process each, in one run: counting sink 0.6 to 90.1 MiB native, sqlcommand upsert 17.4 to 146.4 MiB, postgres sink 0.0 to 73.5 MiB. The ranking agrees with the flush loop. The per-message slopes after warm-up do not rank them: the counting sink's moved from 12.7 to 27.6 B between two runs, which is wider than a per-flush effect spread over 3,000 messages a flush.

End to end, the same 200,000 recorded posts through the new bluesky.postgres.windowed.yml and through the sqlcommand version it replaces, into Postgres 16:

postgres sink  2503 rows, 2026-09-13 12:37 to 13:45 UTC, 179332 posts
sqlcommand     2503 rows, 2026-09-13 12:37 to 13:45 UTC, 179332 posts
rows in one table and not the other: 0 and 0

Stopping Postgres under the running pipeline:

flushing closed windows: [system.sink.unreachable] sink still failing after 4 attempts:
[system.sink.unreachable] postgres sink: connect: failed to connect to `user=postgres database=e2e_sink`
sqlflow exit=12

4. Small or flat

  • Websocket source, one connection, 2,000,000 messages: native -4.2 to -4.0 MiB, -0.07 B per message.
  • Websocket source dropped every 50 frames, 16,000 reconnects: native -3.4 to -3.4 MiB, +31 B per reconnect.
  • sqlcommand into a local DuckDB table, 12,000 flushes: native 0.7 to 21.4 MiB, +991 B per flush. duckdb_memory() rose to 8.9 MiB, fell to 4.1 at a checkpoint, and ended at 11.3, so about half of that growth is table storage DuckDB accounts for.

What is not settled

  • Whether the upsert growth that survives malloc_trim is a leak or jemalloc retention.
  • Render runs amd64. Every run here is arm64.
  • Render's Postgres table size is unknown here, so the loops do not reproduce its per-flush read.
  • Whether the StructuredBatch growth levels off past 10 million messages.
  • The noise floor of a loop. Select only varied by 2x across four runs at 2,000,000 messages.

What the tests prove

The conformance run against postgres:16 behind the fault proxy passes all 11 sink invariants, including sink.flush.idempotent_on_key and sink.flush.honours_context, and all 6 type invariants. The type table is written by hand and was corrected by the run: a timestamp inside a JSON list renders as RFC 3339 (2026-09-08T12:00:00.123Z), not with a space and no zone.

Six integration tests prove what this sink adds:

Test What it proves
LastRowInABatchWins (1,10), (2,20), (1,30) leaves {1: 30, 2: 20}
RetryAppliesBufferedBatchesInOrder a failed flush, then two buffered batches sharing a key, leaves the second value. A merge of both in one statement fails with 21000
OmittedColumnsTakeDefaultsAndKeepValues a NOT NULL DEFAULT column the batch omits is filled on insert and unchanged on update
ProbeChecksTheTarget a missing table, a missing key column, a key with no exact unique index, and a partial unique index exit 10; a unique index in another column order passes; append onto a unique index warns
ARefusedValueIsAUserError 1<<40 into smallint exits 10 and is not retried; a NOT NULL the batch omits names the target and 23502
ARedialRecreatesTheStagingTable a backend the server terminates is replaced on the next flush

The refused-value test caught a defect on the way: pgx abandons a COPY it cannot encode, the server answers 57014 COPY from stdin failed, and class 57 read that as unreachable, exit 12, retried. It is now user.sink.encode_failed.

Three harness tests hold the new step to its claim: an unkeyed double is skipped, a replacing double passes, and a keyed double that appends a second row is caught.

Upstream: the full-table key copy is filed as duckdb/duckdb-postgres#575. A fix there helps sqlcommand users; it changes nothing in this sink.

Second review: nine findings

An adversarial review ran the sink through sinks.New against Postgres 16 and broke it nine ways. Each finding reproduced as a failing test first; every one of those tests now passes.

# Finding Test Fix Commit
1 A server that holds packets blocked a flush past 20 s with a 3 s retry deadline, and the startup probe the same AStalledServerFailsTheFlushInsideTheDeadline, ...TheProbeInsideTheDeadline each attempt bounded by the retry deadline; both now fail in about 3 s, coded unreachable, and the next flush redials 8612733
2 A connection closed with a FIN between flushes failed as write_failed: begin: conn closed and stopped the pipeline AConnectionClosedBetweenFlushesIsRetried (FIN and RST) a failure that closed the connection, or that pgx reports safe to retry, is unreachable and retried 8612733
3 DROP TABLE IF EXISTS sqlflow_staging dropped a user's public.sqlflow_staging AUserTableNamedLikeStagingSurvives every staging reference is pg_temp.sqlflow_staging 8612733
4 A nullable key: the same null-key batch three times left three rows ANullableKeyIsRefusedAtStartup the probe refuses a nullable key column 8612733
5 run did not refuse upsert with late_rows: reemit TestWindowUpsertWithReemitIsRefusedAtStartup config.Window.ReemitOverwrites, read by validate and run; exit 10 before any dial ea5656a
6 The batch was boxed into [][]any: 1M rows x 4 columns held +177 MiB peak heap sampled every 5 ms across a real flush a CopyFromSource streams one row at a time: +29 MiB, 4.40 s to 3.93 s 1208c8e
7 One refused value fails the whole batch documented on the config and in kafka.postgres.sink.yml; a sink-side DLQ is a separate change 2b5ed42
8 DuckDB TIME, INTERVAL, ENUM failed the first flush TimeIntervalAndEnumConvert, the type table pgtype.Time, pgtype.Interval, decoded dictionary; real DuckDB output stores 12:34:56.789, 01:30:00, ja 2ecd4c4
9 A deferrable constraint (55000) and an invalid index (42P10) passed the probe DeferrableAndInvalidIndexesAreRefusedAtStartup the probe requires indimmediate and indisvalid 8612733

Not changed, and said so in the code and spec: the sink needs a direct connection or session pooling, since transaction pooling does not keep the session staging table; a handler whose output columns change per batch recreates the staging table on every flush where they change; and the harness's idempotent_on_key step re-delivers an identical row, so replacement is proven by LastRowInABatchWins and RetryAppliesBufferedBatchesInOrder rather than by the harness.

The bench configs under dev/bench/bluesky carried the removed manager: tumbling_window block from reproducing v1.2.0, and main's validate refused them. They are replaced with the pipeline this branch teaches: demo-10x.yml (window with the postgres sink), demo-10x-sqlcommand.yml (the same window through the extension) and demo-10x-noop-sink.yml. Each ran four minutes on the branch image. The two writers produced identical tables, 1,443 rows. The v1.2.0 runs in the findings above used the old configs, which are at 0184802.

Verification

  • go test -short -race ./... after the second review's fixes: 23 packages ok, 0 FAIL. go vet ./... clean with and without -tags leakloop, and gofmt -l prints nothing.
  • uv run --locked pytest tests/tooling -q: 205 passed.
  • make coverage-page && git status --short docs/coverage is clean after the registry changes were committed.
  • go test -run '^TestIntegration' ./internal/sinks after the second review's fixes: ok in 114 s. That is every ClickHouse, Kafka, Iceberg and Postgres integration test, including Conformance, Types, the six behaviour tests and the six review tests.
  • bluesky.postgres.windowed.yml end to end against the sqlcommand version: identical tables, and exit 12 with Postgres stopped. Output above.
  • uv run --locked pytest tests/release -q on the branch image turbolytics/sql-flow:postgres-sink (label v2026.09.14-19-g94db41b, MALLOC_ARENA_MAX=2 in its environment): 19 passed.
  • scripts/soak.sh 10 on the same image: PASS, verdict below.
  • go test -run '^TestIntegration' ./internal/sinks: ok in 102 s, so the ClickHouse, Kafka and Iceberg integrations beside the new Postgres ones still pass. CI's Integration job passed on the same commit.
  • make coverage-check against CI run 34886117062's own suite reports: passes after committing the regenerated docs/coverage/status/. The first push failed Coverage because those files were stale; sink.postgres now reads {unit: covered, integration: covered, release: not_required}, and every invariant it claims is covered at integration.

Soak verdict

turbolytics/sql-flow:postgres-sink:

window        minutes 3-10, 105,222,464 messages
native        9.9 -> 9.0 MiB
go retained   24.7 -> 25.1 MiB
native slope  -0.018 MiB/min
go slope      -0.080 MiB/min
per message   -0.009 B/msg (threshold 1.0)

PASS  memory is flat over 105,222,464 messages

The soak runs Kafka through InferredMemBatch into noop, so it gates the engine's per-message path and does not exercise the Postgres sink. The per-flush loop in 3a is the sink's memory evidence.

Notes for the reviewer

  • The loops assert nothing and are not in the suite. go test -short -race ./... and CI do not compile them.
  • Four decisions the plan records against the spec: a sink type the pgx path has no conversion for fails with user.sink.type_unsupported, the code ClickHouse uses, rather than encode_failed; a client-side encode failure is encode_failed; sinks.New gains WithLogger and a Warner interface so the append warning reaches the log; a keyed sink is detected through core.KeyedSink rather than a subject field.
  • A missing mode is the schema's finding (missing property 'mode'), so checkSinks does not repeat it.
  • Captures stay out of the repository. The posts are public user content.
  • main has had no tumbling manager since Windows owned by the engine: a watermark manager and a late-row policy #281, so the container runs use the v1.2.0 image that Render runs. The Go loops use main's components. The websocket source and the handlers are unchanged since v1.2.0, and the sqlcommand sink gained only the connection lock from Every statement on the pipeline's DuckDB connection holds the shared … #283.
  • DuckDB v1.5.5 (DuckDB v1.5.5, and window leak tests that count stored rows #285) is not measured here.

Reproduce

# Record 2M posts (about 7 minutes)
uv run --with websockets python dev/bench/record.py 22 2000000 posts.ndjson.gz

# Component loops on Linux, one process each, built with -tags leakloop
SQLFLOW_LEAK_SCALE=12 \
SQLFLOW_LEAK_POSTGRES=postgresql://postgres:postgres@dev_postgres_1:5432/bench \
  dev/bench/leakloops.sh leak-out 'TestSinkSQLCommand__Postgres' ./internal/sinks
SQLFLOW_LEAK_SCALE=40 SQLFLOW_LEAK_JETSTREAM=posts.ndjson.gz \
SQLFLOW_LEAK_POSTGRES=postgresql://postgres:postgres@dev_postgres_1:5432/bench \
  dev/bench/leakloops.sh leak-out 'TestWindowDemo__|TestStructuredDemo__' ./internal/managers ./internal/handlers

# The demo at 10x on the Render image
go run ./dev/bench/replay -file posts.ndjson.gz -speed 10 &
SQLFLOW_POSTGRES_URI=postgresql://postgres:postgres@dev_postgres_1:5432/bench \
SQLFLOW_JETSTREAM_URI='ws://host.docker.internal:8765/subscribe?wantedCollections=app.bsky.feed.post' \
  dev/bench/replay-soak.sh turbolytics/sql-flow:v1.2.0 dev/bench/bluesky/render-10x.yml 72 demo

bluesky/postgres.sql creates the demo's table in the target database.

Related: #268, #277, #247.

…s limits

The demo on Render still grows after the #277 fix, about 1 MB an hour. A
growth that shows per hour is caused per event, and a fast replay changes
how many of each event happen per hour, so each loop drives one kind of
event and reports growth per event of that kind:

- internal/leakloop samples RssAnon, Go retained and duckdb_memory(), fits
  bytes per event after warm-up, and can malloc_trim before each sample.
- The websocket source per message and per reconnect.
- StructuredBatch with the demo's nested schema, handler SQL, progress
  update and window SQL, per message, with and without Postgres attached.
- The sqlcommand sink per flush: a local table, and the demo's upsert into
  Postgres with a growing table, the same keys, and a truncated table,
  against a plain insert and a read.

dev/bench records real Jetstream posts from a cursor, replays them over a
websocket paced by their own timestamps, and runs a pipeline container
under Render's 0.5 CPU and 512 MB. render-10x.yml is the demo as deployed,
compressed ten times in wall clock, with noop-sink and no-postgres variants.

SQLFLOW_LEAK_SCALE scales every loop. The defaults run in the -short pass.
A loop inherits the allocator state of every loop before it in the same test binary, so the third StructuredBatch loop started 78 MiB above the first. leakloops.sh builds the test binaries once in a Go and libduckdb container and runs each matching test alone.
…er, and MALLOC_ARENA_MAX=2

The loops report a rate and assert nothing, so they are benchmarks, not
tests. They now build only with -tags leakloop, carry no coverage.Covers,
and fail rather than skip when SQLFLOW_LEAK_POSTGRES is unset. A passing
test the matrix reads as proof must be able to fail.

The handler loop had emulated v1.2.0's manager SQL. It is now the handler
alone, and internal/managers gets the demo's shape through the real
StructuredBatch handler, the progress row, and Watermark.Poll on the
manager's connection, with a counting sink and with the demo's sqlcommand
upsert into Postgres. leakloop.Replay shifts each post's time_us forward on
every pass over the capture, so the stream clock keeps moving and minutes
keep closing.

The image sets MALLOC_ARENA_MAX=2: two arenas cut the upsert's per-flush
growth by two thirds in the loop.
…r the harness and the type runner

The harness delivers id=1 a second time after its sequence and requires a
sink that implements core.KeyedSink to hold ids 1, 2 and 3 once each. A
sink that names no key is skipped, and each of the six is exempt with a
structural proof. Three harness tests hold the step to its claim: an
unkeyed double is skipped, a replacing double passes, a doubling double is
caught.

Against postgres:16 behind the fault proxy, every sink invariant passes,
including honours_context, and every type invariant passes.

The type table was measured, not assumed, and the run corrected it: a
timestamp inside a list renders as RFC 3339, "2026-09-08T12:00:00.123Z"
and "2026-09-08T21:00:00.123456+09:00", not with a space and no zone. The
instant claim counts only text bound for a temporal column, so the marks
moved from the zoned timestamp rows to two utf8 entries, into timestamp
and timestamptz.
… abandoned COPY is the user's

Six integration tests against postgres:16: two rows with one key in a
batch keep the last; a retry with two buffered batches sharing a key
applies them in order and the table holds the second value; an omitted
column takes its default on insert and keeps its value on update; the probe
refuses a missing table, a missing key column, a key with no exact unique
index and a partial unique index, and warns on append onto a unique index;
a refused value exits 10; a redial recreates the staging table.

The refused-value test caught a misclassification. 1<<40 into a smallint
column made pgx abandon the COPY it had started, and the server answered

  57014 COPY from stdin failed: unable to encode 1099511627776 into binary
  format for int2 (OID 21)

Class 57 read that as operator intervention: system.sink.unreachable, exit
12, retried for the whole ladder. A 57014 whose message starts "COPY from
stdin failed" is now user.sink.encode_failed. Any other 57014, a statement
timeout say, keeps the class rule.
…name the cost of ON CONFLICT through the extension
…d end to end and per flush

bluesky.postgres.windowed.yml and kafka.postgres.sink.yml use type:
postgres, and neither attaches Postgres through DuckDB.

The same 200,000 recorded posts through the new example and the
sqlcommand version it replaces, into postgres:16:

  postgres sink  2503 rows, 2026-09-13 12:37 to 13:45 UTC, 179332 posts
  sqlcommand     2503 rows, 2026-09-13 12:37 to 13:45 UTC, 179332 posts
  rows in one table and not the other: 0 and 0

Stopping Postgres under the running pipeline exits 12:

  flushing closed windows: [system.sink.unreachable] sink still failing
  after 4 attempts: [system.sink.unreachable] postgres sink: connect

The per-flush loop, 3,600 flushes of 40 rows into a growing table, run
together on Linux:

  sqlcommand upsert through the extension  +42,132 B a flush
  sqlcommand plain insert                     +110 B
  postgres sink upsert                         -62 B
  postgres sink append                         +17 B

The window loop through the real manager gains a postgres sink row. Its
per-message rate is inside that loop's run-to-run noise, so the per-flush
loop above is the comparison.
@turbolytics
turbolytics force-pushed the bench/component-leak-loops branch from db43ac9 to 94db41b Compare September 14, 2026 19:18
@turbolytics turbolytics changed the title Leak loops per component: the Bluesky demo's Postgres upsert grows native memory every flush A keyed Postgres sink on pgx, and the leak loops that found the demo's growth Sep 14, 2026
@turbolytics
turbolytics marked this pull request as ready for review September 14, 2026 19:18
… only a Postgres target

Close dropped the connection and kept every table a failed flush had
buffered, so a shutdown with a batch stuck in the retry ladder leaked it.
It now releases them. Flush holds a reference of its own across each send,
so a Close during a send cannot free the batch being sent, and it removes
the head only if Close has not already emptied the buffer. A checked
allocator proves the release: 128 bytes held after Close before, 0 after.

The sqlcommand warning fired on any ON CONFLICT while any Postgres was
attached, including an upsert into a DuckDB table, which sends Postgres
nothing. It now reads each ATTACH ... (TYPE POSTGRES) alias and warns only
when the upsert's INTO names one. An ATTACH with no AS still warns on any
upsert, because validate does not resolve the name it derives. INSERT OR
REPLACE into the attachment is warned too: its query log shows the same
full-table COPY (SELECT "bucket", "lang", ctid ...) TO STDOUT.
…anager block

The four bench configs carried manager: tumbling_window, which #281
removed; main's validate refuses all of them. They reproduced the v1.2.0
image Render runs, and they are recorded at 0184802 for that purpose.

They are replaced with the pipeline this branch teaches, compressed ten
times in wall clock:

  demo-10x.yml             window with the keyed postgres sink
  demo-10x-sqlcommand.yml  the same window, written through the extension
  demo-10x-noop-sink.yml   the same window, writing nothing

Each ran four minutes on the branch image against the 10x replay. The
postgres sink and the sqlcommand variant each wrote 1443 rows to 13:16 UTC
with no null updated_at, and the noop run held flat. validate is clean on
two and warns on the sqlcommand variant.

The first sqlcommand run stopped on its first flush with 23502: the
statement copied from the example omitted updated_at, and the extension
sends an omitted column as NULL. The variant now names it, as Render's did.
The postgres sink wrote the same rows into the same table with updated_at
omitted, and Postgres applied the default.
…on, and a table named like its staging

Review findings 1, 2, 3, 4 and 9 on #290, each reproduced first as a
failing integration test through New, with the retry ladder and the probe:

1. A server that holds packets and keeps the socket open blocked a flush
   past 20 s with a 3 s retry deadline, and the startup probe the same.
   The ladder checks its deadline only between attempts. Each attempt, a
   probe or one batch's transaction, is now bounded by the retry deadline:
   both fail in about 3 s, coded unreachable, and the next flush redials.
2. A connection a pooler closes with a FIN between flushes failed with
   "begin: conn closed", coded write_failed, which is not retried, so the
   pipeline stopped with nothing written. A failure that closed the
   connection, or that pgx reports safe to retry, is now unreachable; the
   retry redials and delivers. A reset already worked.
3. DROP TABLE IF EXISTS sqlflow_staging on a session with no temp schema
   resolved the name on search_path and dropped a user's
   public.sqlflow_staging. Every reference is pg_temp-qualified.
4. A nullable key column passed the probe, and a unique index never matches
   a null, so a redelivered null key was inserted again: three deliveries,
   three rows, against idempotent_on_key. The probe refuses a nullable key.
9. A deferrable unique constraint (55000) and an invalid index left by a
   failed CREATE INDEX CONCURRENTLY (42P10) passed the probe and failed the
   first flush. The probe requires indimmediate and indisvalid.
…e does

Review finding 5 on #290. checkSinks ran only in validate, so a config that
skipped validate ran the count overwrite the refusal exists to prevent.
config.Window.ReemitOverwrites holds the rule once; validate fails on it and
buildManagedTables refuses it before it dials anything, user.config.invalid,
exit 10. The retry deadline's doc says it now bounds a postgres attempt too.
Review finding 6 on #290. postgresRows converted the whole batch into
[][]any before the COPY started. A postgresCopySource now hands pgx one
reused row at a time, and pgx encodes it before asking for the next.

Peak Go heap across one flush of 1M rows and 4 columns into Postgres 16,
sampled every 5 ms:

  before  +177 MiB, 7,001,967 allocations, 4.40 s
  after    +29 MiB, 6,001,776 allocations, 3.93 s

A type the sink cannot convert is refused by a schema check before the
transaction opens, so it keeps its own code rather than surfacing mid-COPY
as the server's 57014. A value that fails mid-stream returns the source's
error, not the abandoned COPY's.
…he first flush

Review finding 8 on #290. DuckDB's TIME, INTERVAL and ENUM arrive as
time64, month_day_nano_interval and dictionary arrays, and each failed
the first flush with type_unsupported, minutes after a deploy.

time32 and time64 become pgtype.Time, month_day_nano_interval and duration
become pgtype.Interval, and a dictionary writes its decoded value. Postgres
keeps microseconds, so nanoseconds are truncated. The same types render
inside a JSON container, and postgresConvertible holds the one type set
both paths accept.

Real DuckDB output through the sink into Postgres 16:

  TIME '12:34:56.789'         time64[us]               time      12:34:56.789
  INTERVAL 90 MINUTE          month_day_nano_interval  interval  01:30:00
  'ja'::ENUM('en','ja')       dictionary<utf8, uint8>  text      ja

The type table declares time64[us], time64[ns], month_day_nano_interval,
dictionary and list<time64[us]>, and the runner passes every row.
…ooling, and the spec records the second review

Review finding 7 and the untested pooler case on #290, as documentation:
the config's doc comment and kafka.postgres.sink.yml say one refused value
fails the batch with exit 10 and replays on restart, and the DSN's comment
says transaction pooling cannot keep the session staging table. The spec
gains a table of the nine findings and what changed for each.
serializeSQL returned col.Value(0), which aliases the record's buffer, and
the deferred Release freed it before ReferenceTables parsed it. On Linux the
test failed 3 runs in 10 with the AST overwritten by a later query's; CI
failed TestReferenceTablesFindsNestedJoin with "invalid character '\u0090'".
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

A window sink failure exits 1, not 12

1 participant