Fleet overview: an Azure master's deadlock last-seen comes from its own databases, and the Viewer card shows no sibling's Last

Darling/Darling.Tests/FleetOverviewAzureMasterScopeLiveTests.cs

@@ -15,6 +15,7 @@
 using Npgsql;
 using PerformanceMonitor.Collectors;
 using PerformanceMonitor.Common;
+using PerformanceMonitor.Darling.Analysis;
 using PerformanceMonitor.Darling.Service;
 using PerformanceMonitor.Darling.Service.Mcp;
 using PerformanceMonitor.Darling.Storage;
@@ -90,17 +91,23 @@ public async Task MasterCard_MaxWait_IsTheLargestWaitOfItsOwnDatabases()
     [Fact]
     public async Task AResolverThatThrows_KeepsTheUnscopedCounts_AndEveryCard()
     {
-        var result = await RunAsync(async (postgres, registry, now, ct) =>
-            await DarlingFleetReader.GetFleetOverviewAsync(
+        var (result, unscopedLast) = await RunAsync(async (postgres, registry, now, ct) =>
+        {
+            var thrown = await DarlingFleetReader.GetFleetOverviewAsync(
                 postgres, now.AddHours(-1), now, now, cancellationToken: ct,
                 separatelyMonitored: (id, token) => id == MasterId
                     ? throw new InvalidOperationException("the registry read failed")
-                    : DarlingWorker.AnalysisSeparatelyMonitoredDatabasesAsync(id, registry, postgres, token)));
+                    : DarlingWorker.AnalysisSeparatelyMonitoredDatabasesAsync(id, registry, postgres, token));
+            var plain = await FleetAsync(postgres, null, now, ct);
+            return (thrown, plain.Cards.Single(c => c.ServerId == MasterId).DeadlockLastSeen);
+        });
 
         var master = Assert.Single(result.Cards, c => c.ServerId == MasterId);
         Assert.Equal(6, master.BlockingCount);
         Assert.Equal(2, master.DeadlockCount);
         Assert.Equal(LargerWaitMs, master.MaxBlockingWaitMs);
+        Assert.NotNull(master.DeadlockLastSeen);
+        Assert.Equal(unscopedLast, master.DeadlockLastSeen);
         foreach (var id in AllIds) Assert.Single(result.Cards, c => c.ServerId == id);
 
         /* A server that did resolve is still scoped: only the failed lookup falls back. */
@@ -115,19 +122,132 @@ await DarlingFleetReader.GetFleetOverviewAsync(
     public async Task AScopedReadThatThrows_KeepsTheUnscopedCounts_AndEveryCard()
     {
         var log = new List<string>();
-        var result = await RunAsync(async (postgres, registry, now, ct) =>
-            await DarlingFleetReader.GetFleetOverviewAsync(
+        var (result, unscopedLast) = await RunAsync(async (postgres, registry, now, ct) =>
+        {
+            var thrown = await DarlingFleetReader.GetFleetOverviewAsync(
                 postgres, now.AddHours(-1), now, now, cancellationToken: ct,
                 separatelyMonitored: (id, token) => Task.FromResult<IReadOnlyList<string>?>(id == MasterId ? new[] { "GP\0" } : null),
-                logger: new ListLogger(log)));
+                logger: new ListLogger(log));
+            var plain = await FleetAsync(postgres, null, now, ct);
+            return (thrown, plain.Cards.Single(c => c.ServerId == MasterId).DeadlockLastSeen);
+        });
 
         var master = Assert.Single(result.Cards, c => c.ServerId == MasterId);
         Assert.Equal(6, master.BlockingCount);
         Assert.Equal(2, master.DeadlockCount);
+        Assert.NotNull(master.DeadlockLastSeen);
+        Assert.Equal(unscopedLast, master.DeadlockLastSeen);
         foreach (var id in AllIds) Assert.Single(result.Cards, c => c.ServerId == id);
         Assert.Contains(log, line => line.Contains(MasterId.ToString(System.Globalization.CultureInfo.InvariantCulture), StringComparison.Ordinal));
     }
 
+    /// <summary>
+    /// The card's "last seen" follows its count: the separately monitored database's deadlock is newer than any of
+    /// the master's own, and the card shows the master's own newest. A plain server and a master with no sibling
+    /// show their newest; a master whose only deadlock is the sibling's has none.
+    /// </summary>
+    [Fact]
+    public async Task MasterCard_DeadlockLastSeen_IsTheNewestOfItsOwnDatabases()
+    {
+        var (card, plainCard, loneCard, unscopedCard, own, sibling, noneLeft) = await RunAsync(async (postgres, registry, now, ct) =>
+        {
+            var scoped = await FleetAsync(postgres, registry, now, ct);
+            var unscoped = await FleetAsync(postgres, null, now, ct);
+            var ownNewest = await ScalarTimeAsync(postgres, $"SELECT MAX(deadlock_time) FROM deadlocks WHERE server_id = {MasterId} AND lower(deadlock_graph_xml) LIKE '%other%'", ct);
+            var siblingNewest = await ScalarTimeAsync(postgres, $"SELECT MAX(deadlock_time) FROM deadlocks WHERE server_id = {MasterId}", ct);
+            await using (var drop = postgres.CreateCommand($"DELETE FROM deadlocks WHERE server_id = {MasterId} AND deadlock_graph_xml LIKE '%Other%'"))
+            {
+                await drop.ExecuteNonQueryAsync(ct);
+            }
+            var onlySiblings = await FleetAsync(postgres, registry, now, ct);
+            return (scoped.Cards.Single(c => c.ServerId == MasterId), scoped.Cards.Single(c => c.ServerId == PlainId),
+                scoped.Cards.Single(c => c.ServerId == LoneId), unscoped.Cards.Single(c => c.ServerId == MasterId),
+                ownNewest, siblingNewest, onlySiblings.Cards.Single(c => c.ServerId == MasterId));
+        });
+
+        Assert.NotNull(own);
+        Assert.NotNull(sibling);
+        Assert.True(sibling > own);
+        Assert.Equal(own, card.DeadlockLastSeen);
+        Assert.Equal(sibling, unscopedCard.DeadlockLastSeen);
+        Assert.NotNull(plainCard.DeadlockLastSeen);
+        Assert.NotNull(loneCard.DeadlockLastSeen);
+        Assert.Equal(0, noneLeft.DeadlockCount);
+        Assert.Null(noneLeft.DeadlockLastSeen);
+    }
+
+    /// <summary>
+    /// One pass answers both: the combined method's count equals the count-only method's on the same rows (an outside
+    /// row, an all-in graph, a mixed graph, a graph with no database stamp, and a row with no event time, which the
+    /// window leaves out and which must not throw), and its newest time is the newest counted row's.
+    /// </summary>
+    [Fact]
+    public async Task TheCombinedDeadlockPass_AgreesWithTheCountOnlyPass_AndFindsTheNewestCounted()
+    {
+        var (combined, countOnly, newestCounted, expectedNewest) = await RunAsync(async (postgres, registry, now, ct) =>
+        {
+            var separate = new[] { "GP" };
+            var t = now.AddMinutes(-10);
+            async Task Row(string? db, string graph, DateTime? time, int offset) =>
+                await Exec2(postgres, ct, CollectionIdGenerator.Next(), now.AddMinutes(-9).AddSeconds(offset), MasterId, Base + "-master",
+                    (object?)time ?? DBNull.Value, graph, (object?)db ?? DBNull.Value);
+            await Row("Other", Graph("Other"), t.AddSeconds(1), 1);
+            await Row("GP", Graph("GP"), t.AddSeconds(2), 2);
+            await Row("master", "<deadlock><process-list><process id=\"p0\" currentdbname=\"GP\" /><process id=\"p1\" currentdbname=\"Other\" /></process-list></deadlock>", t.AddSeconds(3), 3);
+            await Row(null, Graph("Other"), t.AddSeconds(4), 4);
+            await Row("Other", Graph("Other"), null, 5);
+            await Row("master", Graph("GP"), t.AddSeconds(30), 6);
+
+            await using var connection = await postgres.OpenConnectionAsync(ct);
+            var start = now.AddHours(-1);
+            var pair = await PgFactCollector.CountAndNewestDeadlocksSkippingSeparateAsync(connection, MasterId, start, now, separate, ct, 30);
+            var count = await PgFactCollector.CountDeadlocksSkippingSeparateAsync(
+                connection, PgFactCollector.DeadlockOutsideCountSql, PgFactCollector.DeadlockGraphsSql, MasterId, start, now, separate, ct, 30);
+            var newest = await ScalarTimeAsync(postgres, $"SELECT MAX(deadlock_time) FROM deadlocks WHERE server_id = {MasterId} AND deadlock_time = '{t.AddSeconds(4):yyyy-MM-dd HH:mm:ss.ffffff}'", ct);
+            return (pair, count, newest, new DateTime(t.AddSeconds(4).Ticks / 10 * 10, DateTimeKind.Unspecified));
+        });
+
+        /* Three planted counters plus the fixture's own "Other" deadlock. */
+        Assert.Equal(countOnly, combined.Count);
+        Assert.Equal(4, combined.Count);
+        Assert.NotNull(newestCounted);
+        Assert.Equal(newestCounted, combined.Newest);
+        Assert.Equal(expectedNewest, combined.Newest);
+    }
+
+    /// <summary>
+    /// The scoped counts make one deadlock pass: the combined method gives the count and the last-seen together, so a
+    /// failed last-seen read cannot lose the count and no graph is walked twice.
+    /// </summary>
+    [Fact]
+    public void TheScopedCounts_MakeOneDeadlockPass()
+    {
+        var reader = RepoFile.ReadRepoFile("Darling", "PerformanceMonitor.Darling.Service", "Mcp", "DarlingFleetReader.cs");
+        var start = reader.IndexOf("internal static async Task<AzureMasterScopedCounts> ReadAzureMasterScopedCountsAsync(", StringComparison.Ordinal);
+        Assert.True(start > 0);
+        var end = reader.IndexOf("private static async Task<Dictionary<int, BlockingRow>> ReadBlockingAsync(", start, StringComparison.Ordinal);
+        var body = reader.Substring(start, end - start);
+
+        Assert.Contains("PgFactCollector.CountAndNewestDeadlocksSkippingSeparateAsync(", body, StringComparison.Ordinal);
+        Assert.DoesNotContain("CountDeadlocksSkippingSeparateAsync(", body.Replace("CountAndNewestDeadlocksSkippingSeparateAsync(", ""), StringComparison.Ordinal);
+        Assert.DoesNotContain("NewestDeadlock", body.Replace("CountAndNewestDeadlocksSkippingSeparateAsync(", ""), StringComparison.Ordinal);
+    }
+
+    private static async Task Exec2(NpgsqlDataSource postgres, CancellationToken ct, params object[] p)
+    {
+        await using var command = postgres.CreateCommand(
+            "INSERT INTO deadlocks (deadlock_id, collection_time, server_id, server_name, deadlock_time, deadlock_graph_xml, database_name) VALUES ($1,$2,$3,$4,$5,$6,$7)");
+        foreach (var v in p) command.Parameters.AddWithValue(v);
+        await command.ExecuteNonQueryAsync(ct);
+    }
+
+    private static async Task<DateTime?> ScalarTimeAsync(NpgsqlDataSource postgres, string sql, CancellationToken ct)
+    {
+        await using var command = postgres.CreateCommand(sql);
+        var value = await command.ExecuteScalarAsync(ct);
+        return value is DateTime t ? t : null;
+    }
+
     /// <summary>
     /// get_server_summary counts a master's last hour the way its fleet card does (3 blocking, 1 deadlock), leaves
     /// a plain server and a lone master alone, and falls back to the unscoped 6 / 2 when the lookup throws.
@@ -298,19 +418,23 @@ await Exec(connection, "INSERT INTO server_properties (collection_id, collection
             async Task Bpr(int id, string name, string? db, long waitMs = 12000) =>
                 await Exec(connection, "INSERT INTO blocked_process_reports (blocked_report_id, collection_time, server_id, server_name, event_time, wait_time_ms, blocking_spid, blocking_status, blocked_spid, database_name) VALUES ($1,$2,$3,$4,$2,$7,60,'suspended',$5,$6)",
                     ct, CollectionIdGenerator.Next(), at.AddSeconds(seq), id, name, 70 + seq++, (object?)db ?? DBNull.Value, waitMs);
-            async Task Dead(int id, string name, string db) =>
+            async Task Dead(int id, string name, string db, string? stamped = null) =>
                 await Exec(connection, "INSERT INTO deadlocks (deadlock_id, collection_time, server_id, server_name, deadlock_time, deadlock_graph_xml, database_name) VALUES ($1,$2,$3,$4,$2,$5,$6)",
-                    ct, CollectionIdGenerator.Next(), at.AddSeconds(seq++), id, name, Graph(db), db);
+                    ct, CollectionIdGenerator.Next(), at.AddSeconds(seq++), id, name, Graph(db), stamped ?? db);
 
             /* The first GP report waited longer than any of master's own: a scoped max wait must not see it. */
             await Bpr(MasterId, Base + "-master", "GP", LargerWaitMs);
             foreach (var db in new[] { "master", "master", "GP", "GP", null }) await Bpr(MasterId, Base + "-master", db);
             foreach (var db in new[] { "GP", "GP", "GP" }) await Bpr(GpId, Base + "-gp", db);
             foreach (var db in new[] { "x", "y" }) await Bpr(PlainId, Base + "-plain", db);
             foreach (var db in new[] { "master", "master" }) await Bpr(LoneId, Base + "-lone", db);
+            /* The master's own deadlock comes first and is stamped with the connection's database, so the graph
+               decides it; the separately monitored database's deadlock is the newer of the two. */
+            await Dead(MasterId, Base + "-master", "Other", "master");
             await Dead(MasterId, Base + "-master", "GP");
-            await Dead(MasterId, Base + "-master", "Other");
             await Dead(GpId, Base + "-gp", "GP");
+            await Dead(PlainId, Base + "-plain", "x");
+            await Dead(LoneId, Base + "-lone", "GP");
 
             var state = new MonitoredServerRegistryState();
             state.Publish(new List<MonitoredServer>

Darling/Darling.Tests/ViewerFleetAzureMasterScopeLiveTests.cs

@@ -152,6 +152,75 @@ private static async Task SeedAsync(NpgsqlConnection connection, DateTime at, Sy
         await DeadlockAsync(connection, PlainId, "x", at, ct);
     }
 
+    /// <summary>
+    /// The card's "Last: N ago" for a master with separately monitored databases: a sibling's blocking report and
+    /// deadlock are newer than any of the master's own, and the master shows NO "Last" for either, whether the scoped
+    /// reads succeed or fail (its counts stay scoped). A plain server and a master with no sibling show their newest.
+    /// </summary>
+    [Theory]
+    [InlineData("none")]
+    [InlineData("blocking")]
+    [InlineData("deadlocks")]
+    [InlineData("registry")]
+    public async Task TheMastersCard_ShowsNoLastForBlockingOrDeadlocks(string failingStage)
+    {
+        var baseConnectionString = Environment.GetEnvironmentVariable("DARLING_TEST_PG");
+        Assert.SkipWhen(string.IsNullOrEmpty(baseConnectionString), "Set DARLING_TEST_PG to run the live Viewer scope pin.");
+
+        var ct = TestContext.Current.CancellationToken;
+        var scratch = await ScratchPostgres.CreateAsync(baseConnectionString!, ct);
+        var bodySucceeded = false;
+        try
+        {
+            await using var connection = new NpgsqlConnection(scratch.ConnectionString);
+            await connection.OpenAsync(ct);
+            await PgMigrations.MigrateAsync(connection, ct);
+            await SeedAsync(connection, DateTime.UtcNow.AddMinutes(-10), ct);
+            await RegisterAsync(connection, LoneMasterId, "host-c.example", "master", 5, ct);
+
+            /* Newer than anything the master recorded in its own databases. */
+            var newer = DateTime.UtcNow.AddMinutes(-5);
+            await BprAsync(connection, MasterId, "GP", newer, ct);
+            await DeadlockAsync(connection, MasterId, "GP", newer, ct);
+            await BprAsync(connection, LoneMasterId, "GP", newer, ct);
+            await DeadlockAsync(connection, LoneMasterId, "GP", newer, ct);
+
+            await using var viewer = new ViewerDataService(scratch.ConnectionString);
+            viewer.ScopeReadHookForTests = stage =>
+                stage == failingStage ? throw new InvalidOperationException("scope read failed") : Task.CompletedTask;
+
+            var master = await viewer.GetServerSummaryAsync(MasterId, "master", null, ct);
+            if (failingStage == "registry")
+            {
+                /* A failed list lookup means unscoped: the card keeps today's "Last". */
+                Assert.InRange(master.LastBlockingMinutesAgo!.Value, 4, 6);
+                Assert.InRange(master.LastDeadlockMinutesAgo!.Value, 4, 6);
+            }
+            else
+            {
+                Assert.Null(master.LastBlockingMinutesAgo);
+                Assert.Null(master.LastDeadlockMinutesAgo);
+                Assert.DoesNotContain("Last", master.BlockingDetail);
+                Assert.DoesNotContain("Last", master.DeadlockDetail);
+            }
+
+            var plain = await viewer.GetServerSummaryAsync(PlainId, "plain", null, ct);
+            Assert.InRange(plain.LastBlockingMinutesAgo!.Value, 9, 11);
+            Assert.InRange(plain.LastDeadlockMinutesAgo!.Value, 9, 11);
+
+            var lone = await viewer.GetServerSummaryAsync(LoneMasterId, "lone", null, ct);
+            Assert.InRange(lone.LastBlockingMinutesAgo!.Value, 4, 6);
+            Assert.InRange(lone.LastDeadlockMinutesAgo!.Value, 4, 6);
+
+            bodySucceeded = true;
+        }
+        finally
+        {
+            await LiveStoreCleanup.RunAsync(scratch.ConnectionString, bodySucceeded, async (_, _) => await Task.CompletedTask);
+            await scratch.DisposeAsync();
+        }
+    }
+
     /// <summary>
     /// A failed scope lookup or scoped read means UNSCOPED, never a dropped card or zeroed totals: whichever
     /// read throws, the master's card shows its unscoped counts and the fleet totals the unscoped totals.