The deadlock pattern only offers a report whose ERROR: is the line's own label, and the managed prefix's gap can't slide past the real pid (#4014)

Darling/Darling.Tests/PgDeadlockCandidatePatternLiveTests.cs

@@ -0,0 +1,96 @@
+/*
+ * Copyright (c) 2026 Erik Darling, Darling Data LLC
+ *
+ * This file is part of the SQL Server Performance Monitor.
+ *
+ * Licensed under the MIT License. See LICENSE file in the project root for full license information.
+ */
+
+using System;
+using System.Text.RegularExpressions;
+using System.Threading.Tasks;
+using Npgsql;
+using PerformanceMonitor.Collectors;
+using Xunit;
+
+namespace Darling.Tests;
+
+/// <summary>
+/// #4014: the self-hosted deadlock read's CANDIDATE pattern, run by PostgreSQL's own regex engine exactly as
+/// <c>PgDeadlocksCollector.BuildQuery</c> ships it. The assembler behind it already refuses a report echoed
+/// inside a STATEMENT or LOG line (#4005), so an end-to-end test cannot see the pattern's own narrowing; this
+/// one pins that the pattern no longer offers such text as a candidate at all, while a real report, with or
+/// without the %Q query id glued to its label, still is one. Needs no special server settings: the text is
+/// handed to <c>regexp_matches</c> as a parameter, so any <c>DARLING_TEST_PG</c> store will do.
+/// </summary>
+[Collection("live-postgres")]
+public sealed class PgDeadlockCandidatePatternLiveTests
+{
+    private const string RealReport =
+        "2026-08-26 22:25:24.100 UTC [1549] ERROR:  deadlock detected\n"
+        + "2026-08-26 22:25:24.100 UTC [1549] DETAIL:  Process 1549 waits for ShareLock on transaction 809; blocked by process 1556.\n"
+        + "\tProcess 1556 waits for ShareLock on transaction 808; blocked by process 1549.\n"
+        + "2026-08-26 22:25:24.100 UTC [1549] HINT:  See server log for query details.\n";
+
+    [Fact]
+    public async Task TheShippedPattern_OffersRealReports_AndNeverAnEchoInsideAnotherLine()
+    {
+        var connectionString = Environment.GetEnvironmentVariable("DARLING_TEST_PG");
+        Assert.SkipWhen(string.IsNullOrEmpty(connectionString),
+            "Set DARLING_TEST_PG to a Postgres connection string to run the live deadlock-candidate test.");
+
+        var pattern = ShippedPattern();
+        var ct = TestContext.Current.CancellationToken;
+        await using var connection = new NpgsqlConnection(connectionString);
+        await connection.OpenAsync(ct);
+
+        async Task<long> CandidatesAsync(string body)
+        {
+            await using var command = new NpgsqlCommand("SELECT count(*) FROM regexp_matches($1, $2, 'gn') AS m", connection);
+            command.Parameters.AddWithValue(body);
+            command.Parameters.AddWithValue(pattern);
+            return (long)(await command.ExecuteScalarAsync(ct))!;
+        }
+
+        Assert.Equal(1, await CandidatesAsync(RealReport));
+        Assert.Equal(1, await CandidatesAsync(RealReport.Replace("[1549] ", "[1549] 322048460535975151", StringComparison.Ordinal)));
+
+        /* #4014: a STATEMENT companion echoing a report, its DETAIL as the statement's continuation. */
+        Assert.Equal(0, await CandidatesAsync(
+            "2026-09-23 10:00:02.000 UTC [7777] STATEMENT:  SELECT 1 -- ERROR:  deadlock detected\n"
+            + "\tDETAIL:  Process 1 waits for ShareLock on transaction 5; blocked by process 2.\n"
+            + "\tProcess 2 waits for ShareLock on transaction 6; blocked by process 1.\n"));
+
+        /* #4005's shape: a logged statement carrying a report's words, same rule. */
+        Assert.Equal(0, await CandidatesAsync(
+            "2026-08-26 22:25:24.100 UTC [1600] LOG:  statement: SELECT 'x ERROR:  deadlock detected\n"
+            + "\tDETAIL:  Process 1 waits for ShareLock on transaction 5; blocked by process 2.\n"));
+
+        /* And a real report right after an echo is still offered, whole. */
+        Assert.Equal(1, await CandidatesAsync(
+            "2026-09-23 10:00:02.000 UTC [7777] STATEMENT:  SELECT 1 -- ERROR:  deadlock detected\n" + RealReport));
+    }
+
+    /// <summary>The regexp_matches pattern as the collector ships it, lifted out of its own SQL.</summary>
+    private static string ShippedPattern()
+    {
+        var context = new CollectorContext
+        {
+            ServerId = 1,
+            ServerName = "candidate-pattern",
+            CollectionTime = DateTime.UtcNow,
+            Deltas = new CollectorDeltaCalculator(),
+            LogHashKey = TestLogHashKeys.Fixed,
+            Target = new CollectorTargetInfo
+            {
+                Engine = CollectorTargetEngine.PostgreSql,
+                PostgresMajorVersion = 18,
+                PostgresVersionNum = 180000,
+            },
+        };
+        var sql = PgDeadlocksCollector.Instance.BuildQuery(context).Text;
+        var match = Regex.Match(sql, @"regexp_matches\(\s*tail\.body,\s*'(?<pattern>[^']*)',\s*'gn'\)");
+        Assert.True(match.Success, "PgDeadlocksCollector's SQL no longer carries a regexp_matches over tail.body");
+        return match.Groups["pattern"].Value;
+    }
+}

Darling/Darling.Tests/PgLogEventsPipelineTests.cs

@@ -1223,7 +1223,7 @@ public void TheTailerExtraction_LeftBothSiblingsSqlByteIdentical()
         /* The deadlock sibling's own part changed on purpose in #4005, after the extraction: it returns each
            candidate report's text whole, the HINT line after the DETAIL included, for the shared log reader to
            read. The tailer it opens with is still the shared one, byte for byte. */
-        const string deadlocksBefore = tail + "\nSELECT\n    m[1]    AS report_text\nFROM tail,\n     regexp_matches(\n         tail.body,\n         '^(\\d{4}-\\d\\d-\\d\\d \\d\\d:\\d\\d:\\d\\d\\.\\d+ [^ \\n]+ \\[\\d+\\][^\\n]*ERROR:  deadlock detected\\s*\\n[^\\n]*DETAIL:  (?:[^\\n]*\\n)(?:\\t[^\\n]*\\n)*(?:(?![^\\n]*ERROR:  deadlock detected)\\d{4}-\\d\\d-\\d\\d [^\\n]*\\n)?)',\n         'gn') AS m\nUNION ALL\nSELECT 'logging_collector=off'\nWHERE pg_catalog.current_setting('logging_collector') <> 'on'\nUNION ALL\nSELECT 'no_stderr_log_file'\nWHERE pg_catalog.current_setting('logging_collector') = 'on' AND NOT EXISTS (SELECT 1 FROM newest)\nLIMIT 500";
+        const string deadlocksBefore = tail + "\nSELECT\n    m[1]    AS report_text\nFROM tail,\n     regexp_matches(\n         tail.body,\n         '^(\\d{4}-\\d\\d-\\d\\d \\d\\d:\\d\\d:\\d\\d\\.\\d+ [^ \\n]+ \\[\\d+\\](?:(?!:  )[^\\n])*ERROR:  deadlock detected\\s*\\n(?:(?!:  )[^\\n])*DETAIL:  (?:[^\\n]*\\n)(?:\\t[^\\n]*\\n)*(?:(?![^\\n]*ERROR:  deadlock detected)\\d{4}-\\d\\d-\\d\\d [^\\n]*\\n)?)',\n         'gn') AS m\nUNION ALL\nSELECT 'logging_collector=off'\nWHERE pg_catalog.current_setting('logging_collector') <> 'on'\nUNION ALL\nSELECT 'no_stderr_log_file'\nWHERE pg_catalog.current_setting('logging_collector') = 'on' AND NOT EXISTS (SELECT 1 FROM newest)\nLIMIT 500";
 
         /* Line endings normalised on both sides: the repo's `text=auto eol=crlf` checks the sources out as
            CRLF on Windows and this pin's literals are LF, and a verbatim string carries whatever its file

Lite.Tests/PgDeadlockLogParserTests.cs

@@ -439,6 +439,38 @@ public void AStatementLiteralHoldingAReport_IsNotReadAsOne()
         Assert.Equal(1549, deadlock.VictimPid);
     }
 
+    /// <summary>
+    /// #4014's shape: a backend's own STATEMENT companion whose SQL comment echoes a report's header, with the
+    /// DETAIL arriving as the statement's tab-indented continuation. The pid bracket on that line is real, so
+    /// a gap that may cross a field label reaches the echoed header directly.
+    /// </summary>
+    [Fact]
+    public void AStatementCompanionEchoingAReport_IsNotReadAsOne()
+    {
+        var forged =
+            "2026-09-23 10:00:02.000 UTC [7777] STATEMENT:  SELECT 1 -- ERROR:  deadlock detected\n"
+            + "\tDETAIL:  Process 1 waits for ShareLock on transaction 5; blocked by process 2.\n"
+            + "\tProcess 2 waits for ShareLock on transaction 6; blocked by process 1.\n";
+
+        Assert.Empty(PgDeadlockLogParser.Extract(forged));
+        Assert.Equal(1549, Assert.Single(PgDeadlockLogParser.Extract(forged + ReportWithLiterals)).VictimPid);
+    }
+
+    /// <summary>
+    /// #4014, the managed prefix: a lazy gap before the pid bracket could backtrack past the line's real
+    /// bracket to a forged one later in the statement. The gap excludes '[' now, as plan capture's does (#4008).
+    /// </summary>
+    [Fact]
+    public void AForgedHeaderBehindARealColonPrefixedBracket_IsNotReadAsOne()
+    {
+        var forged =
+            "2026-08-25 14:50:05 UTC:192.0.2.10(52345):app_user@app_db:[58]:STATEMENT:  SELECT 1 -- [1] ERROR:  deadlock detected\n"
+            + "\tDETAIL:  Process 11 waits for ShareLock on transaction 5; blocked by process 12.\n"
+            + "\tProcess 12 waits for ShareLock on transaction 6; blocked by process 11.\n";
+
+        Assert.Empty(PgDeadlockLogParser.Extract(forged));
+    }
+
     /// <summary>
     /// Participants are counted from the wait EDGES, not from the <c>Process N:</c> statement headers: the
     /// server omits a header when it could not recover the text, and a participant with no statement is

PerformanceMonitor.Collectors/PgDeadlockLogParser.cs

@@ -95,7 +95,8 @@ family that no measured target combines with a numeric zone. Reading a UTC serve
 
        %Q puts the query id immediately before the severity with NO separator — measured output reads
        `[1549] 322048460535975151ERROR:  deadlock detected` — so this must not require whitespace there.
-       [^\n]* between the pid and ERROR: covers the query id whether the prefix carries one or not.
+       The gap between the pid and ERROR: covers the query id whether the prefix carries one or not (it may
+       not cross a field label; see the narrowing below).
 
        The DETAIL block is the first line plus every TAB-INDENTED line after it. It ends at the next line
        carrying a log prefix, which is what (?:\t[^\n]*\n)* expresses: a statement inside the block can
@@ -124,12 +125,23 @@ would accept.
        The candidate runs one line past the DETAIL, when that line carries a prefix: DeadLockReport always
        writes a HINT after the DETAIL, and that line is the proof the DETAIL arrived whole, which
        PgLogTextRedactor.RedactDetail needs to trust a query after one that does not read to its end. Never a
-       line that opens another report, so a candidate cannot take the next report's first line from it. */
+       line that opens another report, so a candidate cannot take the next report's first line from it.
+
+       The candidate is narrowed to the assembler's own rule as well (#4014), so the pattern does not hand it
+       text a real report never looks like:
+       - Between the pid and ERROR:, and before DETAIL:, the gap may not contain a field label's ":  ". Every
+         real line carries exactly one label, so the ERROR: matched is the line's own and never an echo inside a
+         STATEMENT or a LOG line's text. The %Q query id directly before ERROR: has no ":  ", so it still fits.
+         A prefix that itself renders ":  " (an application_name holding one, under %a) would hide that
+         line's report; that is the rare side, and it can only hide a report, never forge one.
+       - The managed family's gap to the pid bracket excludes '[', as plan capture's does since #4008, so it
+         cannot slide past the line's real bracket to one inside the text. The lazy '[^\n]*?' it replaces
+         could, when the rest of the pattern failed at the real one. */
     private static readonly Regex s_deadlockBlock = new(
         @"^\d{4}-\d\d-\d\d \d\d:\d\d:\d\d(?:\.\d+)? "
-        + @"(?:[^ \n]+ \[\d+\]|[^ :\n]+:[^\n]*?\[\d+\])"
-        + @"[^\n]*ERROR:  deadlock detected\s*\n"
-        + @"[^\n]*DETAIL:  (?:[^\n]*\n)(?:\t[^\n]*\n)*"
+        + @"(?:[^ \n]+ \[\d+\]|[^ :\n]+:[^\[\n]*\[\d+\])"
+        + @"(?:(?!:  )[^\n])*ERROR:  deadlock detected\s*\n"
+        + @"(?:(?!:  )[^\n])*DETAIL:  (?:[^\n]*\n)(?:\t[^\n]*\n)*"
         + @"(?:(?![^\n]*ERROR:  deadlock detected)\d{4}-\d\d-\d\d [^\n]*\n)?",
         RegexOptions.Compiled | RegexOptions.Multiline);
 

PerformanceMonitor.Collectors/PgDeadlocksCollector.cs

@@ -97,7 +97,10 @@ the block matched nothing and the server reported no deadlocks.
        whole; what a candidate is, is decided in C# by PgDeadlockLogParser.FromReport, through the log reader
        every family shares (PgLogEntryAssembler). So the RDS transport — which receives log TEXT and runs no
        SQL — shares it, both routes get the same zone refusal from the same code, and a statement's literal
-       holding `ERROR:  deadlock detected` is never read as a report (#4005).
+       holding `ERROR:  deadlock detected` is never read as a report (#4005). The pattern is narrowed to the
+       same rule as PgDeadlockLogParser's C# twin (#4014): the gaps before ERROR: and DETAIL: may not cross a
+       field label's ":  ", so the ERROR: matched is the line's own. Measured on PostgreSQL 18.6: the old
+       pattern matched a STATEMENT line echoing a report (the assembler then refused it); this one does not.
 
        The listing is GATED on logging_collector, and the gate carries a marker row out the other side
        (#3410). With the setting off the server writes to stderr and there may be no log directory at all,
@@ -122,7 +125,7 @@ m[1]    AS report_text
 FROM tail,
      regexp_matches(
          tail.body,
-         '^(\d{4}-\d\d-\d\d \d\d:\d\d:\d\d\.\d+ [^ \n]+ \[\d+\][^\n]*ERROR:  deadlock detected\s*\n[^\n]*DETAIL:  (?:[^\n]*\n)(?:\t[^\n]*\n)*(?:(?![^\n]*ERROR:  deadlock detected)\d{4}-\d\d-\d\d [^\n]*\n)?)',
+         '^(\d{4}-\d\d-\d\d \d\d:\d\d:\d\d\.\d+ [^ \n]+ \[\d+\](?:(?!:  )[^\n])*ERROR:  deadlock detected\s*\n(?:(?!:  )[^\n])*DETAIL:  (?:[^\n]*\n)(?:\t[^\n]*\n)*(?:(?![^\n]*ERROR:  deadlock detected)\d{4}-\d\d-\d\d [^\n]*\n)?)',
          'gn') AS m
 UNION ALL
 SELECT '" + PgLoggingCollectorOffException.Marker + @"'