[ai] Match the completion marker as a whole log line

Task: 2026/09/02/match-the-test-complete-marker-as-a-whole-line
This commit is contained in:
John Preston
2026-09-02 23:57:22 +04:00
parent 5f39bf165b
commit aec4539f90
3 changed files with 78 additions and 5 deletions

View File

@@ -504,7 +504,8 @@ so it can never run against real account data. The overlay must:
- Log through `test_log.h` (`Step`/`Pass`/`Fail`/`Check`/`Note`/`CheckNear`/`LogGeometry`) —
it already writes the flushed absolute-path log and the exact `TEST_STEP` / `TEST_RESULT` /
`SCREENSHOT` / `TEST_COMPLETE` markers the external runner parses. Never hand-roll marker
strings or log files.
strings or log files. The runner reads `TEST_COMPLETE` as a whole line, so a stage name, note
or check detail that quotes the marker inside a longer line is safe and never ends the run.
- **Capture the target tightly** with `CaptureWidget`/`CaptureRect` — the specific widget /
row / glyph, unambiguously in frame at usable resolution. A full-window grab that leaves the
target clipped, off-screen, or thumbnail-sized is NOT acceptable evidence — if the target
@@ -613,7 +614,10 @@ command, environment, exit-code, log, artifact and control evidence.
from launch** and a quiet-log watchdog while polling `<EVIDENCE_DIR>/test_log.txt`, detects
`TEST_COMPLETE` versus process death (crash) versus the caps elapsing (hang), kills any
straggler, and returns one JSON report with the parsed markers, stderr tail, fresh crash
diagnostics, `crashpad_dumps_added`, `death_signals`, and `stale_crash_cleared`.
diagnostics, `crashpad_dumps_added`, `death_signals`, and `stale_crash_cleared`. The
completion marker is matched as a **whole log line** — a line equal to `TEST_COMPLETE` once
trailing whitespace is dropped — and never as a substring, so a line that merely quotes it,
such as `NOTE: mtp: rpc retry code=500 type=TEST_COMPLETE request=0x…`, is not a completion.
`TEST_COMPLETE` alone is not success: when the process writes it and then dies, the verdict is
`died-after-complete`, not `complete`, on any of three independent signals — a non-zero
`exit_code`, a new `.dmp` in the live `tdata/dumps/completed/` Crashpad database across the run,

View File

@@ -2302,6 +2302,21 @@ def parse_test_log(text):
}
def log_marks_complete(text):
# Whole-line match, never a substring. A line that merely contains the
# literal would otherwise end a live run: a note, stage name or check
# detail quoting the marker, or the permanent MTP seam's
# "rpc retry code=500 type=TEST_COMPLETE request=0x..." row, whose type
# comes straight from a server-sent rpc_error. Trailing whitespace is
# dropped so a stray space or a reader that leaves a CR still counts;
# leading whitespace is not, because Test::Complete() writes the marker
# flush left.
return any(
line.rstrip() == TEST_COMPLETE_MARKER
for line in text.splitlines()
)
def tail_of_file(path, lines=60):
if not path.is_file():
return None
@@ -2378,9 +2393,9 @@ def command_test_run(args):
last_change = now
complete = False
if size > 0:
complete = TEST_COMPLETE_MARKER in log_path.read_text(
complete = log_marks_complete(log_path.read_text(
encoding="utf-8", errors="replace"
)
))
if complete and complete_seen_at is None:
complete_seen_at = now
exit_code = process.poll()
@@ -2408,7 +2423,7 @@ def command_test_run(args):
if log_path.is_file()
else ""
)
test_complete = TEST_COMPLETE_MARKER in log_text
test_complete = log_marks_complete(log_text)
crash_report_fresh = (
working.is_file()
and working.stat().st_mtime_ns != working_before

View File

@@ -1908,6 +1908,28 @@ class MechanicsTest(unittest.TestCase):
self.assertEqual(markers["steps"], ["gated stage self-test: arm"])
self.assertEqual(markers["screenshots"], ["/tmp/fake.png"])
def test_log_marks_complete_reads_the_marker_as_a_whole_line(self):
for text in [
"TEST_COMPLETE",
"TEST_COMPLETE\n",
"TEST_COMPLETE\r\n",
"TEST_COMPLETE ",
"TEST_STEP: open settings\nTEST_COMPLETE\n",
"NOTE: waiting\nTEST_COMPLETE",
]:
self.assertTrue(workspace.log_marks_complete(text), repr(text))
for text in [
"",
"NOTE: waiting for TEST_COMPLETE\n",
"NOTE: mtp: rpc retry code=500 type=TEST_COMPLETE "
"request=0x0000002d\n",
"TEST_COMPLETED\n",
"TEST_COMPLETE_LATER\n",
" TEST_COMPLETE\n",
"TEST_RESULT: PASS: TEST_COMPLETE\n",
]:
self.assertFalse(workspace.log_marks_complete(text), repr(text))
def test_test_run_reports_a_death_after_complete(self):
with tempfile.TemporaryDirectory() as temporary:
root = Path(temporary)
@@ -2128,6 +2150,38 @@ class MechanicsTest(unittest.TestCase):
self.assertIsNone(result["exit_code"])
self.assertEqual(result["death_signals"], [])
def test_test_run_refuses_a_line_that_only_contains_the_marker(self):
with tempfile.TemporaryDirectory() as temporary:
root = Path(temporary)
debug = make_portable_root(root)
line = (
"NOTE: mtp: rpc retry code=500 type=TEST_COMPLETE"
" request=0x0000002d"
)
exe = write_fake_exe(debug / "Telegram", (
'LOG="$TDESKTOP_TEST_EVIDENCE_DIR/test_log.txt"\n'
f'echo "{line}" >> "$LOG"\n'
"sleep 30\n"
), (
'set "LOG=%TDESKTOP_TEST_EVIDENCE_DIR%\\test_log.txt"\n'
f'echo {line}>>"%LOG%"\n'
":loop\ngoto loop\n"
))
result = run_test_run(
exe, root / "run1", quiet=2.0, grace=1.0,
)
self.assertEqual(result["outcome"], "quiet-killed")
self.assertEqual(result["verdict_hint"], "hang")
self.assertFalse(result["test_complete"])
self.assertIsNone(result["exit_code"])
self.assertEqual(result["death_signals"], [])
self.assertEqual(
Path(result["log_path"]).read_text(
encoding="utf-8", errors="replace"
).splitlines(),
[line],
)
def test_test_run_reports_a_grace_kill_with_a_dump(self):
with tempfile.TemporaryDirectory() as temporary:
root = Path(temporary).resolve()