diff --git a/Lib/profiling/sampling/gecko_collector.py b/Lib/profiling/sampling/gecko_collector.py index 2de8cce387e7f26..e3754b76a4b6bf5 100644 --- a/Lib/profiling/sampling/gecko_collector.py +++ b/Lib/profiling/sampling/gecko_collector.py @@ -245,10 +245,9 @@ def collect(self, stack_frames, timestamps_us=None): first_time = times[0] - # Update interval calculation - if self.sample_count > 0 and self.last_sample_time > 0: - self.interval = (times[-1] - self.last_sample_time) / self.sample_count - self.last_sample_time = times[-1] + # Binary replay can deliver batches from different threads out of + # order, so keep the latest time seen rather than the last one. + self.last_sample_time = max(self.last_sample_time, times[-1]) # Process async tasks if stack_frames and hasattr(stack_frames[0], "awaited_by"): @@ -732,9 +731,6 @@ def _finalize_markers(self): def export(self, filename): """Export the profile to a Gecko JSON file.""" - if self.sample_count > 0 and self.last_sample_time > 0: - self.interval = self.last_sample_time / self.sample_count - # Spinner for progress indication spinner = itertools.cycle(['⠋', '⠙', '⠹', '⠸', '⠼', '⠴', '⠦', '⠧', '⠇', '⠏']) stop_spinner = threading.Event() @@ -864,6 +860,8 @@ def _profile_tail(self): def _prepare_for_serialization(self): if self.exported: raise RuntimeError("GeckoCollector has already been exported") + if self.sample_count > 0 and self.last_sample_time > 0: + self.interval = self.last_sample_time / self.sample_count self._finalize_markers() for thread_data in self.threads.values(): thread_data["_spill"].prepare_read() diff --git a/Lib/test/test_profiling/test_sampling_profiler/test_collectors.py b/Lib/test/test_profiling/test_sampling_profiler/test_collectors.py index d4ba2df5044559f..e0e7fcea8ef8fb0 100644 --- a/Lib/test/test_profiling/test_sampling_profiler/test_collectors.py +++ b/Lib/test/test_profiling/test_sampling_profiler/test_collectors.py @@ -1072,6 +1072,38 @@ def test_gecko_collector_markers(self): f"Marker {i} should have valid category", ) + def test_gecko_collector_replay_out_of_order_batches(self): + """Open markers are closed at the latest replayed sample.""" + collector = GeckoCollector(1000) + # Binary replay can send thread 2's last batch after thread 1's later + # samples + batches = [ + (1, [1000], THREAD_STATUS_ON_CPU), + (2, [1500], 0), + (1, [2000], THREAD_STATUS_ON_CPU), + (1, [3000, 4000], 0), + (2, [2500], 0), + ] + for tid, timestamps, status in batches: + frames = [MockFrameInfo(f"t{tid}.py", 10, f"func{tid}")] + collector.collect( + [MockInterpreterInfo(0, [MockThreadInfo(tid, frames, status=status)])], + timestamps_us=timestamps, + ) + + profile_data = collector._build_profile() + + end_times = [] + for thread_data in profile_data["threads"]: + markers = thread_data["markers"] + for start_time, end_time in zip(markers["startTime"], + markers["endTime"]): + self.assertLessEqual(start_time, end_time) + end_times.append(end_time) + self.assertEqual(max(end_times), 3.0) + # Six samples up to 3.0 ms + self.assertEqual(profile_data["meta"]["interval"], 0.5) + def test_pstats_collector_export(self): collector = PstatsCollector( sample_interval_usec=1000000 diff --git a/Misc/NEWS.d/next/Library/2026-10-26-21-14-17.gh-issue-160735.IIUifI.rst b/Misc/NEWS.d/next/Library/2026-10-26-21-14-17.gh-issue-160735.IIUifI.rst new file mode 100644 index 000000000000000..cf64610a9e62590 --- /dev/null +++ b/Misc/NEWS.d/next/Library/2026-10-26-21-14-17.gh-issue-160735.IIUifI.rst @@ -0,0 +1,2 @@ +Fix Tachyon's Gecko export closing open markers too early when replaying a +binary profile whose thread samples arrive out of time order.