Skip to content
Merged
Show file tree
Hide file tree
Changes from 3 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
46 changes: 46 additions & 0 deletions pkg/cli/logs_orchestrator.go
Original file line number Diff line number Diff line change
Expand Up @@ -41,6 +41,50 @@ 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

// 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.",
age.Round(time.Hour), 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 +227,7 @@ func DownloadWorkflowLogs(ctx context.Context, opts LogsDownloadOptions) error {
continuation: continuation,
verbose: opts.Verbose,
artifactFilter: runtime.artifactFilter,
startDate: opts.StartDate,
endDate: opts.EndDate,
})
}
14 changes: 13 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,21 @@ 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).
var hints []string
if warning := staleLogsWarning(processedRuns, opts.startDate, opts.endDate); warning != "" {
hints = append(hints, 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.).
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
2 changes: 2 additions & 0 deletions pkg/cli/logs_orchestrator_types.go
Original file line number Diff line number Diff line change
Expand Up @@ -89,4 +89,6 @@ type renderLogsOutputOptions struct {
continuation *ContinuationData
verbose bool
artifactFilter []string
startDate string
endDate string
}
40 changes: 40 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,43 @@ 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) {
oldest := time.Now().Add(-11 * 24 * time.Hour)
runs := []ProcessedRun{
{Run: WorkflowRun{CreatedAt: oldest}},
{Run: WorkflowRun{CreatedAt: oldest.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")
})
}
22 changes: 22 additions & 0 deletions pkg/cli/mcp_logs_guardrail.go
Original file line number Diff line number Diff line change
Expand Up @@ -51,6 +51,18 @@ func extractLogsContinuation(outputStr string) *ContinuationData {
return parsed.Continuation
}

// extractLogsMessage returns the top-level "message" field embedded in the logs
// JSON output (e.g. a stale-data warning), or "" when absent or unparseable.
func extractLogsMessage(outputStr string) string {
var parsed struct {
Message string `json:"message"`
}
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.

return ""
}
return parsed.Message
}

// 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 @@ -142,6 +154,16 @@ func buildLogsFileResponse(outputStr string) string {
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)
}
// Surface any top-level warning (e.g. stale-data warning when no date range was
// requested) directly in the tool response so callers see it without having to
// open the file.
if warning := extractLogsMessage(outputStr); warning != "" {
if response.Message == "" {
response.Message = "WARNING: " + warning
} else {

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.

[/codebase-design] buildLogsFileResponse now contains two separate message-assembly patterns: one for the continuation case (inline fmt.Sprintf) and one for the stale-data warning (if/else append). This makes it hard to see the final message shape at a glance and will grow messier as more warning types are added.

💡 Suggested refactor

Collect all message fragments into a []string and strings.Join them at the end — the same pattern used in renderLogsOutput:

var msgs []string
if continuation != nil {
    msgs = append(msgs, fmt.Sprintf("PARTIAL RESULTS: ... '%s'.", filePath))
}
if warning := extractLogsMessage(outputStr); warning != "" {
    msgs = append(msgs, "WARNING: "+warning)
}
if len(msgs) > 0 {
    response.Message = strings.Join(msgs, " ")
}

This also removes the duplicated "WARNING: " prefix logic.

@copilot please address this.

response.Message = fmt.Sprintf("%s WARNING: %s", response.Message, warning)
}
}

responseJSON, err := json.MarshalIndent(response, "", " ")
if err != nil {
Expand Down
21 changes: 21 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,24 @@ func TestBuildLogsFileResponse_CompleteResultsNotPartial(t *testing.T) {
// Cleanup
_ = os.Remove(response.FilePath)
}

func TestBuildLogsFileResponse_SurfacesStaleDataWarning(t *testing.T) {
output := `{"summary":{"total_runs":1},"runs":[],"message":"No start_date/end_date was specified, and the most recent run in this result is 264h0m0s 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)
}
Loading