Merge pull request #494 from qase-tms/fix/behavex-real-timestamps

fix: preserve behavex absolute timestamps when replaying JSON

Author: gibiw

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"]

qase-behave/src/qase/behave/formatter.py

@@ -137,30 +137,58 @@ 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)
 
         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):

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
 

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)."""

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