diff --git a/docs/ko/upstream-update.md b/docs/ko/upstream-update.md index 0796c41..933dadc 100644 --- a/docs/ko/upstream-update.md +++ b/docs/ko/upstream-update.md @@ -46,6 +46,10 @@ PR에 이전·새 SHA, 동작 변경, 테스트 근거를 기록합니다. 호 전체 로컬 검증은 `python3 scripts/validate-upstream.py all`로 실행합니다. CI도 같은 이름의 단계를 병렬 실행하며 목록은 `--help`로 확인합니다. 보고서와 명령 로그는 기본적으로 `target/upstream-reports/local`에 생성됩니다. +단계가 실패하면 스크립트는 그 단계 로그에서 무엇이 실패했는지 알려 주는 줄, 곧 +실패한 테스트와 panic 위치, 테스트 수, 실패한 cargo나 unittest 대상도 출력하므로 +CI job 로그에서 바로 확인할 수 있습니다. 테스트 자체의 출력은 자식 프로세스의 +환경을 담을 수 있어 로그에만 남깁니다. 시도마다 `--output`으로 다른 Git 무시 디렉터리를 지정하거나 이전 결과를 보관합니다. 보고서에는 소스 HEAD, Codex SHA, Rust 호스트, 소스와 lockfile 해시가 기록되며 실행 중 입력이 바뀌면 실패합니다. `passed`는 기록된 단계만의 통과를 뜻합니다. diff --git a/docs/translations.json b/docs/translations.json index dbf73e1..435a08c 100644 --- a/docs/translations.json +++ b/docs/translations.json @@ -800,8 +800,8 @@ "향후-crate와-백엔드의-경계", "후보-검토" ], - "source_sha256": "ddad4af90f67de89b70c93ff143b72386bc0227e66dadeba3cf73491dab1e853", - "translation_sha256": "070d7b0a63d6835df285bd8f8905c4a9c4e4ec0144b25d1e0ec527d9f5ee2985" + "source_sha256": "f0846a7de343b43410f0df86873ea3773b863baabc2379c27eb2f69d9bcd7409", + "translation_sha256": "9a99fb130cbd1099f3b58134ba0907f9edcd11f917bd1e3445209509bfc5098b" }, { "id": "upstream-patches", diff --git a/docs/upstream-update.md b/docs/upstream-update.md index 17d00cc..d8c108d 100644 --- a/docs/upstream-update.md +++ b/docs/upstream-update.md @@ -42,6 +42,10 @@ Open a PR with the old/new SHA, behavioral changes, and test evidence. Do not me Run `python3 scripts/validate-upstream.py all` for the complete local sequence. CI calls the same named stages in parallel; use `--help` to list them. Reports and command logs default to `target/upstream-reports/local`. +When a stage fails, the script also prints the lines of that stage's log that +name what failed: the failed tests and where they panicked, the test counts, and +the failed cargo or unittest target, so a CI job log names them. A test's own +output stays in the log, since its messages can carry a child's environment. Choose a different ignored directory with `--output` for each attempt; preserve previous reports before repeating a run. Reports record the source HEAD, Codex SHA, Rust host, and source/lockfile hashes. A changed input invalidates the run. diff --git a/scripts/tests/test_upstream.py b/scripts/tests/test_upstream.py index 48e335b..e44a758 100644 --- a/scripts/tests/test_upstream.py +++ b/scripts/tests/test_upstream.py @@ -1,3 +1,4 @@ +import contextlib import importlib.util import io import json @@ -15,6 +16,38 @@ spec.loader.exec_module(validation) +# A stage's log as cargo writes it when a test fails, with a secret in the failure's messages. +FAILED_LOG = """+ cargo test --locked -p codespace-runner --lib -- wire + Running unittests src/lib.rs (target/upstream-validation/debug/deps/codespace_runner-01d87e8c1b2c1a82) + +running 3 tests +test wire::tests::passes ... ok +test wire::tests::slow has been running for over 60 seconds +test wire::tests::fails ... FAILED +test wire::tests::slow ... ok + +failures: + +---- wire::tests::fails stdout ---- + +thread 'worker' (585) panicked at crates/runner/src/wire.rs:21:68: +child said: SECRET_TOKEN=abc +thread 'wire::tests::fails' (583) panicked at crates/runner/src/wire.rs:13:9: +assertion `left == right` failed: SECRET_TOKEN=abc + left: 1 + right: 2 +note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace + + +failures: + wire::tests::fails + +test result: FAILED. 2 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 61.28s + +error: test failed, to rerun pass `-p codespace-runner --lib` +""" + + def fixture(names, edges, sources=None): """Codex packages sit in the gitlink, others in `crates/`, unless `sources` names another.""" def manifest(n): @@ -211,6 +244,57 @@ def test_failure_report(self): report = json.loads((Path(tmp) / 'report.json').read_text()) self.assertEqual(report['stages'][0]['status'], 'failed') + def test_a_failed_stage_names_its_failed_tests_and_none_of_their_output(self): + def fail(commands, env, log): + log.write(FAILED_LOG) + raise RuntimeError('command exited 101') + with tempfile.TemporaryDirectory() as tmp, \ + patch.object(validation, 'fingerprint', return_value={'head': 'a', 'codex_sha': 'pin'}), \ + patch.object(validation, 'apply_codex_patches', return_value=None), \ + patch.object(validation, 'capture', return_value='host: x86_64-unknown-linux-gnu'), \ + patch.object(validation, 'execute', side_effect=fail), \ + contextlib.redirect_stdout(io.StringIO()) as printed: + self.assertEqual(validation.run(['unit-pty'], Path(tmp)), 1) + self.assertIn('\n'.join([ + 'unit-pty failed; from unit-pty.log:', + ' test wire::tests::slow has been running for over 60 seconds', + ' test wire::tests::fails ... FAILED', + " thread 'worker' (585) panicked at crates/runner/src/wire.rs:21:68:", + " thread 'wire::tests::fails' (583) panicked at crates/runner/src/wire.rs:13:9:", + ' test result: FAILED. 2 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 61.28s', + ' error: test failed, to rerun pass `-p codespace-runner --lib`\n']), printed.getvalue()) + self.assertNotIn('SECRET', printed.getvalue()) + + def test_failure_lines_are_names_counts_and_locations_only(self): + named = ['test src/lib.rs - one (line 1) ... FAILED', + 'error: doctest failed, to rerun pass `--doc`', + "process didn't exit successfully: `/t/debug/deps/crash-3f65` (signal: 6, SIGABRT: process abort signal)", + 'error: could not compile `codespace-runner` (lib test) due to 1 previous error', + 'ERROR: test_broken (unittest.loader._FailedTest.test_broken)', + "FAIL: test_sub (test_upstream.RunnerTests.test_sub) (stage='pin')", + 'FAILED (failures=2, errors=1)'] + output = ['SECRET_TOKEN=abc', 'AssertionError: 1 != 2 : SECRET_TOKEN=abc', + "thread 'main' panicked at 'SECRET_TOKEN=abc', src/lib.rs:1:1", + "thread 'main' (1) panicked at src/lib.rs:1:1: SECRET_TOKEN=abc", + 'test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.01s', + 'test wire::tests::passes ... ok', ' wire::tests::fails'] + with tempfile.TemporaryDirectory() as tmp: + log = Path(tmp) / 'stage.log' + log.write_text('\n'.join(output + named + named) + '\n') + self.assertEqual(validation.failure_lines(log), named) + + def test_an_unreadable_log_or_many_failures_keep_the_summary_short(self): + with tempfile.TemporaryDirectory() as tmp, contextlib.redirect_stdout(io.StringIO()) as printed: + log = Path(tmp) / 'unit-pty.log' + validation.print_failures('unit-pty', log) + log.write_text(''.join(f'test t{n} ... FAILED\n' for n in range(validation.FAILURES_SHOWN + 10))) + validation.print_failures('unit-pty', log) + lines = printed.getvalue().splitlines() + self.assertTrue(lines[0].startswith('unit-pty failed; its log could not be read: ')) + self.assertEqual(lines[1], 'unit-pty failed; from unit-pty.log:') + self.assertEqual(len(lines), 2 + validation.FAILURES_SHOWN + 1) + self.assertEqual(lines[-1], ' and 10 more lines in unit-pty.log') + if __name__ == '__main__': unittest.main() diff --git a/scripts/validate-upstream.py b/scripts/validate-upstream.py index f9e138f..66c8149 100644 --- a/scripts/validate-upstream.py +++ b/scripts/validate-upstream.py @@ -7,6 +7,7 @@ import os from pathlib import Path import platform +import re import subprocess import sys import time @@ -175,6 +176,46 @@ def execute(commands, env, log): raise RuntimeError(f'command exited {status}: {command}') +# The lines of a failed stage's log that name what failed: the failed tests and where they +# panicked, a test binary's counts and the target that cargo or unittest failed. They are also +# printed, so a CI job log names them without the uploaded report. A test's own output is never +# repeated: its messages can carry a child's environment. +FAILURE_LINE = re.compile('|'.join([ + r'test \S.* \.\.\. FAILED', + r'test \S.* has been running for over \d+ seconds', + r"thread '[^']*'(?: \(\d+\))? panicked at [^\s']+:\d+:\d+:", + r'test result: FAILED\. \d+ passed; \d+ failed; \d+ ignored; \d+ measured; \d+ filtered out; finished in [\d.]+s', + r'error: (?:doc)?test failed, to rerun pass `[^`]*`', + r'error: could not compile `[\w-]+`[^`]*', + r"process didn't exit successfully: `[^`]*` \([^()]*\)", + r'(?:FAIL|ERROR): \w+ \([\w.]+\)(?: \([^()]*\))?', + r'FAILED \([\w ]+=\d+(?:, [\w ]+=\d+)*\)'])) +# Enough for one test binary's failures; the log keeps the rest. +FAILURES_SHOWN = 40 + + +def failure_lines(path): + """The lines of a stage's log that FAILURE_LINE matches, each once, in order.""" + with path.open(encoding='utf-8', errors='replace') as log: + lines = (line.strip() for line in log) + return list(dict.fromkeys(line for line in lines if FAILURE_LINE.fullmatch(line))) + + +def print_failures(stage, path): + """Print what a failed stage's log names as failed. A log that cannot be read changes nothing + but this summary.""" + try: + lines = failure_lines(path) + except OSError as error: + print(f'{stage} failed; its log could not be read: {error}', flush=True) + return + print(f'{stage} failed; ' + (f'from {path.name}:' if lines else f'{path.name} names no failed test'), flush=True) + for line in lines[:FAILURES_SHOWN]: + print(' ' + line, flush=True) + if len(lines) > FAILURES_SHOWN: + print(f' and {len(lines) - FAILURES_SHOWN} more lines in {path.name}', flush=True) + + def run(selected, output): output.mkdir(parents=True, exist_ok=True) report = {'schema': 1, 'platform': platform.platform(), 'stages': [], 'status': 'failed'} @@ -227,6 +268,7 @@ def run(selected, output): except (OSError, RuntimeError) as error: entry['error'] = str(error) failed = True + print_failures(stage, output / (stage + '.log')) entry['seconds'] = round(time.monotonic() - started, 2) fork_race = output / 'fork-race' / 'summary.json' if stage == 'macos-fork-race' and fork_race.is_file():