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
29 changes: 29 additions & 0 deletions .github/workflows/qwen-code-pr-review.yml
Original file line number Diff line number Diff line change
Expand Up @@ -1133,6 +1133,23 @@ jobs:
fi
export QWEN_REVIEW_DEADLINE_RESERVE_SECONDS
set +e
# The agent streams its ENTIRE transcript to stdout, and the runner
# scans every line for workflow commands. A tool result that quotes
# a file containing one is executed as a command: reviewing a PR
# that touches `actions/setup-node`, the agent read that action's
# own main.ts, which legitimately contains
# `core.info(\`##[add-matcher]${...}\`)`. The runner took the rest
# of the JSON line as a matcher path and errored. Observed on run
# 31167034020 (PR #8681): three `Unable to process command`, and
# 1h37m of review work discarded. Any PR whose review quotes a file
# containing `##[...]` or `::...::` breaks the same way — this

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

[Suggestion] The ::...:: half of this claim is not reachable, and stating it here misdescribes the threat model the guard defends against.

Verified against actions/runner@main, src/Runner.Common/ActionCommand.cs:

  • TryParseV2 (::cmd::…) — message.TrimStart() then StartsWith("::"): line start only.
  • TryParse (##[cmd]…) — message.IndexOf("##["): anywhere in the line.

Under --output-format stream-json every transcript line starts with {, and JSON escapes newlines as \n, so quoted file content can never place a ::…:: at a line start. Only the ##[…] form is reachable from a quoted file — which is exactly why the incident fired from inside a JSON line, and exactly why the resume below needs its leading newline. As written, the comment implies the two forms are symmetric; a future reader could reasonably conclude the leading-newline printf is interchangeable with an echo.

Suggest narrowing to the ##[...] form (the ::...:: asymmetry is worth one clause, since it is what makes the resume fragile).

Raised in the round-1 self-review; still on head.

中文说明

这句里的 ::...:: 一半不可达,写在这里会误述该守卫真正防的威胁模型。

对照 actions/runner@mainsrc/Runner.Common/ActionCommand.cs 核实:TryParseV2::cmd::…)先 TrimStart()StartsWith("::")仅行首匹配;TryParse##[cmd]…)用 IndexOf("##[")行内任意位置匹配。

--output-format stream-json 下每行会话都以 { 开头,且 JSON 把换行转义成 \n,因此被引用的文件内容永远无法把 ::…:: 放到行首。能从引用文件触发的只有 ##[…] 形式——这正是事故从 JSON 行内部触发的原因,也正是下面 resume 必须以换行开头的原因。按现在的写法,注释暗示两种形式对称,后来的读者可能因此认为那个带前导换行的 printfecho 可以互换。

建议收窄为只讲 ##[...] 形式(::...:: 的不对称性值得单独一句,因为它才是 resume 脆弱的根源)。第一轮自审已提出,head 上仍未修改。

# repository's own workflows included.
# Turn command parsing off around the agent and nothing else. The
# token is random per attempt, so no output the agent produces can
# guess it and re-enable parsing early.
local stop_token
stop_token="qwen-review-stop-$(date +%s%N)-${RANDOM}${RANDOM}"
echo "::stop-commands::${stop_token}"
# GNU timeout times out command children unless --foreground is used.
timeout --kill-after=10s "${attempt_timeout}s" qwen \
--auth-type openai \
Expand All @@ -1142,6 +1159,18 @@ jobs:
--output-format stream-json \
| tee "$LOG_PATH"
local ps=("${PIPESTATUS[@]}")
# Resume BEFORE anything else can exit: errexit is still off here,
# so this line is reached on every agent outcome — timeout, crash
# or success. Leaving it off would silently swallow this job's own
# ::error:: and the fallback comment's diagnostics for the rest of

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

[Suggestion] Both specifics in this justification are wrong, while the real justification is stronger and sits one screen below.

  • this job's own ::error:: — this step has no ::error::. fail() (line 753) does echo "$message" >&2, echo "failure_reason=…" >> "$GITHUB_OUTPUT" and echo "$message" >> "$GITHUB_STEP_SUMMARY". Nothing there is a stdout workflow command.
  • the fallback comment's diagnostics for the rest of the runPost fallback comment on failure is a separate step, and _stopProcessCommand cannot cross a step boundary: ActionCommandManager is constructed per handler in Runner.Worker/Handlers/Handler.cs (hostContext.CreateService<IActionCommandManager>(), non-singleton). It also reads failure_reason from $GITHUB_OUTPUT, which is file-based either way. The blast radius is the remainder of this step, not the run.

The one thing a missing resume actually loses is echo "::warning::Transient review failure (${REASON}) — retrying once…" on line 1281 — same step, after the resume, on the retry path this guard exists to survive. The test's own comment already says exactly that ("losing the retry ::warning::"); the workflow comment is the one that drifted.

The code is correct as-is — only the stated reason needs narrowing to the retry ::warning:: and to "the rest of this step".

Raised in the round-1 self-review; still on head.

中文说明

这段理由里的两个具体说法都不成立,而真正的理由更有力、就在下方一屏处。

  • this job's own ::error:: —— 本步骤没有任何 ::error::fail()(753 行)只做 echo "$message" >&2echo "failure_reason=…" >> "$GITHUB_OUTPUT"echo "$message" >> "$GITHUB_STEP_SUMMARY",其中没有 stdout 工作流命令。
  • the fallback comment's diagnostics for the rest of the run —— Post fallback comment on failure 是独立步骤,而 _stopProcessCommand 无法跨步骤:ActionCommandManagerRunner.Worker/Handlers/Handler.cs 中按 handler(即按步骤)构造(hostContext.CreateService<IActionCommandManager>(),非单例)。该步骤还是从 $GITHUB_OUTPUTfailure_reason,本就是基于文件的。影响范围是本步骤的剩余部分,而不是整个 run。

resume 缺失真正会丢掉的,是 1281 行的 echo "::warning::Transient review failure (${REASON}) — retrying once…" —— 同一步骤、位于 resume 之后、正好在这个守卫要保住的重试路径上。测试里的注释已经写对了("losing the retry ::warning::"),是 workflow 注释这边跑偏了。

代码本身没问题,只需把理由收窄到重试的 ::warning:: 和"本步骤的剩余部分"。第一轮自审已提出,head 上仍未修改。

# the run, turning one broken review into a silent one.
# Lead with a newline: the runner only recognises `::cmd::` at the
# start of a line, and `--kill-after` SIGKILLs the agent, which can
# leave a partial stream-json line with no trailing newline. An
# `echo` would append the resume to that fragment, where it is just
# text — parsing would stay off for the rest of the job, on exactly
# the path this guard exists to survive.
printf '\n::%s::\n' "$stop_token"
set -e
local qwen_status="${ps[0]}"
local tee_status="${ps[1]}"
Expand Down
153 changes: 150 additions & 3 deletions scripts/tests/qwen-pr-review-workflow.test.js
Original file line number Diff line number Diff line change
Expand Up @@ -54,7 +54,7 @@ function retryLoopSource() {

// Drive the extracted loop with a stub qwen whose stream-json `result` event is
// scripted per attempt, plus stub timeout/sleep so the test is instant.
function runScenario(scenario, { timeoutMinutes = 180 } = {}) {
function runScenario(scenario, { timeoutMinutes = 180, logPath } = {}) {
const dir = mkdtempSync(join(tmpdir(), 'review-retry-'));
try {
const bin = join(dir, 'bin');
Expand All @@ -71,9 +71,21 @@ function runScenario(scenario, { timeoutMinutes = 180 } = {}) {
// timeout: record the per-attempt duration (`$2`, e.g. `10800s`) so tests
// can assert the budget each attempt was given, then drop
// `--kill-after=Xs` and that duration and exec the rest.
// `timeout_kill` dies before the agent ever runs; `timeout_partial_line`
// lets it stream first and only then reports 124, which is what a real
// `--kill-after` SIGKILL looks like: output already on stdout, cut off
// mid-line.
write(
'timeout',
'#!/bin/bash\necho "$2" >> "$DUR"\nif [ "${SCENARIO:-}" = "timeout_kill" ]; then exit 124; fi\nshift\nshift\nexec "$@"\n',
[
'#!/bin/bash',
'echo "$2" >> "$DUR"',
'if [ "${SCENARIO:-}" = "timeout_kill" ]; then exit 124; fi',
'shift',
'shift',
'if [ "${SCENARIO:-}" = "timeout_partial_line" ]; then "$@"; exit 124; fi',
'exec "$@"',
].join('\n') + '\n',
);
write('sleep', '#!/bin/bash\nexit 0\n');
write(
Expand All @@ -97,6 +109,13 @@ function runScenario(scenario, { timeoutMinutes = 180 } = {}) {
' success_mentions_api_error) PAD=$(printf "x%.0s" $(seq 1 600)); r success false "This PR detects the [API Error: ...] pattern and routes to retry. quota and rate.?limit keywords cover the common messages. ${PAD} Review complete: COMMENT posted (0 Critical, 1 Suggestion inline)." ;;',
' success_quotes_status_code) PAD=$(printf "x%.0s" $(seq 1 700)); r success false "This PR adds retry for [API Error: 429 quota exceeded] and similar. ${PAD} Verdict: COMMENT, 0 Critical." ;;',
' success_ends_with_bracket) r success false "Review of [API Error: 429 quota exhausted] handling. Checklist: - [x]" ;;',
// A transcript that quotes a file containing a workflow command. The
// real case: reviewing a PR that touches actions/setup-node, the agent
// read that action's main.ts, which contains `##[add-matcher]...`.
' workflow_command) printf \'{"type":"assistant","content":"90- const matchersPath = ...\\n91- core.info(`##[add-matcher]${path.join(matchersPath, \\x27tsc.json\\x27)}`);"}\\n\'; r success false "Review complete: COMMENT posted (0 Critical)." ;;',
// Killed mid-write: the last line reaches stdout WITHOUT its newline,
// so whatever the step prints next lands on the same line.
' timeout_partial_line) printf \'{"type":"assistant","content":"90- core.info(`##[add-matcher]x`);"}\\n{"type":"assistant","content":"91- trunc\' ;;',
' errresult) r error true "connection dropped mid-review" ;;',
' hardexit) exit 3 ;;',
'esac',
Expand All @@ -106,7 +125,7 @@ function runScenario(scenario, { timeoutMinutes = 180 } = {}) {
const harness = [
'set -euo pipefail',
`QWEN_TIMEOUT=${timeoutMinutes}; MODEL_ARGS=(--model x); PROMPT="/review x"`,
`LOG_PATH="${join(dir, 'log')}"`,
`LOG_PATH="${logPath ?? join(dir, 'log')}"`,
`GITHUB_OUTPUT="${join(dir, 'gho')}"; GITHUB_STEP_SUMMARY="${join(dir, 'gss')}"`,
': > "$GITHUB_OUTPUT"; : > "$GITHUB_STEP_SUMMARY"',
'fail(){ echo "FAIL kind=[${3:-}] reason=[$1]"; exit "${2:-1}"; }',
Expand Down Expand Up @@ -140,6 +159,9 @@ function runScenario(scenario, { timeoutMinutes = 180 } = {}) {
.map((d) => Number.parseInt(d, 10));
return {
line,
// The whole transcript, so the stop-commands bracket around the agent
// can be checked in the order the runner would see it.
raw: stdout,
attempts: Number(readFileSync(attemptFile, 'utf8').trim()),
durations,
};
Expand All @@ -148,6 +170,131 @@ function runScenario(scenario, { timeoutMinutes = 180 } = {}) {
}
}

describe('qwen pr review workflow-command containment', () => {
// The agent streams its whole transcript to stdout and the runner scans every
// line for workflow commands, so a tool result that quotes a file containing
// one gets EXECUTED. Observed on run 31167034020 (PR #8681): the agent read
// actions/setup-node's main.ts, whose `core.info(\`##[add-matcher]...\`)`
// made the runner take the rest of the JSON line as a matcher path — three
// `Unable to process command` errors and 1h37m of review work discarded.
// The runner matches `::cmd::` at the start of a line only, so both ends of
// the bracket are located as WHOLE lines — a resume glued onto a partial
// transcript line is inert text, and finding it by substring would report a
// bracket the runner never closed.
const bracketOf = (raw) => {
const lines = raw.split('\n');
const stopIdx = lines.findIndex((l) => l.startsWith('::stop-commands::'));
const token =
stopIdx === -1
? undefined
: lines[stopIdx].slice('::stop-commands::'.length);
return {
token,
lines,
stopAt: stopIdx === -1 ? -1 : raw.indexOf(lines[stopIdx]),
resumeAt: token ? raw.indexOf(`\n::${token}::\n`) : -1,
};
};

it('brackets the agent transcript so a quoted command is inert', () => {
const r = runScenario('workflow_command');
// The review still succeeds — containment must not change the outcome.
expect(r.line).toContain('OK outcome=success');

const { token, stopAt, resumeAt } = bracketOf(r.raw);
expect(token).toBeTruthy();
// A fixed token could be re-enabled by anything the agent chose to print.
expect(token).not.toBe('stop-commands');
expect(token.length).toBeGreaterThan(16);
Comment thread
wenshao marked this conversation as resolved.

// The dangerous line must land strictly INSIDE the bracket.
const injected = r.raw.indexOf('##[add-matcher]');
expect(injected).toBeGreaterThan(stopAt);
expect(resumeAt).toBeGreaterThan(injected);
});

it('resumes command parsing on every agent outcome', () => {
// Left off, the rest of the job goes silent: its own ::error:: and the
// fallback comment's diagnostics would stop reaching the log — turning one
// broken review into an unexplained one. The failure paths are the ones
// that matter, since they are what still needs to report.
for (const scenario of ['success', 'hardexit', 'timeout_kill']) {
Comment thread
wenshao marked this conversation as resolved.
const { token, resumeAt } = bracketOf(runScenario(scenario).raw);
expect(token, scenario).toBeTruthy();
Comment thread
wenshao marked this conversation as resolved.
expect(resumeAt, scenario).toBeGreaterThan(-1);
Comment thread
wenshao marked this conversation as resolved.
}
});

it('resumes on its own line when the agent is killed mid-write', () => {
// `--kill-after` SIGKILLs the agent, so its last stream-json line can reach
// stdout without a trailing newline. An `echo`d resume would be appended to
// that fragment, where the runner never sees it at a line start: parsing
// stays off for the remainder of the job — losing the retry `::warning::`
// and every later diagnostic — on the exact path the guard exists for.
const r = runScenario('timeout_partial_line');
expect(r.line).toContain('FAIL kind=[timeout]');

const { token, lines } = bracketOf(r.raw);
expect(token).toBeTruthy();
// The agent's truncated line really is truncated, or this proves nothing.
expect(lines.some((l) => l.endsWith('"91- trunc'))).toBe(true);
expect(lines).toContain(`::${token}::`);
});

it('resumes command parsing when the log write fails', () => {
// The tee-failure branch returns before every other check, so a resume
// relocated past it would leave parsing off exactly when the step still has
// to report why it failed.
const r = runScenario('success', {
logPath: join(sep, 'nonexistent-qwen-review-dir', 'log'),
});
expect(r.line).toContain('Failed to write qwen review log');
const { token, resumeAt } = bracketOf(r.raw);
expect(token).toBeTruthy();
expect(resumeAt).toBeGreaterThan(-1);
});

it('opens a fresh bracket for every attempt', () => {
// Hoisting the stop echo and token out of `run_review_once` would still
// pass every single-attempt test, but attempt 2 would then run unbracketed
// under a token the runner has already consumed.
const r = runScenario('transient_then_success');
expect(r.attempts).toBe(2);
const tokens = r.raw
.split('\n')
.filter((l) => l.startsWith('::stop-commands::'))
.map((l) => l.slice('::stop-commands::'.length));
expect(tokens).toHaveLength(2);
// Per-attempt randomness: a reused token is one the transcript has already
// had the chance to print.
expect(new Set(tokens).size).toBe(2);
for (const t of tokens) {
expect(r.raw.split('\n')).toContain(`::${t}::`);
}
});

it('reads the agent exit status before resuming', () => {
// `echo` clobbers PIPESTATUS, so a resume placed before the capture would
// read the echo's status instead of the agent's and report every timeout
// or crash as a clean run. Pinned on the source because the symptom is a
// silent misclassification, not a failure.
const run = runReviewStep();
const capture = run.indexOf('local ps=("${PIPESTATUS[@]}")');
const resume = run.indexOf('printf \'\\n::%s::\\n\' "$stop_token"');
const stop = run.indexOf('echo "::stop-commands::${stop_token}"');
const agent = run.indexOf('--output-format stream-json');
// Every anchor is asserted present: `indexOf` returns -1 when a line is
// deleted or reworded, and -1 satisfies every ordering comparison below.
expect(capture).toBeGreaterThan(-1);
expect(resume).toBeGreaterThan(-1);
expect(stop).toBeGreaterThan(-1);
expect(agent).toBeGreaterThan(-1);
expect(resume).toBeGreaterThan(capture);
// And the stop must come before the agent it is meant to contain.
expect(stop).toBeLessThan(agent);
});
});

describe('qwen pr review transient retry', () => {
it('does not retry a clean success', () => {
const r = runScenario('success');
Expand Down
Loading