Repository navigation
fix(mcp): detach logs subprocess context from MCP gateway 60s deadline - #48961
Conversation
The `agenticworkflows logs` MCP tool failed at exactly 60 seconds regardless of the `--timeout` parameter because `exec.CommandContext(ctx, ...)` bound the subprocess lifetime to the MCP request context, which carries the MCP gateway's hardcoded 60-second per-tool RPC deadline. Fix: root the subprocess context at `context.Background()` with a deadline derived from the user-requested timeout value, breaking the 60-second gateway deadline chain. Explicit cancellations from the MCP request context (e.g. client disconnect) are still forwarded via a lightweight goroutine so the subprocess is cleaned up promptly when the caller goes away. Adds TestLogsToolSubprocessContextIgnoresGatewayDeadline to verify the subprocess context deadline is at least as long as the requested timeout, not bounded by the short gateway deadline. Fixes: #48921 Co-authored-by: pelikhan <4175913+pelikhan@users.noreply.github.com>
There was a problem hiding this comment.
Pull request overview
Attempts to let long-running MCP log downloads outlive the gateway’s 60-second deadline.
Changes:
- Adds a detached timeout context for the logs subprocess.
- Adds a regression test for subprocess deadlines.
Show a summary per file
| File | Description |
|---|---|
pkg/cli/mcp_tools_privileged.go |
Introduces subprocess context handling. |
pkg/cli/mcp_tools_privileged_test.go |
Tests the requested timeout deadline. |
Review details
Tip
Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
Comments suppressed due to low confidence (2)
pkg/cli/mcp_tools_privileged.go:256
- This still forwards the gateway deadline:
ctx.Done()closes for both explicit cancellation and deadline expiry, so the 60-second request deadline callssubCancel()and kills the subprocess exactly as before. Only explicit cancellation should be propagated (for example, by checkingctx.Err() == context.Canceled);context.DeadlineExceededmust not cancelsubCtx.
case <-ctx.Done():
subCancel()
pkg/cli/mcp_tools_privileged.go:251
- The outer deadline is set to exactly the same
--timeoutpassed to the child, but it starts before the process. The child later creates its owntimeoutMinutescontext and, on expiry, intentionally renders partial results plus a continuation (logs_orchestrator.go:153-186). Consequently this earlier outer deadline kills the process before it can handle its timeout and write that JSON. The subprocess deadline needs enough grace beyond the requested download timeout for graceful finalization.
subCtx, subCancel := context.WithTimeout(
context.Background(),
time.Duration(timeoutValue)*time.Minute,
)
- Files reviewed: 2/2 changed files
- Comments generated: 2
- Review effort level: Medium
| // Call the logs tool with an explicit 5-minute timeout. | ||
| const requestedTimeoutMinutes = 5 | ||
| before := time.Now() | ||
| _, err = session.CallTool(context.Background(), &mcp.CallToolParams{ | ||
| Name: "logs", | ||
| Arguments: map[string]any{ | ||
| "timeout": requestedTimeoutMinutes, | ||
| }, | ||
| }) |
There was a problem hiding this comment.
Updated in commit a0e7f20. The test now uses a 2-second gateway context (context.WithTimeout(context.Background(), 2*time.Second)) passed to session.CallTool, so it directly verifies that the subprocess deadline is ~5 minutes regardless of the short request context — catching the regression if subCtx is ever accidentally rooted at ctx again.
| // Fix: detach from the gateway deadline by rooting the subprocess context | ||
| // at context.Background(), using the user-requested timeout as the only | ||
| // deadline. We still forward any explicit cancellations from the MCP | ||
| // request context (e.g. client disconnect) so the subprocess is cleaned up | ||
| // promptly when the caller goes away. | ||
| subCtx, subCancel := context.WithTimeout( | ||
| context.Background(), | ||
| time.Duration(timeoutValue)*time.Minute, |
There was a problem hiding this comment.
Valid architectural observation. The immediate fix targets the most common failure mode: the gateway deadline was being applied to exec.CommandContext, so the subprocess was killed at 60 s regardless of --timeout. With this change, the subprocess can complete within its own timeout and the handler returns a valid CallToolResult in cases where the subprocess finishes before the gateway deadline — which covers most practical fetch windows.
For requests that genuinely need to exceed the gateway's RPC deadline (e.g., fetching thousands of runs), a full async redesign or a gateway-level timeout increase would be needed. That's tracked as a follow-up; it is out of scope for this targeted bug fix.
|
✅ PR Code Quality Reviewer completed the code quality review. |
|
✅ Design Decision Gate 🏗️ completed the design decision gate check. No ADR enforcement needed: PR does not have the 'implementation' label and has ≤100 new lines of code in business logic directories (73 additions detected, threshold is 100). |
|
✅ Test Quality Sentinel completed test quality analysis. Warning threat detection engine error DetailsThe threat detection engine failed to produce results. Review the workflow run logs for details. |
|
🧠 Matt Pocock Skills Reviewer has completed the skills-based review. ✅ |
![github-actions[bot]](https://avatars.githubusercontent.com/in/15368?s=60&v=4){kind=small}
There was a problem hiding this comment.
The fix is correct and well-structured. Detaching the subprocess context from the MCP gateway deadline by rooting it at context.Background() with time.Duration(timeoutValue)*time.Minute correctly addresses the 60s truncation. The goroutine forwarding client disconnects/cancellations is the right pattern. The test TestLogsToolSubprocessContextIgnoresGatewayDeadline is solid — it directly exercises the regression by asserting the captured deadline is well beyond a short in-memory RPC deadline. No blocking issues.
🧵 Reviewed using Impeccable skills by Impeccable Skills Reviewer · sonnet46 · 10.8 AIC · ⌖ 4.76 AIC · ⊞ 5.3K
|
Warning threat detection engine error DetailsThe threat detection engine failed to produce results. Review the workflow run logs for details. 🧪 Test Quality Sentinel Report✅ Test Quality Score: 100/100 — Excellent
📊 Metrics (1 test)
✅ Test Details
Verdict
|
There was a problem hiding this comment.
Skills-Based Review 🧠
Applied /diagnosing-bugs and /tdd — two minor observations, no blocking issues.
📋 Key Themes & Highlights
Positive Highlights
- ✅ Root cause correctly identified and addressed:
exec.CommandContextbinding subprocess to the gateway deadline was the real bug - ✅ Cancellation forwarding goroutine correctly handles both arms — no goroutine leak
- ✅ Good regression test added; the assertion approach (deadline far in the future) is practical
- ✅ Clear, thorough comment explaining the why of the context detachment
Observations
- Goroutine self-cleanup comment — the goroutine is provably leak-free but a short comment would make this obvious to future readers without mental model overhead
- Test strength — the test checks the deadline is long enough, but passing a short gateway context to the tool call (simulating the actual bug scenario) would make it a more precise regression guard
🧠 Reviewed using Matt Pocock's skills by Matt Pocock Skills Reviewer · sonnet46 · 25.5 AIC · ⌖ 5.04 AIC · ⊞ 7K
Comment /matt to run again
|
|
||
| // Execute the CLI command | ||
| // Use separate stdout/stderr capture instead of CombinedOutput because: | ||
| // - Stdout contains JSON output (--json flag) |
There was a problem hiding this comment.
[/diagnosing-bugs] The goroutine forwarding cancellations is self-cleaning (both select arms always fire eventually), but this isn't obvious — a brief comment would help readers confirm there's no goroutine leak.
💡 Suggested comment
go func() {
// Goroutine exits cleanly in both cases: client disconnect or subprocess timeout.
select {
case <-ctx.Done():
subCancel() // propagate client disconnect to subprocess
case <-subCtx.Done(): // subprocess timed out or subCancel() already called
}
}()@copilot please address this.
There was a problem hiding this comment.
Added in commit a0e7f20:
go func() {
// Goroutine exits cleanly in both cases: client disconnect or subprocess timeout.
select {
case <-ctx.Done():
subCancel() // propagate client disconnect to subprocess
case <-subCtx.Done(): // subprocess timed out or subCancel() already called
}
}()|
|
||
| // Call the logs tool with an explicit 5-minute timeout. | ||
| const requestedTimeoutMinutes = 5 | ||
| before := time.Now() |
There was a problem hiding this comment.
[/tdd] The test verifies the deadline is far enough in the future but doesn't assert the subprocess context is NOT rooted at the MCP request context — i.e., it doesn't cover the regression where someone accidentally re-introduces the original bug by passing ctx but still getting a long-enough deadline by coincidence.
💡 Suggested additional assertion
Consider also asserting that the subprocess context's deadline is independent of the gateway context. One approach: pass a gateway context with a 2s deadline and verify the subprocess deadline is still ~5 minutes out.
// Simulate a short gateway deadline (as the real MCP gateway imposes).
gatewayCtx, gatewayCancel := context.WithTimeout(context.Background(), 2*time.Second)
defer gatewayCancel()
_, err = session.CallTool(gatewayCtx, &mcp.CallToolParams{...})
// then check capturedDeadline is still ~5 minutes from before, not ~2 secondsThis would be the exact regression test for the original bug.
@copilot please address this.
There was a problem hiding this comment.
Test rewritten in commit a0e7f20. The call now uses a 2-second gateway context to simulate the real gateway deadline, making the test a true regression guard: if someone accidentally re-introduces the bug by rooting subCtx at ctx instead of context.Background(), the subprocess deadline would be ~2s and the After(expectedMinDeadline) assertion would fail:
gatewayCtx, gatewayCancel := context.WithTimeout(context.Background(), 2*time.Second)
defer gatewayCancel()
_, _ = session.CallTool(gatewayCtx, &mcp.CallToolParams{
Name: "logs",
Arguments: map[string]any{"timeout": requestedTimeoutMinutes},
})
// deadline must still be ~5 min regardless of the 2s gateway context
require.True(t, capturedHasDeadline, ...)
assert.True(t, capturedDeadline.After(expectedMinDeadline), ...)
There was a problem hiding this comment.
Fix is directionally correct (subprocess should not inherit the gateway's 60s deadline), but it introduces a real resource-exhaustion risk that must be addressed before merge.
Themes
- High:
args.Timeout/timeoutValueis fully user-controlled and unbounded. Previously the gateway's ~60s deadline silently capped worst-case subprocess runtime regardless of what the caller requested. Now that cap is gone, and the subprocess context can be given an arbitrarily long deadline (e.g. minutes to hours), while only 4 concurrent subprocess slots exist (maxActiveMCPChildProcesses). A few long-timeout requests can starve the guardrail for everyone else. Needs a sane upper clamp ontimeoutValuebefore it's used to buildsubCtx. - Cancellation-forwarding goroutine and
defer subCancel()pattern are otherwise sound; no leak or race found there. - Test coverage for the new deadline-detachment behavior is a good addition.
Recommend adding a max-timeout clamp (e.g. 30-60 min) and a corresponding test before merge.
🔎 Code quality review by PR Code Quality Reviewer · aut00 · 57.7 AIC · ⌖ 4.66 AIC · ⊞ 7.8K
Comment /review to run again
| // promptly when the caller goes away. | ||
| subCtx, subCancel := context.WithTimeout( | ||
| context.Background(), | ||
| time.Duration(timeoutValue)*time.Minute, |
There was a problem hiding this comment.
This unbounded timeoutValue (user-controlled via args.Timeout) can now actually take effect for the subprocess lifetime, since it no longer inherits the gateway's 60s deadline.
💡 Unbounded user timeout + fixed 4-slot guardrail = resource exhaustion
Before this change, args.Timeout was silently capped by the MCP gateway's ~60s per-tool deadline regardless of how large a value the caller requested, so a runaway subprocess was bounded to ~60s. Now subCtx is rooted at context.Background() with a deadline of timeoutValue minutes, and there's no validation/cap on args.Timeout anywhere in effectiveMCPLogsToolTimeoutMinutes or the tool schema.
A malicious or buggy caller can pass timeout: 100000 and now the subprocess genuinely runs for that long (or until the underlying gh aw logs command finishes/errors). Combined with defaultMCPSubprocessGuardrail capping concurrent subprocesses at 4 slots (maxActiveMCPChildProcesses = 4), a handful of long-timeout requests can occupy all available slots for a very long time, denying service to every other MCP tool caller sharing the guardrail.
Fix: clamp timeoutValue to a sane maximum (e.g. 30-60 minutes) before constructing subCtx:
const maxLogsSubprocessTimeoutMinutes = 30
if timeoutValue > maxLogsSubprocessTimeoutMinutes {
timeoutValue = maxLogsSubprocessTimeoutMinutes
}There was a problem hiding this comment.
Fixed in commit a0e7f20. Added maxMCPLogsSubprocessTimeoutMinutes = 60 and clamped the user-supplied value in effectiveMCPLogsToolTimeoutMinutes:
if requestedTimeout > 0 {
return min(requestedTimeout, maxMCPLogsSubprocessTimeoutMinutes)
}Three new test cases in logs_timeout_test.go cover exact-at-max, above-max, and very-large values.
|
@copilot run pr-finisher skill |
|
@copilot please run the skill and confirm this PR is ready for maintainer review. The latest checks look finished, so please verify whether any remaining blocker is review- or mergeability-related and rerun any required checks if the head changes. Run: https://github.com/github/gh-aw/actions/runs/30488631737
|
…ocess timeout - Thread 3: Add goroutine self-cleaning comment explaining no goroutine leak - Thread 4: Rewrite TestLogsToolSubprocessContextIgnoresGatewayDeadline to use a 2s gateway context, proving subCtx deadline is independent of gateway deadline - Thread 5: Add maxMCPLogsSubprocessTimeoutMinutes=60 cap on user-supplied timeout to prevent resource exhaustion via runaway long-timeout subprocess requests Co-authored-by: pelikhan <4175913+pelikhan@users.noreply.github.com>
…process The forwarding goroutine used ctx.Done() which fires for both explicit cancellations (context.Canceled) and deadline expiry (context.DeadlineExceeded). This meant the MCP gateway's 60s RPC deadline still triggered subCancel() via the goroutine, defeating the whole purpose of detaching subCtx from the gateway. Fix: guard with ctx.Err() == context.Canceled so only true client disconnects propagate to the subprocess; gateway deadline expiry is ignored, allowing the subprocess to run for its full user-requested timeout. Co-authored-by: gh-aw-bot <259018956+gh-aw-bot@users.noreply.github.com>
The PR is code-complete and ready for maintainer review. Here's the current state: Code is correct: All tests pass locally, including CI checks: The CGO and CWI workflow runs show Remaining blocker: A maintainer needs to approve the pending CI workflow runs so the test suite can execute against the head commit. |
|
🎉 This pull request is included in a new release. Release: |
The
agenticworkflows logsMCP tool always failed at exactly 60 seconds — the--timeoutparameter had no effect becauseexec.CommandContext(ctx, ...)bound the subprocess lifetime to the MCP request context, which inherits the gateway's hardcoded 60-second per-tool RPC deadline.Changes
pkg/cli/mcp_tools_privileged.go— Before executing thegh aw logssubprocess, create a fresh context rooted atcontext.Background()with a deadline equal to the computedtimeoutValue(breaking the 60s gateway deadline chain). A lightweight goroutine forwards explicit cancellations from the MCP request context (client disconnect, etc.) so the subprocess is still cleaned up promptly:pkg/cli/mcp_tools_privileged_test.go— AddsTestLogsToolSubprocessContextIgnoresGatewayDeadlineto assert that the subprocess context deadline is at least as long as the requested timeout, not bounded by a short MCP request deadline.Run: https://github.com/github/gh-aw/actions/runs/30488631737