fix(ssh): preserve agent generation timeout budget (#12644)
AI commit-message and PR-field generation over SSH failed deterministically at exactly 30 seconds whenever the remote agent CLI took longer, reporting "Claude could not be reached on the remote PATH. Try again after the SSH connection recovers." That message was wrong twice over: the SSH connection was healthy (terminals and git kept working on it) and the agent binary existed — it was simply still running. Cause: the SSH channel multiplexer applies a 30s default deadline when a request omits its own, and the generation call passed none, even though the operation itself carries a 60s budget. The shorter transport deadline always won, and the resulting rejection was then mapped onto the generic connection/PATH error. Fix: derive the transport deadline from the operation's own budget plus a margin at that call site (the global default is deliberately unchanged, since other callers depend on it), and classify a transport timeout as a timeout — reporting that the agent exceeded its budget and may still be running — while genuine connection and PATH failures keep their existing guidance. Verified red on main first: a 45s response rejected by the 30s default, and a typed timeout mapped to the PATH message. Both green after. Caller audit covered commit messages, PR fields, branch naming and model discovery. Fixes STA-3073.
This commit is contained in:
parent
cbc005c8aa
commit
9666087faf
|
|
@ -278,13 +278,17 @@ describe('SshGitProvider', () => {
|
|||
|
||||
const result = await provider.execNonInteractive('pnpm', ['--version'], '/home/user/repo', 8000)
|
||||
|
||||
expect(mux.request).toHaveBeenCalledWith('agent.execNonInteractive', {
|
||||
binary: 'pnpm',
|
||||
args: ['--version'],
|
||||
cwd: '/home/user/repo',
|
||||
stdin: null,
|
||||
timeoutMs: 8000
|
||||
})
|
||||
expect(mux.request).toHaveBeenCalledWith(
|
||||
'agent.execNonInteractive',
|
||||
{
|
||||
binary: 'pnpm',
|
||||
args: ['--version'],
|
||||
cwd: '/home/user/repo',
|
||||
stdin: null,
|
||||
timeoutMs: 8000
|
||||
},
|
||||
{ timeoutMs: 13_000 }
|
||||
)
|
||||
expect(result).toEqual(execResult)
|
||||
})
|
||||
|
||||
|
|
@ -309,17 +313,21 @@ describe('SshGitProvider', () => {
|
|||
}
|
||||
)
|
||||
|
||||
expect(mux.request).toHaveBeenCalledWith('agent.execNonInteractive', {
|
||||
binary: '/bin/bash',
|
||||
args: ['-lc', 'echo "$ORCA_WORKTREE_PATH"'],
|
||||
cwd: '/home/user/repo',
|
||||
stdin: null,
|
||||
timeoutMs: 120_000,
|
||||
env: {
|
||||
ORCA_ROOT_PATH: '/home/user/repo',
|
||||
ORCA_WORKTREE_PATH: '/home/user/repo-feature'
|
||||
}
|
||||
})
|
||||
expect(mux.request).toHaveBeenCalledWith(
|
||||
'agent.execNonInteractive',
|
||||
{
|
||||
binary: '/bin/bash',
|
||||
args: ['-lc', 'echo "$ORCA_WORKTREE_PATH"'],
|
||||
cwd: '/home/user/repo',
|
||||
stdin: null,
|
||||
timeoutMs: 120_000,
|
||||
env: {
|
||||
ORCA_ROOT_PATH: '/home/user/repo',
|
||||
ORCA_WORKTREE_PATH: '/home/user/repo-feature'
|
||||
}
|
||||
},
|
||||
{ timeoutMs: 125_000 }
|
||||
)
|
||||
})
|
||||
|
||||
it('cancelNonInteractiveExec sends best-effort relay cancellation', async () => {
|
||||
|
|
@ -432,6 +440,65 @@ describe('SshGitProvider', () => {
|
|||
)
|
||||
})
|
||||
|
||||
it('keeps the transport alive for an agent response beyond the default request timeout', async () => {
|
||||
vi.useFakeTimers()
|
||||
try {
|
||||
const execResult = {
|
||||
stdout: 'Update docs',
|
||||
stderr: '',
|
||||
exitCode: 0,
|
||||
timedOut: false
|
||||
}
|
||||
mux.request.mockImplementation((_method, _payload, options) => {
|
||||
return new Promise((resolve, reject) => {
|
||||
const timeout = setTimeout(
|
||||
() => reject(new Error('transport request timed out')),
|
||||
options?.timeoutMs ?? 30_000
|
||||
)
|
||||
setTimeout(() => {
|
||||
clearTimeout(timeout)
|
||||
resolve(execResult)
|
||||
}, 45_000)
|
||||
})
|
||||
})
|
||||
|
||||
let state: 'pending' | 'resolved' | 'rejected' = 'pending'
|
||||
const pending = provider
|
||||
.executeCommitMessagePlan(
|
||||
{
|
||||
binary: 'codex',
|
||||
args: ['exec', 'PROMPT'],
|
||||
stdinPayload: null,
|
||||
label: 'Codex'
|
||||
},
|
||||
'/home/user/repo',
|
||||
60_000
|
||||
)
|
||||
.then(
|
||||
(result) => {
|
||||
state = 'resolved'
|
||||
return result
|
||||
},
|
||||
(error) => {
|
||||
state = 'rejected'
|
||||
throw error
|
||||
}
|
||||
)
|
||||
void pending.catch(() => {})
|
||||
|
||||
await vi.advanceTimersByTimeAsync(30_000)
|
||||
expect(state).toBe('pending')
|
||||
await vi.advanceTimersByTimeAsync(15_000)
|
||||
|
||||
await expect(pending).resolves.toEqual(execResult)
|
||||
expect(mux.request).toHaveBeenCalledWith('agent.execNonInteractive', expect.any(Object), {
|
||||
timeoutMs: 65_000
|
||||
})
|
||||
} finally {
|
||||
vi.useRealTimers()
|
||||
}
|
||||
})
|
||||
|
||||
it('executeCommitMessagePlan delegates the prepared plan to the relay', async () => {
|
||||
const execResult = {
|
||||
stdout: 'Update docs',
|
||||
|
|
@ -452,14 +519,18 @@ describe('SshGitProvider', () => {
|
|||
60_000
|
||||
)
|
||||
|
||||
expect(mux.request).toHaveBeenCalledWith('agent.execNonInteractive', {
|
||||
binary: 'codex',
|
||||
args: ['exec', 'PROMPT'],
|
||||
cwd: '/home/user/repo',
|
||||
stdin: null,
|
||||
timeoutMs: 60_000,
|
||||
operation: 'commit-message'
|
||||
})
|
||||
expect(mux.request).toHaveBeenCalledWith(
|
||||
'agent.execNonInteractive',
|
||||
{
|
||||
binary: 'codex',
|
||||
args: ['exec', 'PROMPT'],
|
||||
cwd: '/home/user/repo',
|
||||
stdin: null,
|
||||
timeoutMs: 60_000,
|
||||
operation: 'commit-message'
|
||||
},
|
||||
{ timeoutMs: 65_000 }
|
||||
)
|
||||
expect(result).toEqual(execResult)
|
||||
})
|
||||
|
||||
|
|
@ -496,22 +567,32 @@ describe('SshGitProvider', () => {
|
|||
)
|
||||
|
||||
await waitForRequestCount(mux.request, 2)
|
||||
expect(mux.request).toHaveBeenNthCalledWith(1, 'agent.execNonInteractive', {
|
||||
binary: 'codex',
|
||||
args: ['exec', 'PROMPT'],
|
||||
cwd: '/home/user/repo',
|
||||
stdin: null,
|
||||
timeoutMs: 60_000,
|
||||
operation: 'commit-message'
|
||||
})
|
||||
expect(mux.request).toHaveBeenNthCalledWith(2, 'agent.execNonInteractive', {
|
||||
binary: 'codex',
|
||||
args: ['exec', 'PROMPT'],
|
||||
cwd: '/home/user/repo',
|
||||
stdin: null,
|
||||
timeoutMs: 60_000,
|
||||
operation: 'pull-request-fields'
|
||||
})
|
||||
expect(mux.request).toHaveBeenNthCalledWith(
|
||||
1,
|
||||
'agent.execNonInteractive',
|
||||
{
|
||||
binary: 'codex',
|
||||
args: ['exec', 'PROMPT'],
|
||||
cwd: '/home/user/repo',
|
||||
stdin: null,
|
||||
timeoutMs: 60_000,
|
||||
operation: 'commit-message'
|
||||
},
|
||||
{ timeoutMs: 65_000 }
|
||||
)
|
||||
expect(mux.request).toHaveBeenNthCalledWith(
|
||||
2,
|
||||
'agent.execNonInteractive',
|
||||
{
|
||||
binary: 'codex',
|
||||
args: ['exec', 'PROMPT'],
|
||||
cwd: '/home/user/repo',
|
||||
stdin: null,
|
||||
timeoutMs: 60_000,
|
||||
operation: 'pull-request-fields'
|
||||
},
|
||||
{ timeoutMs: 65_000 }
|
||||
)
|
||||
|
||||
await provider.cancelGenerateCommitMessage('/home/user/repo')
|
||||
await provider.cancelGenerateCommitMessage('/home/user/repo', 'pull-request-fields')
|
||||
|
|
@ -556,13 +637,18 @@ describe('SshGitProvider', () => {
|
|||
await first
|
||||
await waitForRequestCount(mux.request, 2)
|
||||
|
||||
expect(mux.request).toHaveBeenNthCalledWith(2, 'agent.execNonInteractive', {
|
||||
binary: 'pnpm',
|
||||
args: ['install'],
|
||||
cwd: '/home/user/repo',
|
||||
stdin: null,
|
||||
timeoutMs: 8000
|
||||
})
|
||||
expect(mux.request).toHaveBeenNthCalledWith(
|
||||
2,
|
||||
'agent.execNonInteractive',
|
||||
{
|
||||
binary: 'pnpm',
|
||||
args: ['install'],
|
||||
cwd: '/home/user/repo',
|
||||
stdin: null,
|
||||
timeoutMs: 8000
|
||||
},
|
||||
{ timeoutMs: 13_000 }
|
||||
)
|
||||
completeRequests.shift()?.()
|
||||
await second
|
||||
})
|
||||
|
|
@ -637,13 +723,18 @@ describe('SshGitProvider', () => {
|
|||
completeRequests.shift()?.()
|
||||
await first
|
||||
await waitForRequestCount(mux.request, 3)
|
||||
expect(mux.request).toHaveBeenNthCalledWith(3, 'agent.execNonInteractive', {
|
||||
binary: 'pnpm',
|
||||
args: ['install'],
|
||||
cwd: '/home/user/repo',
|
||||
stdin: null,
|
||||
timeoutMs: 8000
|
||||
})
|
||||
expect(mux.request).toHaveBeenNthCalledWith(
|
||||
3,
|
||||
'agent.execNonInteractive',
|
||||
{
|
||||
binary: 'pnpm',
|
||||
args: ['install'],
|
||||
cwd: '/home/user/repo',
|
||||
stdin: null,
|
||||
timeoutMs: 8000
|
||||
},
|
||||
{ timeoutMs: 13_000 }
|
||||
)
|
||||
completeRequests.shift()?.()
|
||||
await second
|
||||
})
|
||||
|
|
|
|||
|
|
@ -40,6 +40,8 @@ type NonInteractiveExecQueueEntry = {
|
|||
release: () => void
|
||||
}
|
||||
|
||||
const NON_INTERACTIVE_TRANSPORT_TIMEOUT_MARGIN_MS = 5_000
|
||||
|
||||
function isJsonRpcMethodNotFoundError(error: unknown): boolean {
|
||||
if (!error || typeof error !== 'object') {
|
||||
return false
|
||||
|
|
@ -370,10 +372,9 @@ export class SshGitProvider implements IGitProvider {
|
|||
}
|
||||
}
|
||||
entry.started = true
|
||||
return (await this.mux.request(
|
||||
'agent.execNonInteractive',
|
||||
payload
|
||||
)) as RemoteCommitMessageExecResult
|
||||
return (await this.mux.request('agent.execNonInteractive', payload, {
|
||||
timeoutMs: payload.timeoutMs + NON_INTERACTIVE_TRANSPORT_TIMEOUT_MARGIN_MS
|
||||
})) as RemoteCommitMessageExecResult
|
||||
} finally {
|
||||
signal?.removeEventListener('abort', abortEntry)
|
||||
entry.release()
|
||||
|
|
|
|||
|
|
@ -7,6 +7,7 @@ import { EventEmitter } from 'node:events'
|
|||
import { beforeEach, describe, expect, it, vi } from 'vitest'
|
||||
import { getDefaultSettings } from '../../shared/constants'
|
||||
import { sourceControlAiSettingsFromLegacy } from '../../shared/source-control-ai'
|
||||
import { SSH_MUX_REQUEST_TIMEOUT_CODE } from '../ssh/ssh-channel-multiplexer'
|
||||
import type { GlobalSettings } from '../../shared/types'
|
||||
import {
|
||||
cancelGenerateCommitMessageLocal,
|
||||
|
|
@ -717,6 +718,27 @@ describe('generateCommitMessageFromContext', () => {
|
|||
})
|
||||
})
|
||||
|
||||
it('reports remote model discovery transport timeouts without PATH guidance', async () => {
|
||||
const transportTimeout = Object.assign(
|
||||
new Error('Request "agent.execNonInteractive" timed out after 65000ms'),
|
||||
{ code: SSH_MUX_REQUEST_TIMEOUT_CODE }
|
||||
)
|
||||
const result = await discoverCommitMessageModelsRemote(
|
||||
'cursor',
|
||||
'/remote/repo',
|
||||
async () => {
|
||||
throw transportTimeout
|
||||
},
|
||||
'npx cursor-agent'
|
||||
)
|
||||
|
||||
expect(result).toEqual({
|
||||
success: false,
|
||||
error:
|
||||
'Cursor model discovery took longer than 60s and may still be running on the remote host.'
|
||||
})
|
||||
})
|
||||
|
||||
it('reports remote model discovery spawn failures with remote install guidance', async () => {
|
||||
const result = await discoverCommitMessageModelsRemote('cursor', '/remote/repo', async () => ({
|
||||
stdout: '',
|
||||
|
|
@ -1229,6 +1251,39 @@ describe('generateCommitMessageFromContext', () => {
|
|||
})
|
||||
})
|
||||
|
||||
it('reports a remote transport timeout without claiming the agent is unreachable', async () => {
|
||||
const transportTimeout = Object.assign(
|
||||
new Error('Request "agent.execNonInteractive" timed out after 65000ms'),
|
||||
{ code: SSH_MUX_REQUEST_TIMEOUT_CODE }
|
||||
)
|
||||
const result = await generateCommitMessageFromContext(
|
||||
{
|
||||
branch: 'main',
|
||||
stagedSummary: 'M\tREADME.md',
|
||||
stagedPatch: '+hello'
|
||||
},
|
||||
{
|
||||
agentId: 'custom',
|
||||
model: '',
|
||||
customAgentCommand: 'agent'
|
||||
},
|
||||
{
|
||||
kind: 'remote',
|
||||
cwd: '/repo',
|
||||
missingBinaryLocation: 'remote PATH',
|
||||
execute: async () => {
|
||||
throw transportTimeout
|
||||
}
|
||||
}
|
||||
)
|
||||
|
||||
expect(result).toEqual({
|
||||
success: false,
|
||||
error: 'agent took longer than 60s to respond and may still be running on the remote host.',
|
||||
canceled: undefined
|
||||
})
|
||||
})
|
||||
|
||||
it('sanitizes remote execution transport failures', async () => {
|
||||
const result = await generateCommitMessageFromContext(
|
||||
{
|
||||
|
|
|
|||
|
|
@ -59,6 +59,7 @@ import {
|
|||
import { withMacTailscaleDnsHint } from '../network/macos-tailscale-dns-diagnostic'
|
||||
import { wslAwareSpawn } from '../git/runner'
|
||||
import { terminateWindowsProcessTree } from '../windows-process-tree-kill'
|
||||
import { isSshMuxRequestTimeoutError } from '../ssh/ssh-channel-multiplexer'
|
||||
|
||||
const GENERATION_TIMEOUT_MS = 60_000
|
||||
const MAX_AGENT_OUTPUT_BYTES = 4 * 1024 * 1024
|
||||
|
|
@ -519,6 +520,12 @@ export async function discoverCommitMessageModelsRemote(
|
|||
result = await execute(planned.plan, cwd, GENERATION_TIMEOUT_MS)
|
||||
} catch (error) {
|
||||
console.error('[commit-message] Remote model discovery request failed:', error)
|
||||
if (isSshMuxRequestTimeoutError(error)) {
|
||||
return {
|
||||
success: false,
|
||||
error: `${spec.label} model discovery took longer than ${GENERATION_TIMEOUT_MS / 1000}s and may still be running on the remote host.`
|
||||
}
|
||||
}
|
||||
return {
|
||||
success: false,
|
||||
error: `${spec.label} model discovery could not be reached on the remote PATH. Try again after the SSH connection recovers.`
|
||||
|
|
@ -996,6 +1003,12 @@ async function runRemotePlan(
|
|||
result = await target.execute(plan, target.cwd, GENERATION_TIMEOUT_MS, operation)
|
||||
} catch (error) {
|
||||
console.error('[commit-message] Remote generator request failed:', error)
|
||||
if (isSshMuxRequestTimeoutError(error)) {
|
||||
return {
|
||||
success: false,
|
||||
error: `${label} took longer than ${GENERATION_TIMEOUT_MS / 1000}s to respond and may still be running on the remote host.`
|
||||
}
|
||||
}
|
||||
return {
|
||||
success: false,
|
||||
error: `${label} could not be reached on the ${target.missingBinaryLocation}. Try again after the SSH connection recovers.`
|
||||
|
|
|
|||
Loading…
Reference in New Issue