Repository navigation
Read the log prefix a managed PostgreSQL target renders, and test both parsers on one (#3030) - #3037
Conversation
PgDeadlockLogParser's block pattern requires fractional seconds and a space before the bracketed pid. A managed parameter group's system default log_line_prefix, '%t:%r:%u@%d:[%p]:', renders neither: %t has no fraction, and the prefix's own ':' sits where PostgreSQL's default puts a space. The pattern therefore matches no line of such a log, Extract returns nothing, and the RDS ingest route reports a window it read and found empty while consuming it on the way out. Both halves are separable and each is independently fatal: restoring only the fraction, or only the space, still yields nothing. The pattern now takes the fraction as optional and either a space or a colon before the bracket, with the prefix run between the delimiter and the bracket absorbed lazily - %r and %u@%d land there, and %r renders empty on a line with no client connection. The zone is bounded by the prefix's own delimiter. Allowed to run to the last delimiter before the bracket it reads UTC:<host>(<port>):<user>@<db>, which IsZeroOffsetLogZone refuses - which would abandon every window on a fleet whose log_timezone is UTC, naming a setting that is already correct. Two alternatives, since only a numeric offset carries a colon of its own, so -03:30 stays whole and a refusal names the zone it read. PgPlanLogParser's pattern has the same delimiter requirement after the pid, and auto_explain's %Q appended to that prefix renders `]:<id> LOG:`. It takes a space or a colon there too. The fixtures are the other half. Every log fixture in the tree carried the self-hosted prefix, including the one in RdsDeadlockIngestorTests, which is the managed transport's own suite - so the transport was proven over text no managed target emits. That suite now carries a managed-prefix report, driven through the real ingestor, and the parser suites carry the four prefix regimes: both requirements present, each one absent alone, and neither present. Identifiers in the new fixtures are synthesised; 192.0.2.10 is RFC 5737 documentation space. The SQL counterparts of both patterns, in PgDeadlocksCollector and PgPlanCaptureCollector, serve the pg_read_file route and still require the fraction and the space. Both parsers now say so.
…onitor into fix/3030-managed-log-prefix
![claude[bot]](https://avatars.githubusercontent.com/in/1236702?s=60&v=4){kind=small}
|
Reviewed the parser/regex change plus the new fixtures across Scope/parity: One correctness finding, left as an inline comment on Every new fixture in this PR uses an IPv4 host ( Everything else — the |
One pattern spanning both prefix families needs the zone to be an abbreviation-or-numeric-offset alternation and the pid delimiter to be [ :]. A numeric offset carries colons of its own, so under a colon-delimited prefix the zone cannot tell its own colon from the prefix's. On `+00:2001:db8::1(...)` - a zero-offset zone and an IPv6 %r - the offset loop takes `:2001` as another of its groups, IPv6's next colon satisfies the delimiter, nothing backtracks, and the zone reads `+00:2001`. IsZeroOffsetLogZone refuses that, so a target whose log_timezone IS zero-offset has every window abandoned with a message naming a setting that is already correct, every cycle, for as long as a client keeps connecting from that address. Bounding the offset's groups to two digits only moves the boundary: `+00:20:db8::1(...)` breaks it again, because 0020 renders as `20`. The two families are alternatives now. The space family is what PostgreSQL's own default renders and is character-for-character what it was, so every existing zone shape captures identically. The colon family excludes ':' from the zone outright, which removes the ambiguity rather than narrowing it. Both name the same two groups, which .NET allows across alternatives, so the reads below do not care which matched. The trade is that a numeric offset under a colon-delimited prefix is read up to the delimiter, so a non-zero one refuses as `-03` rather than `-03:30`. The verdict is unchanged in every case; only the token in the message is shorter, and only on a prefix family no measured target combines with a numeric zone. Three fixtures for the combination that decides it, which had none: a zero-offset numeric zone under a colon-delimited prefix with an IPv4 %r, with an IPv6 %r whose leading hextet is all digits, and with one whose leading hextet is two digits. Each asserts the absence of a refusal separately from the count, because a misread zone and an unmatched block are different failures. A fourth pins that a non-zero offset still refuses there, and that the space-delimited prefix still names it whole. 2001:db8::1 is RFC 3849 documentation space.
|
Reviewed. No blocking issues found. Scope: only Correctness — traced the new alternation by hand against the added test fixtures:
Lite/Darling parity — the parser fix lives in the shared Security/perf — no injection surface (log text parsing only, not used to build queries), no secrets, regexes stay linear (lazy quantifier bounded by Note: I wasn't able to actually execute |
1 participant
PgDeadlockLogParser.s_deadlockBlockrequires two things a managed PostgreSQL target's log never renders, and so it matches no line of one.Extractreturns nothing,RdsDeadlockIngestorstores nothing, and the cycle records the source as reached with zero rows — while advancing and persisting its resume marker, so the window is consumed and the text is not offered again. Fixes #3030.log_line_prefix = '%m [%p] ', PostgreSQL's own default, renders2026-08-26 22:25:24.100 UTC [1549]. The system default on a managed parameter group is'%t:%r:%u@%d:[%p]:', rendering2026-08-26 22:25:24 UTC:<host>(<port>):<user>@<db>:[1549]:. Two things differ, and each is independently fatal — restoring only the fraction, or only the space, still yields nothing:%trenders no fractional seconds where\.\d+was mandatory. The fraction is optional now.:sits where the pattern spelled a space, with%rand%u@%dbetween the zone and the pid, and%rrenders empty on a line with no client connection.The two prefix families are alternatives, not one relaxed pattern
The obvious single pattern —
[ :]for the delimiter and an abbreviation-or-numeric-offset alternation for the zone — is wrong in the worst available direction: a wrong answer rather than a missing one. A numeric offset carries colons of its own, so under a colon-delimited prefix the zone cannot tell its own colon from the prefix's. On+00:2001:db8::1(...)— a zero-offset zone and an IPv6%r— the offset loop takes:2001as another of its groups, IPv6's next colon satisfies the delimiter, nothing backtracks, and the zone reads+00:2001.IsZeroOffsetLogZonerefuses that, so a target whoselog_timezoneis zero-offset has every window abandoned with a message naming a setting that is already correct — every cycle, for as long as a client keeps connecting from that address. Bounding the offset's inner groups to two digits only moves the boundary:+00:20:db8::1(...)breaks it again, because0020renders as20.Splitting by delimiter removes the ambiguity instead of narrowing it. The space family is character-for-character what it was, so every existing zone shape captures identically; the colon family excludes
:from the zone outright. Both name the same two groups, which .NET allows across alternatives.The trade is that a numeric offset under a colon-delimited prefix is read up to the delimiter, so a non-zero one refuses as
-03rather than-03:30. The verdict is unchanged in every case — measured across 22 renderings — and only the token in the message is shorter, on a prefix family no measured target combines with a numeric zone. Reading a UTC server as non-UTC is the failure worth designing against; a terser refusal message is not.The plan parser
PgPlanLogParser.s_planBlockhas the same delimiter requirement after the pid, and takes a space or a colon there now. That route is inert on a managed target with the system default prefix regardless, becauseauto_explain's query id only reaches the log through%Qand the system default has none — but appending the%Qthis parser already requires gives'%t:%r:%u@%d:[%p]:%Q ', and the line then reads]:<id> LOG:, which is what the change accepts.The fixtures are the other half of the fix
Swept over 2,688 tracked files with the self-hosted prefix as a firing positive control and the managed prefix cross-controlled against it: 27 log-prefix lines across five files, every one self-hosted, none managed anywhere in the tree.
RdsDeadlockIngestorTestsis the managed transport's own suite, and itsDeadlockTextis captured self-hosted output — so the transport was proven over text no managed target emits, and a regex-only fix would leave the same class of defect undetectable.That suite now carries a managed-prefix report driven through the real ingestor. The parser suites carry the four prefix regimes as separate tests — both requirements present, each one absent alone, and neither present — plus the combination that decides the zone question and previously had no coverage at all: a numeric zero-offset zone under a colon-delimited prefix, with an IPv4
%r, an IPv6%rwhose leading hextet is four digits, and one whose leading hextet is two.Identifiers in the new fixtures are synthesised.
192.0.2.10is RFC 5737 documentation space and2001:db8::1is RFC 3849.Verification
Compiled the real Windows-only test files into
net10.0xunit v3 hosts on macOS. Lite 63/63 and Darling 109/109 pass, 0 failed, 0 skipped, 0 not run. The Darling host covers all sixDarling.Testsfiles that reference either parser or either collector, plusDocCommentHygieneTestsandFleetIdentifierScrubTests; both guards were shown to reach the changed files by planting a violation in one of them and watching each name the file and line.Six mutations, each against a committed baseline, rebuilt every cycle, restored by content-verified single-path checkout. Each half reverted separately reddens a different named assertion and leaves the other half's green:
ParsesAStampWithNoFractionalSeconds—Assert.SingleemptyParsesAColonBeforeTheBracketedPidParsesAColonBeforeTheBracketedPid—Assert.SingleemptyParsesAStampWithNoFractionalSecondsANumericZeroOffsetZoneParsesUnderAColonDelimitedPrefix—Assert.Null, i.e. a refusal, not a missExtractReadsAManagedPrefixAlongsideASelfHostedOne(2 → 1)ReportUndermade an identityExpected 3, Actual 0, and five regime tests on their timestamp assertionsManagedDeadlockTextcollapsed toDeadlockTextAssert.DoesNotContainThe third row is the one that matters most: with the single relaxed pattern the IPv4 fixture passes and only the IPv6 ones fail, which is exactly why an IPv4-only fixture set could not have caught it.
The self-hosted format still parses, by count and not by assertion: the 45 pre-existing tests across
PgDeadlockLogParserTestsandPgPlanLogParserTestsare unchanged and green,+00:00,-00,-0000,GMTandUCTprefixes still parse, andEST,+07,-03:30and+0530still refuse with the observed zone reported verbatim under the space-delimited family. A 22-case adversarial probe against the built assembly — patterns dumped back out ofPerformanceMonitor.Collectors.dllby reflection — covers both families, both isolating regimes, IPv6 and empty%r, a bracketed app name before the pid, CRLF bodies, a mixed slab (2 reports, no duplicates), and every zone spelling. All 22 verdicts correct.Scope boundary
The SQL counterparts of both patterns —
PgDeadlocksCollectorandPgPlanCaptureCollector, which serve thepg_read_fileroute — carry the space family only. Both parsers now say so in place of assuming parity. They are left narrow deliberately: that route only runs against self-hosted targets, the verification rig's own prefix is%m [%p] %Q, widening them needs any new groups spelled non-capturing som[1]…m[4]do not shift, and there is no PostgreSQL here to exercise ARE against.CHANGELOG entry
Not committed, per the routing rule. For the
[Unreleased]→### Fixedblock:And the link reference: