Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
48 changes: 48 additions & 0 deletions docs/adr/53719-warn-on-stale-logs-without-date-range.md
Original file line number Diff line number Diff line change
@@ -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.*
65 changes: 65 additions & 0 deletions pkg/cli/logs_orchestrator.go
Original file line number Diff line number Diff line change
Expand Up @@ -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). "+

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[/diagnosing-bugs] age.Round(time.Hour) formats as "264h0m0s" — callers see a raw Go duration string rather than "11 days old" as shown in the PR description. A human-readable form is far more actionable for agents and users.

💡 Suggested fix

Add a small helper and use it in the Sprintf:

func humanizeDuration(d time.Duration) string {
    days := int(d.Hours()) / 24
    if days >= 1 {
        return fmt.Sprintf("%d day(s)", days)
    }
    return fmt.Sprintf("%d hour(s)", int(d.Hours()))
}

Also add a test that asserts the stale-data warning for 11-day-old data contains "11 day" to prevent format regressions.

@copilot please address this.

"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.
Expand Down Expand Up @@ -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,
})
}
19 changes: 18 additions & 1 deletion pkg/cli/logs_orchestrator_render.go
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@ import (
"io"
"os"
"path/filepath"
"strings"

"github.com/github/gh-aw/pkg/constants"
)
Expand All @@ -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)
Expand Down
7 changes: 7 additions & 0 deletions pkg/cli/logs_orchestrator_types.go
Original file line number Diff line number Diff line change
Expand Up @@ -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
}
41 changes: 41 additions & 0 deletions pkg/cli/logs_orchestrator_unit_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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, "", ""))
})

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[/diagnosing-bugs] The staleLogsWarning in the test for "warns when no dates given and newest run is old" uses a variable named oldest but assigns it the newest timestamp (the other run is oldest.Add(-time.Hour)). The naming mismatch makes the test harder to follow and could mask a logic inversion.

💡 Suggested rename
newest := time.Now().Add(-11 * 24 * time.Hour)
runs := []ProcessedRun{
    {Run: WorkflowRun{CreatedAt: newest}},
    {Run: WorkflowRun{CreatedAt: newest.Add(-time.Hour)}},
}

While here, assert the warning contains "11 day" to lock in the human-readable format.

@copilot please address this.

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")
})
}
39 changes: 39 additions & 0 deletions pkg/cli/logs_output_hint_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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")
})
}
1 change: 1 addition & 0 deletions pkg/cli/logs_report.go
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
35 changes: 32 additions & 3 deletions pkg/cli/mcp_logs_guardrail.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ import (
"fmt"
"os"
"path/filepath"
"strings"

"github.com/github/gh-aw/pkg/constants"
"github.com/github/gh-aw/pkg/logger"
Expand Down Expand Up @@ -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 {

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[/diagnosing-bugs] extractLogsMessage silently returns "" on JSON parse error, meaning a malformed outputStr will cause the stale-data warning to be silently dropped rather than surfaced. This makes the guardrail harder to debug in production.

💡 Suggested fix

Log the parse error at debug level so it's visible under DEBUG=cli:*:

func extractLogsMessage(outputStr string) string {
    var parsed struct {
        Message string `json:"message"`
    }
    if err := json.Unmarshal([]byte(outputStr), &parsed); err != nil {
        mcpLogsGuardrailLog.Printf("extractLogsMessage: failed to parse output JSON: %v", err)
        return ""
    }
    return parsed.Message
}

@copilot please address this.

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
Expand Down Expand Up @@ -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 {
Expand Down
42 changes: 42 additions & 0 deletions pkg/cli/mcp_logs_guardrail_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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)

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[/tdd] TestBuildLogsFileResponse_SurfacesStaleDataWarning uses t.Errorf for assertions but the test above it (TestBuildLogsFileResponse_CompleteResultsNotPartial) uses assert/require helpers. Mixing styles makes the test suite harder to scan. The t.Errorf path also continues running after the first failure, which can produce misleading secondary failures.

💡 Suggested fix

Switch to require/assert from the existing testify import:

require.NoError(t, json.Unmarshal([]byte(result), &response))
assert.Contains(t, response.Message, "WARNING:")
assert.Contains(t, response.Message, "No start_date/end_date was specified")

@copilot please address this.

}

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)
}
Loading