Repository navigation
PostgreSQL's log is read by a classifier now, not by two regexes: errors, connections and lock waits land in pg_log_events off the same tail and RDS API the deadlock and plan readers use, redacted with the plan parser's own patterns (#3601) - #3646
Conversation
| and stays; the right tuple is the row's values, unquoted whatever their type, and goes whole. */ | ||
| private static readonly Regex s_keyTupleValue = new( | ||
| @"(?<=\bKey \([^)]*\))=\([^)]*\)", | ||
| RegexOptions.Compiled | RegexOptions.CultureInvariant); |
There was a problem hiding this comment.
s_keyTupleValue's value capture (=\([^)]*\)) stops at the first ) it meets, not the tuple's actual closing paren. PostgreSQL does not escape the value in this DETAIL shape, so any value that itself contains a literal ) produces a partial redaction rather than a full one.
Example: a unique-violation on a column holding "Acme (USA) Inc." writes
DETAIL: Key (name)=(Acme (USA) Inc.) already exists.
RedactMessage turns this into
Key (name)=(?) Inc.) already exists.
— ?) replaces only up to the first ), and Inc.) already exists. (part of the customer's literal value) survives verbatim into the stored detail column.
This directly undermines the invariant this PR states as the whole point of the redaction layer ("no literal from the user's SQL exists anywhere in the store" / "the log pipeline must not become the place parameter values leak into the store"). RedactMessage's only test case (Key (email)=(someone@example.com) already exists.) happens to have no parens in the value, so this gap isn't caught.
A balanced-paren-aware match (or matching to the last ) on the line before already exists./end-of-string) would close this. Worth a test case with a parenthesis inside the value.
There was a problem hiding this comment.
Real, and fixed in 8b5b6d7 — thank you; this is exactly the leak the scope note forbids and the one test happened to use a paren-free value.
What changed. The value no longer stops at the first ). It runs GREEDILY to the LAST ) in the text (=\((?!\?\)).*\)(?=[^)]*$)), which is the tuple's true close because every sentence PostgreSQL writes after the tuple — already exists., is duplicated., is still referenced from table "t"., is not present in table "t". — carries no parenthesis of its own; the lookahead asserts none follows. Wrong in the safe direction if a future sentence ever did: it would redact the sentence too, never leak the value. Greedy-to-last-paren rather than a balancing-paren matcher because PostgreSQL does not escape the value, so a balanced matcher is fooled by an unbalanced value (Acme (USA Inc.) exactly where the leak lives; end-of-text is the only anchor the format guarantees. The key tuple is matched lazily so an expression key (Key (lower(email))=(…)) is read whole.
The two-tuple exclusion-violation DETAIL (Key (during)=(…) conflicts with existing key (during)=(…).) is matched FIRST with its own pattern so both key names and the sentence survive and both values go; both patterns refuse a value that is already the mark (?), which is what stops the general rule from re-reading the exclusion rule's output as one tuple.
Pinned (Redaction_StripsEveryLiteral_BeforeAnythingIsStored): Acme (USA) Inc. and Acme (USA) Inc., EMEA (west) (values carrying )), a)=(b and x) conflicts with (values carrying )=( and a sentence fragment), the expression key, the FK is still referenced / is not present sentences, the exclusion two-tuple shape, and DoesNotContain("Acme", …). Executed here (mactest harness, 22/22 in the pipeline classes) before the push.
There was a problem hiding this comment.
Reviewed the log-classification pipeline (PgServerLogTail, PgLogEntryAssembler, PgLogEventClassifier, the three family parsers, PgLogTextRedactor, the V129 migration, both transports, and the get_pg_log_events read/tool). The architecture, migration ladder discipline, naive-UTC handling, and marker/exception plumbing all follow the established conventions correctly, and this is Darling/PostgreSQL-only work so there's no Lite parity gap (Lite has no Postgres log-reading collectors to keep in step with).
- Redaction bypass in
PgLogTextRedactor.s_keyTupleValue(PerformanceMonitor.Collectors/PgLogTextRedactor.cs:58-60) — the unique-violationKey (col)=(val)redaction stops at the first)rather than the tuple's true closing paren, since PostgreSQL doesn't escape the value in this DETAIL shape. Any value containing a literal)(e.g."Acme (USA) Inc.") is only partially redacted, leaking the tail of the customer's literal value into the storeddetailcolumn. This directly contradicts the PR's stated invariant that no literal from the user's data reaches the store, and the only test for this pattern happens to use a value with no parens, so the gap is untested. See inline comment for a concrete repro and fix direction.
Everything else checked (severity ranking parity between C# and SQL, page/truncation contract, RDS marker-after-write ordering, zone-refusal propagation, schema-qualified migration, parameterized reader SQL, dispatch wiring for Aurora/RDS vs self-hosted) held up.
Remediated in 8b5b6d7: the key-tuple value runs to the tuple's true close (values carrying ')' and ')=(' pinned), the exclusion two-tuple shape keeps both key names; inline reply carries the reasoning. Re-review on the new head.
8b5b6d7 to
4bd8b4f
Compare
| public static IReadOnlyList<string> RecognisedOnly { get; } = new[] { TempFile, Autovacuum, Checkpoint }; | ||
|
|
||
| /// <summary>Whether a caller-supplied family name is one of ours. Ordinal, lower-case: the column is.</summary> | ||
| public static bool IsKnown(string? family) |
There was a problem hiding this comment.
Non-blocking: PgLogFamilies.IsKnown includes Other ("other") in the closed vocabulary it validates against, so DarlingMcpPgLogEventTools.GetPgLogEvents will accept family=other as valid — but no parser ever emits that family today (PgRecognisedFamilyParser's Family property is documented as unused; the classifier reads the family off the emitted event, not this property), and the tool's own error message explicitly excludes Other from the list of families it advertises (PgLogFamilies.All.Where(f => f != PgLogFamilies.Other)). A caller passing family=other gets silently zero rows with a "no events" answer rather than the "not one this pipeline classifies" rejection a typo would get. Might be worth excluding Other from IsKnown too, for symmetry with the error message.
There was a problem hiding this comment.
Taken, in 6347fc8: PgLogFamilies.IsKnown now refuses other (it stays in All as the reserved vocabulary word, since the reader's NULL-family fallback and a future parser may name it), so family=other gets the same "not one this pipeline classifies" rejection a typo does instead of a silent no_events — symmetric with the error message's list. Pinned: IsKnown(Other) false, every parsed and recognised-only family true.
|
Reviewed the full diff: the log-entry assembler, classifier, redactor, the three family parsers, the shared Highlights of what I checked closely:
Left one non-blocking inline note about |
There was a problem hiding this comment.
LGTM — reviewed the log-event pipeline (assembler, classifier, redactor, family parsers), the shared tailer refactor, the RDS transport, the V129 migration, the MCP reader/tool contract, and Viewer/web wiring for correctness, security (redaction, SQL parameter binding), and Lite/Darling parity. No substantive issues found; one non-blocking inline note posted.
…ors, connections and lock waits land in pg_log_events off the same tail and the same RDS API the deadlock and plan readers use, redacted with the plan parser's own patterns (#3601) The server log is the engine's primary event record and Darling read exactly two shapes out of it. This makes the shared part of those two readers explicit — PgServerLogTail is the one spelling of the pg_read_file tailer both siblings now splice byte-for-byte, PgLogEntryAssembler is the prefix/zone/ companion-line assembly done once — and adds the classifier on top: IPgLogFamilyParser is the seam, three families ship with parsers (error, connection, lock_wait), three are recognised and stored under their own name for #3602/#3603 to structure (temp_file, autovacuum, checkpoint). One cursor, every parser on every line, one identity per entry (raw_line_hash) for the overlapping tail to dedupe on. V129 creates collect.pg_log_events exactly as the generator emits it (one index; the family index is a separate rung for V104's reason). Both transports: PgLogEventsCollector (self-hosted; the body crosses the wire so no family's recogniser is spelled twice) and RdsLogEventIngestor (its own RdsLogSource, marker committed after the write). get_pg_log_events reads it with the #3594/#3613 page contract. Retention 30 d, operator-tunable. Censuses moved: 28 PG collectors, 70 collector tables, 71 hypertables (workflows 73/84), 34 get_pg_* tools, 152 tools.
…se (a value carrying ')' or ')=(' no longer leaks past it), the exclusion shape keeps both key names; the new COPY writer joins the phase/deadline rosters, the reader sets the MCP-read deadline, the README's derived counts move to 28/70/71 (#3601)
…t beside get_pg_log_events (instructions 153/67/thirty-five, runbook 35)
…rites the shared store, so it serializes against the other live classes (hygiene pin)
…ction (#1902 ratchet), not on the body's
…ror message already excludes, so family=other is a rejection rather than a silent zero (review note)
4f7801b to
6347fc8
Compare
|
Reviewed the log-event pipeline end to end: Also checked Lite/Darling parity: this pipeline is Darling-only by design (Lite never dispatches PostgreSQL collectors — see No correctness, security, or parity issues found. The redaction tradeoffs (e.g., a hypothetical multi- |
There was a problem hiding this comment.
LGTM — reviewed the log-event pipeline (assembly, classification, redaction, both transports, the reader/MCP tool, V129 migration, viewer wiring) for correctness, SQL-injection/XSS safety, and Lite/Darling parity; no substantive issues found. Details in the top-level comment.
…ss-app inventory pins read them)
| var scrubbed = PgPlanLogParser.s_quotedLiteral.Replace(text, "'?'"); | ||
| scrubbed = s_exclusionTupleValues.Replace(scrubbed, "${key}=(?) conflicts with existing key ${key2}=(?)"); | ||
| return s_keyTupleValue.Replace(scrubbed, "${key}=(?)"); | ||
| } |
There was a problem hiding this comment.
Redaction gap: PostgreSQL's double-quoted value shapes pass through unredacted into message/detail.
RedactMessage only strips single-quoted literals (s_quotedLiteral) plus the Key (...)=(...) tuple. But a large, common family of PostgreSQL error messages quotes the offending value — not an identifier — with double quotes, e.g.:
ERROR: invalid input syntax for type integer: "abc123"
ERROR: invalid input syntax for type uuid: "not-a-uuid"
ERROR: malformed array literal: "{bad"
ERROR: date/time field value out of range: "2026-13-40"
These are all WARNING-or-worse, so PgErrorEventParser classifies them into error and they get stored via PgLogEvent.From → RedactMessage(entry.Message). Since the redactor's rationale for leaving double quotes alone is "PostgreSQL double-quotes identifiers in its prose... those are not values" (type header, lines 49-52), this class of message is treated as safe when it is actually the raw client-supplied value that failed to parse — exactly the kind of thing the issue's scope note (line 19-20: "the log pipeline must not become the place parameter values leak into the store") is meant to prevent.
The test added for this in PgLogEventsPipelineTests.cs (Redaction_IsThePlanParsersOwnPatterns_AppliedAtTwoStrengths) asserts against a single-quoted variant:
Assert.Equal("invalid input syntax for type integer: '?'",
PgLogTextRedactor.RedactMessage("invalid input syntax for type integer: 'abc'"));but real PostgreSQL emits this message with double quotes around the value, not single quotes — so the test doesn't exercise the actual wire format and gives false confidence that this shape is handled.
Since error requires no special target configuration (log_min_messages = warning is the default), this will fire on any monitored server whose clients occasionally send malformed input — potentially leaking emails, malformed identifiers, or other PII-bearing values into a table retained 30 days and exposed through get_pg_log_events/the Viewer.
There was a problem hiding this comment.
Real, in scope, and fixed in ecf16f4 — thank you. The first draft's "identifiers stay" rule read the QUOTE CHARACTER as the signal, and PostgreSQL uses the same character for the offending value in exactly the class of error that needs no setting on the target.
What changed. The rule is now an ALLOWLIST in the safe direction, by MESSAGE SHAPE:
: "…"andat or near "…"— the two value-quoting shapes — are redacted first, GREEDILY to the closing quote ((?<=:\s|\bat or near\s)".*"(?=[^"]*$)), because a JSON or array value carries quotes of its own and a first-quote match would leave its middle standing; both shapes end the message, so the last quote is the value's close.Failing row contains (…)— the NOT NULL / CHECK violation DETAIL, values unquoted — goes whole to the last), the key-tuple rule's reason.- Every remaining double-quoted run is kept ONLY when the word before it is one PostgreSQL uses for a named object (
relation,table,column,constraint,index,database,role,user,type,schema,function,parameter,file,path,extension, … plus the connection-authenticated line'sidentity=/method=and the temp-file line'spath, which Per-event temp spill attribution from log_temp_files — counters know a database spilled, not which execution spilled 4 GB at 03:07 #3602 reads). Anything else — an unknown lead, a quoted run at the start of a message — becomes"?". A noun missing from the list over-redacts one name; a value shape missing from a blocklist would have leaked, which is why it is an allowlist.
Pinned with the shapes PostgreSQL actually writes, double quotes and all: invalid input syntax for type integer: "abc123", … type uuid: "not-a-uuid", malformed array literal: "{"a"}" (inner quotes), date/time field value out of range: "2026-13-40", invalid input value for enum mood: "happ", syntax error at or near "DELTE", unterminated quoted string at or near "'abc", invalid value for parameter "work_mem": "lots" (name kept, value gone), Failing row contains (1, someone@example.com, Acme (USA) Inc., null), the pg_hba line 117: "host all all …" DETAIL, an unknown-lead value — all "?"; and ten identifier shapes asserted to survive unchanged (constraint "customers_email_key", user "intruder", role, database, column "email" of relation "customers", identity="app_rw", path "base/pgsql_tmp/…", table "app_db.public.orders", relation "orders", parameter "foo"). The single-quoted assertion you called out is gone. The classifier fixture gained a real invalid input syntax for type integer: "secret-order-ref-9931" line and the end-to-end redaction pin asserts the literal reaches neither message, detail nor the fingerprint; the live round-trip against a fresh timescale/timescaledb:2.28.1-pg18 re-ran green with the same assertion over the tool's JSON.
There was a problem hiding this comment.
Reviewed the log-event classifier pipeline (assembler, classifier, family parsers, redactor, both transports, migration, and MCP read surface). The architecture is sound — parameterized SQL throughout, the tail/gate/marker machinery is correctly shared byte-for-byte with the two existing readers, severity ranking agrees between C# and SQL, and the RDS/self-hosted dispatch wiring is consistent.
- Redaction gap (correctness/security, PerformanceMonitor.Collectors/PgLogTextRedactor.cs):
RedactMessagestrips single-quoted literals and theKey (...)=(...)tuple, but PostgreSQL uses double quotes to wrap the offending value (not an identifier) in a common class of messages —invalid input syntax for type integer: "abc",malformed array literal: "...",date/time field value out of range: "...", etc. The redactor's "identifiers stay" rule treats all double-quoted content as safe, so these values pass through unredacted into the storedmessagecolumn. This directly undercuts the PR's own stated scope note ("the log pipeline must not become the place parameter values leak into the store"), and since these come from theerrorfamily (WARNING+, no special target config needed —log_min_messages=warningis the default), it will trigger routinely on any monitored server with malformed client input. The added test for this shape (Redaction_IsThePlanParsersOwnPatterns_AppliedAtTwoStrengths) asserts against a single-quoted variant that isn't what PostgreSQL actually emits, so it doesn't catch the gap. Left as an inline comment with details.
No Lite/Darling parity issue: this feature is Darling/PostgreSQL-only by design (Lite doesn't create PostgreSQL collector tables), and the shared PerformanceMonitor.Collectors code plus its Lite-side pin tests are consistent with that split.
… after an identifier noun, the ': "…"' / 'at or near "…"' value shapes and 'Failing row contains (…)' go whole, and the pins use the shapes PostgreSQL actually writes (review)
Remediated in ecf16f4: double-quoted VALUE shapes (': "…"', 'at or near "…"', Failing row) are redacted greedily and every other double-quoted run is kept only after an identifier noun — allowlist, safe direction; pinned with PostgreSQL's real message text. Inline reply carries the reasoning. Re-review on the new head.
| /// <para>Four shapes, all at LOG, all opening <c>process N</c>: <c>still waiting for <mode> on | ||
| /// <resource> after N ms</c> (the report), <c>acquired <mode> on <resource> after N ms</c> | ||
| /// (the same wait ending — pair them by pid to get the wait's length), <c>avoided deadlock for ... by | ||
| /// rearranging queue order after N ms</c>, and <c>detected deadlock while waiting for ... after N ms</c>. | ||
| /// The <c>DETAIL</c> names the holder and the queue (<c>Process holding the lock: 4321. Wait queue: | ||
| /// 1234.</c>), the <c>STATEMENT</c> is the waiter's SQL, and the <c>CONTEXT</c> — where present — names the | ||
| /// tuple and relation. All of that survives redaction because it is pids, modes and identifiers; the | ||
| /// statement is fingerprinted.</para> |
There was a problem hiding this comment.
This doc comment says the lock-wait entry's CONTEXT — "names the tuple and relation" — "survives redaction" alongside DETAIL and the fingerprinted STATEMENT. It doesn't actually reach the store: PgLogEvent (PgLogEvent.cs) has no Context field, PgLogEvent.From never reads entry.Context, and collect.pg_log_events (V129 in PgMigrations.cs) has no context column. PgLogEntryAssembler does capture Context onto PgLogEntry (and PgLogEventsPipelineTests asserts that at the entry level), but nothing downstream of the parser ever looks at it — it's parsed and then silently dropped for every family, not just lock_wait.
For lock_wait specifically this is a real loss: the doc calls CONTEXT out as the thing that "names the tuple and relation" a wait is blocked on, which is exactly the detail an operator investigating a lock wait would want, and the tool description doesn't mention that it's missing either. Either wire entry.Context into PgLogEvent/the table (redacted like Detail), or fix this comment (and the "survives redaction" claim) to say it isn't stored.
There was a problem hiding this comment.
Right — the doc promised what the row did not carry. Fixed in 1aa01de by making the row carry it: V129 (not yet landed, so this is free) gains context text after detail; PgLogEvent gains Context, filled in From through RedactMessage at prose strength — the same pass as detail, so an inner statement in a CONTEXT (SQL statement "UPDATE … WHERE id = 42") is taken whole because statement is not an identifier noun, while while updating tuple (0,7) in relation "orders" survives intact. The collector's PayloadColumns, the reader's SQL and ordinals, the tool payload (context) and description, the Viewer grid and the web panel all carry the column; the rung stays byte-identical to the generator's output (pinned). HINT is deliberately still not stored and the From comment now says so — advice text, never evidence, and nothing claims otherwise. Pinned: the lock-wait event's Context equals the fixture's CONTEXT line, and the every-literal sweep now includes Context in what it searches.
| public static PgLogEvent From( | ||
| in PgLogEntry entry, | ||
| string family, | ||
| string? databaseName = null, | ||
| string? userName = null, | ||
| string? applicationName = null) | ||
| { | ||
| var redactedStatement = PgLogTextRedactor.RedactStatement(entry.Statement); | ||
|
|
||
| return new PgLogEvent( | ||
| OccurredAtUtc: entry.OccurredAtUtc, | ||
| Family: family, | ||
| Severity: entry.Severity, | ||
| SqlState: entry.SqlState, | ||
| DatabaseName: databaseName ?? entry.DatabaseName, | ||
| UserName: userName ?? entry.UserName, | ||
| ApplicationName: applicationName, | ||
| Pid: entry.Pid, | ||
| Message: PgLogTextRedactor.RedactMessage(entry.Message) ?? string.Empty, | ||
| Detail: PgLogTextRedactor.RedactMessage(entry.Detail), | ||
| StatementFingerprint: PgLogTextRedactor.Fingerprint(redactedStatement), | ||
| RawLineHash: PgLogTextRedactor.RawLineHash(entry.RawText)); | ||
| } |
There was a problem hiding this comment.
From is the "ONLY constructor path" and takes entry plus whatever a parser extracted, but it never reads entry.Context — only Message, Detail and Statement make it into the stored row. See the comment on PgLockWaitEventParser (PgLogFamilyParsers.cs), which documents CONTEXT as surviving redaction into the row; as written here it can't, because there's no column and no parameter for it. Same for entry.Hint, though nothing claims that one is stored.
| /* Every remaining double-quoted run, with what precedes it captured so the allowlist can be asked. */ | ||
| private static readonly Regex s_doubleQuoted = new( | ||
| @"(?<lead>(?:[A-Za-z_]+=|\b[A-Za-z_]+\s|^|\S))(?<quoted>""[^""]*"")", | ||
| RegexOptions.Compiled | RegexOptions.CultureInvariant); | ||
|
|
||
| /* The words PostgreSQL puts before a double-quoted IDENTIFIER. A run preceded by one of these is a | ||
| name and stays; a run preceded by anything else is treated as a value. Enumerated rather than | ||
| inferred, and wrong in the safe direction: a noun missing from this list over-redacts one name, a | ||
| value shape missing from a blocklist would leak. `identity=` / `method=` / `application_name=` are | ||
| the connection-authenticated line's own key=value spellings; `path` is the temp-file line's, which | ||
| #3602 reads. */ | ||
| private static readonly Regex s_identifierNoun = new( | ||
| @"(?:^|\b)(?:relation|table|column|constraint|index|sequence|view|function|procedure|routine|type|schema|database|role|user|extension|parameter|tablespace|trigger|rule|policy|language|domain|collation|operator|aggregate|publication|subscription|server|wrapper|mapping|file|directory|path|option|setting|slot|partition|attribute|object|library|module|record|conversion|dictionary|template|configuration|statistics|method|namespace|catalog|cursor|portal|savepoint|prepared statement|access method|event trigger|foreign table|materialized view|composite type|enum type|range type|base type|text search configuration|text search dictionary|text search parser|text search template|application_name=|identity=|method=)\s?$", | ||
| RegexOptions.Compiled | RegexOptions.CultureInvariant | RegexOptions.IgnoreCase); |
There was a problem hiding this comment.
Non-blocking, flagging for a second look since this is the redaction path: s_doubleQuoted's lead group has no zero-width alternative other than ^ (true start of string), so a "..." run whose immediately-preceding character is whitespace that isn't part of a word + space (e.g. a quote that opens a continuation line right after the \n that PgLogEntryAssembler.Builder.Continue inserts, or one preceded by two spaces) won't be matched by this regex at all — not redacted, not allowlisted, just left as-is in the output. That's different from the "over-redacted, never leaked" guarantee the type doc claims, since here it's neither. Contrast with a quote preceded by punctuation (\S covers those) or by word , which do get evaluated correctly.
I couldn't construct a concrete real stderr message where PostgreSQL puts a value-bearing quote right after a bare space/newline with nothing recognizable before it — the known value shapes (: "…", at or near "…") are caught by s_quotedValueShape earlier — so this may not be reachable in practice. Worth a test case (a quote at the very start of a tab-continuation line) to confirm one way or the other, given how much weight this path carries.
There was a problem hiding this comment.
Good second look — it was reachable in principle, and the fix costs nothing: the lead fallback is now . under Singleline, so a double-quoted run preceded by a bare space, two spaces, a newline at the head of a tab-continuation, or punctuation is always EVALUATED by the allowlist, and with no noun before it is redacted. The word-and-space alternative is still tried first so relation "x" reaches the allowlist with its noun. Pinned with exactly the shapes you named: two spaces "value" here, line one\n"value" on a continuation, "value" at the start — all "?" — beside SQL statement "…" (whole) and COPY t, line 3, column c: "…" (the : "…" shape) in 1aa01de.
There was a problem hiding this comment.
Reviewed the new PostgreSQL classified log-event pipeline (PgLogEntryAssembler/PgLogEventClassifier/PgLogFamilyParsers/PgLogTextRedactor/PgLogEvent, the shared PgServerLogTail extraction, V129, the DarlingPgLogEventReader SQL, the RDS ingestor, the MCP tool, and the Viewer probe wiring). Overall this is very solid: reader SQL is fully parameterized (no injection), the V129 rung is schema-qualified per CONTRIBUTING, the severity ranking is consistent between C# (PgLogEntry.RankOf) and the reader's SQL CASE, the RDS ingestor mirrors RdsDeadlockIngestor's marker-commit-after-write discipline correctly, the self-hosted/RDS dispatch mirrors the existing pg_deadlocks pattern, and the viewer schema-version probe's new hasPgLogEvents arm is placed above (newer than) the prior top rung as required. This is Postgres-only C# (not T-SQL), so the OPTION(RECOMPILE) guidance doesn't apply, and I confirmed the Lite/Darling split is intentional and unaffected: Lite's DuckDbSchemaGenerator.StoredCollectors filters the shared catalog to TargetEngine == SqlServer only, so this PostgreSQL-only collector (like the pre-existing pg_deadlocks) correctly needs no Lite-side schema/UI changes — no parity gap.
One substantive issue:
CONTEXTis parsed but silently dropped before storage, contradicting the code's own doc comments.PgLogEntryAssemblercaptures theCONTEXTcompanion ontoPgLogEntry.Context, andPgLockWaitEventParser's doc comment explicitly claims it "names the tuple and relation" and "survives redaction" alongsideDETAILand the fingerprintedSTATEMENT. In factPgLogEventhas noContextfield,PgLogEvent.Fromnever readsentry.Context, andcollect.pg_log_events(V129) has no context column — it never reaches the store, for any family. Forlock_waitspecifically this throws away exactly the detail (which tuple/relation a wait is blocked on) the doc calls out as valuable, and the MCP tool description doesn't disclose the gap either. See inline comments on PgLogFamilyParsers.cs and PgLogEvent.cs.
Also left a non-blocking inline note on PgLogTextRedactor's double-quote allowlist regex (a possible gap in the "over-redacted, never leaked" guarantee for a quote immediately preceded by bare whitespace/newline) — I could not construct a concrete realistic PostgreSQL log line that triggers it, so it's flagged for a second look rather than as a confirmed bug.
…ck-wait doc already promised), and a double-quoted run after bare whitespace or a newline is evaluated by the allowlist rather than skipped (review)
Remediated in 1aa01de: CONTEXT is stored (V129 gains the column; redacted like detail; tool/Viewer/web carry it; doc now true), and the double-quote lead evaluates a run after bare whitespace or a newline instead of skipping it. Inline replies carry the reasoning. Re-review on the new head.
|
Reviewed the full diff (PgLogEntryAssembler, PgLogEventClassifier, PgLogTextRedactor, the three family parsers, the two transports, the V129 migration, viewer/MCP/web wiring, and the parity pins). A few things I specifically checked and found in order:
Nothing rises to a blocking finding. This is a large, well-tested change (30+ new unit tests plus a live-Postgres test class) with unusually thorough self-documentation of edge cases already caught in review (the exclusion-tuple redaction ordering, the CONTEXT-companion drop that was caught and fixed, the double-quote allowlist gap). Nice work. |
There was a problem hiding this comment.
LGTM — reviewed the full log-event pipeline (assembler, classifier, redactor, family parsers, both transports), the V129 migration's four coordinated parts, Lite/Darling parity (correctly ratcheted as a SKU boundary, no DuckDB table needed), SQL parameterization in the MCP reader, and the XSS invariant for the new web dashboard columns. No correctness, security, or parity issues found.
…spliced once Fifty-nine PRs merged to dev today across the coordinator's lanes and the wave-2 worker's; each lane returned its entry to a buffer instead of touching this file, so that fifty-plus PRs did not each rebase the same twenty lines. This is the one splice. Every entry is one line (the archiver's compact() and the pins read them that way); riders fold into their parent's entry (#3599 under #3590, #3619 under #3611, #3623 under #3616, #3640 under #3633; #3617 test-only and #3661 re-cut as #3666 carry none); #3657's entry is in because it MERGED to dev - the twin to main is what is still pending. [Unreleased] gains a `### Added` above `### Fixed` (Keep-a-Changelog order) for the six new capabilities: per-user theme colours (#3606 / #3577 arm B), routed alert families (#3668 / #3598), the PostgreSQL logging audit tool (#3643 / #3607), the service-side wait sampler (#3645 / #3604), and the log-event classifier with its temp-file / autovacuum parser families (#3646 / #3601, #3664 / #3602 #3603). The other forty-eight are honesty fixes to existing surfaces and append to `### Fixed` after the wave-1 bullets, in PR-number order. Thirty-six reference definitions added for the issues the new entries cite and the index did not yet define; the [Unreleased] group is one ascending run again, which moves [#3557] into its slot (the one deleted line). Nothing under ## [3.8.0] or older is touched; the archive script was not run. One editorial touch: the #3585 entry ended in a dangling "Darling" and now reads "Darling only." (the tool exists only in the Darling MCP host). tools/changelog/changelog_archive.py verify: all PASS (1420 bold entries, floor 1,329; 1,358 distinct refs resolve; CRLF throughout; 356,539 bytes under the 750 KiB ceiling). ChangelogIndexAndArchiveTests: 5/5 pass via a net10.0 harness.
…spliced once (#3672) Fifty-nine PRs merged to dev today across the coordinator's lanes and the wave-2 worker's; each lane returned its entry to a buffer instead of touching this file, so that fifty-plus PRs did not each rebase the same twenty lines. This is the one splice. Every entry is one line (the archiver's compact() and the pins read them that way); riders fold into their parent's entry (#3599 under #3590, #3619 under #3611, #3623 under #3616, #3640 under #3633; #3617 test-only and #3661 re-cut as #3666 carry none); #3657's entry is in because it MERGED to dev - the twin to main is what is still pending. [Unreleased] gains a `### Added` above `### Fixed` (Keep-a-Changelog order) for the six new capabilities: per-user theme colours (#3606 / #3577 arm B), routed alert families (#3668 / #3598), the PostgreSQL logging audit tool (#3643 / #3607), the service-side wait sampler (#3645 / #3604), and the log-event classifier with its temp-file / autovacuum parser families (#3646 / #3601, #3664 / #3602 #3603). The other forty-eight are honesty fixes to existing surfaces and append to `### Fixed` after the wave-1 bullets, in PR-number order. Thirty-six reference definitions added for the issues the new entries cite and the index did not yet define; the [Unreleased] group is one ascending run again, which moves [#3557] into its slot (the one deleted line). Nothing under ## [3.8.0] or older is touched; the archive script was not run. One editorial touch: the #3585 entry ended in a dangling "Darling" and now reads "Darling only." (the tool exists only in the Darling MCP host). tools/changelog/changelog_archive.py verify: all PASS (1420 bold entries, floor 1,329; 1,358 distinct refs resolve; CRLF throughout; 356,539 bytes under the 750 KiB ceiling). ChangelogIndexAndArchiveTests: 5/5 pass via a net10.0 harness.
The PostgreSQL log is read by a classifier now, not by two regexes
The server log is the engine's primary event record — errors, cancelled statements, FATAL connection refusals, lock waits past
deadlock_timeout, temp-file spills, autovacuum runs, connection churn — and Darling read exactly two shapes out of it:auto_explainplan blocks andERROR: deadlock detectedblocks. Everything else was invisible between two samples of a cumulative counter, and the SQL Server DBA's first instinct — "check the error log" — had no answer here. This PR generalizes the machinery those two readers already carry into a classified log-event pipeline, ships three families on it, and lands the one migration rung of the night, V129. It is the keystone for #3602 (log_temp_files) and #3603 (log_autovacuum_min_duration), which each add one parser family on top.What was shared between the two families, and what was per-family
Read from the six files first, as the brief asked; this is the inventory the pipeline is built from.
Shared today by being written twice and kept in step by comment:
newest(pg_ls_logdir()for the CURRENT file, gated onlogging_collector) andtail(pg_read_file(current_setting('log_directory') || '/' || name, greatest(size - 4 MB, 0), 4 MB)), plus thelogging_collector=offmarker arm ([FEATURE] Locate the server log from log_directory, so non-default log locations work too #3410). Byte-identical inPgPlanCaptureCollectorandPgDeadlocksCollector.RdsLogSource(per-(instance, file) resume marker,DownloadDBLogFilePortionpaging), the "marker moves after the write and nowhere else" order (RdsLogSource advances the resume marker inside the fetch, so any failure before the write loses that chunk permanently #3008), the NOT_REACHED-vs-empty note pair (get_fleet_overview's total_deadlocks cannot count a PostgreSQL deadlock, and the RDS ingest note describes a log the cycle never opened #3017), theRdsLogUnavailableExceptionwrap (RDS plan capture reports SUCCESS "no new plans" when the AWS call was DENIED #2633), and aWriteAsyncthat is the runner's binary COPY driven by the collector's own definition. Verbatim inRdsPlanIngestorandRdsDeadlockIngestor.log_line_prefixfamilies (%m [%p]space-delimited; the managed%t:%r:%u@%d:[%p]:colon-delimited), the%Qquery id glued to the severity label with no separator, the zone token read per line.PgDeadlockLogParser.IsZeroOffsetLogZone+PgLogTimezoneUnsupportedException(PgDeadlockLogParser captures the log's timezone abbreviation and never reads it — occurred_at assumes UTC no matter what log_timezone says #2993) — refuse the whole read, never shift.(?:\t[^\n]*\n)*).PgPlanLogParser's two patterns — quoted literals from every string, bare numbers only where a number is a value, with the identifier guard that keepstransactionitems1whole.Per-family: the block regex (server-side on the
pg_read_fileroute, C# on the RDS route), the row shape, the table, the identity column (plan_hash,deadlock_hash), the family's own preconditions (auto_explainloaded;log_error_verbositynot terse).The mechanism
The shared part is now explicit, once:
PgServerLogTail— the tailer as constants (TailBytes,TailBytesLiteral,TailCteSql,LoggingCollectorOffMarkerSql).PgPlanCaptureCollectorandPgDeadlocksCollectorsplice it; theirQueryTextstays a compile-timeconstand their shipped SQL is byte-for-byte what it was — pinned byTheTailerExtraction_LeftBothSiblingsSqlByteIdenticalagainst the text as it stood at the parent commit, and by the two existingBuildQuery-reading pins (PgServerLogPathPinTests,PgLoggingCollectorGateTests), which pass unchanged.PgLogEntryAssembler→PgLogEntry— rawstderr-format text in, one record per primary line out: prefix stamp/zone/pid read once, both prefix families,%Qhandled by a lazy run to the firstLABEL:,%u@%dand%elifted from the prefix where present,DETAIL/HINT/STATEMENT/CONTEXTcompanions attached only when the same pid wrote them, tab continuations folded, the cut head and the cut tail of a window dropped. Zone checked per primary line with the deadlock parser's own method; a non-zero offset throws the same exception the deadlock route throws.stderronly —csvlog/jsonlogare not handled, matching the two existing readers' coverage; the readiness collector already reports the format and Logging-settings audit with readiness-style facets — a target with everything off looks identical to a fully instrumented one #3607 is where that becomes a named finding for this pipeline.IPgLogFamilyParser— the seam Per-event temp spill attribution from log_temp_files — counters know a database spilled, not which execution spilled 4 GB at 03:07 #3602/Autovacuum per-run cost from log_autovacuum_min_duration — the health view says whether it ran, not what it cost #3603 implement:PgLogEvent.From(entry, family, databaseName?, userName?, applicationName?)— the ONLY constructor path, and the one place every text column meets the redactor. A parser cannot build an unredacted row, does not know a transport, and does not touch a cursor. Registration is one line inPgLogEventClassifier.DefaultParsers, and the order is the rule: severity first, then the LOG-level shapes, then the recognised-only arm last, so a sibling goes before it and takes its family's lines out of the generic arm (proven with a stand-in parser in the tests).PgErrorEventParser(WARNING or worse, whatever it says; liftsfor user "…"/database "…"from auth and startup failures),PgConnectionEventParser(received / authenticated / authorized / 18's ready / disconnection / replication authorized; liftsuser=,database=,application_name=),PgLockWaitEventParser(still waiting for/acquired/avoided deadlock for/detected deadlock while waiting for— the blocked-process report SQL Server DBAs ask for first, written by the engine rather than sampled).PgRecognisedFamilyParserstorestemp_file,autovacuumandcheckpointlines as generic events under their own family name, nothing lifted, sofamily = temp_filereturns the lines TODAY and Per-event temp spill attribution from log_temp_files — counters know a database spilled, not which execution spilled 4 GB at 03:07 #3602/Autovacuum per-run cost from log_autovacuum_min_duration — the health view says whether it ran, not what it cost #3603 land their structured tables and parsers as pure additions: nothing here changes, no stored row is relabelled.otheris a reserved vocabulary word, produced by no parser tonight. Unrecognised LOG/INFO/NOTICE lines are DROPPED — this table is not a copy of the log.PgLogTextRedactor— the plan parser'ss_quotedLiteralands_bareNumbermadeinternaland applied by instance, not by a second spelling (pinned: the redactor's source references the plan parser's fields and declares no literal regex of its own). Two strengths, because log text has the plan parser's two populations under other names:RedactStatement(theSTATEMENT:companion — literals AND bare numbers go; the identifier guard keepstransactionitems1) andRedactMessage(PostgreSQL's prose — literals go, numbers STAY becauseprocess 1549 still waiting … after 1000.123 msis three numbers a reader needs and none a customer typed; plus one prose-only pattern for the unquoted value tuple inKey (email)=(someone@example.com) already exists.→=(?)). The statement is never stored:statement_fingerprintis SHA-256 over the REDACTED, whitespace-normalised text, so one shape recurs to one fingerprint and no literal from the user's SQL exists anywhere in the store.raw_line_hashis SHA-256 over the raw entry — the identity the overlapping tail dedupes on, over the raw text on purpose so two events that redact alike stay two events.PgLogEventClassifier—Assemblethen first-acceptance-wins over the registered parsers. One instance (Default), stateless, fed by both transports.PgLogEventsCollector(self-hosted) opens withPgServerLogTail.TailCteSqland returnstail.bodywhole — the body crosses the wire, deliberately, because the classifier IS the thing being shared and a server-side pre-filter would be a second spelling of every family's recogniser in SQL. Cost: up to 4 MB per cycle per target on the monitoring connection at the deadlock cadence; the target-side read cost is unchanged (the deadlock collector already pulls the same 4 MB throughpg_read_fileevery five minutes). Marker row →PgLoggingCollectorOffExceptionas its siblings.RdsLogEventIngestor(managed) isRdsDeadlockIngestorover the classifier: its ownRdsLogSource(a shared one would starve whichever ingestor ran second), marker committed after the write, NOT_REACHED for a non-RDS host, zone refusal propagated uncommitted. Dispatch inDarlingWorkeris the deadlock entry's shape;ReadsServerLogWithPgReadFilenames the third reader so the 42501/58P01 sentences apply.collect.pg_log_events—collection_id, collection_time, server_id, server_name, occurred_at timestamp, family text, severity text, sqlstate text, database_name text, user_name text, application_name text, pid integer, message text, detail text, statement_fingerprint text, raw_line_hash text+idx_pg_log_events_time (server_id, collection_time). Column-for-column whatPgSchemaGeneratoremits fromPgLogEventsCollector.PayloadColumns—PgSchemaGeneratorTests.EveryPostgresRung_IsIdenticalToTheGeneratedSchemarequires it and now lists(129, PgLogEventsCollector.Instance). Hypertable conversion, one-day chunks, compression segmented byserver_idand retention all follow from the catalog entry.StorageVersion 129; the Viewer probe gains sentinel 104 (information_schema.tables … 'pg_log_events'), thehasPgLogEventstop arm, and V128's "I am the top rung" claims hand off toPgLogEventsRungTests.log_connectionson a reconnect-per-statement pool writes three rows per query, a FATAL storm writes thousands an hour.CollectorScheduleDefaults["pg_log_events"] = new(5, 30): operator-tunable per store like every entry.get_pg_log_events(server_name,hours_back,family,min_severity,limit,as_of) — the MCP pages now say what bounded them: caps bind to the caller's limit, truncation is detected not inferred, and no page count is called a total (#3541 A3) #3594/MCP percents name their denominator: shares are of the window or say they are of the page, so a three-row page stops summing to 100% of everything (#3541 A7) #3613 page contract:LIMIT $6bound,limit + 1fetched and truncation OBSERVED,events_returned,oldest_returned_at/newest_returned_at,order, andtotal_events=COUNT(*) OVER ()on the same statement afterDISTINCT ON (raw_line_hash)and the filters, before the limit — the window's distinct-event count under the same filters, never the page's.times_seenper row (sightings, never occurrences, transport-dependent as for deadlocks).min_severityranks by seriousness (LOG/INFO < NOTICE < WARNING < ERROR < FATAL < PANIC), which is NOTlog_min_messages' order (where LOG sits above ERROR) — the description says so, because a SQL Server DBA would draw exactly the wrong conclusion; the C#PgLogEntry.RankOfand the reader's SQLCASEare pinned to agree label by label. Unknownfamilyormin_severityis an error status, not an empty page. The empty branch asks capability, then the collector's recorded precondition ([FEATURE] Locate the server log from log_directory, so non-default log locations work too #3410 — grant, file,logging_collector,log_timezone), then names whichlog_*setting each family depends on. Registered (DarlingMcpHostService), web-dispatched (DarlingWebEndpoints+ a Log Events panel on the PostgreSQL Activity tab inserver-tabs.js), counted inDarlingMcpInstructions(152 tools / 66 Darling-only / thirty-four PostgreSQL reads), and given a Viewer panel under the deadlocks grid (ViewerPostgresTabsplacespg_log_eventson Activity;LoadPgLogEventsAsyncnames the collector; the XAML grid + note) so the Viewer pins hold without relaxing.log_min_messages,log_connections/log_disconnections,log_lock_waits,log_temp_files,log_autovacuum_min_duration,log_checkpoints). Logging-settings audit with readiness-style facets — a target with everything off looks identical to a fully instrumented one #3607's audit reads them; this does not.Evidence
timescale/timescaledb:2.28.1-pg18container (PostgreSQL 18.4) serving as store AND target, started withlog_lock_waits=on log_connections=on log_disconnections=on log_min_messages=warning log_temp_files=0 log_autovacuum_min_duration=0 deadlock_timeout=200ms log_timezone=UTC, plus a workload that produced one of everything:SELECT 1/0, a unique violation carrying'someone@example.com', a bad-role login (FATAL), awork_mem=64kBsort (two temp files),CHECKPOINT, dead tuples withautovacuum_naptime=2s, and two sessions colliding on one row pastdeadlock_timeout. The log then held:connection authorized14,still waiting1,acquired1,temporary file2,automatic vacuum3,checkpoint complete1, WARNING-or-worse 4.TheSelfHostedCollector_ReadsTheTargetsOwnLog_EndToEnd, gated onDARLING_TEST_PG_LOG_TARGET): the collector's shipped SQL ran on the target (pg_ls_logdir(),pg_read_file, the gate), the classifier ran on what came back, the rows went through the collector's COPY into the migrated store, and the tool read them. Rig counts per family:autovacuum=35, checkpoint=2, connection=61, error=5, lock_wait=2, temp_file=2(the autovacuum and connection counts include the rig's own naptime churn and psql sessions). Everyoccurred_atcame backKind=Utc;window_totalequalled the distinctraw_line_hashcount.ThePipeline_StoresReadsFiltersAndDedupes_AgainstDevPostgres,DARLING_TEST_PG): the fixture written TWICE through the collector's COPY (the overlapping re-read) reads back as 14 distinct events withtimes_seen: 2; boundary pairlimit=13truncated /limit=14not withtotal_events: 14both ways;min_severity=WARNING→ 4/4;family=lock_wait→ 2/2;family=error, min_severity=FATAL→ the one FATAL withuser_name: "intruder";connectionatPANIC→no_eventsnaminglog_connections;family=nonsenseandmin_severity=SEVERE→error. No literal from the fixture (someone@example.com,O'Brien,shipped,gift) appears anywhere in the JSON.DarlingPg*ReaderSQL parse-checks on PG 18 (DarlingPgReadSqlParsesLiveTests) including the newEventsSql;SeverityRankSqlis declared a fragment, not a statement.net10.0-windowsxunit.v3 exe namedDarling.Testswith the WindowsDesktop framework entry dropped from its runtimeconfig):PgLogEventsPipelineTests+PgLogEventsRungTests22/22; the touched pin classes (PgSchemaGeneratorTests,DeltaFamilyIntervalCompletionRungTests,ConsumedTimestampFrameDisciplineTests,McpPageContractTests,CollectorMeasurementSeamTests,McpToolTypeRegistrationTests,CiClusterWorkerSizingTests,ServerPageTabsTests,ViewerPostgresTabsTests,PgLoggingCollectorOffTests,PgDeadlockLogTimezoneTests,RdsDeadlockIngestorTests,PgRegistryPanelPlacementTests,ViewerCollectorCoverageTests,EngineCapabilityMissTests,RuntimePreconditionMissTests,PostgresFaultOutcomeTests,MigrationLadderPins,MigrationDataMovingRungCensusPins) — 331 executed, the only failures beingDarlingManagedPostgresTests' threeD:\darling\…Windows-path assertions, a platform artifact. Lite pins via aLite.Tests-named harness:PgServerLogPathPinTests,LogTailOverlapThresholdPinTests,PgLoggingCollectorGateTests,PgDeadlockLogParserTests— 70/70. Every touched project builds-c Release -p:EnableWindowsTargeting=truewith 0 warnings.Why this shape
otherwith a hint column: the family filter works for them today, the sibling issues add structure without relabelling anything, andotherstays a vocabulary word rather than a firehose.ERROR: deadlock detectedlands here beside its graph inpg_deadlocks— is said in the description.internalfields on the plan parser, not copied patterns. The scope note is enforced at the row constructor, not by convention.PgSchemaGeneratorTestsrequires a collector rung to be exactly the generator's output, which emits one index, so a second index inside V129 would give the upgraded store an index the fresh store never gets. The(server_id, family, collection_time)index the brief asked for is a SEPARATE rung when a family-filtered read over a long window on a loud target wants it; the rung doc says so. The read'scollection_time >= $2bound (an event is collected after it occurs) excludes older chunks meanwhile.What this does NOT do
temp_file/autovacuumtables (Per-event temp spill attribution from log_temp_files — counters know a database spilled, not which execution spilled 4 GB at 03:07 #3602, Autovacuum per-run cost from log_autovacuum_min_duration — the health view says whether it ran, not what it cost #3603 — they register a parser ahead ofPgRecognisedFamilyParserand add their tables).csvlog/jsonlog— same coverage as the two existing readers.(server_id, family, collection_time)index — separate rung (above).RdsLogSourceacross the three ingestors; no sharedWriteAsynchelper (the deadline-and-phase discipline stays in place where 133 NpgsqlCommand sites still inherit Npgsql's undocumented 30s default timeout #2874/RdsLogSource advances the resume marker inside the fetch, so any failure before the write loses that chunk permanently #3008's reviewers read it).total_eventsunder the caller's filters is the window figure.PgLogTimezoneUnsupportedException's message still says "deadlock reports" — its wording is shared by three readers now and generalising it is a one-line follow-up left out to keep its existing pins untouched.Census moved
28 PostgreSQL collectors (runbook: every "of 27" → "of 28", "All 27" → "All 28", "26 collectors are unaffected" → 27); 70 collector tables / 71 hypertables (
PgSchemaGeneratorTests69 → 70; runbook + README "all 69 … 27 PostgreSQL" → "70 … 28"; README V1 row); background workers 72/83 → 73/84 inbuild.yml,nightly.yml, the runbook and the README (CiClusterWorkerSizingTestsderives and passes); 34get_pg_*tools (runbook table row added;DarlingMcpInstructions151 → 152, 65 → 66, thirty-three → thirty-four); timestamp census 66/17 → 67/18 (ConsumedTimestampFrameDisciplineTests);CrossAppMcpToolInventoryPinTestsandServerPageTabsTests.CollectorForReadname the tool;PgServerLogPathPinTestsnow expectsPgServerLogTail.csas the one file carrying the tailer literal;LogTailOverlapThresholdPinTestsreads the one shared spelling and asserts each collector references it.Tests
New:
Darling/Darling.Tests/PgLogEventsPipelineTests.cs(assembly on both prefix families,%Q,%e, cut head/tail, zone refusal with every zero-offset spelling; routing of all six families and the drop; error/connection/lock-wait lifting; recognised-only storage; the stand-in sibling parser; redaction pins incl. the never-a-column assertion and the by-instance sharing; the byte-identity pin of both siblings' shipped SQL; collector read/marker/write order; wiring census; C#↔SQL severity rank; tool registration/dispatch/description/instructions; RDS ingestor marker discipline on failed write, zone refusal and NOT_REACHED) +PgLogEventsRungTests(top rung, generated-schema identity, one index, 30-day retention, hypertable membership, probe ordinal 104 and the arm order, workflow/runbook/README numbers) +PgLogEventsLivePostgresTests(the two gated live tests above). Moved: the V128 top-rung claims. Load-bearing edits outside the named files:PgPlanLogParser(two fieldsprivate→internal), the Viewer (probe sentinel, tab registry, panel, data-service read),server-tabs.js, the two workflows, the runbook and README censuses.Closes #3601