Skip to content

Commit 2e976f3

Browse files
committed
fix: Scope the parse verdict to the DAG-integrity session
`astro dev parse` captures the image build and the integrity run in one stream, and a Dockerfile `RUN pytest` contributes its own pytest output. Buildkit prefixes those lines so they missed the anchored patterns, but the legacy builder emits RUN stdout verbatim — and a stray "=== 4 passed in 0.21s ===" satisfied the completion check for a run that never tested a DAG. Three false passes were reachable: a CLI refusal (which also discarded its own reason), an integrity run killed mid-flight, and a session that collected nothing. Scope every pytest-shaped signal to the last session in the log (the image must exist before its container runs, so the integrity session is always last), let the CLI's error wrapper outrank any summary, and treat counted-but-unnameable failures as no verdict rather than a pass. In verify.sh, decide a timeout on the kill we own instead of on what the output resembles. Real failures now outrank both, so a run cut short after finding them reports them instead of discarding them. Found by adversarial review.
1 parent d933f9a commit 2e976f3

3 files changed

Lines changed: 154 additions & 28 deletions

File tree

scripts/parse_check.py

Lines changed: 44 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -33,6 +33,15 @@
3333
from report_fmt import failure
3434

3535
BUILD_MARKER = "an error was encountered while building the image"
36+
# `astro dev parse` captures the image build and the DAG-integrity run in ONE
37+
# stream, and the build can contribute pytest output of its own (a Dockerfile
38+
# `RUN pytest`). Buildkit prefixes those lines ("#12 1.204 ") so they miss the
39+
# anchored patterns below, but the legacy builder emits RUN stdout verbatim — and
40+
# a stray "=== 4 passed in 0.21s ===" was enough to read a run that never tested
41+
# a DAG as a pass. Every pytest-shaped signal is therefore scoped to the LAST
42+
# session in the log: the image must exist before its container runs, so the
43+
# integrity session is always the final one.
44+
_SESSION_START = "test session starts"
3645
_COLLECTED = re.compile(r"^collected (\d+) items?")
3746
# pytest's closing summary line — its presence is the evidence the run FINISHED.
3847
# A timeout kill mid-run leaves "collected N items" with no summary; that must
@@ -44,6 +53,11 @@
4453
r"^=+ .*\b(passed|failed|error|no tests ran)\b.* in [0-9.]+s(?: \([0-9:]+\))?",
4554
re.MULTILINE,
4655
)
56+
# The same summary, but reporting something broken. Used to catch the one shape
57+
# where a completed run still must not read as a pass: pytest counted failures
58+
# that no test_file_imports[...] entry accounted for, so we cannot name what
59+
# broke and have nothing honest to report.
60+
_SUMMARY_BROKEN = re.compile(r"^=+ .*\b\d+ (?:failed|error)", re.MULTILINE)
4761
_FAILED_LINE = re.compile(r"^FAILED .*::test_file_imports\[(?P<path>[^\]]+)\]")
4862
_EXC_HEAD = re.compile(r"^E\s+Exception: (?P<path>\S+) failed to import with message")
4963
_EXC_CLASS = re.compile(r"^([A-Za-z_][A-Za-z0-9_.]*(?:Error|Exception|Warning))\b")
@@ -61,17 +75,28 @@
6175
def parse_output(text: str) -> tuple[int, dict]:
6276
if BUILD_MARKER in text:
6377
return 4, {"checked": 0, "failures": []}
64-
if "error during collection" in text or "errors during collection" in text:
78+
79+
idx = text.rfind(_SESSION_START)
80+
body = text[idx:] if idx != -1 else text
81+
82+
if "error during collection" in body or "errors during collection" in body:
6583
# Surface the terse cause (e.g. "TypeError: DagBag.__init__() got...")
6684
# from pytest's short summary so the caller can show why.
6785
cause = ""
68-
for line in text.splitlines():
86+
for line in body.splitlines():
6987
if line.startswith("ERROR ") and " - " in line:
7088
cause = line.split(" - ", 1)[1].strip()
7189
break
7290
return 5, {"checked": 0, "failures": [], "collection_error": cause}
7391

74-
lines = text.splitlines()
92+
# The CLI wraps every Pytest outcome it cannot read as "tests failed" (exit 1
93+
# gets its own "See above for errors detected in your DAGs") in this line: a
94+
# missing venv, a venv without pytest, or pytest exiting 5 for "no tests ran".
95+
# Its presence means this run produced no verdict, so it outranks any summary
96+
# the stream happens to contain.
97+
cli_err = _CLI_ERROR.search(text)
98+
99+
lines = body.splitlines()
75100
checked = 0
76101
for line in lines:
77102
m = _COLLECTED.match(line.strip())
@@ -107,18 +132,24 @@ def parse_output(text: str) -> tuple[int, dict]:
107132
failures[m.group("path")] = failure(
108133
m.group("path"), "", "failed to import (see the CI log for the traceback)")
109134

110-
# A verdict requires evidence the run COMPLETED, not merely started:
111-
# the astro clean marker or pytest's closing summary line. "collected N
112-
# items" alone is what a timeout kill leaves behind.
113-
completed = _CLEAN in text or _SUMMARY.search(text) is not None
114-
if not completed:
135+
sorted_failures = sorted(failures.values(), key=lambda f: f["path"])
136+
# Real failures are reported even when the run was cut short or the CLI
137+
# errored: they are evidence of genuine breakage, and reporting them is
138+
# fail-closed where degrading to the fallback would discard them.
139+
if failures:
140+
return 3, {"checked": checked, "failures": sorted_failures}
141+
142+
# A pass requires evidence the run COMPLETED, not merely started: the astro
143+
# clean marker (which only the CLI prints, and only on success) or the closing
144+
# summary of the integrity session. "collected N items" alone is what a
145+
# timeout kill leaves behind.
146+
completed = _CLEAN in text or _SUMMARY.search(body) is not None
147+
if cli_err is not None or not completed or _SUMMARY_BROKEN.search(body):
115148
result: dict = {"checked": 0, "failures": []}
116-
m = _CLI_ERROR.search(text)
117-
if m:
118-
result["cli_error"] = m.group("cause").strip()
149+
if cli_err is not None:
150+
result["cli_error"] = cli_err.group("cause").strip()
119151
return 2, result
120-
return (3 if failures else 0), {"checked": checked, "failures": sorted(
121-
failures.values(), key=lambda f: f["path"])}
152+
return 0, {"checked": checked, "failures": []}
122153

123154

124155
def main() -> int:

scripts/verify.sh

Lines changed: 17 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -227,6 +227,16 @@ verify_parse_level() {
227227
tail -n 40 "$WORKDIR/parse-target.log"
228228
echo "::endgroup::"
229229

230+
# The kill outranks the scrape. A `timeout` can land on a log that still looks
231+
# finished — the image build's own pytest output, a session cut off after its
232+
# summary — and nothing was fully verified either way, so decide on the signal
233+
# we own rather than on what the output resembles.
234+
if [[ "$target_run_rc" -eq 124 ]]; then
235+
fallback_note="ℹ️ Image-level verification could not run (\`astro dev parse\` timed out before completing). Results below come from the import-level fallback."
236+
echo "::warning::verify-level parse: astro dev parse timed out before completing; falling back to import-level verification."
237+
return 1
238+
fi
239+
230240
# Both "harness produced no verdict" classes degrade to the import-level
231241
# check rather than reporting nothing: rc 5 = the project's integrity test is
232242
# incompatible with the target Airflow; rc 2 = the run never completed
@@ -237,19 +247,14 @@ verify_parse_level() {
237247
echo "::warning::verify-level parse: the project's DAG integrity test is incompatible with the target Airflow; falling back to import-level verification."
238248
return 1
239249
elif [[ "$target_rc" -eq 2 ]]; then
250+
# The CLI usually states exactly why it refused (a project configured for
251+
# standalone dev mode, a venv without pytest, …). Its words beat the
252+
# catch-all: "produced no recognizable result" is what made a field case take
253+
# a full log dig to explain. Timeouts already returned above.
240254
local reason="produced no recognizable result"
241-
local cli_error
242-
if [[ "$target_run_rc" -eq 124 ]]; then
243-
# A timeout kill leaves no explanation of its own, so keep ours.
244-
reason="timed out before completing"
245-
else
246-
# The CLI usually states exactly why it refused (a project configured for
247-
# standalone dev mode, a venv without pytest, …). Its words beat the
248-
# catch-all: "produced no recognizable result" is what made a field case
249-
# take a full log dig to explain.
250-
cli_error=$(jq -r '.cli_error // empty' "$WORKDIR/import-failures.json" 2>/dev/null || true)
251-
[[ -n "$cli_error" ]] && reason="failed: ${cli_error}"
252-
fi
255+
local cli_error=""
256+
cli_error=$(jq -r '.cli_error // empty' "$WORKDIR/import-failures.json" 2>/dev/null || true)
257+
if [[ -n "$cli_error" ]]; then reason="failed: ${cli_error}"; fi
253258
fallback_note="ℹ️ Image-level verification could not run (\`astro dev parse\` ${reason}). Results below come from the import-level fallback."
254259
echo "::warning::verify-level parse: astro dev parse ${reason}; falling back to import-level verification."
255260
return 1

tests/test_parse_check.py

Lines changed: 93 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -158,15 +158,105 @@ def test_build_failure_wrapper_is_not_demoted_to_cli_error(tmp_path):
158158
assert "cli_error" not in result
159159

160160

161-
def test_completed_run_never_gains_a_cli_error(tmp_path):
162-
# Defensive: a finished run is a verdict. Even if the wrapper somehow appears
163-
# alongside a closing summary, the summary wins.
161+
def test_failing_run_with_wrapper_still_reports_the_failures(tmp_path):
162+
# A wrapper alongside real failures means the run was cut short after finding
163+
# them (pytest exit 1 gets its own message, not the wrapper). Reporting the
164+
# failures is fail-closed; degrading to the fallback would discard them.
164165
text = FAILING_RUN + "Error: something went wrong while parsing your DAGs: noise\n"
165166
rc, result, *_ = _run(tmp_path, text)
166167
assert rc == 3
168+
assert result["failures"][0]["path"] == "dags/format_probe.py"
167169
assert "cli_error" not in result
168170

169171

172+
# A Dockerfile `RUN pytest` lands in the same captured stream as the integrity
173+
# run. Buildkit prefixes those lines ("#12 1.204 ") so they miss the anchored
174+
# patterns, but the legacy builder emits RUN stdout verbatim — and an unprefixed
175+
# summary was enough to manufacture a pass. Found by adversarial review.
176+
BUILD_PYTEST_NOISE = """\
177+
Checking your DAGs for errors…
178+
Step 6/7 : RUN pytest tests/unit -q
179+
---> Running in a1b2c3
180+
collected 4 items
181+
=========================== 4 passed in 0.21s ===========================
182+
---> d4e5f6
183+
Successfully built d4e5f6
184+
"""
185+
186+
187+
def test_build_pytest_summary_cannot_pass_a_refused_parse(tmp_path):
188+
# The worst shape: the build's summary satisfies "completed" while the CLI is
189+
# saying it never ran the parse at all.
190+
text = BUILD_PYTEST_NOISE + (
191+
"Error: something went wrong while parsing your DAGs: no virtual "
192+
"environment found — run 'astro dev start' first\n"
193+
)
194+
rc, result, *_ = _run(tmp_path, text)
195+
assert rc == 2, "a build's pytest summary must not stand in for the integrity run"
196+
assert result["checked"] == 0, "the build's collected count must not be reported"
197+
assert "virtual environment" in result["cli_error"]
198+
199+
200+
def test_build_pytest_summary_cannot_pass_a_truncated_integrity_run(tmp_path):
201+
truncated = (
202+
"============================= test session starts ==============================\n"
203+
"collected 37 items\n\n"
204+
".astro/test_dag_integrity_default.py ......\n"
205+
)
206+
rc, result, *_ = _run(tmp_path, BUILD_PYTEST_NOISE + truncated)
207+
assert rc == 2
208+
assert result["checked"] == 0
209+
210+
211+
def test_no_tests_ran_is_not_a_pass(tmp_path):
212+
# pytest exits 5 when it collects nothing, which the CLI wraps. Reporting
213+
# "all 0 DAG file(s) import cleanly" over an untested project is the exact
214+
# false green this level exists to prevent.
215+
text = (
216+
"Checking your DAGs for errors…\n"
217+
"============================= test session starts ==============================\n"
218+
"collected 0 items\n\n"
219+
"==================== no tests ran in 0.12s ====================\n"
220+
"Error: something went wrong while parsing your DAGs: "
221+
"something went wrong while Pytesting your DAGs\n"
222+
)
223+
rc, result, *_ = _run(tmp_path, text)
224+
assert rc == 2
225+
assert "Pytesting" in result["cli_error"]
226+
227+
228+
def test_build_noise_does_not_hide_a_real_collection_error(tmp_path):
229+
# The integrity session's own collection error must still win rc 5 even with a
230+
# clean build-stage pytest run ahead of it in the stream.
231+
rc, result, *_ = _run(tmp_path, BUILD_PYTEST_NOISE + COLLECTION_ERROR_RUN)
232+
assert rc == 5
233+
assert "DagBag.__init__()" in result["collection_error"]
234+
235+
236+
def test_counted_failures_we_cannot_name_are_not_a_pass(tmp_path):
237+
# pytest counted a failure that no test_file_imports[...] entry accounts for
238+
# (an unexpected harness shape). We can't name what broke, so the only honest
239+
# answers are "no verdict" or a fabricated one — take the former.
240+
text = (
241+
"Checking your DAGs for errors…\n"
242+
"============================= test session starts ==============================\n"
243+
"collected 1 item\n\n"
244+
"tests/test_something_else.py F [100%]\n"
245+
"=========================== 1 failed in 1.93s ===========================\n"
246+
)
247+
rc, result, *_ = _run(tmp_path, text)
248+
assert rc == 2
249+
assert result["checked"] == 0
250+
251+
252+
def test_build_noise_does_not_inflate_a_real_pass(tmp_path):
253+
# The complement: with a genuine integrity run after the build noise, the
254+
# count must come from the integrity session (21), not the build's (4).
255+
rc, result, *_ = _run(tmp_path, BUILD_PYTEST_NOISE + CLEAN_RUN)
256+
assert rc == 0
257+
assert result["checked"] == 21
258+
259+
170260
def test_long_run_summary_with_hms_suffix_is_recognized(tmp_path):
171261
# pytest switches the summary duration format at 60s: "in 62.50s (0:01:02)".
172262
# Missing that form silently disabled parse-level verdicts for any project

0 commit comments

Comments
 (0)