From 70ac3bdfb2c32eb2f4e16e9bacd7278d6f2204ab Mon Sep 17 00:00:00 2001 From: Alex Luck Date: Thu, 8 Oct 2026 10:11:14 -0700 Subject: [PATCH 1/2] warn on closed step and rollup status at closure --- .../pytest_plugin/_step_status_capture.py | 5 + .../pytest_plugin/step_status_states.md | 3 + .../_tests/pytest_plugin/test_pass_fail.py | 130 ++++++++++++- python/lib/sift_client/errors.py | 4 + .../sift_client/util/test_results/__init__.py | 3 + .../util/test_results/context_manager.py | 171 ++++++++++++------ 6 files changed, 256 insertions(+), 60 deletions(-) diff --git a/python/lib/sift_client/_tests/pytest_plugin/_step_status_capture.py b/python/lib/sift_client/_tests/pytest_plugin/_step_status_capture.py index 53fa2672fa..2a7cae3196 100644 --- a/python/lib/sift_client/_tests/pytest_plugin/_step_status_capture.py +++ b/python/lib/sift_client/_tests/pytest_plugin/_step_status_capture.py @@ -160,6 +160,11 @@ def test_step(name: str) -> CapturedStep | None: return min(matches, key=lambda s: s.step_path.count(".")) +def module_step() -> CapturedStep: + """The outermost step in the run: the module parent, shallowest by path depth.""" + return min(_steps().values(), key=lambda s: s.step_path.count(".")) + + def final_status(name: str) -> TestStatus | None: step = test_step(name) return step.statuses[-1] if step and step.statuses else None diff --git a/python/lib/sift_client/_tests/pytest_plugin/step_status_states.md b/python/lib/sift_client/_tests/pytest_plugin/step_status_states.md index 8b046b9e95..894975ef27 100644 --- a/python/lib/sift_client/_tests/pytest_plugin/step_status_states.md +++ b/python/lib/sift_client/_tests/pytest_plugin/step_status_states.md @@ -88,6 +88,9 @@ be traced back to its row here without rereading the scenario: | `API-07` | `pytest.exit()` after a failed `report_outcome`, in a class | `step.report_outcome(..., False); pytest.exit(...)` | Failure stop: leaf `ABORTED`; class and module roll up `FAILED`; the failed substep keeps `FAILED` | | `API-08` | Session-aborting `KeyboardInterrupt` in a class | `step.report_outcome(..., False); raise KeyboardInterrupt` | System stop: leaf, class, and module all `ABORTED` (the run was cut off, not failed); the failed substep keeps `FAILED` | | `API-09` | Sift `abort()` helper in a class | `from sift_client.pytest_plugin import abort; abort(...)` | System stop: leaf, class, module, and the report all `ABORTED`, even with no failing check | +| `API-10` | Failing measurement recorded after the substep's block exited | `with step.substep(...) as s: pass` then `s.measure(... out-of-bounds)` | `FAILED` on the closed substep and on every ancestor: the late failure is corrected in place rather than reaching only the report | +| `API-11` | Passing measurement recorded after the substep's block exited | `with step.substep(...) as s: pass` then `s.measure(... in-bounds)` | Statuses unchanged (`PASSED`); the mis-ordering still warns, since nothing distinguishes it from `API-10` until a value goes out of bounds | +| `API-12` | `substep` opened on a closed step | `with step.substep(...) as s: pass` then `s.substep(...)` | Warns: the new step attaches to the stack top, which is no longer `s` | ## Out of scope diff --git a/python/lib/sift_client/_tests/pytest_plugin/test_pass_fail.py b/python/lib/sift_client/_tests/pytest_plugin/test_pass_fail.py index 86f8b01c24..713b432af8 100644 --- a/python/lib/sift_client/_tests/pytest_plugin/test_pass_fail.py +++ b/python/lib/sift_client/_tests/pytest_plugin/test_pass_fail.py @@ -17,10 +17,12 @@ from __future__ import annotations import textwrap +import warnings import pytest from sift_client._tests.pytest_plugin import _step_status_capture as capture +from sift_client.errors import SiftReportLifecycleWarning from sift_client.sift_types.test_report import TestStatus pytest_plugins = ["pytester"] @@ -731,7 +733,7 @@ def test_flash(self, step): assert substep.statuses[-1] == TestStatus.FAILED assert klass.statuses[-1] == TestStatus.FAILED # The module step is the shallowest; it inherits the failure too. - module = min(capture._steps().values(), key=lambda s: s.step_path.count(".")) + module = capture.module_step() assert module.statuses[-1] == TestStatus.FAILED @@ -761,7 +763,7 @@ def test_flash(self, step): assert leaf.statuses[-1] == TestStatus.ABORTED assert substep.statuses[-1] == TestStatus.FAILED assert klass.statuses[-1] == TestStatus.ABORTED - module = min(capture._steps().values(), key=lambda s: s.step_path.count(".")) + module = capture.module_step() assert module.statuses[-1] == TestStatus.ABORTED @@ -787,5 +789,127 @@ def test_flash(self, step): assert klass is not None assert leaf.statuses[-1] == TestStatus.ABORTED assert klass.statuses[-1] == TestStatus.ABORTED - module = min(capture._steps().values(), key=lambda s: s.step_path.count(".")) + module = capture.module_step() assert module.statuses[-1] == TestStatus.ABORTED + + +# --------------------------------------------------------------------------- +# Steps used after their ``with`` block exited +# --------------------------------------------------------------------------- + + +def test_late_failure_corrects_closed_step_and_ancestors(inner): + # Case: API-10 + _run( + inner, + """ + def test_x(step): + with step.substep(name="inner") as s: + pass + s.measure(name="m", value=10.0, bounds={"min": 0.0, "max": 5.0}) + """, + ) + # The substep already resolved PASSED on close, so nothing was left to read + # the failure flag; it is corrected in place instead. The chain above it is + # still open at that point and resolves FAILED through the normal path, so + # the roll-up reaches the module step rather than only the report. + substep = next(iter(capture.steps_by_name("inner")), None) + assert substep is not None + assert substep.statuses[-2:] == [TestStatus.PASSED, TestStatus.FAILED] + assert capture.final_status("test_x") == TestStatus.FAILED + module = capture.module_step() + assert module.statuses[-1] == TestStatus.FAILED + + +def test_late_passing_measurement_leaves_statuses_alone(inner): + # Case: API-11 + _run( + inner, + """ + def test_x(step): + with step.substep(name="inner") as s: + pass + s.measure(name="m", value=1.0, bounds={"min": 0.0, "max": 5.0}) + """, + ) + # The same mis-ordering with an in-bounds value: the measurement attaches to + # the right step and there is nothing to correct. Only the warning separates + # this from API-10, which is why it fires on the ordering and not the outcome. + substep = next(iter(capture.steps_by_name("inner")), None) + assert substep is not None + assert substep.statuses[-1] == TestStatus.PASSED + assert capture.final_status("test_x") == TestStatus.PASSED + + +@pytest.fixture +def simulate_context(): + """A real ``ReportContext`` on the ``--sift-disabled`` simulate path. + + Exercises the actual ``TestStep`` objects and statuses without contacting Sift. + """ + from sift_client._internal.pytest_plugin.report import build_disabled_client + from sift_client.util.test_results import ReportContext + + return ReportContext(build_disabled_client(), name="n", log_file=False) + + +@pytest.fixture +def closed_step(simulate_context): + """A step whose ``with`` block has already exited.""" + step = simulate_context.new_step(name="s") + with step: + pass + return step + + +class TestClosedStepWarning: + """Using a step after its ``with`` block exited warns, whatever the outcome.""" + + def test_warning_is_latched_per_operation(self, closed_step) -> None: + with pytest.warns(SiftReportLifecycleWarning, match=r"a result was recorded on step 's'"): + closed_step.measure(name="a", value=1.0, bounds={"min": 0.0, "max": 5.0}) + # A repeat is latched: a wrapper doing this on every step would otherwise + # flood the runner's warning summary. The per-call record is in the audit + # log instead. + with warnings.catch_warnings(): + warnings.simplefilter("error", SiftReportLifecycleWarning) + closed_step.measure(name="b", value=1.0, bounds={"min": 0.0, "max": 5.0}) + # A substep records no outcome, so it never reaches the chokepoint the + # measure family shares, and it fails differently (it mis-parents as well + # as losing the status). Its own guard, its own signal. + with pytest.warns(SiftReportLifecycleWarning, match="a substep was recorded"): + closed_step.substep(name="late") + + def test_measure_all_warns_even_when_it_records_nothing(self, closed_step) -> None: + # An all-in-bounds series records no measurement, so the delegated + # ``measure`` never runs; the trailing ``record_step_outcome`` still does. + with pytest.warns(SiftReportLifecycleWarning, match="a result was recorded"): + closed_step.measure_all(name="m", values=[1.0, 2.0], bounds={"min": 0.0, "max": 5.0}) + + def test_open_step_does_not_warn(self, simulate_context) -> None: + with warnings.catch_warnings(): + warnings.simplefilter("error", SiftReportLifecycleWarning) + with simulate_context.new_step(name="s") as step: + step.measure(name="m", value=1.0, bounds={"min": 0.0, "max": 5.0}) + step.measure_all(name="series", values=[1.0], bounds={"min": 0.0, "max": 5.0}) + step.measure_avg(name="avg", values=[1.0], bounds={"min": 0.0, "max": 5.0}) + step.report_outcome(name="check", result=True) + with step.substep(name="inner"): + pass + + def test_late_failure_after_finalize_warns_and_writes_nothing( + self, simulate_context, closed_step + ) -> None: + current = closed_step.current_step + assert current is not None + simulate_context.finalize() + with pytest.warns(SiftReportLifecycleWarning) as recorded: + closed_step.measure(name="m", value=10.0, bounds={"min": 0.0, "max": 5.0}) + # Both signals fire: the call is mis-ordered, and the correction that would + # normally absorb that has nowhere left to go. + messages = [str(w.message) for w in recorded] + assert any("a result was recorded" in m for m in messages) + assert any("after the report was finalized" in m for m in messages) + # Past finalize the report status is already written, so the step keeps what + # it closed with. + assert current.status == TestStatus.PASSED diff --git a/python/lib/sift_client/errors.py b/python/lib/sift_client/errors.py index b8f511e60e..b370b110a9 100644 --- a/python/lib/sift_client/errors.py +++ b/python/lib/sift_client/errors.py @@ -19,6 +19,10 @@ class SiftIgnoredInputWarning(SiftWarning): """ +class SiftReportLifecycleWarning(SiftWarning): + """Warning for test-results updates that are out of the intended lifecycle order.""" + + class SiftCredentialsError(ValueError): """Raised when Sift credentials cannot be resolved. diff --git a/python/lib/sift_client/util/test_results/__init__.py b/python/lib/sift_client/util/test_results/__init__.py index edff9e135d..8435815562 100644 --- a/python/lib/sift_client/util/test_results/__init__.py +++ b/python/lib/sift_client/util/test_results/__init__.py @@ -25,6 +25,9 @@ return result # This is optional for other uses, but the step and its parents will be updated correctly i.e. failed if the measurement fails. ``` +Measure inside the step's `with` block. Closing a step resolves its status and +rolls the result up to its parents. + #### Manually Updating Underlyling Report You can also manually update the underlying report or steps by accessing the context manager's attributes. ```python diff --git a/python/lib/sift_client/util/test_results/context_manager.py b/python/lib/sift_client/util/test_results/context_manager.py index 3c94a87581..431bd0c3c2 100644 --- a/python/lib/sift_client/util/test_results/context_manager.py +++ b/python/lib/sift_client/util/test_results/context_manager.py @@ -17,7 +17,7 @@ import numpy as np from sift_client._internal.pytest_plugin.audit_log import _make_session_dir, log_event -from sift_client.errors import SiftWarning +from sift_client.errors import SiftReportLifecycleWarning, SiftWarning from sift_client.sift_types.test_report import ( ErrorInfo, NumericBounds, @@ -195,6 +195,8 @@ class ReportContext(AbstractContextManager): # statuses. ``update`` mutates step instances in place, so these references # reflect late status changes (e.g. a teardown-phase failure). created_steps: list[TestStep] + # The same steps keyed by ``step_path`` + _steps_by_path: dict[str, TestStep] # Every measurement recorded in this report, retained for end-of-run # summaries. Appended in ``NewStep.measure``. A measurement's ``passed`` is # fixed at creation, so the retained references stay accurate. @@ -215,6 +217,11 @@ class ReportContext(AbstractContextManager): # entry is written. defer_finalize: bool = False _finalized: bool = False + # One-shot latches for ``_warn_once``, keyed by caller-chosen string. Held per + # report rather than in module state because a process can run several + # sessions back to back (pytester drives inner sessions in-process), and a + # module-level latch would silence the second session's first warning. + _warned: set # Whether the ``with`` block exited with an exception; folded into the # report's status by ``finalize``. _exit_failed: bool = False @@ -287,11 +294,13 @@ def __init__( self.any_failures = False self.session_aborted = False self.created_steps = [] + self._steps_by_path = {} self.created_measurements = [] self.replay_incomplete = False self.defer_finalize = defer_finalize self._finalized = False self._exit_failed = False + self._warned = set() if log_file is True: session_dir = _make_session_dir() @@ -636,73 +645,114 @@ def create_step( self.open_step_results[step.step_path] = True # Retained for end-of-run tallies; never popped (unlike step_stack). self.created_steps.append(step) + self._steps_by_path[step.step_path] = step return step + def _warn_once(self, key: str, message: str, category: type[Warning] = SiftWarning) -> None: + """Emit ``message`` the first time ``key`` is seen in this report.""" + if key in self._warned: + return + self._warned.add(key) + warnings.warn(message, category, stacklevel=3) + + def _warn_step_closed(self, step: TestStep, kind: str) -> None: + """Warn that a ``kind`` ("result", "substep") reached ``step`` after it closed.""" + log_event( + logger, + logging.DEBUG, + "step.after_close", + step_path=step.step_path, + kind=kind, + ) + key = f"after_close:{kind}" + if key in self._warned: + return + self._warn_once( + key, + f"Sift: a {kind} was recorded on step {step.name!r} " + f"({step.step_path}) after its `with` block exited. Move the call " + "inside the block so the result reaches the step and its parents. " + "Recorded data is kept and a failure is rolled up where it still can " + "be, but the step's own timing and the pytest verdict are already " + "fixed by this point.", + SiftReportLifecycleWarning, + ) + + def _is_step_open(self, step_path: str) -> bool: + """Whether ``step_path`` is still inside its ``with`` block.""" + return step_path in self.open_step_results + + def _fail_ancestors(self, step_path: str) -> list[str]: + """Mark every ancestor of ``step_path`` failed.""" + ancestors = _ancestor_paths(step_path) + for ancestor_path in ancestors: + if self._is_step_open(ancestor_path): + self.open_step_results[ancestor_path] = False + continue + ancestor = self._steps_by_path.get(ancestor_path) + if ancestor is not None and ancestor.status == TestStatus.PASSED: + ancestor.update({"status": TestStatus.FAILED}) + return ancestors + def record_step_outcome(self, outcome: bool, step: TestStep): - """Report a failure to the report context.""" - # Failures will be propogated when the step exits. - if not outcome: - self.open_step_results[step.step_path] = False - self.any_failures = True - # Diagnostic: a failure recorded on this step's OWN scope (a failing - # report_outcome or an out-of-bounds measure), as distinct from one - # inherited from a child (which shows up as a step.propagate line). - # Lets a reader tell why a later step.resolve marks the step failed. - log_event( - logger, - logging.DEBUG, - "step.outcome", - step_path=step.step_path, - result="fail", - ) + """Report an outcome for ``step`` to the report context.""" + # Failures will be propogated when the step exits + if not self._is_step_open(step.step_path): + self._warn_step_closed(step, "result") + if not outcome: + # Nothing is left to read the flag and roll the failure up. + self._record_late_failure(step) + return + if outcome: + return + self.open_step_results[step.step_path] = False + self.any_failures = True + # Diagnostic: a failure recorded on this step's OWN scope (a failing + # report_outcome or an out-of-bounds measure), as distinct from one + # inherited from a child (which shows up as a step.propagate line). + # Lets a reader tell why a later step.resolve marks the step failed. + log_event( + logger, + logging.DEBUG, + "step.outcome", + step_path=step.step_path, + result="fail", + ) def record_measurement(self, measurement: TestMeasurement) -> None: """Retain a recorded measurement for end-of-run summaries.""" self.created_measurements.append(measurement) def mark_step_failed_after_close(self, step: TestStep): - """Roll a failure up the ancestor chain after the step was already closed. - - Used by the pytest plugin when a teardown-phase report fires after the - fixture's ``__exit__`` has already resolved and exited the step. - - Every ancestor is walked, not just the immediate parent. A teardown - failure can surface after ``finalize_parents`` has closed the whole chain - (for the last item in a session it always does), and those ancestors have - already been written out as PASSED. Marking ``open_step_results`` alone - would change nothing server-side, so each closed ancestor is re-updated - to FAILED. Ancestors still open are left to ``propagate_step_result``, - which picks up the ``open_step_results`` flag when they close. + """Roll a failure up the ancestor chain after the step was already closed.""" + self._record_late_failure(step, signal="teardown_fail") - The report's own status is not touched here; it is derived from - ``any_failures`` in ``finalize``. - """ + def _record_late_failure(self, step: TestStep, signal: str = "after_close") -> None: + """Record a failure reported against ``step`` after it already closed.""" self.any_failures = True - ancestors = _ancestor_paths(step.step_path) - if not ancestors: + if self._finalized: + # The report status is already written and the replay worker drained, + # so there is nowhere left to put the correction. + self._warn_once( + "late_failure_after_finalize", + f"Sift: a failure was recorded on step {step.name!r} " + f"({step.step_path}) after the report was finalized. The report " + "keeps the status it was closed with; this failure is not in it.", + SiftReportLifecycleWarning, + ) return - by_path = {s.step_path: s for s in self.created_steps} - for ancestor_path in ancestors: - self.open_step_results[ancestor_path] = False - ancestor = by_path.get(ancestor_path) - # Only a cleanly-closed ancestor needs the correction. One still open - # resolves through the normal path, and one already FAILED/ABORTED - # must not be downgraded. - if ancestor is not None and ancestor.status == TestStatus.PASSED: - ancestor.update({"status": TestStatus.FAILED}) - # Diagnostic: a teardown-phase failure fires after the step's own - # __exit__ has resolved, so it never runs through propagate_step_result. - # One line for the whole chain, so a deep hierarchy does not bury the - # single signal it represents. + if step.status == TestStatus.PASSED: + step.update({"status": TestStatus.FAILED}) + ancestors = self._fail_ancestors(step.step_path) log_event( logger, logging.DEBUG, "step.propagate", step_path=step.step_path, status=step.status.name, - signal="teardown_fail", - parents=",".join(ancestors), + signal=signal, + parents=",".join(ancestors) or "-", ) def propagate_step_result(self, step: TestStep, status: TestStatus) -> bool: @@ -717,13 +767,11 @@ def propagate_step_result(self, step: TestStep, status: TestStatus) -> bool: if not succeeded: self.any_failures = True self.open_step_results[step.step_path] = False - path_parts = step.step_path.split(".") - if len(path_parts) > 1: - parent_path = ".".join(path_parts[:-1]) - self.open_step_results[parent_path] = False - # Diagnostic: record the child→parent roll-up so the parent's + ancestors = self._fail_ancestors(step.step_path) + if ancestors: + # Diagnostic: record the child→ancestor roll-up so an ancestor's # eventual ``cause=child_failed`` can be traced back to the step - # that triggered it. The parent inherits a not-pass signal only; + # that triggered it. Ancestors inherit a not-pass signal only; # ABORTED stays on the step in whose scope the exit fired (and the # substeps the exception unwinds through), so an aborted child # still rolls up to its container parent as FAILED. ``signal`` @@ -735,7 +783,7 @@ def propagate_step_result(self, step: TestStep, status: TestStatus) -> bool: step_path=step.step_path, status=status.name, signal="abort" if status == TestStatus.ABORTED else "fail", - parent=parent_path, + parents=",".join(ancestors), ) return succeeded @@ -1287,7 +1335,16 @@ def substep( description: str | None = None, metadata: dict[str, str | float | bool] | None = None, ) -> NewStep: - """Alias to return a new step context manager from the current step. The ReportContext will manage nesting of steps.""" + """Alias to return a new step context manager from the current step. The ReportContext will manage nesting of steps. + + Called on a closed step this also mis-parents: with no explicit ``parent`` + the new step attaches to whatever is on top of the step stack, which by + then is this step's own parent. Hence the warning; ``report_outcome`` + reaches it through here too. + """ + step = self.current_step + if step is not None and not self.report_context._is_step_open(step.step_path): + self.report_context._warn_step_closed(step, "substep") return self.report_context.new_step( name=name, description=description, From 432fd20bee51aa65d5bd47b69d3d59e2081ff2f0 Mon Sep 17 00:00:00 2001 From: Alex Luck Date: Thu, 8 Oct 2026 11:05:45 -0700 Subject: [PATCH 2/2] make more concise warning --- python/lib/sift_client/util/test_results/context_manager.py | 5 +---- 1 file changed, 1 insertion(+), 4 deletions(-) diff --git a/python/lib/sift_client/util/test_results/context_manager.py b/python/lib/sift_client/util/test_results/context_manager.py index 431bd0c3c2..e50eca2110 100644 --- a/python/lib/sift_client/util/test_results/context_manager.py +++ b/python/lib/sift_client/util/test_results/context_manager.py @@ -672,10 +672,7 @@ def _warn_step_closed(self, step: TestStep, kind: str) -> None: key, f"Sift: a {kind} was recorded on step {step.name!r} " f"({step.step_path}) after its `with` block exited. Move the call " - "inside the block so the result reaches the step and its parents. " - "Recorded data is kept and a failure is rolled up where it still can " - "be, but the step's own timing and the pytest verdict are already " - "fixed by this point.", + "inside the block so the result reaches the step and its parents. ", SiftReportLifecycleWarning, )