From 26fdc2e14a57b980ed72bc730b03b6c2f9fe7c7f Mon Sep 17 00:00:00 2001 From: Dmitrii Gridnev Date: Mon, 25 May 2026 21:27:58 +0300 Subject: [PATCH 1/2] fix: preserve behavex absolute timestamps when replaying JSON When QaseFormatter.launch_json_formatter consumed the consolidated BehaveX JSON report, parse_scenario_from_json and parse_step_from_json synthesised timestamps from the recorded duration and the current time: every scenario ended at now() and started at now() - duration. Scenarios that BehaveX actually executed 200 ms apart all collapsed onto the same moment in the TestOps timeline, with timeline ordering matching parser iteration rather than real execution order. BehaveX records absolute ``start`` / ``stop`` milliseconds on every scenario and step. Use them: compute a single time_offset such that the earliest BehaveX scenario lands at the moment we begin replay (get_real_time()), and shift every scenario/step by that constant. The whole timeline ends up inside the run window the API accepts, worker parallelism survives, and the gaps between scenarios match the gaps BehaveX recorded. Fall back to the legacy "now - duration" path only when ``start`` / ``stop`` are missing. Drive-by: ``scenario_dict.get('background', {})`` returned ``None`` when the key existed with a null value (which is exactly what BehaveX writes for scenarios without a background), and the next ``.get('steps')`` raised AttributeError. Use ``or {}`` so a null background is treated as empty. --- qase-behave/src/qase/behave/formatter.py | 36 ++++++++++-- qase-behave/src/qase/behave/utils.py | 48 +++++++++++---- qase-behave/tests/test_formatter.py | 55 ++++++++++++++++++ qase-behave/tests/test_utils.py | 74 ++++++++++++++++++++++++ 4 files changed, 197 insertions(+), 16 deletions(-) diff --git a/qase-behave/src/qase/behave/formatter.py b/qase-behave/src/qase/behave/formatter.py index cc900f4e..a791a015 100644 --- a/qase-behave/src/qase/behave/formatter.py +++ b/qase-behave/src/qase/behave/formatter.py @@ -137,23 +137,27 @@ def launch_json_formatter(self, json_data): # Workers didn't run QaseFormatter — process JSON ourselves self.reporter.start_run() + time_offset = self._compute_time_offset(json_data) + for feature in json_data.get('features', []): feature_filename = feature.get('filename', '') for scenario_dict in feature.get('scenarios', []): - result = parse_scenario_from_json(scenario_dict, feature_filename) + result = parse_scenario_from_json( + scenario_dict, feature_filename, time_offset=time_offset + ) if result.ignore: continue # Background steps first - background = scenario_dict.get('background', {}) + background = scenario_dict.get('background') or {} for step_dict in background.get('steps', []): - step = parse_step_from_json(step_dict) + step = parse_step_from_json(step_dict, time_offset=time_offset) result.steps.append(step) # Regular steps for step_dict in scenario_dict.get('steps', []): - step = parse_step_from_json(step_dict) + step = parse_step_from_json(step_dict, time_offset=time_offset) result.steps.append(step) self.reporter.add_result(result) @@ -161,6 +165,30 @@ def launch_json_formatter(self, json_data): self.reporter.complete_worker() self.reporter.complete_run() + @staticmethod + def _compute_time_offset(json_data) -> float: + """Offset added to every BehaveX scenario/step timestamp. + + BehaveX records absolute timestamps from before this Qase run was + created, and the API rejects test results whose start_time predates + the run. Shift all timestamps by the same constant so the earliest + scenario lands at "now" — the relative ordering and durations + between scenarios/steps (including worker parallelism) are + preserved, but the whole timeline ends up inside the run window. + """ + earliest_ms = None + for feature in json_data.get('features', []): + for scenario_dict in feature.get('scenarios', []): + sc_start = scenario_dict.get('start') + if sc_start is None: + continue + if earliest_ms is None or sc_start < earliest_ms: + earliest_ms = sc_start + if earliest_ms is None: + return 0.0 + from qase.commons.utils import QaseUtils + return QaseUtils.get_real_time() - (earliest_ms / 1000.0) + def _cleanup_lock_files(self): """Remove lock and run_id files.""" for path in (self._run_id_file, self._lock_file): diff --git a/qase-behave/src/qase/behave/utils.py b/qase-behave/src/qase/behave/utils.py index f0a9cb83..07e5718b 100644 --- a/qase-behave/src/qase/behave/utils.py +++ b/qase-behave/src/qase/behave/utils.py @@ -143,8 +143,17 @@ def __extract_fields(tag: str) -> dict: return {} -def parse_scenario_from_json(scenario_dict: dict, feature_filename: str) -> Result: - """Parse a BehaveX JSON scenario dict into a Qase Result.""" +def parse_scenario_from_json( + scenario_dict: dict, + feature_filename: str, + time_offset: float = 0.0, +) -> Result: + """Parse a BehaveX JSON scenario dict into a Qase Result. + + ``time_offset`` (seconds) is added to every absolute timestamp read + from BehaveX so the original timeline can be replayed inside the + current Qase run window. See ``QaseFormatter._compute_time_offset``. + """ tags = __parse_tags(scenario_dict.get('tags', [])) name = scenario_dict.get('name', '') @@ -190,11 +199,17 @@ def parse_scenario_from_json(scenario_dict: dict, feature_filename: str) -> Resu duration = scenario_dict.get('duration', 0) result.execution.duration = int(duration * 1000) - # Always calculate timestamps relative to current time. - # BehaveX timestamps are from before run creation and would be rejected by the API. - current_time = QaseUtils.get_real_time() - result.execution.end_time = current_time - result.execution.start_time = current_time - duration + start_ms = scenario_dict.get('start') + stop_ms = scenario_dict.get('stop') + if start_ms is not None and stop_ms is not None: + result.execution.start_time = (start_ms / 1000.0) + time_offset + result.execution.end_time = (stop_ms / 1000.0) + time_offset + else: + # Fallback when BehaveX did not record absolute timestamps: + # synthesise a window ending "now" with the recorded duration. + current_time = QaseUtils.get_real_time() + result.execution.end_time = current_time + result.execution.start_time = current_time - duration worker_id = scenario_dict.get('worker_id') if worker_id is not None: @@ -216,8 +231,11 @@ def parse_scenario_from_json(scenario_dict: dict, feature_filename: str) -> Resu return result -def parse_step_from_json(step_dict: dict) -> QaseStep: - """Parse a BehaveX JSON step dict into a Qase Step.""" +def parse_step_from_json(step_dict: dict, time_offset: float = 0.0) -> QaseStep: + """Parse a BehaveX JSON step dict into a Qase Step. + + See ``parse_scenario_from_json`` for the ``time_offset`` contract. + """ keyword = step_dict.get('step_type', 'given') name = step_dict.get('name', '') line = step_dict.get('line', 0) @@ -242,9 +260,15 @@ def parse_step_from_json(step_dict: dict) -> QaseStep: duration = step_dict.get('duration', 0) model.execution.duration = int(duration * 1000) - current_time = QaseUtils.get_real_time() - model.execution.end_time = current_time - model.execution.start_time = current_time - duration + start_ms = step_dict.get('start') + stop_ms = step_dict.get('stop') + if start_ms is not None and stop_ms is not None: + model.execution.start_time = (start_ms / 1000.0) + time_offset + model.execution.end_time = (stop_ms / 1000.0) + time_offset + else: + current_time = QaseUtils.get_real_time() + model.execution.end_time = current_time + model.execution.start_time = current_time - duration return model diff --git a/qase-behave/tests/test_formatter.py b/qase-behave/tests/test_formatter.py index 668f52a2..17e71a4f 100644 --- a/qase-behave/tests/test_formatter.py +++ b/qase-behave/tests/test_formatter.py @@ -281,6 +281,61 @@ def test_launch_json_formatter_with_existing_lock_file(self): if os.path.exists(lock_path): os.remove(lock_path) + def test_launch_json_formatter_survives_null_background(self): + """Real BehaveX reports often carry ``"background": null`` for + scenarios without a background — ``.get('background', {})`` would + return None and the next ``.get('steps')`` would raise.""" + formatter = QaseFormatter() + mock_reporter = MagicMock() + mock_reporter.start_run.return_value = "1" + + json_data = { + "features": [{ + "name": "F", "filename": "f.feature", + "scenarios": [{ + "name": "X", "status": "passed", "duration": 0.0, + "tags": [], "filename": "f.feature", "line": 1, + "steps": [], + "background": None, + }], + }], + } + + with patch('qase.behave.formatter.QaseCoreReporter', return_value=mock_reporter), \ + patch('qase.behave.formatter.ConfigManager'): + formatter.launch_json_formatter(json_data) + + mock_reporter.add_result.assert_called_once() + + +class TestComputeTimeOffset: + """``_compute_time_offset`` shifts the whole BehaveX timeline so the + earliest scenario lands at ~"now", preserving relative timing.""" + + def test_no_scenarios_returns_zero(self): + offset = QaseFormatter._compute_time_offset({"features": []}) + assert offset == 0.0 + + def test_scenarios_without_start_returns_zero(self): + json_data = {"features": [{"scenarios": [{"name": "x"}]}]} + assert QaseFormatter._compute_time_offset(json_data) == 0.0 + + def test_offset_lands_earliest_near_now(self): + from qase.commons.utils import QaseUtils + before = QaseUtils.get_real_time() + json_data = {"features": [{"scenarios": [ + {"name": "later", "start": 1_000_500}, # 1000.5 s + {"name": "earlier", "start": 1_000_000}, # 1000.0 s ← earliest + {"name": "latest", "start": 1_000_800}, + ]}]} + + offset = QaseFormatter._compute_time_offset(json_data) + after = QaseUtils.get_real_time() + + # Earliest BehaveX ts (1000.0 s) + offset ≈ now → offset ≈ now - 1000.0. + # Allow for the small wall-clock window in this test. + assert before - 1000.0 <= offset <= after - 1000.0 + class TestBehaveXWorkerMode: """Test QaseFormatter in BehaveX worker mode (lock file coordination).""" diff --git a/qase-behave/tests/test_utils.py b/qase-behave/tests/test_utils.py index d5ab8e39..5dfef007 100644 --- a/qase-behave/tests/test_utils.py +++ b/qase-behave/tests/test_utils.py @@ -350,3 +350,77 @@ def test_step_defaults(self): assert step.data.name == '' assert step.data.line == 0 assert step.step_type == StepType.GHERKIN + + +class TestBehavexAbsoluteTimestamps: + """When BehaveX records ``start`` / ``stop`` (unix-ms), the parsed + Result/Step must use those timestamps (shifted by ``time_offset``) + rather than synthesising a window relative to ``now()``.""" + + def test_scenario_uses_real_start_stop_with_offset(self): + # BehaveX timestamps from an old run (start=10s, stop=10.5s in unix-ms). + scenario_dict = { + 'name': 'old run', 'status': 'passed', 'duration': 0.5, + 'tags': [], 'start': 10_000, 'stop': 10_500, + } + offset = 1_000_000.0 # shift the whole timeline by 1e6 seconds + + result = parse_scenario_from_json( + scenario_dict, 'features/x.feature', time_offset=offset + ) + + assert result.execution.start_time == 10.0 + offset + assert result.execution.end_time == 10.5 + offset + assert result.execution.duration == 500 + + def test_scenario_without_start_stop_falls_back_to_now(self): + scenario_dict = { + 'name': 'no times', 'status': 'passed', 'duration': 0.3, 'tags': [], + } + result = parse_scenario_from_json( + scenario_dict, 'features/x.feature', time_offset=999.0 + ) + + # No start/stop → behave like the legacy path; offset must NOT be applied. + assert result.execution.duration == 300 + assert result.execution.end_time > 1_000_000 # current unix time, not 999 + assert abs(result.execution.end_time - result.execution.start_time - 0.3) < 0.1 + + def test_step_uses_real_start_stop_with_offset(self): + step_dict = { + 'step_type': 'when', 'name': 'press button', 'line': 1, + 'status': 'passed', 'duration': 0.12, + 'start': 2_000, 'stop': 2_120, + } + offset = 5_000_000.0 + step = parse_step_from_json(step_dict, time_offset=offset) + + assert step.execution.start_time == 2.0 + offset + assert step.execution.end_time == 2.12 + offset + assert step.execution.duration == 120 + + def test_scenarios_preserve_real_ordering_after_offset(self): + """Three BehaveX scenarios spaced 200 ms apart must remain spaced + 200 ms apart after offsetting (regression for the bug that + collapsed all scenarios onto the same current_time).""" + offset = 1_000_000.0 + scenarios = [ + {'name': 'A', 'status': 'passed', 'duration': 0.1, 'tags': [], + 'start': 0, 'stop': 100}, + {'name': 'B', 'status': 'passed', 'duration': 0.2, 'tags': [], + 'start': 200, 'stop': 400}, + {'name': 'C', 'status': 'passed', 'duration': 0.3, 'tags': [], + 'start': 600, 'stop': 900}, + ] + + results = [ + parse_scenario_from_json(sc, 'features/x.feature', time_offset=offset) + for sc in scenarios + ] + + starts = [r.execution.start_time for r in results] + ends = [r.execution.end_time for r in results] + + assert ends[0] < starts[1] < ends[1] < starts[2] < ends[2] + assert pytest.approx(starts[1] - starts[0], abs=1e-6) == 0.2 + assert pytest.approx(starts[2] - starts[1], abs=1e-6) == 0.4 From 699cc46cc615a79be02430e3b41707a2e8edfe02 Mon Sep 17 00:00:00 2001 From: Dmitrii Gridnev Date: Mon, 25 May 2026 21:27:59 +0300 Subject: [PATCH 2/2] chore: bump qase-behave to 3.2.1 --- qase-behave/pyproject.toml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/qase-behave/pyproject.toml b/qase-behave/pyproject.toml index b83ef770..b4f93fd4 100644 --- a/qase-behave/pyproject.toml +++ b/qase-behave/pyproject.toml @@ -4,7 +4,7 @@ build-backend = "setuptools.build_meta" [project] name = "qase-behave" -version = "3.2.0" +version = "3.2.1" description = "Qase Behave Plugin for Qase TestOps and Qase Report" readme = "README.md" keywords = ["qase", "behave", "plugin", "testops", "report", "qase reporting", "test observability"]