diff --git a/docs/adr/53719-warn-on-stale-logs-without-date-range.md b/docs/adr/53719-warn-on-stale-logs-without-date-range.md new file mode 100644 index 00000000000..9fd373b53ef --- /dev/null +++ b/docs/adr/53719-warn-on-stale-logs-without-date-range.md @@ -0,0 +1,48 @@ +# ADR-53719: Warn Callers When `logs` MCP Tool Returns Stale Data Without a Date Range + +**Date**: 2026-08-18 +**Status**: Draft +**Deciders**: pelikhan, copilot-swe-agent + +--- + +### Context + +The `logs` MCP tool paginates workflow runs backwards by creation date until it has collected the requested count. In high-activity repositories, this walk can silently land on a window that is days or weeks old when recent non-agentic runs dominate the page. Callers that omit `start_date`/`end_date` receive stale data with no signal that more recent runs exist, causing deep-report and audit workflows to draw incorrect conclusions about current fleet health (see issue #53683). + +### Decision + +We will add a post-query staleness check (`staleLogsWarning`) that fires only when no date range was requested and the newest run in the result set is older than 48 hours. The warning is folded into the output's `message` field by `renderLogsOutput`, then extracted and surfaced verbatim in the MCP tool's top-level response text by `buildLogsFileResponse` so callers see it immediately without opening the cached file. + +### Alternatives Considered + +#### Alternative 1: Require explicit date bounds (hard rejection) + +Reject any `logs` call that omits both `start_date` and `end_date`, returning an error that forces the caller to specify a range. + +This eliminates the ambiguity entirely but is a breaking change: all existing callers that rely on the count-only invocation pattern would need to be updated simultaneously, and some legitimate use-cases (e.g., "give me the last N runs regardless of when they ran") become impossible to express. + +#### Alternative 2: Transparent auto-retry with a default date window + +Detect staleness and automatically re-issue the query with a sensible default `start_date` (e.g., `-1d`) without telling the caller. + +This silently fixes the common case but hides the ambiguity rather than exposing it. Callers lose visibility into the scope of their query; if the auto-selected window is wrong for a given repo's cadence, results are still wrong—and now there is no warning to prompt investigation. + +### Consequences + +#### Positive +- Callers receive an actionable warning in the MCP response's top-level `message` field immediately, without reading the cached file. +- No breaking change: callers that already supply explicit date bounds see no difference in behavior. +- The 48-hour threshold is documented as a named constant (`staleLogsWarningThreshold`), making it easy to tune. + +#### Negative +- The staleness heuristic (48 hours) is repo-cadence-agnostic; low-activity repositories may never trigger the warning even when results are genuinely stale, while repos with infrequent runs could trigger false positives. +- The warning travels through two encoding layers (render → JSON `message` field → guardrail JSON extraction), creating coupling between `renderLogsOutput` and `buildLogsFileResponse` that can silently break if the output schema changes. + +#### Neutral +- Unit tests cover all four guard conditions: explicit start date, explicit end date, empty result set, and recent-data threshold, providing a regression baseline for future threshold changes. +- The `renderLogsOutputOptions` struct gains two new fields (`startDate`, `endDate`) that are threaded from `DownloadWorkflowLogs`, a minor expansion of the internal API surface. + +--- + +*ADR created by [adr-writer agent]. Review and finalize before changing status from Draft to Accepted.* diff --git a/pkg/cli/logs_orchestrator.go b/pkg/cli/logs_orchestrator.go index 4d5d1fc1297..3759bb56395 100644 --- a/pkg/cli/logs_orchestrator.go +++ b/pkg/cli/logs_orchestrator.go @@ -41,6 +41,68 @@ func applyMetricsTurnsToRun(run *WorkflowRun, metrics LogMetrics) { } } +// staleLogsWarningThreshold is how old the most recent run in a result set may be, +// when no explicit start_date/end_date was requested, before we warn the caller +// that the data may not reflect the truly latest workflow runs. +// +// When no date range is supplied, pagination walks backwards through time (paging +// on run creation date) until it has collected the requested count of runs. In a +// repository with heavy non-agentic or still-in-progress run volume, this walk can +// silently settle on an old window without any indication to the caller that more +// recent runs exist. Passing an explicit start_date/end_date bypasses this ambiguity +// entirely because it bounds the query server-side, so no warning is needed there. +const staleLogsWarningThreshold = 48 * time.Hour + +// humanizeDuration formats a duration as a coarse, human-readable age such as +// "11 days" or "5 hours", rather than a raw Go duration string like "264h0m0s". +func humanizeDuration(d time.Duration) string { + if days := int(d.Hours()) / 24; days >= 1 { + if days == 1 { + return "1 day" + } + return fmt.Sprintf("%d days", days) + } + if hours := int(d.Hours()); hours >= 1 { + if hours == 1 { + return "1 hour" + } + return fmt.Sprintf("%d hours", hours) + } + return "less than 1 hour" +} + +// staleLogsWarning returns a warning message when a date-unbounded logs query +// (no start_date/end_date requested) returns a result set whose most recent run +// is unexpectedly old. Returns "" when no warning is warranted, i.e. when an +// explicit date range was requested, there are no runs, or the newest run is +// recent enough. +func staleLogsWarning(processedRuns []ProcessedRun, startDate, endDate string) string { + if startDate != "" || endDate != "" { + // Caller supplied an explicit bound; the result is exactly what was asked for. + return "" + } + if len(processedRuns) == 0 { + return "" + } + var newest time.Time + for _, pr := range processedRuns { + if pr.Run.CreatedAt.After(newest) { + newest = pr.Run.CreatedAt + } + } + if newest.IsZero() { + return "" + } + age := time.Since(newest) + if age < staleLogsWarningThreshold { + return "" + } + return fmt.Sprintf( + "No start_date/end_date was specified, and the most recent run in this result is %s old (created %s). "+ + "Retry with an explicit start_date (e.g. \"-1d\") to confirm you are seeing the latest workflow runs.", + humanizeDuration(age), newest.Format(time.RFC3339)) +} + // noRunsMessage returns a human-readable explanation for why zero workflow runs // were returned. It inspects the startDate filter and the timeoutReached flag // so callers receive actionable guidance instead of a silent empty result. @@ -183,5 +245,8 @@ func DownloadWorkflowLogs(ctx context.Context, opts LogsDownloadOptions) error { continuation: continuation, verbose: opts.Verbose, artifactFilter: runtime.artifactFilter, + startDate: opts.StartDate, + endDate: opts.EndDate, + checkStaleness: true, }) } diff --git a/pkg/cli/logs_orchestrator_render.go b/pkg/cli/logs_orchestrator_render.go index 040fb8ae663..a169132bed9 100644 --- a/pkg/cli/logs_orchestrator_render.go +++ b/pkg/cli/logs_orchestrator_render.go @@ -10,6 +10,7 @@ import ( "io" "os" "path/filepath" + "strings" "github.com/github/gh-aw/pkg/constants" ) @@ -29,10 +30,26 @@ func renderLogsOutput(processedRuns []ProcessedRun, opts renderLogsOutputOptions logsOrchestratorLog.Printf("Building logs data from %d processed runs (continuation=%t)", len(processedRuns), opts.continuation != nil) logsData := buildLogsData(processedRuns, opts.outputDir, opts.continuation) + // When no explicit start_date/end_date was requested and the newest run in the + // result is unexpectedly old, warn the caller so stale data is never served + // silently (see issue: logs MCP tool returns stale data without date params). + // This only applies to discovery-mode rendering (pagination walking backwards + // through time); the stdin path processes explicit run IDs with no pagination, + // so the check is skipped there. + if opts.checkStaleness { + if warning := staleLogsWarning(processedRuns, opts.startDate, opts.endDate); warning != "" { + logsData.StaleWarning = warning + } + } + // When only the usage artifact was downloaded, add a hint so consumers know how // to fetch additional artifact sets (agent logs, firewall data, etc.). + var hints []string if isUsageOnlyArtifactFilter(opts.artifactFilter) { - logsData.Message = usageOnlyArtifactHintMessage() + hints = append(hints, usageOnlyArtifactHintMessage()) + } + if len(hints) > 0 { + logsData.Message = strings.Join(hints, " ") } // Write summary file if requested (default behavior unless disabled with empty string) diff --git a/pkg/cli/logs_orchestrator_types.go b/pkg/cli/logs_orchestrator_types.go index d9568d999ae..af50a03937b 100644 --- a/pkg/cli/logs_orchestrator_types.go +++ b/pkg/cli/logs_orchestrator_types.go @@ -89,4 +89,11 @@ type renderLogsOutputOptions struct { continuation *ContinuationData verbose bool artifactFilter []string + startDate string + endDate string + // checkStaleness enables the stale-data warning check. It is only meaningful + // for discovery-mode rendering (pagination walking backwards through time + // looking for runs); the stdin path processes explicit run IDs with no + // pagination, so it leaves this false. + checkStaleness bool } diff --git a/pkg/cli/logs_orchestrator_unit_test.go b/pkg/cli/logs_orchestrator_unit_test.go index 5f8853f655f..5baa1f39f91 100644 --- a/pkg/cli/logs_orchestrator_unit_test.go +++ b/pkg/cli/logs_orchestrator_unit_test.go @@ -368,3 +368,44 @@ func TestCollectProcessedWorkflowRunsAccumulatesBatches(t *testing.T) { assert.Equal(t, int64(1), runs[0].Run.DatabaseID) assert.Equal(t, int64(3), runs[2].Run.DatabaseID) } + +// TestStaleLogsWarning verifies that a warning is only emitted when no explicit +// start_date/end_date was requested and the newest run in the result set is older +// than the staleness threshold. This guards against the "logs" tool silently +// serving stale data without any indication when called with only a count. +func TestStaleLogsWarning(t *testing.T) { + t.Run("no warning when start date explicitly provided", func(t *testing.T) { + runs := []ProcessedRun{{Run: WorkflowRun{CreatedAt: time.Now().Add(-30 * 24 * time.Hour)}}} + assert.Empty(t, staleLogsWarning(runs, "-1d", "")) + }) + + t.Run("no warning when end date explicitly provided", func(t *testing.T) { + runs := []ProcessedRun{{Run: WorkflowRun{CreatedAt: time.Now().Add(-30 * 24 * time.Hour)}}} + assert.Empty(t, staleLogsWarning(runs, "", "2024-01-01")) + }) + + t.Run("no warning when no runs", func(t *testing.T) { + assert.Empty(t, staleLogsWarning(nil, "", "")) + }) + + t.Run("no warning when newest run is recent", func(t *testing.T) { + runs := []ProcessedRun{ + {Run: WorkflowRun{CreatedAt: time.Now().Add(-1 * time.Hour)}}, + {Run: WorkflowRun{CreatedAt: time.Now().Add(-40 * 24 * time.Hour)}}, + } + assert.Empty(t, staleLogsWarning(runs, "", "")) + }) + + t.Run("warns when no dates given and newest run is old", func(t *testing.T) { + newest := time.Now().Add(-11 * 24 * time.Hour) + runs := []ProcessedRun{ + {Run: WorkflowRun{CreatedAt: newest}}, + {Run: WorkflowRun{CreatedAt: newest.Add(-time.Hour)}}, + } + warning := staleLogsWarning(runs, "", "") + require.NotEmpty(t, warning) + assert.Contains(t, warning, "No start_date/end_date was specified") + assert.Contains(t, warning, "start_date") + assert.Contains(t, warning, "11 day") + }) +} diff --git a/pkg/cli/logs_output_hint_test.go b/pkg/cli/logs_output_hint_test.go index 2eb01e5b1ec..bdf2d598c82 100644 --- a/pkg/cli/logs_output_hint_test.go +++ b/pkg/cli/logs_output_hint_test.go @@ -55,3 +55,42 @@ func TestRenderLogsOutputWritesArtifactHintForNonCompactFormats(t *testing.T) { }) } } + +func TestRenderLogsOutputStaleWarningGatedByCheckStaleness(t *testing.T) { + // A result set whose newest run is well past the staleness threshold with no + // start_date/end_date requested. + processedRuns := []ProcessedRun{{ + Run: WorkflowRun{ + DatabaseID: 1, + Status: "completed", + WorkflowName: "logs", + CreatedAt: time.Now().Add(-11 * 24 * time.Hour), + }, + }} + + t.Run("discovery mode surfaces the stale warning", func(t *testing.T) { + stdout, _ := captureOutput(t, func() error { + return renderLogsOutput(processedRuns, renderLogsOutputOptions{ + outputDir: t.TempDir(), + format: "console", + jsonOutput: true, + checkStaleness: true, + }) + }) + + assert.Contains(t, stdout, "No start_date/end_date was specified") + }) + + t.Run("stdin/explicit-run mode does not surface the stale warning", func(t *testing.T) { + stdout, _ := captureOutput(t, func() error { + return renderLogsOutput(processedRuns, renderLogsOutputOptions{ + outputDir: t.TempDir(), + format: "console", + jsonOutput: true, + // checkStaleness left false, as it is for DownloadWorkflowLogsFromStdin. + }) + }) + + assert.NotContains(t, stdout, "No start_date/end_date was specified") + }) +} diff --git a/pkg/cli/logs_report.go b/pkg/cli/logs_report.go index 1782f569561..cbf1009a553 100644 --- a/pkg/cli/logs_report.go +++ b/pkg/cli/logs_report.go @@ -39,6 +39,7 @@ type LogsData struct { Continuation *ContinuationData `json:"continuation,omitempty" console:"-"` LogsLocation string `json:"logs_location" console:"-"` Message string `json:"message,omitempty" console:"-"` + StaleWarning string `json:"stale_warning,omitempty" console:"-"` } // ContinuationData provides parameters to continue querying when timeout is reached diff --git a/pkg/cli/mcp_logs_guardrail.go b/pkg/cli/mcp_logs_guardrail.go index 513bdf7a71b..ba13ddce9c7 100644 --- a/pkg/cli/mcp_logs_guardrail.go +++ b/pkg/cli/mcp_logs_guardrail.go @@ -7,6 +7,7 @@ import ( "fmt" "os" "path/filepath" + "strings" "github.com/github/gh-aw/pkg/constants" "github.com/github/gh-aw/pkg/logger" @@ -51,6 +52,23 @@ func extractLogsContinuation(outputStr string) *ContinuationData { return parsed.Continuation } +// extractLogsStaleWarning returns the top-level "stale_warning" field embedded +// in the logs JSON output, or "" when absent or unparseable. This is a +// dedicated field (distinct from the generic "message" field, which is also +// used for non-warning hints such as the usage-only artifact hint) so that +// only genuine stale-data warnings are surfaced as "WARNING" in the MCP +// response. +func extractLogsStaleWarning(outputStr string) string { + var parsed struct { + StaleWarning string `json:"stale_warning"` + } + if err := json.Unmarshal([]byte(outputStr), &parsed); err != nil { + mcpLogsGuardrailLog.Printf("extractLogsStaleWarning: failed to parse output JSON: %v", err) + return "" + } + return parsed.StaleWarning +} + // buildLogsFileResponse writes the logs JSON output to a content-addressed cache // file and returns a JSON response containing the file path. // The file is named by the SHA256 hash of its content so that identical results @@ -134,14 +152,25 @@ func buildLogsFileResponse(outputStr string) string { } response := MCPLogsGuardrailResponse{ - Message: fmt.Sprintf("Logs data has been written to '%s'. Use the file_path to read the full data.", filePath), FilePath: filePath, } - if continuation := extractLogsContinuation(outputStr); continuation != nil { + + var msgs []string + continuation := extractLogsContinuation(outputStr) + if continuation != nil { response.Partial = true response.Continuation = continuation - response.Message = fmt.Sprintf("PARTIAL RESULTS: the download stopped before all matching runs were collected. %s Partial logs data has been written to '%s'. Use the file_path to read the collected data and the continuation parameters to fetch the remaining logs.", continuation.Message, filePath) + msgs = append(msgs, fmt.Sprintf("PARTIAL RESULTS: the download stopped before all matching runs were collected. %s Partial logs data has been written to '%s'. Use the file_path to read the collected data and the continuation parameters to fetch the remaining logs.", continuation.Message, filePath)) + } else { + msgs = append(msgs, fmt.Sprintf("Logs data has been written to '%s'. Use the file_path to read the full data.", filePath)) + } + // Surface the stale-data warning (when no date range was requested and the + // newest run returned is unexpectedly old) directly in the tool response so + // callers see it without having to open the file. + if warning := extractLogsStaleWarning(outputStr); warning != "" { + msgs = append(msgs, "WARNING: "+warning) } + response.Message = strings.Join(msgs, " ") responseJSON, err := json.MarshalIndent(response, "", " ") if err != nil { diff --git a/pkg/cli/mcp_logs_guardrail_test.go b/pkg/cli/mcp_logs_guardrail_test.go index 146d7d08cdc..074c02c0585 100644 --- a/pkg/cli/mcp_logs_guardrail_test.go +++ b/pkg/cli/mcp_logs_guardrail_test.go @@ -207,3 +207,45 @@ func TestBuildLogsFileResponse_CompleteResultsNotPartial(t *testing.T) { // Cleanup _ = os.Remove(response.FilePath) } + +func TestBuildLogsFileResponse_SurfacesStaleDataWarning(t *testing.T) { + output := `{"summary":{"total_runs":1},"runs":[],"stale_warning":"No start_date/end_date was specified, and the most recent run in this result is 11 days old."}` + + result := buildLogsFileResponse(output) + + var response MCPLogsGuardrailResponse + if err := json.Unmarshal([]byte(result), &response); err != nil { + t.Fatalf("Response should be valid JSON: %v", err) + } + + if !strings.Contains(response.Message, "WARNING:") { + t.Errorf("Message should surface the embedded warning, got %q", response.Message) + } + if !strings.Contains(response.Message, "No start_date/end_date was specified") { + t.Errorf("Message should include the stale-data warning text, got %q", response.Message) + } + + // Cleanup + _ = os.Remove(response.FilePath) +} + +func TestBuildLogsFileResponse_DoesNotWarnOnOrdinaryMessage(t *testing.T) { + // A non-stale "message" field (e.g. the usage-only artifact hint) must not + // be relabeled as a WARNING; only the dedicated "stale_warning" field should + // trigger the WARNING prefix. + output := `{"summary":{"total_runs":1},"runs":[],"message":"Only the usage artifact was downloaded."}` + + result := buildLogsFileResponse(output) + + var response MCPLogsGuardrailResponse + if err := json.Unmarshal([]byte(result), &response); err != nil { + t.Fatalf("Response should be valid JSON: %v", err) + } + + if strings.Contains(response.Message, "WARNING:") { + t.Errorf("Message should not contain WARNING for a non-stale message, got %q", response.Message) + } + + // Cleanup + _ = os.Remove(response.FilePath) +}