diff --git a/Darling/Darling.Tests/CollectionLogWebRowPreservesFullTextPinTests.cs b/Darling/Darling.Tests/CollectionLogWebRowPreservesFullTextPinTests.cs new file mode 100644 index 0000000000..8469ef6dc5 --- /dev/null +++ b/Darling/Darling.Tests/CollectionLogWebRowPreservesFullTextPinTests.cs @@ -0,0 +1,53 @@ +/* + * 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.IO; +using System.Runtime.CompilerServices; +using Xunit; + +namespace Darling.Tests; + +/// +/// #4198: the web viewer's /api/read row for get_collection_log must keep passing today's +/// behavior explicitly now that the MCP tool previews error_message by default — the same "pass the +/// old default through the row" contract #3897's trend tools pin for TrendBudget.Chart. No rig: a +/// source-text pin, like PgCappedReadSurfaceTests. +/// +public sealed class CollectionLogWebRowPreservesFullTextPinTests +{ + private const string WebEndpoints = + "Darling/PerformanceMonitor.Darling.Service/DarlingWebEndpoints.cs"; + + [Fact] + public void GetCollectionLog_WebRow_PassesFullTextTrue_AndTheOldRowLimit() + { + var path = Path.Combine(RepoRoot(), WebEndpoints); + Assert.True(File.Exists(path), $"web endpoints source not found: {path}"); + var source = File.ReadAllText(path); + + var at = source.IndexOf("[\"get_collection_log\"] = (c, pg, an) =>", System.StringComparison.Ordinal); + Assert.True(at >= 0, "get_collection_log's /api/read row was not found — has it been renamed or moved?"); + + var stop = source.IndexOf("[\"get_current_waits_trend\"]", at, System.StringComparison.Ordinal); + Assert.True(stop > at, "could not bound get_collection_log's row against its next sibling"); + var row = source[at..stop]; + + Assert.Contains("full_text: true", row); + Assert.Contains("Rows(c, \"limit\", 200)", row); + } + + private static string RepoRoot([CallerFilePath] string thisFile = "") + { + var dir = Path.GetDirectoryName(thisFile)!; + while (!File.Exists(Path.Combine(dir, "PerformanceMonitor.sln"))) + { + dir = Path.GetDirectoryName(dir)!; + } + return dir; + } +} diff --git a/Darling/Darling.Tests/McpCollectionLogPerServerResponseBudgetLivePostgresTests.cs b/Darling/Darling.Tests/McpCollectionLogPerServerResponseBudgetLivePostgresTests.cs new file mode 100644 index 0000000000..5fe8b71b92 --- /dev/null +++ b/Darling/Darling.Tests/McpCollectionLogPerServerResponseBudgetLivePostgresTests.cs @@ -0,0 +1,246 @@ +/* + * 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.Globalization; +using System.Linq; +using System.Text; +using System.Threading; +using System.Threading.Tasks; +using Npgsql; +using PerformanceMonitor.Collectors; +using PerformanceMonitor.Common; +using PerformanceMonitor.Darling.Service.Mcp; +using PerformanceMonitor.Darling.Storage; +using Xunit; + +namespace Darling.Tests; + +/// +/// #4198's own per-server pass: get_collection_log's ONE-SERVER form (as opposed to the fleet form +/// #4199/#4205 already sized), at DEFAULT arguments, against a real store. Seeded to approximate a genuine +/// server's row mix rather than the optimistic all-columns-null minimum: most rows are one of two +/// server-scoped collectors (sql_open_ms/sql_drain_ms/watermark_ms plus the drain +/// block), a third are an ENUMERATED collector (plan_fetch/text_fetch, SQL Server target +/// only — PostgreSQL targets never run the deferred Query Store plan/text fetch this splits), and one in +/// ten is a failure carrying an error_message. +/// +/// Two shapes, not one, because the two target kinds write different rows (a SQL Server target's +/// query_store fills plan_fetch/text_fetch; a PostgreSQL target's collectors never +/// do) and #4198 sizes the shared default against the WIDER of the two. +/// +[Collection("live-postgres")] +public sealed class McpCollectionLogPerServerResponseBudgetLivePostgresTests +{ + /* NEGATIVE and tied to the issue number so a collision with any other live-postgres fixture's range is + obvious on sight; nothing else in this test assembly uses -4198_7xxx (see McpFleetResponseBudgetLivePostgresTests + for the sibling -994_ ranges this deliberately avoids). */ + private const int SqlServerTargetId = -4198_7001; + private const int PostgresTargetId = -4198_7002; + private const string SqlServerTargetName = "zz-4198-sqltarget"; + private const string PostgresTargetName = "zz-4198-pgtarget"; + private static readonly int[] AllIds = [SqlServerTargetId, PostgresTargetId]; + + private const int RowsPerServer = 200; + + private const string ModerateError = + "Timeout expired. The timeout period elapsed prior to completion of the operation or the monitored-server round trip is not responding."; + + [Fact] + public async Task GetCollectionLog_PerServerDefaultCall_OnSqlServerTarget_StaysUnderTheResponseBudget() + { + 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 MCP collection-log per-server budget tests."); + + var ct = TestContext.Current.CancellationToken; + using var connection = new NpgsqlConnection(connectionString); + await connection.OpenAsync(ct); + await PgMigrations.MigrateAsync(connection, ct); + await DeleteRowsAsync(connection, ct); + + await using var postgres = NpgsqlDataSource.Create(connectionString!); + + var bodySucceeded = false; + try + { + await InsertServerAsync(connection, SqlServerTargetId, SqlServerTargetName, MonitoredEngineKind.SqlServer, ct); + + var now = DateTime.UtcNow; + for (var r = 0; r < RowsPerServer; r++) + { + var when = now.AddMinutes(-(r + 1)); + if (r % 10 == 0) + { + await InsertErrorRowAsync(connection, SqlServerTargetId, SqlServerTargetName, "query_store", when, ct); + } + else if (r % 3 == 0) + { + await InsertEnumeratedRowAsync(connection, SqlServerTargetId, SqlServerTargetName, "query_store", when, ct); + } + else + { + await InsertServerScopedRowAsync(connection, SqlServerTargetId, SqlServerTargetName, "wait_stats", when, ct); + } + } + + var defaultJson = await DarlingMcpDataTools.GetCollectionLog(postgres, server_name: SqlServerTargetName, hours_back: 24); + var defaultBytes = Encoding.UTF8.GetByteCount(defaultJson); + + TestContext.Current.SendDiagnosticMessage( + $"get_collection_log per-server default call, SQL Server target, {RowsPerServer} rows seeded: {defaultBytes:N0} bytes, budget={McpResponseBudget.DefaultBytes:N0} bytes."); + + Assert.True(defaultBytes <= McpResponseBudget.DefaultBytes, + $"Per-server default call on a SQL Server target was {defaultBytes:N0} bytes, over the {McpResponseBudget.DefaultBytes:N0}-byte budget."); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(connectionString!, bodySucceeded, DeleteRowsAsync); + } + } + + [Fact] + public async Task GetCollectionLog_PerServerDefaultCall_OnPostgresTarget_StaysUnderTheResponseBudget() + { + 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 MCP collection-log per-server budget tests."); + + var ct = TestContext.Current.CancellationToken; + using var connection = new NpgsqlConnection(connectionString); + await connection.OpenAsync(ct); + await PgMigrations.MigrateAsync(connection, ct); + await DeleteRowsAsync(connection, ct); + + await using var postgres = NpgsqlDataSource.Create(connectionString!); + + var bodySucceeded = false; + try + { + await InsertServerAsync(connection, PostgresTargetId, PostgresTargetName, MonitoredEngineKind.Postgres, ct); + + var now = DateTime.UtcNow; + for (var r = 0; r < RowsPerServer; r++) + { + var when = now.AddMinutes(-(r + 1)); + if (r % 10 == 0) + { + await InsertErrorRowAsync(connection, PostgresTargetId, PostgresTargetName, "pg_stat_statements", when, ct); + } + else + { + /* No enumerated (plan_fetch/text_fetch) rows on a PostgreSQL target: that split exists + only for SQL Server's deferred Query Store plan/text fetch (see this class's doc + comment), so every non-error row here is the server-scoped shape. */ + var collector = r % 2 == 0 ? "pg_stat_statements" : "pg_locks"; + await InsertServerScopedRowAsync(connection, PostgresTargetId, PostgresTargetName, collector, when, ct); + } + } + + var defaultJson = await DarlingMcpDataTools.GetCollectionLog(postgres, server_name: PostgresTargetName, hours_back: 24); + var defaultBytes = Encoding.UTF8.GetByteCount(defaultJson); + + TestContext.Current.SendDiagnosticMessage( + $"get_collection_log per-server default call, PostgreSQL target, {RowsPerServer} rows seeded: {defaultBytes:N0} bytes, budget={McpResponseBudget.DefaultBytes:N0} bytes."); + + Assert.True(defaultBytes <= McpResponseBudget.DefaultBytes, + $"Per-server default call on a PostgreSQL target was {defaultBytes:N0} bytes, over the {McpResponseBudget.DefaultBytes:N0}-byte budget."); + + bodySucceeded = true; + } + finally + { + await LiveStoreCleanup.RunAsync(connectionString!, bodySucceeded, DeleteRowsAsync); + } + } + + private static async Task InsertServerAsync( + NpgsqlConnection connection, int serverId, string name, string engineKind, CancellationToken ct) + { + using var command = new NpgsqlCommand(@" +INSERT INTO servers (server_id, server_name, display_name, is_enabled, sql_engine_edition, engine_kind, created_date) +VALUES ($1, $2, $2, TRUE, 2, $3, $4)", connection); + command.Parameters.AddWithValue(serverId); + command.Parameters.AddWithValue(name); + command.Parameters.AddWithValue(engineKind); + command.Parameters.AddWithValue(DateTime.SpecifyKind(DateTime.UtcNow.AddDays(-2), DateTimeKind.Unspecified)); + await command.ExecuteNonQueryAsync(ct); + } + + /// The server-scoped shape: sql_phases (open/drain/watermark) plus drain, the + /// columns V108/V109 added for the collectors that read one monitored server directly rather than + /// fanning out per database. + private static async Task InsertServerScopedRowAsync( + NpgsqlConnection connection, int serverId, string name, string collectorName, DateTime collectionTime, CancellationToken ct) + { + using var command = new NpgsqlCommand(@" +INSERT INTO collection_log + (log_id, server_id, server_name, collector_name, collection_time, status, duration_ms, sql_duration_ms, + duckdb_duration_ms, rows_collected, sql_open_ms, sql_drain_ms, watermark_ms, + drain_rows_read, drain_bytes_read, drain_last_read_ms, target_session_id, sweep_peer_max_ms) +VALUES ($1, $2, $3, $4, $5, 'SUCCESS', 340, 260, 40, 5000, 180, 60, 12, 5000, 812345, 55, 771, 410)", connection); + command.Parameters.AddWithValue(CollectionIdGenerator.Next()); + command.Parameters.AddWithValue(serverId); + command.Parameters.AddWithValue(name); + command.Parameters.AddWithValue(collectorName); + command.Parameters.AddWithValue(DateTime.SpecifyKind(collectionTime, DateTimeKind.Unspecified)); + await command.ExecuteNonQueryAsync(ct); + } + + /// The ENUMERATED shape: plan_fetch and text_fetch, V110's per-database deferred + /// plan/statement-text fetch split — SQL Server's query_store only. + private static async Task InsertEnumeratedRowAsync( + NpgsqlConnection connection, int serverId, string name, string collectorName, DateTime collectionTime, CancellationToken ct) + { + using var command = new NpgsqlCommand(@" +INSERT INTO collection_log + (log_id, server_id, server_name, collector_name, collection_time, status, duration_ms, sql_duration_ms, + duckdb_duration_ms, rows_collected, sweep_peer_max_ms, + plan_fetch_probe_ms, plan_fetch_target_ms, plan_fetch_write_ms, plan_fetch_ids_attempted, plan_fetch_probe_ids, + text_fetch_probe_ms, text_fetch_target_ms, text_fetch_write_ms, text_fetch_ids_attempted, text_fetch_probe_ids) +VALUES ($1, $2, $3, $4, $5, 'SUCCESS', 5200, 4800, 300, 2500, 480, + 2650, 210, 80, 48, 22, + 1870, 140, 60, 36, 18)", connection); + command.Parameters.AddWithValue(CollectionIdGenerator.Next()); + command.Parameters.AddWithValue(serverId); + command.Parameters.AddWithValue(name); + command.Parameters.AddWithValue(collectorName); + command.Parameters.AddWithValue(DateTime.SpecifyKind(collectionTime, DateTimeKind.Unspecified)); + await command.ExecuteNonQueryAsync(ct); + } + + private static async Task InsertErrorRowAsync( + NpgsqlConnection connection, int serverId, string name, string collectorName, DateTime collectionTime, CancellationToken ct) + { + using var command = new NpgsqlCommand(@" +INSERT INTO collection_log + (log_id, server_id, server_name, collector_name, collection_time, status, duration_ms, sql_duration_ms, + duckdb_duration_ms, rows_collected, error_message) +VALUES ($1, $2, $3, $4, $5, 'ERROR', 120, 100, 0, 0, $6)", connection); + command.Parameters.AddWithValue(CollectionIdGenerator.Next()); + command.Parameters.AddWithValue(serverId); + command.Parameters.AddWithValue(name); + command.Parameters.AddWithValue(collectorName); + command.Parameters.AddWithValue(DateTime.SpecifyKind(collectionTime, DateTimeKind.Unspecified)); + command.Parameters.AddWithValue(ModerateError); + await command.ExecuteNonQueryAsync(ct); + } + + private static async Task DeleteRowsAsync(NpgsqlConnection connection, CancellationToken ct) + { + var idList = string.Join(", ", AllIds.Select(i => i.ToString(CultureInfo.InvariantCulture))); + + foreach (var table in new[] { "collection_log", "servers" }) + { + using var cleanup = new NpgsqlCommand($"DELETE FROM {table} WHERE server_id IN ({idList});", connection); + await cleanup.ExecuteNonQueryAsync(ct); + } + } +} diff --git a/Darling/Darling.Tests/McpPayloadContractCensusTests.cs b/Darling/Darling.Tests/McpPayloadContractCensusTests.cs index 15042e0c25..787b062444 100644 --- a/Darling/Darling.Tests/McpPayloadContractCensusTests.cs +++ b/Darling/Darling.Tests/McpPayloadContractCensusTests.cs @@ -1477,11 +1477,11 @@ public void TheSharedTimestampParsers_RefuseWhatTheGeneralParserAccepts() /// caller to raise a limit that changes nothing. /// A field-level response-budget preview — : #4198 sizes /// each tool's DEFAULT answer under the shared 32 KB McpResponseBudget.DefaultBytes by previewing - /// one wide field (query text, a plan fragment, a deadlock graph) rather than the page — unlike a - /// source-side cut, a caller CAN get the rest, with an opt-in argument (get_deadlock_detail's + /// one wide field (query text, a plan fragment, a deadlock graph, an error message) rather than the page — + /// unlike a source-side cut, a caller CAN get the rest, with an opt-in argument (get_deadlock_detail's /// full_graph; get_active_queries and get_store_query_stats both take /// full_text, the same name — get_active_queries' own was renamed from full_query_text to - /// match). + /// match; get_collection_log uses full_text for its error_message preview). /// The withheld summary — : #3594's own vocabulary for a /// reach verdict that withholds a figure rather than publishing a page's count under a whole's name. /// @@ -1532,6 +1532,8 @@ public static readonly (string Key, string[] Files, string WhatWasCut)[] FieldPr "#4198: get_deadlock_detail's own wide field — deadlock_graph_xml is a 2000-character preview by default (a busy production store measured 120,454 bytes for 3 graphs), full_graph or a dedup_key call gets the whole XML"), ("query_text_truncated", ["DarlingMcpPlanCorrectionTools.cs", "DarlingMcpSessionTools.cs", "McpPlanCorrectionTools.cs", "McpSessionTools.cs"], "#4198: query_text is previewed at read time by two tools: get_active_queries previews at 500 chars (full_text gets the whole text; a synthetic 50-row page measured 81,489 bytes), get_plan_corrections previews at 150 chars (full_text gets the whole text; the full text IS in the store, not collector-capped)"), + ("error_message_truncated", ["DarlingMcpDataTools.cs", "McpHealthTools.cs"], + "#4198: get_collection_log's own wide field — error_message is a 500-character preview by default (a seeded store measured 90,514 bytes for 200 rows at the old 200-row default), full_text opts back into the whole (up to 4000-character, DarlingObservability.LogCollectionAsync's own write-time ceiling) field"), ("top_query_text_truncated", ["DarlingMcpQueryHeatmapTools.cs", "McpQueryTools.cs"], "get_query_heatmap's (#4198) per-cell top-query preview width (DefaultPreviewLength on both SKUs) — the full statement is already in the store; full_text opts back into it rather than re-paging, so this is not the page dialect's truncated and nothing was lost the way a source-side cut loses it"), ]; diff --git a/Darling/Darling.Tests/McpToolsListBudget/DarlingMcpDataTools.txt b/Darling/Darling.Tests/McpToolsListBudget/DarlingMcpDataTools.txt index 98611e363f..0c722c76bb 100644 --- a/Darling/Darling.Tests/McpToolsListBudget/DarlingMcpDataTools.txt +++ b/Darling/Darling.Tests/McpToolsListBudget/DarlingMcpDataTools.txt @@ -10,8 +10,9 @@ param get_collection_health.server_name 28 tool get_collection_log 606 param get_collection_log.as_of 167 param get_collection_log.collector_name 149 +param get_collection_log.full_text 76 param get_collection_log.hours_back 191 -param get_collection_log.limit 160 +param get_collection_log.limit 159 param get_collection_log.min_duration_ms 191 param get_collection_log.server_name 161 param get_collection_log.status 195 diff --git a/Darling/Darling.Tests/McpToolsListBudgetTests.cs b/Darling/Darling.Tests/McpToolsListBudgetTests.cs index 01e9a3aa4a..520c47a7e2 100644 --- a/Darling/Darling.Tests/McpToolsListBudgetTests.cs +++ b/Darling/Darling.Tests/McpToolsListBudgetTests.cs @@ -110,13 +110,18 @@ so neither counts here. */ /* #4198 (lane TB): +364 bytes for get_deadlock_detail's default-preview note in its served description and its new full_graph opt-in parameter (deadlock_graph_xml, the wide field, is now a 2000-char preview by default). */ + /* #4198: get_collection_log's per-server form gained full_text (its error_message preview opt-in, + 76 bytes) and limit's own description banked 1 byte describing the new lower default. +127 net. */ /* #4198 (per-tool lane, get_object_locking): +79 bytes for the new limit parameter (default lowered from a 200-row hard cap to 75, measured under McpResponseBudget.DefaultBytes on a seeded fixture). Merged with origin/dev's own #4192/#4195/#4193/#4217 bump above; the constant below is the measured total with both changes applied, not the two deltas added by hand. */ /* #4198 (lane TH, merge with get_object_locking): re-measured after merging origin/dev; combined total of active_queries (#4261) + object_locking (#4258) changes on top of dev. */ - private const int TotalCeilingBytes = 172_632; + /* #4198 (collection_log, merge): re-measured after merging origin/dev (dev now includes #4261+#4258); + combined total with collection_log (#4265) changes on top. */ + private const int TotalCeilingBytes = 172_760; + private const int ConvertedHeadCap = 1_000; private const int ConvertedParameterCap = 200; diff --git a/Darling/PerformanceMonitor.Darling.Service/DarlingWebEndpoints.cs b/Darling/PerformanceMonitor.Darling.Service/DarlingWebEndpoints.cs index aeeac6800c..b25752aceb 100644 --- a/Darling/PerformanceMonitor.Darling.Service/DarlingWebEndpoints.cs +++ b/Darling/PerformanceMonitor.Darling.Service/DarlingWebEndpoints.cs @@ -2663,8 +2663,13 @@ budget cut does not silently shrink what the viewer renders. */ /* ── core data reads ── */ ["get_collection_health"] = (c, pg, an) => DarlingMcpDataTools.GetCollectionHealth(pg, Server(c)), + /* #4198: full_text: true, because error_message carried no preview cap before this PR — the + web viewer keeps that behavior (an operator reading the Collection Log grid gets the whole + error, the same way get_deadlock_detail's row passes TrendBudget.Chart-style overrides to + hold its OWN pre-existing behavior steady). limit stays explicit at the pre-#4198 200, also + unaffected by the new lower MCP default. */ ["get_collection_log"] = (c, pg, an) => OptionalDouble(c, "min_duration_ms", out var minDurationMs) - ? DarlingMcpDataTools.GetCollectionLog(pg, Server(c), Hours(c, 24), Rows(c, "limit", 200), AsOf(c), Str(c, "collector_name"), minDurationMs) + ? DarlingMcpDataTools.GetCollectionLog(pg, Server(c), Hours(c, 24), Rows(c, "limit", 200), AsOf(c), Str(c, "collector_name"), minDurationMs, full_text: true) : UnparseableParam("min_duration_ms"), ["get_current_waits_trend"] = (c, pg, an) => DarlingMcpDataTools.GetCurrentWaitsTrend(pg, Server(c), Hours(c, 4), Str(c, "database_name"), as_of: AsOf(c)), ["get_blocking_stats"] = (c, pg, an) => DarlingMcpDataTools.GetBlockingStats(pg, Server(c), Hours(c, 24), as_of: AsOf(c)), diff --git a/Darling/PerformanceMonitor.Darling.Service/Mcp/DarlingMcpDataTools.cs b/Darling/PerformanceMonitor.Darling.Service/Mcp/DarlingMcpDataTools.cs index 66cb3e7afd..9d647758b5 100644 --- a/Darling/PerformanceMonitor.Darling.Service/Mcp/DarlingMcpDataTools.cs +++ b/Darling/PerformanceMonitor.Darling.Service/Mcp/DarlingMcpDataTools.cs @@ -1565,12 +1565,23 @@ did not RUN when it ran and merely did not match. */ $"No fleet-maintenance run-records at all in the last {hours} hour(s). " + cadence); } - [McpServerTool(Name = "get_collection_log"), Description("Raw per-run collector log: duration split into monitored-server and store-write time, rows, status, error. NEWEST FIRST by default; min_duration_ms flips it to SLOWEST FIRST, ranked by cost. hours_back is the ask; oldest/newest_returned_collection_time bound what you actually got — under a min_duration_ms floor that is the cost-ranked sample's age, not reach. Filters apply before the cap; truncated/run_count reflect matches. status is the failure filter: an unknown value is refused, never silently empty. get_collection_health is the rollup; this is the underlying runs. <> Gets the RAW per-run collection log for a server, NEWEST FIRST by default and SLOWEST FIRST whenever min_duration_ms is supplied: one row per collector run with its total duration, the part spent querying the monitored server, the part spent writing to the store, rows collected, status and any error. get_collection_health rolls seven days of these into a per-collector verdict; this is the underlying runs, which is what you need when the rollup says healthy and collection still looks wrong, or when you want to see what a collector was doing during a specific incident window. READ THE PAGE-SPAN FIELDS BEFORE CONCLUDING ANYTHING FROM THE ROWS. hours_back is the span you ASKED for; oldest_returned_collection_time and newest_returned_collection_time bound the page you GOT, and on a busy fleet those are wildly different — roughly 500 log rows a minute across 50 servers means a 24-hour request at the 200-row default is satisfied by about the last 25 seconds of activity. truncated says the cap bit; the two timestamps say what the page holds. THE TWO FIELDS MEAN DIFFERENT THINGS UNDER THE TWO ORDERINGS and the difference matters: under the default newest-first ordering the page is a contiguous slice of the window's tail, so oldest_returned_collection_time IS how far back this read reached; under a min_duration_ms floor the page is a cost-RANKED sample drawn from the whole window, so it tells you how old the slowest matching runs are and NOTHING about reach. Read order to know which you have. Neither field is a window floor: nothing here probes for the oldest row the window could have held. A read whose newest and oldest are seconds apart has told you nothing about the window you named, and raising limit does NOT fix it under the default ordering because the slow runs are not the recent ones — min_duration_ms is the knob for that, because supplying it ranks by duration instead of by time. All THREE filters are applied in SQL, BEFORE the cap, so truncated and run_count describe the MATCHING rows rather than the unfiltered window. order names which ordering you got, so a caller never has to infer it from the filters it sent. status IS THE FAILURE-HUNTING FILTER and the reason to reach for this tool during an incident: 'show me the failures' is the most common question asked of this log, and without it a caller pages the newest-first tail eyeballing status — which the page-span contract above explains cannot work, because a 200-row page on a busy fleet covers seconds and raising limit does not reach a failure that happened twenty minutes ago. Pass one of SUCCESS, SKIPPED, YIELDED, ABANDONED, ERROR, PERMISSIONS, EXTENSION_MISSING, SESSION_MISSING, WARNING (case-insensitive); an unknown value is REFUSED and the refusal names the whole set, rather than being applied as an equality filter that returns an empty page a caller would read as 'no failures'. get_collection_health is not this question's answer either: it carries one last_error per collector over a seven-day rollup, not the runs, their timestamps or their sequence — which is what says whether every collector failed at 03:41 or one collector failed all night. A status filter changes the page from a contiguous tail to a filtered one, so read the two page-span timestamps the same way you would under a duration floor. The filter you sent is echoed back as status_filter (not status, which on an empty result is the miss word instead), in the stored UPPERCASE spelling whatever case you sent. Also carries the phase decomposition where the run recorded one, as nested blocks that are null when the run took a path that does not report them — and a row carries at most ONE family. Server-scoped collectors fill sql_phases (open_ms, drain_ms, other_ms which is derived, watermark_ms) and drain (rows_read, bytes_read, last_read_ms, target_session_id). Per-database collectors that perform a deferred plan or statement-text fetch instead fill plan_fetch and/or text_fetch, each carrying probe_ms, target_ms, write_ms, ids_attempted and probe_ids summed across that run's databases. sweep_peer_max_ms is flat and present on every row: it is the slowest peer collector in the same sweep, the denominator for asking whether a slow run was slow alone or the whole sweep was. A null block means the run took the other path, not that the phase was free — most runs perform no deferred fetch at all. Divide target_ms by ids_attempted for the per-id target cost, probe_ms by probe_ids for the per-reference probe cost. CRITICAL for reading sql_duration_ms on a fetching collector: it is NOT purely target-side there. The deferred fetches run inside the driver's per-item SQL stopwatch and each one round-trips the MONITORING STORE to decide what plan XML and statement text are already held before writing back what came off the target, so the store's probe and write are billed to the column documented as the monitored server's. The probe is the largest single term in both fetches on this fleet — 55.4% of plan_fetch and 80.6% of text_fetch — and on one production run it was 107,334 ms of a 124,972 ms sql_duration_ms, 86%, against a plan-plus-text target time of 6,494 ms. sql_store_ms is that store share, derived from the two fetch blocks (probe_ms + write_ms of each) and null when no fetch ran. It is a FLOOR, not the whole: the per-item watermark refresh is also a store read inside the same stopwatch, the enumerated path records no watermark_ms, and that component is stored nowhere — so sql_duration_ms minus sql_store_ms is an UPPER bound on target-side time rather than the target-side time. store_duration_ms is not where the probe went either: it is the binary COPY of the collected rows and nothing else. Do NOT conclude a monitored server is slow from a large sql_duration_ms on query_store without reading sql_store_ms beside it. THE RESERVED server_name (fleet) READS THE FLEET-MAINTENANCE RUN-RECORDS instead of a monitored server's collector runs: the passes that iterate the whole fleet have no one server to attribute a run to, so they log under a sentinel that is not in the server list — data_retention for the daily purge, oversized_plan_sweep for the fifteen-minute oversized-plan backlog drain. Read those rows by their ABSENCE as much as their contents: every tick writes one whatever it found, including a tick that found an empty backlog and captured nothing, so rows_collected = 0 means the pass ran and had nothing to fetch while a MISSING row past the pass's cadence means the pass did not run at all. That is the only way to tell those two apart. error_message carries the tick's counts on a SUCCESS row (servers swept, plans claimed, captured, expired, fetch failures); sql_duration_ms is the time inside the monitored-server fetches and store_duration_ms the rest of the tick. These rows are excluded from get_collection_health and from get_fleet_overview by design — they are maintenance passes, not collectors, so a per-server staleness ladder does not apply to them. Five parameters carry more guidance than their 200-character cap allows; the rest of each below. collector_name: A name this server has never run returns the no-matches status rather than a quiet-window one. min_duration_ms: Applied in SQL before the cap. 0 is a real value: it admits every run and is how you ask for the whole window ranked by cost. A negative is refused. Omit for no floor and newest-first order. status: THE FAILURE FILTER — 'show me the failures' is what this log exists to answer, and paging the newest-first tail cannot reach a failure that is not recent. An unknown value is REFUSED, naming the accepted set, rather than applied as a filter that matches nothing. Omit for every status. server_name: Omitted, blank, or \"*\" reads the WHOLE FLEET (#4199) — every enabled server's runs, merged and ranked together, each row carrying server_name — instead of one server; this is different from the reserved name (fleet), which still reads the fleet-MAINTENANCE run-records and still requires being named exactly. limit: Default 200 for one server. The fleet-wide form (server_name omitted or \"*\") defaults instead to McpResponseBudget.CollectionLogFleetDefaultLimit, sized from measured bytes/row so a default fleet call stays under the shared response-size target; pass limit explicitly for more rows either way.")] + /// + /// #4198: error_message is this tool's one wide field — DarlingObservability.LogCollectionAsync caps it + /// at 4000 characters at WRITE time, so a page of failing runs (the exact "show me the failures" + /// incident-window ask this tool's guide leads with) can still carry a large multiple of that per row. + /// Previewed to this length per row at default (full_text: true opts back in), the same + /// preview-plus-opt-in shape get_store_query_stats uses for its own full_text. Also covers + /// the (fleet) sentinel's SUCCESS rows, where error_message carries the tick's counts rather than a + /// fault — a long summary line is previewed the same as a long fault. + /// + private const int ErrorMessagePreviewLength = 500; + + [McpServerTool(Name = "get_collection_log"), Description("Raw per-run collector log: duration split into monitored-server and store-write time, rows, status, error. NEWEST FIRST by default; min_duration_ms flips it to SLOWEST FIRST, ranked by cost. hours_back is the ask; oldest/newest_returned_collection_time bound what you actually got — under a min_duration_ms floor that is the cost-ranked sample's age, not reach. Filters apply before the cap; truncated/run_count reflect matches. status is the failure filter: an unknown value is refused, never silently empty. get_collection_health is the rollup; this is the underlying runs. <> Gets the RAW per-run collection log for a server, NEWEST FIRST by default and SLOWEST FIRST whenever min_duration_ms is supplied: one row per collector run with its total duration, the part spent querying the monitored server, the part spent writing to the store, rows collected, status and any error. error_message is a preview by default (ErrorMessagePreviewLength characters, error_message_truncated marks a cut); full_text returns it whole (#4198). get_collection_health rolls seven days of these into a per-collector verdict; this is the underlying runs, which is what you need when the rollup says healthy and collection still looks wrong, or when you want to see what a collector was doing during a specific incident window. READ THE PAGE-SPAN FIELDS BEFORE CONCLUDING ANYTHING FROM THE ROWS. hours_back is the span you ASKED for; oldest_returned_collection_time and newest_returned_collection_time bound the page you GOT, and on a busy fleet those are wildly different — roughly 500 log rows a minute across 50 servers means a 24-hour request at the 200-row default is satisfied by about the last 25 seconds of activity. truncated says the cap bit; the two timestamps say what the page holds. THE TWO FIELDS MEAN DIFFERENT THINGS UNDER THE TWO ORDERINGS and the difference matters: under the default newest-first ordering the page is a contiguous slice of the window's tail, so oldest_returned_collection_time IS how far back this read reached; under a min_duration_ms floor the page is a cost-RANKED sample drawn from the whole window, so it tells you how old the slowest matching runs are and NOTHING about reach. Read order to know which you have. Neither field is a window floor: nothing here probes for the oldest row the window could have held. A read whose newest and oldest are seconds apart has told you nothing about the window you named, and raising limit does NOT fix it under the default ordering because the slow runs are not the recent ones — min_duration_ms is the knob for that, because supplying it ranks by duration instead of by time. All THREE filters are applied in SQL, BEFORE the cap, so truncated and run_count describe the MATCHING rows rather than the unfiltered window. order names which ordering you got, so a caller never has to infer it from the filters it sent. status IS THE FAILURE-HUNTING FILTER and the reason to reach for this tool during an incident: 'show me the failures' is the most common question asked of this log, and without it a caller pages the newest-first tail eyeballing status — which the page-span contract above explains cannot work, because a 200-row page on a busy fleet covers seconds and raising limit does not reach a failure that happened twenty minutes ago. Pass one of SUCCESS, SKIPPED, YIELDED, ABANDONED, ERROR, PERMISSIONS, EXTENSION_MISSING, SESSION_MISSING, WARNING (case-insensitive); an unknown value is REFUSED and the refusal names the whole set, rather than being applied as an equality filter that returns an empty page a caller would read as 'no failures'. get_collection_health is not this question's answer either: it carries one last_error per collector over a seven-day rollup, not the runs, their timestamps or their sequence — which is what says whether every collector failed at 03:41 or one collector failed all night. A status filter changes the page from a contiguous tail to a filtered one, so read the two page-span timestamps the same way you would under a duration floor. The filter you sent is echoed back as status_filter (not status, which on an empty result is the miss word instead), in the stored UPPERCASE spelling whatever case you sent. Also carries the phase decomposition where the run recorded one, as nested blocks that are null when the run took a path that does not report them — and a row carries at most ONE family. Server-scoped collectors fill sql_phases (open_ms, drain_ms, other_ms which is derived, watermark_ms) and drain (rows_read, bytes_read, last_read_ms, target_session_id). Per-database collectors that perform a deferred plan or statement-text fetch instead fill plan_fetch and/or text_fetch, each carrying probe_ms, target_ms, write_ms, ids_attempted and probe_ids summed across that run's databases. sweep_peer_max_ms is flat and present on every row: it is the slowest peer collector in the same sweep, the denominator for asking whether a slow run was slow alone or the whole sweep was. A null block means the run took the other path, not that the phase was free — most runs perform no deferred fetch at all. Divide target_ms by ids_attempted for the per-id target cost, probe_ms by probe_ids for the per-reference probe cost. CRITICAL for reading sql_duration_ms on a fetching collector: it is NOT purely target-side there. The deferred fetches run inside the driver's per-item SQL stopwatch and each one round-trips the MONITORING STORE to decide what plan XML and statement text are already held before writing back what came off the target, so the store's probe and write are billed to the column documented as the monitored server's. The probe is the largest single term in both fetches on this fleet — 55.4% of plan_fetch and 80.6% of text_fetch — and on one production run it was 107,334 ms of a 124,972 ms sql_duration_ms, 86%, against a plan-plus-text target time of 6,494 ms. sql_store_ms is that store share, derived from the two fetch blocks (probe_ms + write_ms of each) and null when no fetch ran. It is a FLOOR, not the whole: the per-item watermark refresh is also a store read inside the same stopwatch, the enumerated path records no watermark_ms, and that component is stored nowhere — so sql_duration_ms minus sql_store_ms is an UPPER bound on target-side time rather than the target-side time. store_duration_ms is not where the probe went either: it is the binary COPY of the collected rows and nothing else. Do NOT conclude a monitored server is slow from a large sql_duration_ms on query_store without reading sql_store_ms beside it. THE RESERVED server_name (fleet) READS THE FLEET-MAINTENANCE RUN-RECORDS instead of a monitored server's collector runs: the passes that iterate the whole fleet have no one server to attribute a run to, so they log under a sentinel that is not in the server list — data_retention for the daily purge, oversized_plan_sweep for the fifteen-minute oversized-plan backlog drain. Read those rows by their ABSENCE as much as their contents: every tick writes one whatever it found, including a tick that found an empty backlog and captured nothing, so rows_collected = 0 means the pass ran and had nothing to fetch while a MISSING row past the pass's cadence means the pass did not run at all. That is the only way to tell those two apart. error_message carries the tick's counts on a SUCCESS row (servers swept, plans claimed, captured, expired, fetch failures); sql_duration_ms is the time inside the monitored-server fetches and store_duration_ms the rest of the tick. These rows are excluded from get_collection_health and from get_fleet_overview by design — they are maintenance passes, not collectors, so a per-server staleness ladder does not apply to them. Five parameters carry more guidance than their 200-character cap allows; the rest of each below. collector_name: A name this server has never run returns the no-matches status rather than a quiet-window one. min_duration_ms: Applied in SQL before the cap. 0 is a real value: it admits every run and is how you ask for the whole window ranked by cost. A negative is refused. Omit for no floor and newest-first order. status: THE FAILURE FILTER — 'show me the failures' is what this log exists to answer, and paging the newest-first tail cannot reach a failure that is not recent. An unknown value is REFUSED, naming the accepted set, rather than applied as a filter that matches nothing. Omit for every status. server_name: Omitted, blank, or \"*\" reads the WHOLE FLEET (#4199) — every enabled server's runs, merged and ranked together, each row carrying server_name — instead of one server; this is different from the reserved name (fleet), which still reads the fleet-MAINTENANCE run-records and still requires being named exactly. limit: Default McpResponseBudget.CollectionLogPerServerDefaultLimit (58) for one server (#4198: sized so a default call stays under the shared response-size target on the wider SQL Server-target row shape). The fleet-wide form (server_name omitted or \"*\") defaults instead to McpResponseBudget.CollectionLogFleetDefaultLimit, sized the same way; pass limit explicitly for more rows either way.")] public static async Task GetCollectionLog( NpgsqlDataSource postgres, [Description("Server name or display name. Omit or pass \"*\" for the WHOLE FLEET (every enabled server's runs, merged; see tool guide) — differs from the reserved name (fleet).")] string? server_name = null, [Description("Hours of history. Default 24. No upper bound (this read exists to look further back than the 168-hour reads allow); a negative or zero value is refused rather than read as its absolute value.")] int hours_back = 24, - [Description("Maximum rows to return, applied after the filters. Default 200 for one server; the fleet-wide form (server_name omitted or \"*\") defaults lower — see tool guide.")] int? limit = null, + [Description("Maximum rows to return, applied after the filters. Default 58 for one server; the fleet-wide form (server_name omitted or \"*\") defaults lower — see tool guide.")] int? limit = null, [Description(McpHelpers.AsOfDescription)] string? as_of = null, /* APPENDED after as_of rather than grouped beside `limit`, and this is not tidiness deferred. @@ -1589,7 +1600,15 @@ every existing one meaning what it already meant. positional C# caller changes meaning. This one is the log's own stored vocabulary, so it is a ValidateChoice parameter rather than free text. */ - [Description("Limit to runs with this status, matched case-insensitively against the log's own vocabulary: SUCCESS, SKIPPED, YIELDED, ABANDONED, ERROR, PERMISSIONS, EXTENSION_MISSING, SESSION_MISSING, WARNING.")] string? status = null) + [Description("Limit to runs with this status, matched case-insensitively against the log's own vocabulary: SUCCESS, SKIPPED, YIELDED, ABANDONED, ERROR, PERMISSIONS, EXTENSION_MISSING, SESSION_MISSING, WARNING.")] string? status = null, + /* + #4198, APPENDED for the reason collector_name and status were: every filter joins the end of + this list so no positional C# caller changes meaning. error_message is the tool's one wide + field (up to 4000 characters at write time, DarlingObservability.LogCollectionAsync's own + ceiling) and is previewed at default the same shape get_store_query_stats already uses for + full_text. + */ + [Description("Return each run's error_message in full instead of a preview. Default false.")] bool full_text = false) { /* #4199: server_name OMITTED, blank, or "*" means the WHOLE FLEET rather than "auto-select the lone server" or "which server did you mean" -- the read whose subject is the log itself is also @@ -1608,11 +1627,12 @@ check and falls through to the resolve below exactly as it always has. */ } /* limit is nullable so the fleet branch above and this per-server branch can default it - differently (#4199 wants a smaller fleet-wide default; per-tool sizing of the per-server - default is #4198 work for another lane) — a caller omitting the argument is otherwise - indistinguishable from one passing the C# default explicitly. Resolved once, here, so - everything below reads one concrete int exactly as it did before this became nullable. */ - var effectiveLimit = limit ?? 200; + differently (#4199 wants a smaller fleet-wide default; #4198 sizes the per-server default + against the wider of the two target-kind row shapes — see CollectionLogPerServerDefaultLimit) + — a caller omitting the argument is otherwise indistinguishable from one passing the C# + default explicitly. Resolved once, here, so everything below reads one concrete int exactly + as it did before this became nullable. */ + var effectiveLimit = limit ?? McpResponseBudget.CollectionLogPerServerDefaultLimit; /* The SENTINEL-AWARE resolve, and this read is the only one that takes it (#3399): its subject is the log itself, so the fleet-maintenance run-records have to be nameable here or they answer @@ -1777,7 +1797,10 @@ so nothing is attributable -- never "the store share was zero". */ sql_store_ms = r.SqlStoreMs is null ? (double?)null : Math.Round(r.SqlStoreMs.Value, 0), rows_collected = r.RowsCollected, status = r.Status, - error_message = r.ErrorMessage, + /* #4198: a preview by default — see ErrorMessagePreviewLength's doc comment above this + method — with full_text opting back into the whole (up to 4000-character) field. */ + error_message = full_text ? r.ErrorMessage : McpHelpers.Truncate(r.ErrorMessage, ErrorMessagePreviewLength), + error_message_truncated = !full_text && r.ErrorMessage is not null && r.ErrorMessage.Length > ErrorMessagePreviewLength, /* The phase decomposition, emitted here rather than only SELECTed because persisting a column nothing reports is half a feature. V108 and V109 both widened CollectionLogSql diff --git a/Lite.Tests/CollectionLogPerServerResponseBudgetToolTests.cs b/Lite.Tests/CollectionLogPerServerResponseBudgetToolTests.cs new file mode 100644 index 0000000000..35782a8f60 --- /dev/null +++ b/Lite.Tests/CollectionLogPerServerResponseBudgetToolTests.cs @@ -0,0 +1,114 @@ +/* + * 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.IO; +using System.Text; +using System.Threading.Tasks; +using DuckDB.NET.Data; +using PerformanceMonitor.Common; +using PerformanceMonitorLite.Database; +using PerformanceMonitorLite.Mcp; +using PerformanceMonitorLite.Models; +using PerformanceMonitorLite.Services; +using Xunit; + +namespace PerformanceMonitorLite.Tests; + +/// +/// #4198's per-server pass, Lite's twin of Darling.Tests/McpCollectionLogPerServerResponseBudgetLivePostgresTests: +/// get_collection_log's ONE-SERVER form at DEFAULT arguments stays under +/// on a store with more rows than the new default row count. +/// No rig: Lite's store is local DuckDB (). +/// +public sealed class CollectionLogPerServerResponseBudgetToolTests : IClassFixture, IDisposable +{ + private const string ServerName = "PerServerBudgetSrv"; + + private readonly int _serverId; + private readonly DuckDbInitializer _duckDb; + private readonly string _configDir; + private readonly ServerManager _serverManager; + private DuckDBConnection? _seedConn; + private long _nextId = 1; + + public CollectionLogPerServerResponseBudgetToolTests(SharedDuckDbFixture fixture) + { + fixture.ResetData(); + _duckDb = fixture.DuckDb; + + _configDir = Path.Combine(Path.GetTempPath(), "pmlite-collogperserver-" + Guid.NewGuid().ToString("N")); + Directory.CreateDirectory(_configDir); + _serverManager = new ServerManager(_configDir); + + var server = new ServerConnection { Id = Guid.NewGuid().ToString(), ServerName = ServerName, IsEnabled = true }; + _serverManager.AddServer(server); + _serverId = RemoteCollectorService.GetDeterministicHashCode(RemoteCollectorService.GetServerNameForStorage(server)); + } + + public void Dispose() + { + _seedConn?.Dispose(); + try { Directory.Delete(_configDir, recursive: true); } catch (IOException) { /* temp dir */ } + } + + [Fact] + public async Task PerServerDefaultCall_StaysUnderTheResponseBudget() + { + var service = new LocalDataService(_duckDb); + + for (var i = 0; i < 200; i++) + { + var when = DateTime.UtcNow.AddMinutes(-(i + 1)); + /* One in ten carries a moderate error_message, the same mix as Darling's twin. */ + var error = i % 10 == 0 + ? "Timeout expired. The timeout period elapsed prior to completion of the operation or the monitored-server round trip is not responding." + : null; + await SeedLogAsync(_serverId, ServerName, i % 3 == 0 ? "query_store" : "wait_stats", when, 100 + i, error); + } + + var json = await McpHealthTools.GetCollectionLog(service, _serverManager, server_name: ServerName, hours_back: 24); + var bytes = Encoding.UTF8.GetByteCount(json); + Assert.True(bytes <= McpResponseBudget.DefaultBytes, + $"Per-server default call was {bytes:N0} bytes, over the {McpResponseBudget.DefaultBytes:N0}-byte budget."); + } + + private async Task SeedConnectionAsync() + { + if (_seedConn is null) + { + _seedConn = _duckDb.CreateConnection(); + await _seedConn.OpenAsync(); + } + return _seedConn; + } + + private async Task SeedLogAsync(int serverId, string serverName, string collector, DateTime collectionTimeUtc, double durationMs, string? errorMessage) + { + using var readLock = _duckDb.AcquireReadLock(); + var connection = await SeedConnectionAsync(); + using var cmd = connection.CreateCommand(); + cmd.CommandText = @" +INSERT INTO collection_log + (log_id, server_id, server_name, collector_name, collection_time, + duration_ms, status, error_message, rows_collected, sql_duration_ms, duckdb_duration_ms) +VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11)"; + cmd.Parameters.Add(new DuckDBParameter { Value = _nextId++ }); + cmd.Parameters.Add(new DuckDBParameter { Value = serverId }); + cmd.Parameters.Add(new DuckDBParameter { Value = serverName }); + cmd.Parameters.Add(new DuckDBParameter { Value = collector }); + cmd.Parameters.Add(new DuckDBParameter { Value = DateTime.SpecifyKind(collectionTimeUtc, DateTimeKind.Unspecified) }); + cmd.Parameters.Add(new DuckDBParameter { Value = durationMs }); + cmd.Parameters.Add(new DuckDBParameter { Value = errorMessage is null ? "SUCCESS" : "ERROR" }); + cmd.Parameters.Add(new DuckDBParameter { Value = (object?)errorMessage ?? DBNull.Value }); + cmd.Parameters.Add(new DuckDBParameter { Value = 10 }); + cmd.Parameters.Add(new DuckDBParameter { Value = durationMs * 0.8 }); + cmd.Parameters.Add(new DuckDBParameter { Value = durationMs * 0.2 }); + await cmd.ExecuteNonQueryAsync(); + } +} diff --git a/Lite.Tests/McpToolsListBudget/McpHealthTools.txt b/Lite.Tests/McpToolsListBudget/McpHealthTools.txt index 1e5ddff2c9..b7a3c0f78e 100644 --- a/Lite.Tests/McpToolsListBudget/McpHealthTools.txt +++ b/Lite.Tests/McpToolsListBudget/McpHealthTools.txt @@ -10,8 +10,9 @@ param get_collection_health.server_name 28 tool get_collection_log 606 param get_collection_log.as_of 167 param get_collection_log.collector_name 149 +param get_collection_log.full_text 76 param get_collection_log.hours_back 191 -param get_collection_log.limit 160 +param get_collection_log.limit 159 param get_collection_log.min_duration_ms 191 param get_collection_log.server_name 120 param get_collection_log.status 195 diff --git a/Lite.Tests/McpToolsListBudgetTests.cs b/Lite.Tests/McpToolsListBudgetTests.cs index 9cad0427cc..d067a73c4f 100644 --- a/Lite.Tests/McpToolsListBudgetTests.cs +++ b/Lite.Tests/McpToolsListBudgetTests.cs @@ -101,7 +101,10 @@ change exactly. */ and its new full_graph opt-in parameter (deadlock_graph_xml, the wide field, is now a 2000-char preview by default). Darling's twin grew by a different amount (+364): Darling's description also covers the dedup_key exemption, which Lite's get_deadlock_detail has no dedup_key parameter to need. */ - private const int TotalCeilingBytes = 90_672; + /* #4198: get_collection_log's per-server form gained full_text (76 bytes), matching Darling's twin; + limit's own description banked 1 byte. +116 net (Lite's server_name description is shorter than + Darling's, since it has no fleet-maintenance sentinel to warn about). */ + private const int TotalCeilingBytes = 90_800; private const int ConvertedHeadCap = 1_000; private const int ConvertedParameterCap = 200; diff --git a/Lite/Mcp/McpHealthTools.cs b/Lite/Mcp/McpHealthTools.cs index c96a828437..c8fbe964c2 100644 --- a/Lite/Mcp/McpHealthTools.cs +++ b/Lite/Mcp/McpHealthTools.cs @@ -666,13 +666,17 @@ to avoid. It also says outright that rows are what a run STORED and never what t } } - [McpServerTool(Name = "get_collection_log"), Description("Raw per-run collector log: duration split into monitored-server and store-write time, rows, status, error. NEWEST FIRST by default; min_duration_ms flips it to SLOWEST FIRST, ranked by cost. hours_back is the ask; oldest/newest_returned_collection_time bound what you actually got — under a min_duration_ms floor that is the cost-ranked sample's age, not reach. Filters apply before the cap; truncated/run_count reflect matches. status is the failure filter: an unknown value is refused, never silently empty. get_collection_health is the rollup; this is the underlying runs. <> Gets the RAW per-run collection log for a server, NEWEST FIRST by default and SLOWEST FIRST whenever min_duration_ms is supplied: one row per collector run with its total duration, the part spent querying the monitored server, the part spent writing to the local store, rows collected, status and any error. get_collection_health rolls these into a per-collector verdict; this is the underlying runs, which is what you need when the rollup says healthy and collection still looks wrong, or when you want to see what a collector was doing during a specific incident window. READ THE PAGE-SPAN FIELDS BEFORE CONCLUDING ANYTHING FROM THE ROWS. hours_back is the span you ASKED for; oldest_returned_collection_time and newest_returned_collection_time bound the page you GOT, and the row cap can make those wildly different — enough collectors writing often enough will satisfy a 24-hour request out of the last few seconds of activity. truncated says the cap bit; the two timestamps say what the page holds. THE TWO FIELDS MEAN DIFFERENT THINGS UNDER THE TWO ORDERINGS and the difference matters: under the default newest-first ordering the page is a contiguous slice of the window's tail, so oldest_returned_collection_time IS how far back this read reached; under a min_duration_ms floor the page is a cost-RANKED sample drawn from the whole window, so it tells you how old the slowest matching runs are and NOTHING about reach. Read order to know which you have. Neither field is a window floor: nothing here probes for the oldest row the window could have held. A read whose newest and oldest are seconds apart has told you nothing about the window you named, and raising limit does NOT fix it under the default ordering because the slow runs are not the recent ones — min_duration_ms is the knob for that, because supplying it ranks by duration instead of by time. All THREE filters are applied in SQL, BEFORE the cap, so truncated and run_count describe the MATCHING rows rather than the unfiltered window. order names which ordering you got, so a caller never has to infer it from the filters it sent. status IS THE FAILURE-HUNTING FILTER and the reason to reach for this tool during an incident: 'show me the failures' is the most common question asked of this log, and without it a caller pages the newest-first tail eyeballing status — which the page-span contract above explains cannot work, because the cap covers a fraction of the window and raising limit does not reach a failure that is not recent. Pass one of SUCCESS, SKIPPED, YIELDED, ABANDONED, ERROR, PERMISSIONS, EXTENSION_MISSING, SESSION_MISSING, WARNING (case-insensitive); an unknown value is REFUSED and the refusal names the whole set, rather than being applied as an equality filter that returns an empty page a caller would read as 'no failures'. get_collection_health is not this question's answer either: it carries one last_error per collector over a rollup, not the runs, their timestamps or their sequence — which is what says whether every collector failed at once or one collector failed all night. A status filter changes the page from a contiguous tail to a filtered one, so read the two page-span timestamps the same way you would under a duration floor. The filter you sent is echoed back as status_filter (not status, which on an empty result is the miss word instead), in the stored UPPERCASE spelling whatever case you sent. Two of those statuses are Darling-only in practice — EXTENSION_MISSING and WARNING are written by PostgreSQL collectors and the fleet-maintenance passes, neither of which exists on this SKU — and they are accepted rather than refused here so the vocabulary is ONE set on both products: a filter that matches nothing on this SKU is an honest empty answer, where a refusal would teach a caller the value does not exist. One precision on sql_duration_ms, which Darling's twin of this tool states at length: on the collectors that enumerate databases it is the driver's per-item stopwatch, which also wraps the per-database watermark refresh - a read against the LOCAL store, so a small part of it is not the monitored server. What does NOT apply here is the large part: this SKU never enables the deferred plan-XML or statement-text fetches, so none of the store probe or write-back that dominates Darling's figure for query_store is in this one, and there is nothing here to attribute. Five parameters carry more guidance than their 200-character cap allows; the rest of each below. collector_name: A name this server has never run returns the no-matches status rather than a quiet-window one. min_duration_ms: Applied in SQL before the cap. 0 is a real value: it admits every run and is how you ask for the whole window ranked by cost. A negative is refused. Omit for no floor and newest-first order. status: THE FAILURE FILTER — 'show me the failures' is what this log exists to answer, and paging the newest-first tail cannot reach a failure that is not recent. An unknown value is REFUSED, naming the accepted set, rather than applied as a filter that matches nothing. Omit for every status. server_name: Omitted, blank, or \"*\" reads the WHOLE FLEET (#4199) — every enabled server's runs, merged and ranked together, each row carrying server_name — matching Darling's twin exactly (Lite has no (fleet) maintenance sentinel to protect). limit: Default 200 for one server. The fleet-wide form (server_name omitted or \"*\") defaults instead to McpResponseBudget.CollectionLogFleetDefaultLimit, sized from measured bytes/row so a default fleet call stays under the shared response-size target; pass limit explicitly for more rows either way.")] + /// #4198, matching Darling's twin exactly: error_message is this tool's one wide field, previewed + /// to this length per row at default (full_text: true opts back in). + private const int ErrorMessagePreviewLength = 500; + + [McpServerTool(Name = "get_collection_log"), Description("Raw per-run collector log: duration split into monitored-server and store-write time, rows, status, error. NEWEST FIRST by default; min_duration_ms flips it to SLOWEST FIRST, ranked by cost. hours_back is the ask; oldest/newest_returned_collection_time bound what you actually got — under a min_duration_ms floor that is the cost-ranked sample's age, not reach. Filters apply before the cap; truncated/run_count reflect matches. status is the failure filter: an unknown value is refused, never silently empty. get_collection_health is the rollup; this is the underlying runs. <> Gets the RAW per-run collection log for a server, NEWEST FIRST by default and SLOWEST FIRST whenever min_duration_ms is supplied: one row per collector run with its total duration, the part spent querying the monitored server, the part spent writing to the local store, rows collected, status and any error. error_message is a preview by default (ErrorMessagePreviewLength characters, error_message_truncated marks a cut); full_text returns it whole (#4198). get_collection_health rolls these into a per-collector verdict; this is the underlying runs, which is what you need when the rollup says healthy and collection still looks wrong, or when you want to see what a collector was doing during a specific incident window. READ THE PAGE-SPAN FIELDS BEFORE CONCLUDING ANYTHING FROM THE ROWS. hours_back is the span you ASKED for; oldest_returned_collection_time and newest_returned_collection_time bound the page you GOT, and the row cap can make those wildly different — enough collectors writing often enough will satisfy a 24-hour request out of the last few seconds of activity. truncated says the cap bit; the two timestamps say what the page holds. THE TWO FIELDS MEAN DIFFERENT THINGS UNDER THE TWO ORDERINGS and the difference matters: under the default newest-first ordering the page is a contiguous slice of the window's tail, so oldest_returned_collection_time IS how far back this read reached; under a min_duration_ms floor the page is a cost-RANKED sample drawn from the whole window, so it tells you how old the slowest matching runs are and NOTHING about reach. Read order to know which you have. Neither field is a window floor: nothing here probes for the oldest row the window could have held. A read whose newest and oldest are seconds apart has told you nothing about the window you named, and raising limit does NOT fix it under the default ordering because the slow runs are not the recent ones — min_duration_ms is the knob for that, because supplying it ranks by duration instead of by time. All THREE filters are applied in SQL, BEFORE the cap, so truncated and run_count describe the MATCHING rows rather than the unfiltered window. order names which ordering you got, so a caller never has to infer it from the filters it sent. status IS THE FAILURE-HUNTING FILTER and the reason to reach for this tool during an incident: 'show me the failures' is the most common question asked of this log, and without it a caller pages the newest-first tail eyeballing status — which the page-span contract above explains cannot work, because the cap covers a fraction of the window and raising limit does not reach a failure that is not recent. Pass one of SUCCESS, SKIPPED, YIELDED, ABANDONED, ERROR, PERMISSIONS, EXTENSION_MISSING, SESSION_MISSING, WARNING (case-insensitive); an unknown value is REFUSED and the refusal names the whole set, rather than being applied as an equality filter that returns an empty page a caller would read as 'no failures'. get_collection_health is not this question's answer either: it carries one last_error per collector over a rollup, not the runs, their timestamps or their sequence — which is what says whether every collector failed at once or one collector failed all night. A status filter changes the page from a contiguous tail to a filtered one, so read the two page-span timestamps the same way you would under a duration floor. The filter you sent is echoed back as status_filter (not status, which on an empty result is the miss word instead), in the stored UPPERCASE spelling whatever case you sent. Two of those statuses are Darling-only in practice — EXTENSION_MISSING and WARNING are written by PostgreSQL collectors and the fleet-maintenance passes, neither of which exists on this SKU — and they are accepted rather than refused here so the vocabulary is ONE set on both products: a filter that matches nothing on this SKU is an honest empty answer, where a refusal would teach a caller the value does not exist. One precision on sql_duration_ms, which Darling's twin of this tool states at length: on the collectors that enumerate databases it is the driver's per-item stopwatch, which also wraps the per-database watermark refresh - a read against the LOCAL store, so a small part of it is not the monitored server. What does NOT apply here is the large part: this SKU never enables the deferred plan-XML or statement-text fetches, so none of the store probe or write-back that dominates Darling's figure for query_store is in this one, and there is nothing here to attribute. Five parameters carry more guidance than their 200-character cap allows; the rest of each below. collector_name: A name this server has never run returns the no-matches status rather than a quiet-window one. min_duration_ms: Applied in SQL before the cap. 0 is a real value: it admits every run and is how you ask for the whole window ranked by cost. A negative is refused. Omit for no floor and newest-first order. status: THE FAILURE FILTER — 'show me the failures' is what this log exists to answer, and paging the newest-first tail cannot reach a failure that is not recent. An unknown value is REFUSED, naming the accepted set, rather than applied as a filter that matches nothing. Omit for every status. server_name: Omitted, blank, or \"*\" reads the WHOLE FLEET (#4199) — every enabled server's runs, merged and ranked together, each row carrying server_name — matching Darling's twin exactly (Lite has no (fleet) maintenance sentinel to protect). limit: Default McpResponseBudget.CollectionLogPerServerDefaultLimit (58) for one server, matching Darling's twin (#4198). The fleet-wide form (server_name omitted or \"*\") defaults instead to McpResponseBudget.CollectionLogFleetDefaultLimit, sized the same way; pass limit explicitly for more rows either way.")] public static async Task GetCollectionLog( LocalDataService dataService, ServerManager serverManager, [Description("Server name or display name. Omit or pass \"*\" for the WHOLE FLEET (every enabled server's runs, merged; see tool guide).")] string? server_name = null, [Description("Hours of history. Default 24. No upper bound (this read exists to look further back than the 168-hour reads allow); a negative or zero value is refused rather than read as its absolute value.")] int hours_back = 24, - [Description("Maximum rows to return, applied after the filters. Default 200 for one server; the fleet-wide form (server_name omitted or \"*\") defaults lower — see tool guide.")] int? limit = null, + [Description("Maximum rows to return, applied after the filters. Default 58 for one server; the fleet-wide form (server_name omitted or \"*\") defaults lower — see tool guide.")] int? limit = null, [Description(McpHelpers.AsOfDescription)] string? as_of = null, /* APPENDED after as_of rather than grouped beside `limit`, matching Darling's twin and for the same @@ -688,7 +692,9 @@ POSITIONALLY would silently rebind it to the collector filter and compile withou joins the end of this list so no positional C# caller changes meaning, and the two SKUs describe one parameter one way. */ - [Description("Limit to runs with this status, matched case-insensitively against the log's own vocabulary: SUCCESS, SKIPPED, YIELDED, ABANDONED, ERROR, PERMISSIONS, EXTENSION_MISSING, SESSION_MISSING, WARNING.")] string? status = null) + [Description("Limit to runs with this status, matched case-insensitively against the log's own vocabulary: SUCCESS, SKIPPED, YIELDED, ABANDONED, ERROR, PERMISSIONS, EXTENSION_MISSING, SESSION_MISSING, WARNING.")] string? status = null, + /* #4198, APPENDED for the reason collector_name and status were, matching Darling's twin exactly. */ + [Description("Return each run's error_message in full instead of a preview. Default false.")] bool full_text = false) { /* #4199, matching Darling's twin exactly: server_name omitted, blank or "*" means every enabled server merged and ranked together, each row carrying server_name, instead of "auto-select the @@ -703,7 +709,7 @@ one parameter one way. /* limit is nullable so the fleet branch above and this per-server branch can default it differently, matching Darling's twin exactly — see its comment for why. */ - var effectiveLimit = limit ?? 200; + var effectiveLimit = limit ?? McpResponseBudget.CollectionLogPerServerDefaultLimit; var (resolved, error) = ServerResolver.ResolveOrError(serverManager, server_name); if (error != null) return error; @@ -822,7 +828,10 @@ question the caller is asking does not. store_duration_ms = r.DuckDbDurationMs, rows_collected = r.RowsCollected, status = r.Status, - error_message = r.ErrorMessage, + /* #4198, matching Darling's twin exactly: a preview by default, full_text opts back into + the whole field. */ + error_message = full_text ? r.ErrorMessage : McpHelpers.Truncate(r.ErrorMessage, ErrorMessagePreviewLength), + error_message_truncated = !full_text && r.ErrorMessage is not null && r.ErrorMessage.Length > ErrorMessagePreviewLength, }); return JsonSerializer.Serialize(new diff --git a/PerformanceMonitor.Common/Mcp/McpResponseBudget.cs b/PerformanceMonitor.Common/Mcp/McpResponseBudget.cs index efc8202d35..f84c1dbc12 100644 --- a/PerformanceMonitor.Common/Mcp/McpResponseBudget.cs +++ b/PerformanceMonitor.Common/Mcp/McpResponseBudget.cs @@ -36,11 +36,23 @@ public static class McpResponseBudget /// /// get_collection_log's fleet-wide form (#4199, both products) default row limit, shared so a caller /// who omits server_name (or passes "*") gets the same page size from Darling and Lite. The - /// per-server form keeps its own default (200) — sizing it is #4198's per-tool pass, out of scope here. + /// per-server form keeps its own default — sized separately by . /// #4198 measured a per-server default call at 85-88 KB for 200 rows (about 435-440 bytes/row); the fleet /// form's row is that same shape plus one added server_name field, so a page this size stays under /// with room for the envelope fields around the array. See the fleet-form /// byte-budget tests in Darling.Tests / Lite.Tests for the measured number this was set from. /// public const int CollectionLogFleetDefaultLimit = 60; + + /// + /// get_collection_log's ONE-SERVER form (#4198) default row limit. The old default (200) measured + /// 85,206-90,514 bytes on a seeded store — about 2.6-2.8x — with the SQL Server + /// target shape the wider of the two, because its query_store rows carry the plan_fetch/ + /// text_fetch deferred-fetch split that PostgreSQL targets never populate. Sized down so a default + /// call stays under budget on the wider shape, with room for the envelope fields around the array; a + /// caller after more rows still passes limit explicitly. See + /// McpCollectionLogPerServerResponseBudgetLivePostgresTests / the Lite.Tests twin for the measured + /// numbers this was set from. + /// + public const int CollectionLogPerServerDefaultLimit = 58; }