nextest_runner/record/
chrome_trace.rs

1// Copyright (c) The nextest Contributors
2// SPDX-License-Identifier: MIT OR Apache-2.0
3
4//! Converts recorded nextest events to Chrome Trace Event Format.
5//!
6//! The Chrome Trace Event Format is a JSON format understood by Chrome's
7//! `chrome://tracing` and [Perfetto UI](https://ui.perfetto.dev). It provides a
8//! timeline view of test parallelism and execution.
9//!
10//! This module operates directly on the storage format, reading
11//! `TestEventSummary<RecordingSpec>` events and converting them to trace
12//! events. No replay infrastructure is needed since we only need timing data.
13
14use super::summary::{
15    CoreEventKind, OutputEventKind, StressConditionSummary, StressIndexSummary,
16    TestEventKindSummary, TestEventSummary, TestsNotSeenSummary,
17};
18use crate::{
19    errors::{ChromeTraceError, RecordReadError},
20    list::OwnedTestInstanceId,
21    output_spec::RecordingSpec,
22    reporter::events::{
23        CancelReason, ErrorSummary, ExecuteStatus, ExecutionResultDescription, RunFinishedStats,
24        RunStats, StressProgress, TestSlotAssignment,
25    },
26};
27use chrono::{DateTime, FixedOffset};
28use debug_ignore::DebugIgnore;
29use nextest_metadata::RustBinaryId;
30use quick_junit::ReportUuid;
31use semver::Version;
32use serde::Serialize;
33use std::{
34    collections::{BTreeMap, HashMap, HashSet},
35    time::Duration,
36};
37/// Controls the JSON serialization format for Chrome trace output.
38#[derive(Copy, Clone, Debug, PartialEq, Eq)]
39pub enum ChromeTraceMessageFormat {
40    /// JSON with no whitespace.
41    Json,
42
43    /// JSON, prettified.
44    JsonPretty,
45}
46
47/// Controls how tests are grouped in the Chrome trace output.
48#[derive(Copy, Clone, Debug, PartialEq, Eq)]
49pub enum ChromeTraceGroupBy {
50    /// Group tests by binary: each `RustBinaryId` gets its own synthetic pid in
51    /// the trace viewer, and event names show only the test name.
52    Binary,
53
54    /// Group tests by slot: all tests share a single synthetic pid, so each row
55    /// in Perfetto represents a slot regardless of binary. Event names include
56    /// the binary name for disambiguation.
57    Slot,
58}
59
60impl ChromeTraceGroupBy {
61    /// Returns the event name for a test, respecting the grouping mode.
62    ///
63    /// In binary mode, the name is the test name alone (the binary is encoded
64    /// in the synthetic pid). In slot mode, the name is prefixed with the
65    /// binary ID for disambiguation.
66    fn test_event_name(self, id: &OwnedTestInstanceId) -> String {
67        match self {
68            Self::Binary => id.test_name.as_ref().to_string(),
69            Self::Slot => format!("{} {}", id.binary_id, id.test_name.as_ref()),
70        }
71    }
72
73    /// Returns the process display name for a test event's pid.
74    ///
75    /// In binary mode, returns the binary ID. In slot mode, returns `"tests"`
76    /// (all tests share a single process).
77    fn test_process_display_name(self, binary_id: &RustBinaryId) -> String {
78        match self {
79            Self::Binary => binary_id.to_string(),
80            Self::Slot => "tests".to_string(),
81        }
82    }
83}
84
85/// Converts an iterator of recorded events to Chrome Trace Event Format JSON.
86///
87/// The output is a JSON object with `"traceEvents"` and `"displayTimeUnit"`
88/// fields, suitable for loading into Chrome's tracing viewer or Perfetto UI.
89///
90/// # Chrome trace dimension mapping
91///
92/// - `pid`: For the binary grouping mode, a synthetic ID issued per
93///   `RustBinaryId`. For the slot grouping mode, a single pid across all tests.
94///   In both situations, run lifecycle events use pid 0, and setup scripts use
95///   pid 1.
96/// - `tid`: The global slot number plus TID_OFFSET. Setup scripts use their
97///   script index plus TID_OFFSET.
98/// - `name`: the test name or script ID.
99/// - `cat`: `"test"`, `"setup-script"`, `"run"`, or `"stress"`.
100/// - `ts`: event timestamps derived from `ExecuteStatus.start_time`. B/E
101///   pairs are used instead of X events.
102/// - `args`: relevant test metadata.
103///
104/// # Pause handling
105///
106/// We use B/E duration events instead of X events. This allows the converter to
107/// split events around pause/resume boundaries: when `RunPaused` is seen, an E
108/// event is emitted for every open span, and when `RunContinued` is seen, a
109/// matching B event re-opens them. The result is a visible gap in the timeline
110/// during pauses.
111///
112/// Run lifecycle events are also emitted:
113///
114/// - `RunStarted`/`RunFinished` produce a B/E pair spanning the entire run.
115/// - `RunBeginCancel`, `RunPaused`, `RunContinued` produce process-scoped
116///   instant events on the run lifecycle process.
117pub fn convert_to_chrome_trace<I>(
118    nextest_version: &Version,
119    events: I,
120    group_by: ChromeTraceGroupBy,
121    message_format: ChromeTraceMessageFormat,
122) -> Result<Vec<u8>, ChromeTraceError>
123where
124    I: IntoIterator<Item = Result<TestEventSummary<RecordingSpec>, RecordReadError>>,
125{
126    let mut converter = ChromeTraceConverter::new(nextest_version.clone(), group_by);
127
128    for event_result in events {
129        let event = event_result.map_err(ChromeTraceError::ReadError)?;
130        converter.process_event(event)?;
131    }
132
133    converter.finish(message_format)
134}
135
136/// State of the run lifecycle bar in the trace.
137#[derive(Debug)]
138enum RunBarState {
139    /// No run bar has been opened.
140    Closed,
141    /// The run bar has an open B event.
142    Open,
143    /// The run bar was open but is currently paused. An E event has been
144    /// emitted; `reopen_all_spans` will emit a new B event on RunContinued.
145    Paused,
146}
147
148/// Internal state machine that accumulates Chrome trace events.
149///
150/// Uses B/E (begin/end) duration events for tests, setup scripts, and the
151/// run lifecycle. This allows splitting events around pause/resume
152/// boundaries to show visible gaps in the timeline.
153#[derive(Debug)]
154struct ChromeTraceConverter {
155    /// Maps test instances to their slot assignments. An entry here means the
156    /// test has an open B event.
157    slot_assignments: HashMap<OwnedTestInstanceId, TestSlotAssignment>,
158
159    /// A map of running setup scripts from index to script name. An entry here
160    /// means the script has an open B event. The BTreeMap ensures deterministic
161    /// iteration order during pause/resume.
162    running_scripts: BTreeMap<usize, String>,
163
164    /// Whether a stress sub-run span is currently open.
165    stress_subrun_open: bool,
166
167    /// State of the run lifecycle bar.
168    run_bar_state: RunBarState,
169
170    /// How tests are grouped in the output trace.
171    group_by: ChromeTraceGroupBy,
172
173    /// A stable numeric pid for each binary ID.
174    binary_pid_map: HashMap<RustBinaryId, u64>,
175
176    /// The next pid to assign. Starts at 2 because 0 is reserved for the run
177    /// lifecycle and 1 for setup scripts.
178    next_pid: u64,
179
180    /// Run metadata.
181    nextest_version: Version,
182    run_id: Option<ReportUuid>,
183    profile_name: Option<String>,
184    cli_args: Vec<String>,
185    stress_condition: Option<StressConditionSummary>,
186
187    /// Next flow ID for retry arrows connecting failed attempts to retries.
188    next_flow_id: u64,
189
190    /// Pending retry flows: test instance → flow ID. When
191    /// TestAttemptFailedWillRetry emits a flow start, the ID is stored here.
192    /// TestRetryStarted consumes it to emit the matching flow finish.
193    pending_retry_flows: HashMap<OwnedTestInstanceId, u64>,
194
195    /// Tracked running test count for counter events. Set from the
196    /// authoritative `running` field in test events (`TestStarted`,
197    /// `TestFinished`, etc.).
198    running_test_count: usize,
199
200    /// Tracked running script count for counter events. Manually
201    /// incremented/decremented because `SetupScriptStarted`/`Finished` don't
202    /// carry a running count. Periodically reset to the authoritative value
203    /// by `RunPaused`/`RunContinued`/`RunBeginCancel` events, which do carry
204    /// `setup_scripts_running`.
205    running_script_count: usize,
206
207    /// Accumulated trace events.
208    trace_events: DebugIgnore<Vec<ChromeTraceEvent>>,
209
210    /// Pids that have already had their process_name metadata event emitted.
211    emitted_process_names: HashSet<u64>,
212
213    /// (pid, tid) pairs that have already had their thread_name metadata event
214    /// emitted.
215    emitted_thread_names: HashSet<(u64, u64)>,
216}
217
218impl ChromeTraceConverter {
219    fn new(nextest_version: Version, group_by: ChromeTraceGroupBy) -> Self {
220        Self {
221            slot_assignments: HashMap::new(),
222            running_scripts: BTreeMap::new(),
223            stress_subrun_open: false,
224            run_bar_state: RunBarState::Closed,
225            group_by,
226            binary_pid_map: HashMap::new(),
227            next_pid: FIRST_BINARY_PID,
228            nextest_version,
229            run_id: None,
230            profile_name: None,
231            cli_args: Vec::new(),
232            stress_condition: None,
233            next_flow_id: 0,
234            pending_retry_flows: HashMap::new(),
235            running_test_count: 0,
236            running_script_count: 0,
237            trace_events: DebugIgnore(Vec::new()),
238            emitted_process_names: HashSet::new(),
239            emitted_thread_names: HashSet::new(),
240        }
241    }
242
243    fn process_event(
244        &mut self,
245        event: TestEventSummary<RecordingSpec>,
246    ) -> Result<(), ChromeTraceError> {
247        let timestamp = event.timestamp;
248        match event.kind {
249            TestEventKindSummary::Core(core) => self.process_core_event(core, timestamp)?,
250            TestEventKindSummary::Output(output) => self.process_output_event(output, timestamp)?,
251        }
252        Ok(())
253    }
254
255    fn process_core_event(
256        &mut self,
257        event: CoreEventKind,
258        timestamp: DateTime<FixedOffset>,
259    ) -> Result<(), ChromeTraceError> {
260        match event {
261            CoreEventKind::RunStarted {
262                run_id,
263                profile_name,
264                cli_args,
265                stress_condition,
266            } => {
267                // Emit process metadata eagerly so that subsequent instant
268                // events (pause, cancel) don't emit a generic name first.
269                let process_name = format!("nextest run ({profile_name})");
270                self.ensure_metadata_events(
271                    RUN_LIFECYCLE_PID,
272                    RUN_LIFECYCLE_TID,
273                    &process_name,
274                    "run",
275                );
276
277                let begin_args = ChromeTraceArgs::RunBegin(RunBeginArgs {
278                    nextest_version: self.nextest_version.to_string(),
279                    run_id: run_id.to_string(),
280                    profile: profile_name.clone(),
281                    cli_args: cli_args.clone(),
282                    stress_condition: stress_condition.clone(),
283                });
284
285                // Open the run lifecycle bar.
286                self.emit_begin(
287                    RUN_LIFECYCLE_PID,
288                    RUN_LIFECYCLE_TID,
289                    "test run",
290                    Category::Run,
291                    datetime_to_microseconds(timestamp),
292                    Some(begin_args),
293                );
294                self.run_bar_state = RunBarState::Open;
295                self.run_id = Some(run_id);
296                self.profile_name = Some(profile_name);
297                self.cli_args = cli_args;
298                self.stress_condition = stress_condition;
299            }
300            CoreEventKind::RunFinished {
301                run_id: _,
302                start_time: _,
303                elapsed,
304                run_stats,
305                outstanding_not_seen,
306            } => {
307                // Close the run lifecycle bar.
308                let ts_us = datetime_to_microseconds(timestamp);
309                match self.run_bar_state {
310                    RunBarState::Open => {
311                        // Normal case: close the open B event.
312                        let args = self.run_finished_args(
313                            elapsed,
314                            run_stats,
315                            outstanding_not_seen.as_ref(),
316                        );
317                        self.emit_end(
318                            RUN_LIFECYCLE_PID,
319                            RUN_LIFECYCLE_TID,
320                            "test run",
321                            Category::Run,
322                            ts_us,
323                            Some(args),
324                        );
325                        self.run_bar_state = RunBarState::Closed;
326                    }
327                    RunBarState::Paused => {
328                        // The run bar was already closed by close_all_open_spans
329                        // during the pause. Re-open briefly so the run_stats
330                        // args are preserved on the final E event.
331                        self.emit_begin(
332                            RUN_LIFECYCLE_PID,
333                            RUN_LIFECYCLE_TID,
334                            "test run",
335                            Category::Run,
336                            ts_us,
337                            None,
338                        );
339                        let args = self.run_finished_args(
340                            elapsed,
341                            run_stats,
342                            outstanding_not_seen.as_ref(),
343                        );
344                        self.emit_end(
345                            RUN_LIFECYCLE_PID,
346                            RUN_LIFECYCLE_TID,
347                            "test run",
348                            Category::Run,
349                            ts_us,
350                            Some(args),
351                        );
352                        self.run_bar_state = RunBarState::Closed;
353                    }
354                    RunBarState::Closed => {}
355                }
356            }
357            CoreEventKind::RunBeginCancel {
358                reason,
359                setup_scripts_running,
360                running,
361            } => {
362                self.running_test_count = running;
363                self.running_script_count = setup_scripts_running;
364                let ts_us = datetime_to_microseconds(timestamp);
365                self.emit_counter_event(ts_us);
366
367                self.emit_run_instant_event(
368                    timestamp,
369                    "cancel",
370                    Some(reason),
371                    running,
372                    setup_scripts_running,
373                );
374            }
375            CoreEventKind::RunPaused {
376                setup_scripts_running,
377                running,
378            } => {
379                self.running_test_count = running;
380                self.running_script_count = setup_scripts_running;
381                let ts_us = datetime_to_microseconds(timestamp);
382                self.emit_counter_event(ts_us);
383
384                // Close all open spans so the pause appears as a gap.
385                self.close_all_open_spans(ts_us);
386
387                self.emit_run_instant_event(
388                    timestamp,
389                    "paused",
390                    None,
391                    running,
392                    setup_scripts_running,
393                );
394            }
395            CoreEventKind::RunContinued {
396                setup_scripts_running,
397                running,
398            } => {
399                self.running_test_count = running;
400                self.running_script_count = setup_scripts_running;
401                let ts_us = datetime_to_microseconds(timestamp);
402                self.emit_counter_event(ts_us);
403
404                self.emit_run_instant_event(
405                    timestamp,
406                    "continued",
407                    None,
408                    running,
409                    setup_scripts_running,
410                );
411
412                // Reopen all spans that were closed at pause.
413                self.reopen_all_spans(ts_us);
414            }
415            CoreEventKind::TestStarted {
416                test_instance,
417                slot_assignment,
418                stress_index: _,
419                current_stats: _,
420                running,
421                command_line,
422            } => {
423                let pid = self.pid_for_test(&test_instance.binary_id);
424                let tid = slot_assignment.global_slot + TID_OFFSET;
425                let ts_us = datetime_to_microseconds(timestamp);
426
427                let process_name = self
428                    .group_by
429                    .test_process_display_name(&test_instance.binary_id);
430                self.ensure_metadata_events(
431                    pid,
432                    tid,
433                    &process_name,
434                    &format!("slot-{}", slot_assignment.global_slot),
435                );
436
437                let event_name = self.group_by.test_event_name(&test_instance);
438                self.emit_begin(
439                    pid,
440                    tid,
441                    &event_name,
442                    Category::Test,
443                    ts_us,
444                    Some(ChromeTraceArgs::TestBegin(TestBeginArgs {
445                        binary_id: test_instance.binary_id.to_string(),
446                        command_line,
447                    })),
448                );
449
450                self.running_test_count = running;
451                self.emit_counter_event(ts_us);
452
453                self.slot_assignments.insert(test_instance, slot_assignment);
454            }
455            CoreEventKind::TestRetryStarted {
456                test_instance,
457                slot_assignment,
458                stress_index: _,
459                retry_data,
460                running,
461                command_line,
462            } => {
463                let pid = self.pid_for_test(&test_instance.binary_id);
464                let tid = slot_assignment.global_slot + TID_OFFSET;
465                let ts_us = datetime_to_microseconds(timestamp);
466
467                // Ensure metadata is emitted for this pid/tid in case the
468                // event stream starts mid-run (e.g., a truncated log that
469                // begins at a retry).
470                let process_name = self
471                    .group_by
472                    .test_process_display_name(&test_instance.binary_id);
473                self.ensure_metadata_events(
474                    pid,
475                    tid,
476                    &process_name,
477                    &format!("slot-{}", slot_assignment.global_slot),
478                );
479
480                let event_name = self.group_by.test_event_name(&test_instance);
481                self.emit_begin(
482                    pid,
483                    tid,
484                    &event_name,
485                    Category::Test,
486                    ts_us,
487                    Some(ChromeTraceArgs::TestRetryBegin(TestRetryBeginArgs {
488                        attempt: retry_data.attempt,
489                        total_attempts: retry_data.total_attempts,
490                        command_line,
491                    })),
492                );
493
494                // Complete the flow arrow from the previous failed attempt.
495                if let Some(flow_id) = self.pending_retry_flows.remove(&test_instance) {
496                    self.emit_flow_finish(pid, tid, ts_us, flow_id);
497                }
498
499                self.running_test_count = running;
500                self.emit_counter_event(ts_us);
501
502                self.slot_assignments.insert(test_instance, slot_assignment);
503            }
504            CoreEventKind::SetupScriptStarted {
505                index,
506                script_id,
507                stress_index: _,
508                total: _,
509                program: _,
510                args: _,
511                no_capture: _,
512            } => {
513                let tid = index as u64 + TID_OFFSET;
514                let name = script_id.to_string();
515                let ts_us = datetime_to_microseconds(timestamp);
516
517                self.ensure_metadata_events(
518                    SETUP_SCRIPT_PID,
519                    tid,
520                    "setup-scripts",
521                    &format!("script-{index}"),
522                );
523
524                self.emit_begin(
525                    SETUP_SCRIPT_PID,
526                    tid,
527                    &name,
528                    Category::SetupScript,
529                    ts_us,
530                    None,
531                );
532
533                self.running_script_count += 1;
534                self.emit_counter_event(ts_us);
535
536                self.running_scripts.insert(index, name);
537            }
538            CoreEventKind::TestSlow {
539                stress_index,
540                test_instance,
541                retry_data,
542                elapsed,
543                will_terminate,
544            } => {
545                let pid = self.pid_for_test(&test_instance.binary_id);
546                let tid = self.tid_for_test(&test_instance)?;
547                let ts_us = datetime_to_microseconds(timestamp);
548
549                self.trace_events.push(ChromeTraceEvent {
550                    name: "slow".to_string(),
551                    cat: Category::Test,
552                    ph: Phase::Instant,
553                    ts: ts_us,
554                    pid,
555                    tid,
556                    s: Some(InstantScope::Thread),
557                    id: None,
558                    bp: None,
559                    args: Some(ChromeTraceArgs::TestSlow(TestSlowArgs {
560                        elapsed_secs: elapsed.as_secs_f64(),
561                        will_terminate,
562                        attempt: retry_data.attempt,
563                        stress_index: stress_index.as_ref().map(StressIndexArgs::new),
564                    })),
565                });
566            }
567            CoreEventKind::StressSubRunStarted { progress } => {
568                let ts_us = datetime_to_microseconds(timestamp);
569
570                self.ensure_metadata_events(
571                    RUN_LIFECYCLE_PID,
572                    STRESS_SUBRUN_TID,
573                    &self.run_process_name(),
574                    "stress sub-runs",
575                );
576
577                self.emit_begin(
578                    RUN_LIFECYCLE_PID,
579                    STRESS_SUBRUN_TID,
580                    "sub-run",
581                    Category::Stress,
582                    ts_us,
583                    Some(ChromeTraceArgs::StressSubRunBegin(StressSubRunBeginArgs {
584                        progress,
585                    })),
586                );
587                self.stress_subrun_open = true;
588            }
589            CoreEventKind::StressSubRunFinished {
590                progress,
591                sub_elapsed,
592                sub_stats,
593            } => {
594                if !self.stress_subrun_open {
595                    return Err(ChromeTraceError::MissingStressSubRunStart);
596                }
597
598                let ts_us = datetime_to_microseconds(timestamp);
599
600                self.emit_end(
601                    RUN_LIFECYCLE_PID,
602                    STRESS_SUBRUN_TID,
603                    "sub-run",
604                    Category::Stress,
605                    ts_us,
606                    Some(ChromeTraceArgs::StressSubRunEnd(StressSubRunEndArgs {
607                        progress,
608                        time_taken_ms: duration_to_millis(sub_elapsed),
609                        sub_stats,
610                    })),
611                );
612                self.stress_subrun_open = false;
613            }
614            CoreEventKind::SetupScriptSlow {
615                stress_index,
616                script_id,
617                program: _,
618                args: _,
619                elapsed,
620                will_terminate,
621            } => {
622                let script_name = script_id.to_string();
623                let tid = self
624                    .running_scripts
625                    .iter()
626                    .find(|(_, name)| **name == script_name)
627                    .map(|(&index, _)| index as u64 + TID_OFFSET)
628                    .ok_or_else(|| ChromeTraceError::MissingScriptStart {
629                        script_id: script_id.clone(),
630                    })?;
631                let ts_us = datetime_to_microseconds(timestamp);
632
633                self.trace_events.push(ChromeTraceEvent {
634                    name: "slow".to_string(),
635                    cat: Category::SetupScript,
636                    ph: Phase::Instant,
637                    ts: ts_us,
638                    pid: SETUP_SCRIPT_PID,
639                    tid,
640                    s: Some(InstantScope::Thread),
641                    id: None,
642                    bp: None,
643                    args: Some(ChromeTraceArgs::SetupScriptSlow(SetupScriptSlowArgs {
644                        script_id: script_id.as_identifier().as_str().to_string(),
645                        elapsed_secs: elapsed.as_secs_f64(),
646                        will_terminate,
647                        stress_index: stress_index.as_ref().map(StressIndexArgs::new),
648                    })),
649                });
650            }
651            // Skipped tests don't produce trace spans (they have no duration).
652            CoreEventKind::TestSkipped { .. } => {}
653        }
654        Ok(())
655    }
656
657    fn process_output_event(
658        &mut self,
659        event: OutputEventKind<RecordingSpec>,
660        timestamp: DateTime<FixedOffset>,
661    ) -> Result<(), ChromeTraceError> {
662        // Use the outer event timestamp for E events rather than computing
663        // from ExecuteStatus.start_time + time_taken. The computed end time
664        // doesn't account for pause duration (the process timer stops during
665        // SIGTSTP), so it can land inside or before a pause gap, producing
666        // broken B/E sequences.
667        let end_us = datetime_to_microseconds(timestamp);
668
669        match event {
670            OutputEventKind::TestAttemptFailedWillRetry {
671                stress_index,
672                test_instance,
673                run_status,
674                delay_before_next_attempt,
675                failure_output: _,
676                running,
677            } => {
678                let pid = self.pid_for_test(&test_instance.binary_id);
679                let tid = self.tid_for_test(&test_instance)?;
680
681                let end_args = self.test_end_args(
682                    &test_instance,
683                    &run_status,
684                    stress_index.as_ref(),
685                    Some(delay_before_next_attempt),
686                );
687
688                let event_name = self.group_by.test_event_name(&test_instance);
689                self.emit_end(
690                    pid,
691                    tid,
692                    &event_name,
693                    Category::Test,
694                    end_us,
695                    Some(end_args),
696                );
697
698                // Emit a flow start arrow to connect to the upcoming retry.
699                let flow_id = self.next_flow_id;
700                self.next_flow_id += 1;
701                self.emit_flow_start(pid, tid, end_us, flow_id);
702                self.pending_retry_flows
703                    .insert(test_instance.clone(), flow_id);
704
705                self.running_test_count = running;
706                self.emit_counter_event(end_us);
707
708                // Close the B/E pair. TestRetryStarted will open a new one.
709                self.slot_assignments.remove(&test_instance);
710            }
711            OutputEventKind::TestFinished {
712                stress_index,
713                test_instance,
714                run_statuses,
715                success_output: _,
716                failure_output: _,
717                junit_store_success_output: _,
718                junit_store_failure_output: _,
719                current_stats,
720                running,
721            } => {
722                // Only emit E for the last attempt; earlier attempts were
723                // already closed by TestAttemptFailedWillRetry.
724                let last = run_statuses.last_status();
725                let pid = self.pid_for_test(&test_instance.binary_id);
726                let tid = self.tid_for_test(&test_instance)?;
727
728                let end_args =
729                    self.test_end_args(&test_instance, last, stress_index.as_ref(), None);
730
731                let event_name = self.group_by.test_event_name(&test_instance);
732                self.emit_end(
733                    pid,
734                    tid,
735                    &event_name,
736                    Category::Test,
737                    end_us,
738                    Some(end_args),
739                );
740
741                self.running_test_count = running;
742                self.emit_counter_event(end_us);
743                self.emit_results_counter_event(end_us, &current_stats);
744
745                self.slot_assignments.remove(&test_instance);
746            }
747            OutputEventKind::SetupScriptFinished {
748                stress_index,
749                index,
750                total: _,
751                script_id,
752                program: _,
753                args: _,
754                no_capture: _,
755                run_status,
756            } => {
757                // Validate that a matching SetupScriptStarted was seen.
758                if !self.running_scripts.contains_key(&index) {
759                    return Err(ChromeTraceError::MissingScriptStart {
760                        script_id: script_id.clone(),
761                    });
762                }
763
764                let tid = index as u64 + TID_OFFSET;
765                let script_id_str = script_id.as_identifier().as_str().to_string();
766                let script_name = script_id.to_string();
767
768                let end_args = ChromeTraceArgs::SetupScriptEnd(SetupScriptEndArgs {
769                    script_id: script_id_str,
770                    time_taken_ms: duration_to_millis(run_status.time_taken),
771                    result: run_status.result.clone(),
772                    is_slow: run_status.is_slow,
773                    stress_index: stress_index.as_ref().map(StressIndexArgs::new),
774                    error: run_status.error_summary.as_ref().map(ErrorSummaryArgs::new),
775                });
776
777                self.emit_end(
778                    SETUP_SCRIPT_PID,
779                    tid,
780                    &script_name,
781                    Category::SetupScript,
782                    end_us,
783                    Some(end_args),
784                );
785
786                self.running_script_count = self.running_script_count.saturating_sub(1);
787                self.emit_counter_event(end_us);
788
789                self.running_scripts.remove(&index);
790            }
791        }
792        Ok(())
793    }
794
795    // --- Span open/close helpers for pause/resume ---
796
797    /// Closes all open B events (tests, setup scripts, stress sub-run, run
798    /// bar) at the given timestamp. Called when the run is paused.
799    fn close_all_open_spans(&mut self, ts_us: f64) {
800        match self.run_bar_state {
801            RunBarState::Open => {
802                self.emit_end(
803                    RUN_LIFECYCLE_PID,
804                    RUN_LIFECYCLE_TID,
805                    "test run",
806                    Category::Run,
807                    ts_us,
808                    None,
809                );
810                self.run_bar_state = RunBarState::Paused;
811            }
812            RunBarState::Paused | RunBarState::Closed => {}
813        }
814
815        if self.stress_subrun_open {
816            self.emit_end(
817                RUN_LIFECYCLE_PID,
818                STRESS_SUBRUN_TID,
819                "sub-run",
820                Category::Stress,
821                ts_us,
822                None,
823            );
824        }
825
826        self.emit_test_and_script_span_events(Phase::End, ts_us);
827    }
828
829    /// Reopens all spans that were closed by `close_all_open_spans`. Called
830    /// when the run is continued after a pause.
831    fn reopen_all_spans(&mut self, ts_us: f64) {
832        match self.run_bar_state {
833            RunBarState::Paused => {
834                self.emit_begin(
835                    RUN_LIFECYCLE_PID,
836                    RUN_LIFECYCLE_TID,
837                    "test run",
838                    Category::Run,
839                    ts_us,
840                    None,
841                );
842                self.run_bar_state = RunBarState::Open;
843            }
844            RunBarState::Open | RunBarState::Closed => {}
845        }
846
847        if self.stress_subrun_open {
848            self.emit_begin(
849                RUN_LIFECYCLE_PID,
850                STRESS_SUBRUN_TID,
851                "sub-run",
852                Category::Stress,
853                ts_us,
854                None,
855            );
856        }
857
858        self.emit_test_and_script_span_events(Phase::Begin, ts_us);
859    }
860
861    /// Emits B or E events for all currently open test and setup script
862    /// spans, in deterministic order. Tests are sorted by global_slot;
863    /// scripts by index (BTreeMap iteration is already sorted).
864    ///
865    /// Uses `self.group_by` methods directly instead of `pid_for_test`
866    /// because `self.slot_assignments` is already borrowed for iteration.
867    /// `self.group_by` is `Copy`, so it can be captured independently by
868    /// the closure. For `Binary` mode, pids are looked up from
869    /// `self.binary_pid_map` (already assigned by `TestStarted`).
870    fn emit_test_and_script_span_events(&mut self, ph: Phase, ts_us: f64) {
871        // Collect test spans sorted by global_slot.
872        let mut test_spans: Vec<(u64, u64, String)> = self
873            .slot_assignments
874            .iter()
875            .map(|(id, sa)| {
876                let pid = match self.group_by {
877                    ChromeTraceGroupBy::Binary => *self
878                        .binary_pid_map
879                        .get(&id.binary_id)
880                        .expect("binary pid already assigned by TestStarted"),
881                    ChromeTraceGroupBy::Slot => ALL_TESTS_PID,
882                };
883                let tid = sa.global_slot + TID_OFFSET;
884                let name = self.group_by.test_event_name(id);
885                (pid, tid, name)
886            })
887            .collect();
888        test_spans.sort_by_key(|&(_, tid, _)| tid);
889        for (pid, tid, name) in &test_spans {
890            self.emit_duration_event(*pid, *tid, name, Category::Test, ph, ts_us, None);
891        }
892
893        // Scripts (BTreeMap iteration is already sorted by index).
894        let script_spans: Vec<(u64, String)> = self
895            .running_scripts
896            .iter()
897            .map(|(&index, name)| (index as u64 + TID_OFFSET, name.clone()))
898            .collect();
899        for (tid, name) in &script_spans {
900            self.emit_duration_event(
901                SETUP_SCRIPT_PID,
902                *tid,
903                name,
904                Category::SetupScript,
905                ph,
906                ts_us,
907                None,
908            );
909        }
910    }
911
912    // --- Low-level event emission ---
913
914    fn emit_begin(
915        &mut self,
916        pid: u64,
917        tid: u64,
918        name: &str,
919        cat: Category,
920        ts_us: f64,
921        args: Option<ChromeTraceArgs>,
922    ) {
923        self.emit_duration_event(pid, tid, name, cat, Phase::Begin, ts_us, args);
924    }
925
926    fn emit_end(
927        &mut self,
928        pid: u64,
929        tid: u64,
930        name: &str,
931        cat: Category,
932        ts_us: f64,
933        args: Option<ChromeTraceArgs>,
934    ) {
935        self.emit_duration_event(pid, tid, name, cat, Phase::End, ts_us, args);
936    }
937
938    // Parameters directly correspond to ChromeTraceEvent fields.
939    #[expect(clippy::too_many_arguments)]
940    fn emit_duration_event(
941        &mut self,
942        pid: u64,
943        tid: u64,
944        name: &str,
945        cat: Category,
946        ph: Phase,
947        ts_us: f64,
948        args: Option<ChromeTraceArgs>,
949    ) {
950        self.trace_events.push(ChromeTraceEvent {
951            name: name.to_string(),
952            cat,
953            ph,
954            ts: ts_us,
955            pid,
956            tid,
957            s: None,
958            id: None,
959            bp: None,
960            args,
961        });
962    }
963
964    /// Emits a counter event tracking running tests and scripts.
965    fn emit_counter_event(&mut self, ts_us: f64) {
966        self.trace_events.push(ChromeTraceEvent {
967            name: "concurrency".to_string(),
968            cat: Category::Run,
969            ph: Phase::Counter,
970            ts: ts_us,
971            pid: RUN_LIFECYCLE_PID,
972            tid: 0,
973            s: None,
974            id: None,
975            bp: None,
976            args: Some(ChromeTraceArgs::Counter(CounterArgs {
977                running_tests: self.running_test_count,
978                running_scripts: self.running_script_count,
979            })),
980        });
981    }
982
983    /// Emits a counter event tracking cumulative test results. Produces a
984    /// stacked area chart in Perfetto with passed/flaky/failed bands.
985    fn emit_results_counter_event(&mut self, ts_us: f64, stats: &RunStats) {
986        self.trace_events.push(ChromeTraceEvent {
987            name: "test results".to_string(),
988            cat: Category::Run,
989            ph: Phase::Counter,
990            ts: ts_us,
991            pid: RUN_LIFECYCLE_PID,
992            tid: 0,
993            s: None,
994            id: None,
995            bp: None,
996            args: Some(ChromeTraceArgs::ResultsCounter(ResultsCounterArgs {
997                passed: stats.passed,
998                flaky: stats.flaky,
999                failed: stats.failed_count(),
1000            })),
1001        });
1002    }
1003
1004    /// Emits a flow start event (arrow origin) for retry connections.
1005    fn emit_flow_start(&mut self, pid: u64, tid: u64, ts_us: f64, flow_id: u64) {
1006        self.trace_events.push(ChromeTraceEvent {
1007            name: "retry".to_string(),
1008            cat: Category::Test,
1009            ph: Phase::FlowStart,
1010            ts: ts_us,
1011            pid,
1012            tid,
1013            s: None,
1014            id: Some(flow_id),
1015            bp: None,
1016            args: None,
1017        });
1018    }
1019
1020    /// Emits a flow finish event (arrow destination) for retry connections.
1021    fn emit_flow_finish(&mut self, pid: u64, tid: u64, ts_us: f64, flow_id: u64) {
1022        self.trace_events.push(ChromeTraceEvent {
1023            name: "retry".to_string(),
1024            cat: Category::Test,
1025            ph: Phase::FlowFinish,
1026            ts: ts_us,
1027            pid,
1028            tid,
1029            s: None,
1030            id: Some(flow_id),
1031            bp: Some(FlowBindingPoint::EnclosingSlice),
1032            args: None,
1033        });
1034    }
1035
1036    /// Emits a process-scoped instant event for run lifecycle markers (cancel,
1037    /// pause, continue). Placed on the run lifecycle process so they appear
1038    /// alongside the run bar in Perfetto.
1039    fn emit_run_instant_event(
1040        &mut self,
1041        timestamp: DateTime<FixedOffset>,
1042        name: &str,
1043        cancel_reason: Option<CancelReason>,
1044        running: usize,
1045        setup_scripts_running: usize,
1046    ) {
1047        let pid = RUN_LIFECYCLE_PID;
1048        let tid = RUN_LIFECYCLE_TID;
1049        let ts_us = datetime_to_microseconds(timestamp);
1050
1051        // Ensure the run lifecycle process metadata is emitted. Uses the
1052        // stored profile name if RunStarted was seen, otherwise a generic
1053        // fallback for truncated logs.
1054        self.ensure_metadata_events(pid, tid, &self.run_process_name(), "run");
1055
1056        self.trace_events.push(ChromeTraceEvent {
1057            name: name.to_string(),
1058            cat: Category::Run,
1059            ph: Phase::Instant,
1060            ts: ts_us,
1061            pid,
1062            tid,
1063            s: Some(InstantScope::Process),
1064            id: None,
1065            bp: None,
1066            args: Some(ChromeTraceArgs::RunInstant(RunInstantArgs {
1067                running,
1068                setup_scripts_running,
1069                reason: cancel_reason,
1070            })),
1071        });
1072    }
1073
1074    // --- Utilities ---
1075
1076    /// Returns the display name for the run lifecycle process. Uses the stored
1077    /// profile name if `RunStarted` was seen, otherwise falls back to a generic
1078    /// name for truncated logs.
1079    fn run_process_name(&self) -> String {
1080        match &self.profile_name {
1081            Some(name) => format!("nextest run ({name})"),
1082            None => "nextest run".to_string(),
1083        }
1084    }
1085
1086    /// Builds `TestEndArgs` from an `ExecuteStatus` and related context.
1087    fn test_end_args(
1088        &self,
1089        test_instance: &OwnedTestInstanceId,
1090        status: &ExecuteStatus<RecordingSpec>,
1091        stress_index: Option<&StressIndexSummary>,
1092        delay_before_next_attempt: Option<Duration>,
1093    ) -> ChromeTraceArgs {
1094        ChromeTraceArgs::TestEnd(TestEndArgs {
1095            binary_id: test_instance.binary_id.to_string(),
1096            time_taken_ms: duration_to_millis(status.time_taken),
1097            result: status.result.clone(),
1098            attempt: status.retry_data.attempt,
1099            total_attempts: status.retry_data.total_attempts,
1100            is_slow: status.is_slow,
1101            test_group: self
1102                .slot_assignments
1103                .get(test_instance)
1104                .map(|s| s.test_group.to_string()),
1105            stress_index: stress_index.map(StressIndexArgs::new),
1106            delay_before_start_secs: non_zero_duration_secs(status.delay_before_start),
1107            error: status.error_summary.as_ref().map(ErrorSummaryArgs::new),
1108            delay_before_next_attempt_secs: delay_before_next_attempt
1109                .and_then(non_zero_duration_secs),
1110        })
1111    }
1112
1113    /// Builds the args for the run lifecycle E event.
1114    fn run_finished_args(
1115        &self,
1116        elapsed: Duration,
1117        run_stats: RunFinishedStats,
1118        outstanding_not_seen: Option<&TestsNotSeenSummary>,
1119    ) -> ChromeTraceArgs {
1120        ChromeTraceArgs::RunEnd(RunEndArgs {
1121            nextest_version: self.nextest_version.to_string(),
1122            time_taken_ms: duration_to_millis(elapsed),
1123            profile: self.profile_name.clone(),
1124            run_stats,
1125            outstanding_not_seen: outstanding_not_seen.map(|ns| OutstandingNotSeenArgs {
1126                total_not_seen: ns.total_not_seen,
1127            }),
1128        })
1129    }
1130
1131    /// Returns the pid for a binary, assigning one if not yet mapped.
1132    fn pid_for_binary(&mut self, binary_id: &RustBinaryId) -> u64 {
1133        if let Some(&pid) = self.binary_pid_map.get(binary_id) {
1134            pid
1135        } else {
1136            let pid = self.next_pid;
1137            self.next_pid += 1;
1138            self.binary_pid_map.insert(binary_id.clone(), pid);
1139            pid
1140        }
1141    }
1142
1143    /// Returns the pid to use for a test event, respecting the grouping mode.
1144    ///
1145    /// In `Binary` mode, delegates to `pid_for_binary` (one pid per binary).
1146    /// In `Slot` mode, returns `ALL_TESTS_PID` (all tests share one pid).
1147    fn pid_for_test(&mut self, binary_id: &RustBinaryId) -> u64 {
1148        match self.group_by {
1149            ChromeTraceGroupBy::Binary => self.pid_for_binary(binary_id),
1150            ChromeTraceGroupBy::Slot => ALL_TESTS_PID,
1151        }
1152    }
1153
1154    /// Returns the tid for a test's global slot, with the offset applied.
1155    ///
1156    /// Returns an error if the test has no slot assignment (i.e. no prior
1157    /// `TestStarted` event was seen).
1158    fn tid_for_test(&self, test_instance: &OwnedTestInstanceId) -> Result<u64, ChromeTraceError> {
1159        match self.slot_assignments.get(test_instance) {
1160            Some(sa) => Ok(sa.global_slot + TID_OFFSET),
1161            None => Err(ChromeTraceError::MissingTestStart {
1162                test_name: test_instance.test_name.clone(),
1163                binary_id: test_instance.binary_id.clone(),
1164            }),
1165        }
1166    }
1167
1168    /// Emits process_name, process_sort_index, thread_name, and
1169    /// thread_sort_index metadata events if not already emitted for the given
1170    /// pid/tid.
1171    ///
1172    /// The sort indexes ensure deterministic ordering in Perfetto: run
1173    /// lifecycle first, then setup scripts, then test binaries.
1174    fn ensure_metadata_events(
1175        &mut self,
1176        pid: u64,
1177        tid: u64,
1178        process_display_name: &str,
1179        thread_display_name: &str,
1180    ) {
1181        if !self.emitted_process_names.contains(&pid) {
1182            self.emit_m_event(
1183                pid,
1184                0,
1185                "process_name",
1186                ChromeTraceArgs::MetadataName(MetadataNameArgs {
1187                    name: process_display_name.to_string(),
1188                }),
1189            );
1190            self.emit_m_event(
1191                pid,
1192                0,
1193                "process_sort_index",
1194                ChromeTraceArgs::MetadataSortIndex(MetadataSortIndexArgs { sort_index: pid }),
1195            );
1196            self.emitted_process_names.insert(pid);
1197        }
1198
1199        if !self.emitted_thread_names.contains(&(pid, tid)) {
1200            self.emit_m_event(
1201                pid,
1202                tid,
1203                "thread_name",
1204                ChromeTraceArgs::MetadataName(MetadataNameArgs {
1205                    name: thread_display_name.to_string(),
1206                }),
1207            );
1208            self.emit_m_event(
1209                pid,
1210                tid,
1211                "thread_sort_index",
1212                ChromeTraceArgs::MetadataSortIndex(MetadataSortIndexArgs { sort_index: tid }),
1213            );
1214            self.emitted_thread_names.insert((pid, tid));
1215        }
1216    }
1217
1218    /// Emits a metadata event.
1219    fn emit_m_event(&mut self, pid: u64, tid: u64, event_name: &str, args: ChromeTraceArgs) {
1220        self.trace_events.push(ChromeTraceEvent {
1221            name: event_name.to_string(),
1222            cat: Category::Empty,
1223            ph: Phase::Metadata,
1224            ts: 0.0,
1225            pid,
1226            tid,
1227            s: None,
1228            id: None,
1229            bp: None,
1230            args: Some(args),
1231        });
1232    }
1233
1234    /// Serializes accumulated events into Chrome Trace Event Format JSON.
1235    fn finish(self, message_format: ChromeTraceMessageFormat) -> Result<Vec<u8>, ChromeTraceError> {
1236        // Always emit otherData: nextest_version is always available, and the
1237        // remaining fields use skip_serializing_if to omit when empty.
1238        let other_data = ChromeTraceOtherData {
1239            nextest_version: self.nextest_version.to_string(),
1240            run_id: self.run_id.map(|id| id.to_string()),
1241            profile_name: self.profile_name,
1242            cli_args: self.cli_args,
1243            stress_condition: self.stress_condition,
1244        };
1245
1246        let output = ChromeTraceOutput {
1247            trace_events: self.trace_events.0,
1248            display_time_unit: "ms",
1249            other_data,
1250        };
1251
1252        let serialize_fn = match message_format {
1253            ChromeTraceMessageFormat::Json => serde_json::to_vec,
1254            ChromeTraceMessageFormat::JsonPretty => serde_json::to_vec_pretty,
1255        };
1256        serialize_fn(&output).map_err(ChromeTraceError::SerializeError)
1257    }
1258}
1259
1260/// Pid reserved for run lifecycle events (appears first in the trace viewer).
1261const RUN_LIFECYCLE_PID: u64 = 0;
1262
1263/// Pid reserved for setup scripts.
1264const SETUP_SCRIPT_PID: u64 = 1;
1265
1266/// Pid used for all tests in `Slot` grouping mode.
1267const ALL_TESTS_PID: u64 = 2;
1268
1269/// The first pid assigned to test binaries in `Binary` grouping mode.
1270/// Starts at 2 because 0 is reserved for the run lifecycle and 1 for setup
1271/// scripts.
1272const FIRST_BINARY_PID: u64 = 2;
1273
1274/// Tid used for the run lifecycle thread on `RUN_LIFECYCLE_PID`.
1275const RUN_LIFECYCLE_TID: u64 = 1;
1276
1277/// Tid used for stress sub-run spans on `RUN_LIFECYCLE_PID`.
1278const STRESS_SUBRUN_TID: u64 = 2;
1279
1280/// Tid offset applied to all test slots and setup script indexes. Perfetto
1281/// treats the thread where tid == pid as the process's main thread, which
1282/// causes rendering artifacts. Using a large offset ensures test and
1283/// script tids never collide with process pids (which start at 2 and
1284/// increment with the number of unique binaries).
1285const TID_OFFSET: u64 = 10_000;
1286
1287/// Chrome trace event phase (the `ph` field in the trace format).
1288#[derive(Copy, Clone, Serialize)]
1289enum Phase {
1290    #[serde(rename = "B")]
1291    Begin,
1292    #[serde(rename = "E")]
1293    End,
1294    #[serde(rename = "M")]
1295    Metadata,
1296    #[serde(rename = "i")]
1297    Instant,
1298    #[serde(rename = "C")]
1299    Counter,
1300    #[serde(rename = "s")]
1301    FlowStart,
1302    #[serde(rename = "f")]
1303    FlowFinish,
1304}
1305
1306/// Chrome trace event category (the `cat` field in the trace format).
1307#[derive(Copy, Clone, Serialize)]
1308enum Category {
1309    #[serde(rename = "test")]
1310    Test,
1311    #[serde(rename = "setup-script")]
1312    SetupScript,
1313    #[serde(rename = "stress")]
1314    Stress,
1315    #[serde(rename = "run")]
1316    Run,
1317    #[serde(rename = "")]
1318    Empty,
1319}
1320
1321/// Instant event scope (the `s` field in the trace format).
1322#[derive(Copy, Clone, Serialize)]
1323enum InstantScope {
1324    #[serde(rename = "p")]
1325    Process,
1326    #[serde(rename = "t")]
1327    Thread,
1328}
1329
1330/// Flow event binding point (the `bp` field in the trace format).
1331#[derive(Copy, Clone, Serialize)]
1332enum FlowBindingPoint {
1333    #[serde(rename = "e")]
1334    EnclosingSlice,
1335}
1336
1337/// A single Chrome Trace Event.
1338#[derive(Serialize)]
1339struct ChromeTraceEvent {
1340    /// Event name (test name or script ID).
1341    name: String,
1342
1343    /// Event category.
1344    cat: Category,
1345
1346    /// Event phase.
1347    ph: Phase,
1348
1349    /// Timestamp in microseconds.
1350    ts: f64,
1351
1352    /// Process ID (binary ID or setup-script group).
1353    pid: u64,
1354
1355    /// Thread ID (global slot or script index).
1356    tid: u64,
1357
1358    /// Instant event scope. Only meaningful for instant events.
1359    #[serde(skip_serializing_if = "Option::is_none")]
1360    s: Option<InstantScope>,
1361
1362    /// Flow event ID. Connects flow start and flow finish events.
1363    #[serde(skip_serializing_if = "Option::is_none")]
1364    id: Option<u64>,
1365
1366    /// Flow event binding point.
1367    #[serde(skip_serializing_if = "Option::is_none")]
1368    bp: Option<FlowBindingPoint>,
1369
1370    /// Typed event arguments.
1371    #[serde(skip_serializing_if = "Option::is_none")]
1372    args: Option<ChromeTraceArgs>,
1373}
1374
1375// -------------------------------------------------------------------
1376// Typed args for Chrome trace events
1377// -------------------------------------------------------------------
1378//
1379// Each variant represents the args for a specific event type. Using typed
1380// structs instead of `serde_json::Value` ensures field names and types are
1381// checked at compile time.
1382//
1383// `#[serde(untagged)]` is used for serialization only (this type is never
1384// deserialized, so the guideline about untagged deserializers does not apply).
1385// Each variant serializes as a plain JSON object.
1386
1387/// Args attached to Chrome trace events.
1388#[derive(Serialize)]
1389#[serde(untagged)]
1390enum ChromeTraceArgs {
1391    RunBegin(RunBeginArgs),
1392    RunEnd(RunEndArgs),
1393    RunInstant(RunInstantArgs),
1394    TestBegin(TestBeginArgs),
1395    TestRetryBegin(TestRetryBeginArgs),
1396    TestEnd(TestEndArgs),
1397    TestSlow(TestSlowArgs),
1398    SetupScriptEnd(SetupScriptEndArgs),
1399    SetupScriptSlow(SetupScriptSlowArgs),
1400    StressSubRunBegin(StressSubRunBeginArgs),
1401    StressSubRunEnd(StressSubRunEndArgs),
1402    Counter(CounterArgs),
1403    ResultsCounter(ResultsCounterArgs),
1404    MetadataName(MetadataNameArgs),
1405    MetadataSortIndex(MetadataSortIndexArgs),
1406}
1407
1408// --- Helper types used within args ---
1409
1410/// Stress index information. Uses plain `u32` for `total` rather than
1411/// `NonZeroU32` to match the Chrome trace output convention.
1412#[derive(Serialize)]
1413struct StressIndexArgs {
1414    current: u32,
1415    total: Option<u32>,
1416}
1417
1418impl StressIndexArgs {
1419    fn new(si: &StressIndexSummary) -> Self {
1420        Self {
1421            current: si.current,
1422            total: si.total.map(|t| t.get()),
1423        }
1424    }
1425}
1426
1427/// Error summary for Chrome trace args.
1428#[derive(Serialize)]
1429struct ErrorSummaryArgs {
1430    short_message: String,
1431    description: String,
1432}
1433
1434impl ErrorSummaryArgs {
1435    fn new(summary: &ErrorSummary) -> Self {
1436        Self {
1437            short_message: summary.short_message.clone(),
1438            description: summary.description.clone(),
1439        }
1440    }
1441}
1442
1443/// Outstanding tests not seen, for `RunEndArgs`.
1444#[derive(Serialize)]
1445struct OutstandingNotSeenArgs {
1446    total_not_seen: usize,
1447}
1448
1449// --- Run lifecycle args ---
1450
1451/// Args for `RunStarted` B events.
1452#[derive(Serialize)]
1453struct RunBeginArgs {
1454    nextest_version: String,
1455    run_id: String,
1456    profile: String,
1457    cli_args: Vec<String>,
1458    #[serde(skip_serializing_if = "Option::is_none")]
1459    stress_condition: Option<StressConditionSummary>,
1460}
1461
1462/// Args for `RunFinished` E events.
1463#[derive(Serialize)]
1464struct RunEndArgs {
1465    nextest_version: String,
1466    time_taken_ms: f64,
1467    #[serde(skip_serializing_if = "Option::is_none")]
1468    profile: Option<String>,
1469    run_stats: RunFinishedStats,
1470    #[serde(skip_serializing_if = "Option::is_none")]
1471    outstanding_not_seen: Option<OutstandingNotSeenArgs>,
1472}
1473
1474/// Args for run lifecycle instant events (cancel, pause, continue).
1475#[derive(Serialize)]
1476struct RunInstantArgs {
1477    running: usize,
1478    setup_scripts_running: usize,
1479    #[serde(skip_serializing_if = "Option::is_none")]
1480    reason: Option<CancelReason>,
1481}
1482
1483// --- Test args ---
1484
1485/// Args for `TestStarted` B events.
1486#[derive(Serialize)]
1487struct TestBeginArgs {
1488    binary_id: String,
1489    #[serde(skip_serializing_if = "Vec::is_empty")]
1490    command_line: Vec<String>,
1491}
1492
1493/// Args for `TestRetryStarted` B events.
1494#[derive(Serialize)]
1495struct TestRetryBeginArgs {
1496    attempt: u32,
1497    total_attempts: u32,
1498    #[serde(skip_serializing_if = "Vec::is_empty")]
1499    command_line: Vec<String>,
1500}
1501
1502/// Args for `TestFinished` and `TestAttemptFailedWillRetry` E events.
1503#[derive(Serialize)]
1504struct TestEndArgs {
1505    binary_id: String,
1506    time_taken_ms: f64,
1507    result: ExecutionResultDescription,
1508    attempt: u32,
1509    total_attempts: u32,
1510    is_slow: bool,
1511    #[serde(skip_serializing_if = "Option::is_none")]
1512    test_group: Option<String>,
1513    #[serde(skip_serializing_if = "Option::is_none")]
1514    stress_index: Option<StressIndexArgs>,
1515    #[serde(skip_serializing_if = "Option::is_none")]
1516    delay_before_start_secs: Option<f64>,
1517    #[serde(skip_serializing_if = "Option::is_none")]
1518    error: Option<ErrorSummaryArgs>,
1519    #[serde(skip_serializing_if = "Option::is_none")]
1520    delay_before_next_attempt_secs: Option<f64>,
1521}
1522
1523/// Args for `TestSlow` instant events.
1524#[derive(Serialize)]
1525struct TestSlowArgs {
1526    elapsed_secs: f64,
1527    will_terminate: bool,
1528    attempt: u32,
1529    #[serde(skip_serializing_if = "Option::is_none")]
1530    stress_index: Option<StressIndexArgs>,
1531}
1532
1533// --- Setup script args ---
1534
1535/// Args for `SetupScriptFinished` E events.
1536#[derive(Serialize)]
1537struct SetupScriptEndArgs {
1538    script_id: String,
1539    time_taken_ms: f64,
1540    result: ExecutionResultDescription,
1541    is_slow: bool,
1542    #[serde(skip_serializing_if = "Option::is_none")]
1543    stress_index: Option<StressIndexArgs>,
1544    #[serde(skip_serializing_if = "Option::is_none")]
1545    error: Option<ErrorSummaryArgs>,
1546}
1547
1548/// Args for `SetupScriptSlow` instant events.
1549#[derive(Serialize)]
1550struct SetupScriptSlowArgs {
1551    script_id: String,
1552    elapsed_secs: f64,
1553    will_terminate: bool,
1554    #[serde(skip_serializing_if = "Option::is_none")]
1555    stress_index: Option<StressIndexArgs>,
1556}
1557
1558// --- Stress args ---
1559
1560/// Args for `StressSubRunStarted` B events.
1561#[derive(Serialize)]
1562struct StressSubRunBeginArgs {
1563    progress: StressProgress,
1564}
1565
1566/// Args for `StressSubRunFinished` E events.
1567#[derive(Serialize)]
1568struct StressSubRunEndArgs {
1569    progress: StressProgress,
1570    time_taken_ms: f64,
1571    sub_stats: RunStats,
1572}
1573
1574// --- Counter and metadata args ---
1575
1576/// Args for counter events tracking running tests and scripts.
1577#[derive(Serialize)]
1578struct CounterArgs {
1579    running_tests: usize,
1580    running_scripts: usize,
1581}
1582
1583/// Args for counter events tracking cumulative test results. Produces a
1584/// stacked area chart with passed (clean), flaky, and failed bands.
1585#[derive(Serialize)]
1586struct ResultsCounterArgs {
1587    /// Tests that passed on the first attempt (excludes flaky).
1588    passed: usize,
1589    /// Tests that passed on retry.
1590    flaky: usize,
1591    /// Tests that failed all attempts, including exec failures.
1592    failed: usize,
1593}
1594
1595/// Args for `process_name` and `thread_name` metadata events.
1596///
1597/// Field names are defined by the Chrome Trace Event Format spec.
1598#[derive(Serialize)]
1599struct MetadataNameArgs {
1600    name: String,
1601}
1602
1603/// Args for `process_sort_index` and `thread_sort_index` metadata events.
1604///
1605/// Field names are defined by the Chrome Trace Event Format spec.
1606#[derive(Serialize)]
1607struct MetadataSortIndexArgs {
1608    sort_index: u64,
1609}
1610
1611/// Top-level Chrome Trace Event Format output.
1612#[derive(Serialize)]
1613#[serde(rename_all = "camelCase")] // required by the Chrome Trace Event Format spec
1614struct ChromeTraceOutput {
1615    trace_events: Vec<ChromeTraceEvent>,
1616    display_time_unit: &'static str,
1617    /// Arbitrary key/value data included at the top level of the trace output.
1618    /// Uses the spec-defined `otherData` field for session-level metadata.
1619    /// Always emitted because `nextest_version` is always available.
1620    other_data: ChromeTraceOtherData,
1621}
1622
1623/// Session-level data included in the `otherData` field of the trace output.
1624#[derive(Serialize)]
1625struct ChromeTraceOtherData {
1626    nextest_version: String,
1627    #[serde(skip_serializing_if = "Option::is_none")]
1628    run_id: Option<String>,
1629    #[serde(skip_serializing_if = "Option::is_none")]
1630    profile_name: Option<String>,
1631    #[serde(skip_serializing_if = "Vec::is_empty")]
1632    cli_args: Vec<String>,
1633    #[serde(skip_serializing_if = "Option::is_none")]
1634    stress_condition: Option<StressConditionSummary>,
1635}
1636
1637/// Converts a `DateTime<FixedOffset>` to microseconds since the Unix epoch.
1638fn datetime_to_microseconds(dt: DateTime<FixedOffset>) -> f64 {
1639    // Use timestamp_micros() which is infallible for all valid DateTime values,
1640    // unlike timestamp_nanos_opt() which overflows outside ~1677-2262.
1641    // The i64 → f64 cast is exact for timestamps through ~year 2255 (2^53 µs).
1642    dt.timestamp_micros() as f64
1643}
1644
1645/// Converts a `Duration` to fractional milliseconds.
1646fn duration_to_millis(d: Duration) -> f64 {
1647    d.as_secs_f64() * 1000.0
1648}
1649
1650/// Returns `Some(secs)` if the duration is non-zero, `None` otherwise.
1651fn non_zero_duration_secs(d: Duration) -> Option<f64> {
1652    if d.is_zero() {
1653        None
1654    } else {
1655        Some(d.as_secs_f64())
1656    }
1657}
1658
1659#[cfg(test)]
1660mod tests {
1661    use super::*;
1662    use crate::{
1663        config::{
1664            elements::{FlakyResult, TestGroup},
1665            scripts::ScriptId,
1666        },
1667        list::OwnedTestInstanceId,
1668        output_spec::RecordingSpec,
1669        record::summary::{
1670            CoreEventKind, OutputEventKind, TestEventKindSummary, TestEventSummary,
1671            ZipStoreOutputDescription,
1672        },
1673        reporter::{
1674            TestOutputDisplay,
1675            events::{
1676                ChildExecutionOutputDescription, ExecuteStatus, ExecutionResultDescription,
1677                ExecutionStatuses, FailureDescription, RetryData, RunFinishedStats, RunStats,
1678                SetupScriptExecuteStatus, TestSlotAssignment,
1679            },
1680        },
1681        runner::StressCount,
1682    };
1683    use chrono::{FixedOffset, TimeZone};
1684    use nextest_metadata::{RustBinaryId, TestCaseName};
1685    use std::{
1686        collections::{BTreeSet, HashMap},
1687        num::NonZero,
1688        time::Duration,
1689    };
1690
1691    /// Asserts that begin and end events are balanced per (pid, tid, cat)
1692    /// triple. Every begin must have a matching end. This catches unbalanced
1693    /// spans that would render as infinite-length bars in Perfetto.
1694    fn assert_be_balanced(trace_events: &[serde_json::Value]) {
1695        let mut b_counts: HashMap<(u64, u64, &str), usize> = HashMap::new();
1696        let mut e_counts: HashMap<(u64, u64, &str), usize> = HashMap::new();
1697
1698        for event in trace_events {
1699            let ph = event["ph"].as_str().unwrap_or("");
1700            let cat = event["cat"].as_str().unwrap_or("");
1701            let pid = event["pid"].as_u64().unwrap_or(0);
1702            let tid = event["tid"].as_u64().unwrap_or(0);
1703            match ph {
1704                "B" => *b_counts.entry((pid, tid, cat)).or_default() += 1,
1705                "E" => *e_counts.entry((pid, tid, cat)).or_default() += 1,
1706                _ => {}
1707            }
1708        }
1709
1710        // Collect all keys from both maps.
1711        let all_keys: BTreeSet<_> = b_counts.keys().chain(e_counts.keys()).copied().collect();
1712
1713        for key in all_keys {
1714            let b = b_counts.get(&key).copied().unwrap_or(0);
1715            let e = e_counts.get(&key).copied().unwrap_or(0);
1716            assert_eq!(
1717                b, e,
1718                "B/E mismatch for (pid={}, tid={}, cat={:?}): {} B events vs {} E events",
1719                key.0, key.1, key.2, b, e,
1720            );
1721        }
1722    }
1723
1724    fn test_version() -> Version {
1725        Version::new(0, 9, 9999)
1726    }
1727
1728    /// Creates a fixed timestamp at the given number of seconds after the
1729    /// epoch.
1730    fn ts(secs: i64) -> DateTime<FixedOffset> {
1731        FixedOffset::east_opt(0)
1732            .unwrap()
1733            .timestamp_opt(secs, 0)
1734            .unwrap()
1735    }
1736
1737    fn test_id(binary: &str, test: &str) -> OwnedTestInstanceId {
1738        OwnedTestInstanceId {
1739            binary_id: RustBinaryId::new(binary),
1740            test_name: TestCaseName::new(test),
1741        }
1742    }
1743
1744    fn slot(global: u64) -> TestSlotAssignment {
1745        TestSlotAssignment {
1746            global_slot: global,
1747            group_slot: None,
1748            test_group: TestGroup::Global,
1749        }
1750    }
1751
1752    fn core_event(
1753        timestamp: DateTime<FixedOffset>,
1754        kind: CoreEventKind,
1755    ) -> TestEventSummary<RecordingSpec> {
1756        TestEventSummary {
1757            timestamp,
1758            elapsed: Duration::ZERO,
1759            kind: TestEventKindSummary::Core(kind),
1760        }
1761    }
1762
1763    fn output_event(
1764        timestamp: DateTime<FixedOffset>,
1765        kind: OutputEventKind<RecordingSpec>,
1766    ) -> TestEventSummary<RecordingSpec> {
1767        TestEventSummary {
1768            timestamp,
1769            elapsed: Duration::ZERO,
1770            kind: TestEventKindSummary::Output(kind),
1771        }
1772    }
1773
1774    fn empty_output() -> ChildExecutionOutputDescription<RecordingSpec> {
1775        ChildExecutionOutputDescription::Output {
1776            result: Some(ExecutionResultDescription::Pass),
1777            output: ZipStoreOutputDescription::Split {
1778                stdout: None,
1779                stderr: None,
1780            },
1781            errors: None,
1782        }
1783    }
1784
1785    fn passing_status(
1786        start_time: DateTime<FixedOffset>,
1787        time_taken: Duration,
1788        attempt: u32,
1789        total_attempts: u32,
1790    ) -> ExecuteStatus<RecordingSpec> {
1791        ExecuteStatus {
1792            retry_data: RetryData {
1793                attempt,
1794                total_attempts,
1795            },
1796            output: empty_output(),
1797            result: ExecutionResultDescription::Pass,
1798            start_time,
1799            time_taken,
1800            is_slow: false,
1801            delay_before_start: Duration::ZERO,
1802            error_summary: None,
1803            output_error_slice: None,
1804        }
1805    }
1806
1807    fn failing_status(
1808        start_time: DateTime<FixedOffset>,
1809        time_taken: Duration,
1810        attempt: u32,
1811        total_attempts: u32,
1812    ) -> ExecuteStatus<RecordingSpec> {
1813        ExecuteStatus {
1814            retry_data: RetryData {
1815                attempt,
1816                total_attempts,
1817            },
1818            output: empty_output(),
1819            result: ExecutionResultDescription::Fail {
1820                failure: FailureDescription::ExitCode { code: 1 },
1821                leaked: false,
1822            },
1823            start_time,
1824            time_taken,
1825            is_slow: false,
1826            delay_before_start: Duration::ZERO,
1827            error_summary: None,
1828            output_error_slice: None,
1829        }
1830    }
1831
1832    /// Converts events and parses the resulting JSON, returning the top-level
1833    /// object and the `traceEvents` array. Automatically asserts B/E balance.
1834    fn convert_and_parse(
1835        events: Vec<Result<TestEventSummary<RecordingSpec>, RecordReadError>>,
1836        group_by: ChromeTraceGroupBy,
1837    ) -> (serde_json::Value, Vec<serde_json::Value>) {
1838        let json_bytes = convert_to_chrome_trace(
1839            &test_version(),
1840            events,
1841            group_by,
1842            ChromeTraceMessageFormat::JsonPretty,
1843        )
1844        .expect("conversion succeeded");
1845        let parsed: serde_json::Value = serde_json::from_slice(&json_bytes).expect("valid JSON");
1846        let trace_events = parsed["traceEvents"]
1847            .as_array()
1848            .expect("traceEvents is an array")
1849            .clone();
1850        assert_be_balanced(&trace_events);
1851        (parsed, trace_events)
1852    }
1853
1854    fn run_started(timestamp: DateTime<FixedOffset>) -> TestEventSummary<RecordingSpec> {
1855        core_event(
1856            timestamp,
1857            CoreEventKind::RunStarted {
1858                run_id: quick_junit::ReportUuid::nil(),
1859                profile_name: "default".to_string(),
1860                cli_args: vec![],
1861                stress_condition: None,
1862            },
1863        )
1864    }
1865
1866    fn run_finished(
1867        timestamp: DateTime<FixedOffset>,
1868        start_time: DateTime<FixedOffset>,
1869        elapsed: Duration,
1870    ) -> TestEventSummary<RecordingSpec> {
1871        core_event(
1872            timestamp,
1873            CoreEventKind::RunFinished {
1874                run_id: quick_junit::ReportUuid::nil(),
1875                start_time,
1876                elapsed,
1877                run_stats: RunFinishedStats::Single(RunStats::default()),
1878                outstanding_not_seen: None,
1879            },
1880        )
1881    }
1882
1883    fn test_started(
1884        timestamp: DateTime<FixedOffset>,
1885        binary: &str,
1886        test: &str,
1887        global_slot: u64,
1888        running: usize,
1889    ) -> TestEventSummary<RecordingSpec> {
1890        core_event(
1891            timestamp,
1892            CoreEventKind::TestStarted {
1893                stress_index: None,
1894                test_instance: test_id(binary, test),
1895                slot_assignment: slot(global_slot),
1896                current_stats: RunStats::default(),
1897                running,
1898                command_line: vec![],
1899            },
1900        )
1901    }
1902
1903    fn test_finished_pass(
1904        timestamp: DateTime<FixedOffset>,
1905        binary: &str,
1906        test: &str,
1907        start_time: DateTime<FixedOffset>,
1908        time_taken: Duration,
1909        running: usize,
1910    ) -> TestEventSummary<RecordingSpec> {
1911        output_event(
1912            timestamp,
1913            OutputEventKind::TestFinished {
1914                stress_index: None,
1915                test_instance: test_id(binary, test),
1916                success_output: TestOutputDisplay::Never,
1917                failure_output: TestOutputDisplay::Never,
1918                junit_store_success_output: false,
1919                junit_store_failure_output: false,
1920                run_statuses: ExecutionStatuses::new(
1921                    vec![passing_status(start_time, time_taken, 1, 1)],
1922                    FlakyResult::Pass,
1923                ),
1924                current_stats: RunStats::default(),
1925                running,
1926            },
1927        )
1928    }
1929
1930    #[test]
1931    fn basic_test_run() {
1932        let events = vec![
1933            Ok(run_started(ts(1000))),
1934            Ok(test_started(
1935                ts(1000),
1936                "my-crate::bin/my-test",
1937                "tests::basic",
1938                0,
1939                1,
1940            )),
1941            Ok(test_finished_pass(
1942                ts(1001),
1943                "my-crate::bin/my-test",
1944                "tests::basic",
1945                ts(1000),
1946                Duration::from_millis(500),
1947                0,
1948            )),
1949            Ok(run_finished(ts(1002), ts(1000), Duration::from_secs(2))),
1950        ];
1951
1952        let (parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
1953
1954        // B/E pairs: run bar (B+E) + test (B+E) = 4 duration events.
1955        // Metadata: 2 process_name + 2 thread_name + 2 process_sort_index
1956        //   + 2 thread_sort_index = 8.
1957        // Concurrency counter: TestStarted + TestFinished = 2.
1958        // Results counter: TestFinished = 1.
1959        // Total = 15.
1960        assert_eq!(
1961            trace_events.len(),
1962            15,
1963            "expected 15 trace events, got: {trace_events:#?}"
1964        );
1965
1966        // Find test B/E pair.
1967        let test_begins: Vec<_> = trace_events
1968            .iter()
1969            .filter(|e| e["ph"] == "B" && e["cat"] == "test")
1970            .collect();
1971        let test_ends: Vec<_> = trace_events
1972            .iter()
1973            .filter(|e| e["ph"] == "E" && e["cat"] == "test")
1974            .collect();
1975        assert_eq!(test_begins.len(), 1);
1976        assert_eq!(test_ends.len(), 1);
1977
1978        let test_b = test_begins[0];
1979        assert_eq!(test_b["name"], "tests::basic");
1980        assert_eq!(test_b["pid"], 2); // First binary gets pid 2.
1981        assert_eq!(test_b["tid"], TID_OFFSET); // Global slot 0 + TID_OFFSET.
1982
1983        // B timestamp should be the TestStarted event time = 1000s = 1e9 us.
1984        let b_ts = test_b["ts"].as_f64().unwrap();
1985        assert!(
1986            (b_ts - 1_000_000_000.0).abs() < 1.0,
1987            "expected ~1e9 us, got {b_ts}"
1988        );
1989
1990        // E timestamp should be the outer event timestamp ts(1001) = 1001s.
1991        let test_e = test_ends[0];
1992        let e_ts = test_e["ts"].as_f64().unwrap();
1993        assert!(
1994            (e_ts - 1_001_000_000.0).abs() < 1.0,
1995            "expected ~1001000000 us, got {e_ts}"
1996        );
1997
1998        // Result args should be on the E event.
1999        assert_eq!(test_e["args"]["attempt"], 1);
2000
2001        // Run bar B/E.
2002        let run_begins: Vec<_> = trace_events
2003            .iter()
2004            .filter(|e| e["ph"] == "B" && e["cat"] == "run")
2005            .collect();
2006        let run_ends: Vec<_> = trace_events
2007            .iter()
2008            .filter(|e| e["ph"] == "E" && e["cat"] == "run")
2009            .collect();
2010        assert_eq!(run_begins.len(), 1);
2011        assert_eq!(run_ends.len(), 1);
2012        assert_eq!(run_ends[0]["args"]["profile"], "default");
2013
2014        assert_eq!(parsed["displayTimeUnit"], "ms");
2015
2016        // otherData should include run information.
2017        let other_data = &parsed["otherData"];
2018        assert_eq!(other_data["profile_name"], "default");
2019        assert!(!other_data["run_id"].is_null(), "runId should be present");
2020        assert!(
2021            !other_data["nextest_version"].is_null(),
2022            "nextest version should be present"
2023        );
2024
2025        // Sort index metadata events.
2026        let proc_sort: Vec<_> = trace_events
2027            .iter()
2028            .filter(|e| e["name"] == "process_sort_index")
2029            .collect();
2030        assert!(
2031            proc_sort.len() >= 2,
2032            "should have sort indexes for run lifecycle and test binary"
2033        );
2034
2035        // Run lifecycle should have sort_index 0.
2036        let run_sort = proc_sort
2037            .iter()
2038            .find(|e| e["pid"] == 0)
2039            .expect("run lifecycle sort index");
2040        assert_eq!(run_sort["args"]["sort_index"], 0);
2041
2042        // Test binary (pid 2) should have sort_index 2.
2043        let binary_sort = proc_sort
2044            .iter()
2045            .find(|e| e["pid"] == 2)
2046            .expect("binary sort index");
2047        assert_eq!(binary_sort["args"]["sort_index"], 2);
2048
2049        // Thread sort indexes should be emitted.
2050        let thread_sort: Vec<_> = trace_events
2051            .iter()
2052            .filter(|e| e["name"] == "thread_sort_index")
2053            .collect();
2054        assert!(!thread_sort.is_empty(), "should have thread sort indexes");
2055    }
2056
2057    #[test]
2058    fn setup_script() {
2059        let script_id = ScriptId::new("db-setup".into()).expect("valid script ID");
2060
2061        let events = vec![
2062            Ok(core_event(
2063                ts(1000),
2064                CoreEventKind::SetupScriptStarted {
2065                    stress_index: None,
2066                    index: 0,
2067                    total: 1,
2068                    script_id: script_id.clone(),
2069                    program: "/bin/setup".to_string(),
2070                    args: vec![],
2071                    no_capture: false,
2072                },
2073            )),
2074            // Slow event at T=1005.
2075            Ok(core_event(
2076                ts(1005),
2077                CoreEventKind::SetupScriptSlow {
2078                    stress_index: None,
2079                    script_id: script_id.clone(),
2080                    program: "/bin/setup".to_string(),
2081                    args: vec![],
2082                    elapsed: Duration::from_secs(5),
2083                    will_terminate: true,
2084                },
2085            )),
2086            Ok(output_event(
2087                ts(1010),
2088                OutputEventKind::SetupScriptFinished {
2089                    stress_index: None,
2090                    index: 0,
2091                    total: 1,
2092                    script_id: script_id.clone(),
2093                    program: "/bin/setup".to_string(),
2094                    args: vec![],
2095                    no_capture: false,
2096                    run_status: SetupScriptExecuteStatus {
2097                        output: empty_output(),
2098                        result: ExecutionResultDescription::Pass,
2099                        start_time: ts(1000),
2100                        time_taken: Duration::from_secs(10),
2101                        is_slow: true,
2102                        env_map: None,
2103                        error_summary: None,
2104                    },
2105                },
2106            )),
2107        ];
2108
2109        let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
2110
2111        let b_events: Vec<_> = trace_events
2112            .iter()
2113            .filter(|e| e["ph"] == "B" && e["cat"] == "setup-script")
2114            .collect();
2115        let e_events: Vec<_> = trace_events
2116            .iter()
2117            .filter(|e| e["ph"] == "E" && e["cat"] == "setup-script")
2118            .collect();
2119        assert_eq!(b_events.len(), 1);
2120        assert_eq!(e_events.len(), 1);
2121
2122        assert_eq!(b_events[0]["name"], "db-setup");
2123        assert_eq!(b_events[0]["pid"], 1); // Setup scripts use pid 1.
2124        assert_eq!(b_events[0]["tid"], TID_OFFSET); // Script index 0 + TID_OFFSET.
2125
2126        // E event should have the result args.
2127        assert_eq!(e_events[0]["args"]["script_id"], "db-setup");
2128
2129        // Slow instant event should be emitted.
2130        let slow_events: Vec<_> = trace_events
2131            .iter()
2132            .filter(|e| e["ph"] == "i" && e["name"] == "slow")
2133            .collect();
2134        assert_eq!(slow_events.len(), 1, "expected 1 slow instant event");
2135
2136        let slow = slow_events[0];
2137        assert_eq!(slow["cat"], "setup-script");
2138        assert_eq!(slow["s"], "t", "should be thread-scoped");
2139        assert_eq!(slow["args"]["will_terminate"], true);
2140        assert_eq!(slow["args"]["elapsed_secs"], 5.0);
2141        assert_eq!(slow["args"]["script_id"], "db-setup");
2142        assert_eq!(slow["pid"], SETUP_SCRIPT_PID);
2143    }
2144
2145    #[test]
2146    fn empty_run_produces_only_run_lifecycle() {
2147        let events = vec![
2148            Ok(run_started(ts(1000))),
2149            Ok(run_finished(ts(1000), ts(1000), Duration::ZERO)),
2150        ];
2151
2152        let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
2153
2154        // Run lifecycle: 1 process_name + 1 process_sort_index +
2155        //   1 thread_name + 1 thread_sort_index + B + E = 6.
2156        // No test events.
2157        assert_eq!(
2158            trace_events.len(),
2159            6,
2160            "empty run should produce only run lifecycle events, got: {trace_events:#?}"
2161        );
2162
2163        let b_events: Vec<_> = trace_events
2164            .iter()
2165            .filter(|e| e["ph"] == "B" && e["cat"] == "run")
2166            .collect();
2167        let e_events: Vec<_> = trace_events
2168            .iter()
2169            .filter(|e| e["ph"] == "E" && e["cat"] == "run")
2170            .collect();
2171        assert_eq!(b_events.len(), 1);
2172        assert_eq!(e_events.len(), 1);
2173        assert_eq!(b_events[0]["name"], "test run");
2174    }
2175
2176    /// Verifies that pause/resume creates gaps in the timeline by splitting
2177    /// B/E events. Also checks instant event markers and cancel events.
2178    #[test]
2179    fn pause_resume_splits_events() {
2180        let events = vec![
2181            // Uses non-default profile "ci" and cli_args, so kept explicit.
2182            Ok(core_event(
2183                ts(1000),
2184                CoreEventKind::RunStarted {
2185                    run_id: quick_junit::ReportUuid::nil(),
2186                    profile_name: "ci".to_string(),
2187                    cli_args: vec!["--run-ignored".to_string()],
2188                    stress_condition: None,
2189                },
2190            )),
2191            Ok(test_started(ts(1000), "crate::bin/test", "test_a", 0, 1)),
2192            // Pause at T=1001.
2193            Ok(core_event(
2194                ts(1001),
2195                CoreEventKind::RunPaused {
2196                    setup_scripts_running: 0,
2197                    running: 1,
2198                },
2199            )),
2200            // Resume at T=1005.
2201            Ok(core_event(
2202                ts(1005),
2203                CoreEventKind::RunContinued {
2204                    setup_scripts_running: 0,
2205                    running: 1,
2206                },
2207            )),
2208            Ok(test_finished_pass(
2209                ts(1010),
2210                "crate::bin/test",
2211                "test_a",
2212                ts(1000),
2213                Duration::from_secs(10),
2214                0,
2215            )),
2216            Ok(core_event(
2217                ts(1011),
2218                CoreEventKind::RunBeginCancel {
2219                    setup_scripts_running: 0,
2220                    running: 0,
2221                    reason: CancelReason::TestFailure,
2222                },
2223            )),
2224            Ok(run_finished(ts(1012), ts(1000), Duration::from_secs(12))),
2225        ];
2226
2227        let (parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
2228
2229        // The test should have 2 B events (start + resume) and 2 E events
2230        // (pause + finish), creating a gap from T=1001 to T=1005.
2231        let test_b: Vec<_> = trace_events
2232            .iter()
2233            .filter(|e| e["ph"] == "B" && e["cat"] == "test")
2234            .collect();
2235        let test_e: Vec<_> = trace_events
2236            .iter()
2237            .filter(|e| e["ph"] == "E" && e["cat"] == "test")
2238            .collect();
2239        assert_eq!(test_b.len(), 2, "expected 2 test B events (start + resume)");
2240        assert_eq!(test_e.len(), 2, "expected 2 test E events (pause + finish)");
2241
2242        // First segment: B at T=1000, E at T=1001 (pause).
2243        let b1_ts = test_b[0]["ts"].as_f64().unwrap();
2244        let e1_ts = test_e[0]["ts"].as_f64().unwrap();
2245        assert!(
2246            (b1_ts - 1_000_000_000.0).abs() < 1.0,
2247            "first B should be at T=1000"
2248        );
2249        assert!(
2250            (e1_ts - 1_001_000_000.0).abs() < 1.0,
2251            "first E should be at T=1001 (pause)"
2252        );
2253
2254        // Second segment: B at T=1005 (resume), E at T=1010 (finish).
2255        let b2_ts = test_b[1]["ts"].as_f64().unwrap();
2256        let e2_ts = test_e[1]["ts"].as_f64().unwrap();
2257        assert!(
2258            (b2_ts - 1_005_000_000.0).abs() < 1.0,
2259            "second B should be at T=1005 (resume)"
2260        );
2261        assert!(
2262            (e2_ts - 1_010_000_000.0).abs() < 1.0,
2263            "second E should be at T=1010 (finish)"
2264        );
2265
2266        // The run bar should also be split: 2 B + 2 E for the run.
2267        let run_b: Vec<_> = trace_events
2268            .iter()
2269            .filter(|e| e["ph"] == "B" && e["cat"] == "run")
2270            .collect();
2271        let run_e: Vec<_> = trace_events
2272            .iter()
2273            .filter(|e| e["ph"] == "E" && e["cat"] == "run")
2274            .collect();
2275        assert_eq!(run_b.len(), 2, "expected 2 run B events (start + resume)");
2276        assert_eq!(run_e.len(), 2, "expected 2 run E events (pause + finish)");
2277
2278        // Instant events: paused, continued, cancel.
2279        let instant_events: Vec<_> = trace_events.iter().filter(|e| e["ph"] == "i").collect();
2280        assert_eq!(instant_events.len(), 3);
2281        let names: Vec<&str> = instant_events
2282            .iter()
2283            .map(|e| e["name"].as_str().unwrap())
2284            .collect();
2285        assert_eq!(names, vec!["paused", "continued", "cancel"]);
2286
2287        // Cancel event should include the reason.
2288        assert_eq!(instant_events[2]["args"]["reason"], "test-failure");
2289
2290        // Process metadata should show the profile name.
2291        let process_meta: Vec<_> = trace_events
2292            .iter()
2293            .filter(|e| e["name"] == "process_name" && e["pid"] == 0)
2294            .collect();
2295        assert_eq!(process_meta.len(), 1);
2296        assert_eq!(process_meta[0]["args"]["name"], "nextest run (ci)");
2297
2298        // otherData should use otherData (not metadata), include version,
2299        // profile, and CLI args.
2300        assert!(parsed["metadata"].is_null(), "metadata should not exist");
2301        let other_data = &parsed["otherData"];
2302        assert!(!other_data.is_null(), "otherData should exist");
2303        let version = other_data["nextest_version"].as_str().unwrap();
2304        assert!(!version.is_empty(), "nextest version should be non-empty");
2305        assert_eq!(other_data["profile_name"], "ci");
2306        assert_eq!(other_data["cli_args"][0], "--run-ignored");
2307    }
2308
2309    /// Verifies that pause/resume correctly splits setup script B/E events,
2310    /// not just test events.
2311    #[test]
2312    fn pause_resume_with_setup_scripts() {
2313        let script_id = ScriptId::new("db-setup".into()).expect("valid script ID");
2314
2315        let events = vec![
2316            Ok(run_started(ts(1000))),
2317            Ok(core_event(
2318                ts(1000),
2319                CoreEventKind::SetupScriptStarted {
2320                    stress_index: None,
2321                    index: 0,
2322                    total: 1,
2323                    script_id: script_id.clone(),
2324                    program: "/bin/setup".to_string(),
2325                    args: vec![],
2326                    no_capture: false,
2327                },
2328            )),
2329            // Pause while script is running.
2330            Ok(core_event(
2331                ts(1002),
2332                CoreEventKind::RunPaused {
2333                    setup_scripts_running: 1,
2334                    running: 0,
2335                },
2336            )),
2337            // Resume.
2338            Ok(core_event(
2339                ts(1005),
2340                CoreEventKind::RunContinued {
2341                    setup_scripts_running: 1,
2342                    running: 0,
2343                },
2344            )),
2345            // Script finishes.
2346            Ok(output_event(
2347                ts(1010),
2348                OutputEventKind::SetupScriptFinished {
2349                    stress_index: None,
2350                    index: 0,
2351                    total: 1,
2352                    script_id: script_id.clone(),
2353                    program: "/bin/setup".to_string(),
2354                    args: vec![],
2355                    no_capture: false,
2356                    run_status: SetupScriptExecuteStatus {
2357                        output: empty_output(),
2358                        result: ExecutionResultDescription::Pass,
2359                        start_time: ts(1000),
2360                        time_taken: Duration::from_secs(10),
2361                        is_slow: false,
2362                        env_map: None,
2363                        error_summary: None,
2364                    },
2365                },
2366            )),
2367            Ok(run_finished(ts(1012), ts(1000), Duration::from_secs(12))),
2368        ];
2369
2370        let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
2371
2372        // The setup script should have 2 B events (start + resume) and 2 E
2373        // events (pause + finish), creating a gap from T=1002 to T=1005.
2374        let script_b: Vec<_> = trace_events
2375            .iter()
2376            .filter(|e| e["ph"] == "B" && e["cat"] == "setup-script")
2377            .collect();
2378        let script_e: Vec<_> = trace_events
2379            .iter()
2380            .filter(|e| e["ph"] == "E" && e["cat"] == "setup-script")
2381            .collect();
2382        assert_eq!(
2383            script_b.len(),
2384            2,
2385            "expected 2 setup-script B events (start + resume)"
2386        );
2387        assert_eq!(
2388            script_e.len(),
2389            2,
2390            "expected 2 setup-script E events (pause + finish)"
2391        );
2392
2393        // First segment: B at T=1000, E at T=1002 (pause).
2394        let b1_ts = script_b[0]["ts"].as_f64().unwrap();
2395        let e1_ts = script_e[0]["ts"].as_f64().unwrap();
2396        assert!(
2397            (b1_ts - 1_000_000_000.0).abs() < 1.0,
2398            "first B should be at T=1000"
2399        );
2400        assert!(
2401            (e1_ts - 1_002_000_000.0).abs() < 1.0,
2402            "first E should be at T=1002 (pause)"
2403        );
2404
2405        // Second segment: B at T=1005 (resume).
2406        let b2_ts = script_b[1]["ts"].as_f64().unwrap();
2407        assert!(
2408            (b2_ts - 1_005_000_000.0).abs() < 1.0,
2409            "second B should be at T=1005 (resume)"
2410        );
2411
2412        // All setup script events should use SETUP_SCRIPT_PID.
2413        for e in script_b.iter().chain(script_e.iter()) {
2414            assert_eq!(
2415                e["pid"], 1,
2416                "setup script events should use SETUP_SCRIPT_PID"
2417            );
2418        }
2419
2420        // The run bar should also be split.
2421        let run_b: Vec<_> = trace_events
2422            .iter()
2423            .filter(|e| e["ph"] == "B" && e["cat"] == "run")
2424            .collect();
2425        let run_e: Vec<_> = trace_events
2426            .iter()
2427            .filter(|e| e["ph"] == "E" && e["cat"] == "run")
2428            .collect();
2429        assert_eq!(run_b.len(), 2, "expected 2 run B events (start + resume)");
2430        assert_eq!(run_e.len(), 2, "expected 2 run E events (pause + finish)");
2431    }
2432
2433    /// The run bar E event should use the RunFinished event's wall-clock
2434    /// timestamp, not `RunFinished.elapsed` (which is monotonic). This
2435    /// ensures the run bar is consistent with test events' coordinate system.
2436    #[test]
2437    fn run_bar_uses_event_timestamp() {
2438        let events = vec![
2439            Ok(run_started(ts(1000))),
2440            Ok(test_started(ts(1000), "crate::bin/test", "slow_test", 0, 1)),
2441            Ok(test_finished_pass(
2442                ts(1010),
2443                "crate::bin/test",
2444                "slow_test",
2445                ts(1000),
2446                Duration::from_secs(10),
2447                0,
2448            )),
2449            // RunFinished event timestamp is ts(1012) (wall-clock), but
2450            // elapsed is only 8 seconds (monotonic). The run bar E should
2451            // use the wall-clock timestamp ts(1012).
2452            Ok(run_finished(ts(1012), ts(1000), Duration::from_secs(8))),
2453        ];
2454
2455        let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
2456
2457        // Run bar B should be at ts(1000), E should be at ts(1012).
2458        let run_b = trace_events
2459            .iter()
2460            .find(|e| e["ph"] == "B" && e["cat"] == "run")
2461            .expect("run B event");
2462        let run_e = trace_events
2463            .iter()
2464            .find(|e| e["ph"] == "E" && e["cat"] == "run")
2465            .expect("run E event");
2466
2467        let run_b_ts = run_b["ts"].as_f64().unwrap();
2468        let run_e_ts = run_e["ts"].as_f64().unwrap();
2469
2470        // Run bar should span ts(1000) → ts(1012) = 12 seconds, not 8.
2471        assert!(
2472            (run_b_ts - 1_000_000_000.0).abs() < 1.0,
2473            "run B should be at ts(1000)"
2474        );
2475        assert!(
2476            (run_e_ts - 1_012_000_000.0).abs() < 1.0,
2477            "run E should be at ts(1012), not ts(1008)"
2478        );
2479
2480        // The test E should not extend past the run E.
2481        let test_e = trace_events
2482            .iter()
2483            .find(|e| e["ph"] == "E" && e["cat"] == "test")
2484            .expect("test E event");
2485        let test_e_ts = test_e["ts"].as_f64().unwrap();
2486        assert!(
2487            test_e_ts <= run_e_ts,
2488            "test E ({test_e_ts}) should not exceed run E ({run_e_ts})"
2489        );
2490    }
2491
2492    /// RunFinished arriving while paused (without RunContinued) should
2493    /// produce well-formed B/E pairs by re-opening the run bar briefly.
2494    #[test]
2495    fn run_finished_while_paused() {
2496        let events = vec![
2497            Ok(run_started(ts(1000))),
2498            Ok(test_started(ts(1000), "crate::bin/test", "test_a", 0, 1)),
2499            // Pause at T=1002.
2500            Ok(core_event(
2501                ts(1002),
2502                CoreEventKind::RunPaused {
2503                    setup_scripts_running: 0,
2504                    running: 1,
2505                },
2506            )),
2507            // RunFinished without RunContinued (e.g., process killed during
2508            // pause, or truncated log).
2509            Ok(run_finished(ts(1005), ts(1000), Duration::from_secs(5))),
2510        ];
2511
2512        let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
2513
2514        // Run bar should have matching B/E pairs. The pause emits an E, and
2515        // RunFinished should re-open with a B and close with an E.
2516        let run_b: Vec<_> = trace_events
2517            .iter()
2518            .filter(|e| e["ph"] == "B" && e["cat"] == "run")
2519            .collect();
2520        let run_e: Vec<_> = trace_events
2521            .iter()
2522            .filter(|e| e["ph"] == "E" && e["cat"] == "run")
2523            .collect();
2524
2525        // Should be 2 B events (RunStarted + reopen at RunFinished) and
2526        // 2 E events (pause + RunFinished close).
2527        assert_eq!(run_b.len(), 2, "expected 2 run B events, got {run_b:#?}");
2528        assert_eq!(run_e.len(), 2, "expected 2 run E events, got {run_e:#?}");
2529
2530        // The final E should have run_stats args.
2531        let last_e = run_e.last().unwrap();
2532        assert!(
2533            !last_e["args"]["run_stats"].is_null(),
2534            "final E should have run_stats"
2535        );
2536
2537        // Every B/E pair should be properly nested (each B must precede its
2538        // corresponding E).
2539        for (b, e) in run_b.iter().zip(run_e.iter()) {
2540            let b_ts = b["ts"].as_f64().unwrap();
2541            let e_ts = e["ts"].as_f64().unwrap();
2542            assert!(
2543                b_ts <= e_ts,
2544                "B timestamp ({b_ts}) should not exceed E timestamp ({e_ts})"
2545            );
2546        }
2547    }
2548
2549    /// Verifies retry B/E pairs, attempt tracking, tid consistency, and
2550    /// flow events (s/f phases) connecting failed attempts to retries.
2551    #[test]
2552    fn retry_flow_events() {
2553        let events = vec![
2554            Ok(test_started(
2555                ts(1000),
2556                "crate::bin/test",
2557                "flaky_test",
2558                0,
2559                1,
2560            )),
2561            Ok(output_event(
2562                ts(1001),
2563                OutputEventKind::TestAttemptFailedWillRetry {
2564                    stress_index: None,
2565                    test_instance: test_id("crate::bin/test", "flaky_test"),
2566                    run_status: failing_status(ts(1000), Duration::from_millis(200), 1, 3),
2567                    delay_before_next_attempt: Duration::ZERO,
2568                    failure_output: TestOutputDisplay::Never,
2569                    running: 1,
2570                },
2571            )),
2572            Ok(core_event(
2573                ts(1001),
2574                CoreEventKind::TestRetryStarted {
2575                    stress_index: None,
2576                    test_instance: test_id("crate::bin/test", "flaky_test"),
2577                    slot_assignment: slot(0),
2578                    retry_data: RetryData {
2579                        attempt: 2,
2580                        total_attempts: 3,
2581                    },
2582                    running: 1,
2583                    command_line: vec![],
2584                },
2585            )),
2586            Ok(output_event(
2587                ts(1002),
2588                OutputEventKind::TestFinished {
2589                    stress_index: None,
2590                    test_instance: test_id("crate::bin/test", "flaky_test"),
2591                    success_output: TestOutputDisplay::Never,
2592                    failure_output: TestOutputDisplay::Never,
2593                    junit_store_success_output: false,
2594                    junit_store_failure_output: false,
2595                    run_statuses: ExecutionStatuses::new(
2596                        vec![
2597                            failing_status(ts(1000), Duration::from_millis(200), 1, 3),
2598                            passing_status(ts(1001), Duration::from_millis(300), 2, 3),
2599                        ],
2600                        FlakyResult::Pass,
2601                    ),
2602                    current_stats: RunStats::default(),
2603                    running: 0,
2604                },
2605            )),
2606        ];
2607
2608        let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
2609
2610        // Flow start (s) should be emitted at TestAttemptFailedWillRetry.
2611        let flow_starts: Vec<_> = trace_events
2612            .iter()
2613            .filter(|e| e["ph"] == "s" && e["name"] == "retry")
2614            .collect();
2615        assert_eq!(flow_starts.len(), 1, "expected 1 flow start event");
2616
2617        // Flow finish (f) should be emitted at TestRetryStarted.
2618        let flow_finishes: Vec<_> = trace_events
2619            .iter()
2620            .filter(|e| e["ph"] == "f" && e["name"] == "retry")
2621            .collect();
2622        assert_eq!(flow_finishes.len(), 1, "expected 1 flow finish event");
2623
2624        // Both should share the same flow ID.
2625        let start_id = flow_starts[0]["id"].as_u64().unwrap();
2626        let finish_id = flow_finishes[0]["id"].as_u64().unwrap();
2627        assert_eq!(start_id, finish_id, "flow start and finish should share ID");
2628
2629        // Flow finish should bind to the enclosing slice.
2630        assert_eq!(flow_finishes[0]["bp"], "e");
2631
2632        // Both should be on the same pid/tid.
2633        assert_eq!(flow_starts[0]["pid"], flow_finishes[0]["pid"]);
2634        assert_eq!(flow_starts[0]["tid"], flow_finishes[0]["tid"]);
2635
2636        // B/E pairs: 2 attempts x (B+E) = 4 duration events.
2637        let b_events: Vec<_> = trace_events
2638            .iter()
2639            .filter(|e| e["ph"] == "B" && e["cat"] == "test")
2640            .collect();
2641        let e_events: Vec<_> = trace_events
2642            .iter()
2643            .filter(|e| e["ph"] == "E" && e["cat"] == "test")
2644            .collect();
2645        assert_eq!(b_events.len(), 2);
2646        assert_eq!(e_events.len(), 2);
2647
2648        // First attempt E: result args with attempt 1.
2649        assert_eq!(e_events[0]["args"]["attempt"], 1);
2650        // Second attempt E: result args with attempt 2.
2651        assert_eq!(e_events[1]["args"]["attempt"], 2);
2652
2653        // All should use the same tid (slot 0).
2654        for e in b_events.iter().chain(e_events.iter()) {
2655            assert_eq!(e["tid"], TID_OFFSET); // Global slot 0 + TID_OFFSET.
2656        }
2657    }
2658
2659    /// Verifies that retry flow events work correctly across pause boundaries.
2660    #[test]
2661    fn retry_across_pause_boundary() {
2662        let events = vec![
2663            Ok(run_started(ts(1000))),
2664            Ok(test_started(ts(1000), "crate::bin/test", "flaky", 0, 1)),
2665            // First attempt fails.
2666            Ok(output_event(
2667                ts(1001),
2668                OutputEventKind::TestAttemptFailedWillRetry {
2669                    stress_index: None,
2670                    test_instance: test_id("crate::bin/test", "flaky"),
2671                    run_status: failing_status(ts(1000), Duration::from_millis(200), 1, 2),
2672                    delay_before_next_attempt: Duration::from_secs(1),
2673                    failure_output: TestOutputDisplay::Never,
2674                    running: 1,
2675                },
2676            )),
2677            // Pause during the retry delay.
2678            Ok(core_event(
2679                ts(1002),
2680                CoreEventKind::RunPaused {
2681                    setup_scripts_running: 0,
2682                    running: 1,
2683                },
2684            )),
2685            // Resume.
2686            Ok(core_event(
2687                ts(1005),
2688                CoreEventKind::RunContinued {
2689                    setup_scripts_running: 0,
2690                    running: 1,
2691                },
2692            )),
2693            // Retry starts after resume.
2694            Ok(core_event(
2695                ts(1005),
2696                CoreEventKind::TestRetryStarted {
2697                    stress_index: None,
2698                    test_instance: test_id("crate::bin/test", "flaky"),
2699                    slot_assignment: slot(0),
2700                    retry_data: RetryData {
2701                        attempt: 2,
2702                        total_attempts: 2,
2703                    },
2704                    running: 1,
2705                    command_line: vec![],
2706                },
2707            )),
2708            Ok(output_event(
2709                ts(1006),
2710                OutputEventKind::TestFinished {
2711                    stress_index: None,
2712                    test_instance: test_id("crate::bin/test", "flaky"),
2713                    success_output: TestOutputDisplay::Never,
2714                    failure_output: TestOutputDisplay::Never,
2715                    junit_store_success_output: false,
2716                    junit_store_failure_output: false,
2717                    run_statuses: ExecutionStatuses::new(
2718                        vec![
2719                            failing_status(ts(1000), Duration::from_millis(200), 1, 2),
2720                            passing_status(ts(1005), Duration::from_millis(300), 2, 2),
2721                        ],
2722                        FlakyResult::Pass,
2723                    ),
2724                    current_stats: RunStats::default(),
2725                    running: 0,
2726                },
2727            )),
2728            Ok(run_finished(ts(1007), ts(1000), Duration::from_secs(7))),
2729        ];
2730
2731        let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
2732
2733        // Flow events should still be paired correctly despite the pause.
2734        let flow_starts: Vec<_> = trace_events.iter().filter(|e| e["ph"] == "s").collect();
2735        let flow_finishes: Vec<_> = trace_events.iter().filter(|e| e["ph"] == "f").collect();
2736        assert_eq!(flow_starts.len(), 1);
2737        assert_eq!(flow_finishes.len(), 1);
2738        assert_eq!(
2739            flow_starts[0]["id"].as_u64(),
2740            flow_finishes[0]["id"].as_u64(),
2741            "flow events should be paired"
2742        );
2743
2744        // Test B/E events should be split across the pause: 2 B + 2 E from
2745        // attempt 1 (start + close at AttemptFailed), plus the pause
2746        // doesn't affect the slot_assignments (already removed). Retry gets
2747        // its own B (after resume) + E (finish).
2748        // Actually, attempt 1: B at start, E at AttemptFailedWillRetry
2749        // (removes from slot_assignments). Pause has nothing to close for
2750        // this test. Retry: B at RetryStarted, E at TestFinished.
2751        let test_b: Vec<_> = trace_events
2752            .iter()
2753            .filter(|e| e["ph"] == "B" && e["cat"] == "test")
2754            .collect();
2755        let test_e: Vec<_> = trace_events
2756            .iter()
2757            .filter(|e| e["ph"] == "E" && e["cat"] == "test")
2758            .collect();
2759        assert_eq!(test_b.len(), 2, "2 B events: initial + retry");
2760        assert_eq!(test_e.len(), 2, "2 E events: attempt failed + finished");
2761    }
2762
2763    /// Verifies that TestSlow emits a thread-scoped instant event.
2764    #[test]
2765    fn test_slow_instant_event() {
2766        let events = vec![
2767            Ok(test_started(ts(1000), "crate::bin/test", "slow_test", 0, 1)),
2768            Ok(core_event(
2769                ts(1005),
2770                CoreEventKind::TestSlow {
2771                    stress_index: None,
2772                    test_instance: test_id("crate::bin/test", "slow_test"),
2773                    retry_data: RetryData {
2774                        attempt: 1,
2775                        total_attempts: 1,
2776                    },
2777                    elapsed: Duration::from_secs(5),
2778                    will_terminate: false,
2779                },
2780            )),
2781            Ok(test_finished_pass(
2782                ts(1010),
2783                "crate::bin/test",
2784                "slow_test",
2785                ts(1000),
2786                Duration::from_secs(10),
2787                0,
2788            )),
2789        ];
2790
2791        let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
2792
2793        // Find the slow instant event.
2794        let slow_events: Vec<_> = trace_events
2795            .iter()
2796            .filter(|e| e["ph"] == "i" && e["name"] == "slow")
2797            .collect();
2798        assert_eq!(slow_events.len(), 1, "expected 1 slow instant event");
2799
2800        let slow = slow_events[0];
2801        assert_eq!(slow["cat"], "test");
2802        assert_eq!(slow["s"], "t", "should be thread-scoped");
2803        assert_eq!(slow["args"]["will_terminate"], false);
2804        assert_eq!(slow["args"]["elapsed_secs"], 5.0);
2805        assert_eq!(slow["args"]["attempt"], 1);
2806
2807        // Should be on the same pid/tid as the test.
2808        let test_b = trace_events
2809            .iter()
2810            .find(|e| e["ph"] == "B" && e["cat"] == "test")
2811            .expect("test B event");
2812        assert_eq!(slow["pid"], test_b["pid"]);
2813        assert_eq!(slow["tid"], test_b["tid"]);
2814    }
2815
2816    #[test]
2817    fn snapshot_basic_trace() {
2818        // A small representative trace for snapshot testing.
2819        let events = vec![
2820            Ok(test_started(
2821                ts(1000),
2822                "my-crate::bin/my-test",
2823                "tests::it_works",
2824                0,
2825                1,
2826            )),
2827            // The outer timestamp (ts(1002)) deliberately differs from
2828            // start_time + time_taken (ts(1000) + 500ms = ts(1000.5)) to
2829            // verify that the E event uses the outer timestamp.
2830            Ok(test_finished_pass(
2831                ts(1002),
2832                "my-crate::bin/my-test",
2833                "tests::it_works",
2834                ts(1000),
2835                Duration::from_millis(500),
2836                0,
2837            )),
2838        ];
2839
2840        let result = convert_to_chrome_trace(
2841            &test_version(),
2842            events,
2843            ChromeTraceGroupBy::Binary,
2844            ChromeTraceMessageFormat::JsonPretty,
2845        );
2846        let json_bytes = result.expect("conversion succeeded");
2847        let json_str = String::from_utf8(json_bytes).expect("valid UTF-8");
2848
2849        insta::assert_snapshot!("basic_chrome_trace", json_str);
2850    }
2851
2852    #[test]
2853    fn snapshot_pause_resume_trace() {
2854        let events = vec![
2855            Ok(run_started(ts(1000))),
2856            Ok(test_started(
2857                ts(1000),
2858                "my-crate::bin/my-test",
2859                "tests::slow",
2860                0,
2861                1,
2862            )),
2863            // Pause at T=1002.
2864            Ok(core_event(
2865                ts(1002),
2866                CoreEventKind::RunPaused {
2867                    setup_scripts_running: 0,
2868                    running: 1,
2869                },
2870            )),
2871            // Resume at T=1008.
2872            Ok(core_event(
2873                ts(1008),
2874                CoreEventKind::RunContinued {
2875                    setup_scripts_running: 0,
2876                    running: 1,
2877                },
2878            )),
2879            // The outer timestamp (ts(1010)) deliberately differs from
2880            // start_time + time_taken (ts(1000) + 4s = ts(1004)). The
2881            // process timer doesn't advance during the 6-second pause
2882            // (T=1002..1008), so time_taken is 4s, not 10s. The E event
2883            // should use the outer timestamp ts(1010), not ts(1004).
2884            Ok(test_finished_pass(
2885                ts(1010),
2886                "my-crate::bin/my-test",
2887                "tests::slow",
2888                ts(1000),
2889                Duration::from_secs(4),
2890                0,
2891            )),
2892            Ok(run_finished(ts(1010), ts(1000), Duration::from_secs(10))),
2893        ];
2894
2895        let result = convert_to_chrome_trace(
2896            &test_version(),
2897            events,
2898            ChromeTraceGroupBy::Binary,
2899            ChromeTraceMessageFormat::JsonPretty,
2900        );
2901        let json_bytes = result.expect("conversion succeeded");
2902        let json_str = String::from_utf8(json_bytes).expect("valid UTF-8");
2903
2904        insta::assert_snapshot!("pause_resume_chrome_trace", json_str);
2905    }
2906
2907    /// Helper to create a count-based `StressProgress` value.
2908    fn stress_progress(completed: u32, total: u32) -> StressProgress {
2909        StressProgress::Count {
2910            total: StressCount::Count {
2911                count: NonZero::new(total).expect("total is non-zero"),
2912            },
2913            elapsed: Duration::from_secs(completed as u64),
2914            completed,
2915        }
2916    }
2917
2918    /// Verifies that stress sub-run events produce B/E pairs on the run
2919    /// lifecycle process.
2920    #[test]
2921    fn stress_subrun_events() {
2922        let events = vec![
2923            Ok(run_started(ts(1000))),
2924            // First sub-run.
2925            Ok(core_event(
2926                ts(1000),
2927                CoreEventKind::StressSubRunStarted {
2928                    progress: stress_progress(0, 3),
2929                },
2930            )),
2931            Ok(test_started(ts(1000), "crate::bin/test", "test_a", 0, 1)),
2932            Ok(test_finished_pass(
2933                ts(1002),
2934                "crate::bin/test",
2935                "test_a",
2936                ts(1000),
2937                Duration::from_secs(2),
2938                0,
2939            )),
2940            Ok(core_event(
2941                ts(1002),
2942                CoreEventKind::StressSubRunFinished {
2943                    progress: stress_progress(1, 3),
2944                    sub_elapsed: Duration::from_secs(2),
2945                    sub_stats: RunStats::default(),
2946                },
2947            )),
2948            // Second sub-run.
2949            Ok(core_event(
2950                ts(1003),
2951                CoreEventKind::StressSubRunStarted {
2952                    progress: stress_progress(1, 3),
2953                },
2954            )),
2955            Ok(test_started(ts(1003), "crate::bin/test", "test_a", 0, 1)),
2956            Ok(test_finished_pass(
2957                ts(1005),
2958                "crate::bin/test",
2959                "test_a",
2960                ts(1003),
2961                Duration::from_secs(2),
2962                0,
2963            )),
2964            Ok(core_event(
2965                ts(1005),
2966                CoreEventKind::StressSubRunFinished {
2967                    progress: stress_progress(2, 3),
2968                    sub_elapsed: Duration::from_secs(2),
2969                    sub_stats: RunStats::default(),
2970                },
2971            )),
2972            Ok(run_finished(ts(1006), ts(1000), Duration::from_secs(6))),
2973        ];
2974
2975        let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
2976
2977        // Should have 2 sub-run B/E pairs.
2978        let subrun_b: Vec<_> = trace_events
2979            .iter()
2980            .filter(|e| e["ph"] == "B" && e["cat"] == "stress")
2981            .collect();
2982        let subrun_e: Vec<_> = trace_events
2983            .iter()
2984            .filter(|e| e["ph"] == "E" && e["cat"] == "stress")
2985            .collect();
2986        assert_eq!(subrun_b.len(), 2, "expected 2 sub-run B events");
2987        assert_eq!(subrun_e.len(), 2, "expected 2 sub-run E events");
2988
2989        // All sub-run events should be on the run lifecycle pid with the
2990        // stress sub-run tid.
2991        for e in subrun_b.iter().chain(subrun_e.iter()) {
2992            assert_eq!(e["pid"], RUN_LIFECYCLE_PID);
2993            assert_eq!(e["tid"], STRESS_SUBRUN_TID);
2994            assert_eq!(e["name"], "sub-run");
2995        }
2996
2997        // First B should have progress args.
2998        assert!(
2999            !subrun_b[0]["args"]["progress"].is_null(),
3000            "sub-run B should have progress args"
3001        );
3002
3003        // E events should have sub_stats.
3004        assert!(
3005            !subrun_e[0]["args"]["sub_stats"].is_null(),
3006            "sub-run E should have sub-stats"
3007        );
3008
3009        // Verify metadata events were emitted for the stress sub-run tid.
3010        let thread_meta: Vec<_> = trace_events
3011            .iter()
3012            .filter(|e| {
3013                e["name"] == "thread_name"
3014                    && e["pid"] == RUN_LIFECYCLE_PID
3015                    && e["tid"] == STRESS_SUBRUN_TID
3016            })
3017            .collect();
3018        assert_eq!(
3019            thread_meta.len(),
3020            1,
3021            "stress sub-run thread_name metadata should be emitted once"
3022        );
3023        assert_eq!(thread_meta[0]["args"]["name"], "stress sub-runs");
3024    }
3025
3026    /// Verifies that pause/resume correctly splits stress sub-run spans,
3027    /// creating a visible gap in the timeline.
3028    #[test]
3029    fn pause_resume_with_stress_subrun() {
3030        let events = vec![
3031            Ok(run_started(ts(1000))),
3032            Ok(core_event(
3033                ts(1000),
3034                CoreEventKind::StressSubRunStarted {
3035                    progress: stress_progress(0, 2),
3036                },
3037            )),
3038            Ok(test_started(ts(1000), "crate::bin/test", "test_a", 0, 1)),
3039            // Pause at T=1002, while both the test and sub-run are active.
3040            Ok(core_event(
3041                ts(1002),
3042                CoreEventKind::RunPaused {
3043                    setup_scripts_running: 0,
3044                    running: 1,
3045                },
3046            )),
3047            // Resume at T=1005.
3048            Ok(core_event(
3049                ts(1005),
3050                CoreEventKind::RunContinued {
3051                    setup_scripts_running: 0,
3052                    running: 1,
3053                },
3054            )),
3055            // Test finishes after resume.
3056            Ok(test_finished_pass(
3057                ts(1008),
3058                "crate::bin/test",
3059                "test_a",
3060                ts(1000),
3061                Duration::from_secs(5),
3062                0,
3063            )),
3064            Ok(core_event(
3065                ts(1008),
3066                CoreEventKind::StressSubRunFinished {
3067                    progress: stress_progress(1, 2),
3068                    sub_elapsed: Duration::from_secs(5),
3069                    sub_stats: RunStats::default(),
3070                },
3071            )),
3072            Ok(run_finished(ts(1009), ts(1000), Duration::from_secs(9))),
3073        ];
3074
3075        let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
3076
3077        // The sub-run should have 2 B events (start + resume) and 2 E events
3078        // (pause + finish), creating a gap from T=1002 to T=1005.
3079        let subrun_b: Vec<_> = trace_events
3080            .iter()
3081            .filter(|e| e["ph"] == "B" && e["cat"] == "stress")
3082            .collect();
3083        let subrun_e: Vec<_> = trace_events
3084            .iter()
3085            .filter(|e| e["ph"] == "E" && e["cat"] == "stress")
3086            .collect();
3087        assert_eq!(
3088            subrun_b.len(),
3089            2,
3090            "expected 2 sub-run B events (start + resume)"
3091        );
3092        assert_eq!(
3093            subrun_e.len(),
3094            2,
3095            "expected 2 sub-run E events (pause + finish)"
3096        );
3097
3098        // First segment: B at T=1000, E at T=1002 (pause).
3099        let b1_ts = subrun_b[0]["ts"].as_f64().unwrap();
3100        let e1_ts = subrun_e[0]["ts"].as_f64().unwrap();
3101        assert!(
3102            (b1_ts - 1_000_000_000.0).abs() < 1.0,
3103            "first sub-run B should be at T=1000"
3104        );
3105        assert!(
3106            (e1_ts - 1_002_000_000.0).abs() < 1.0,
3107            "first sub-run E should be at T=1002 (pause)"
3108        );
3109
3110        // Second segment: B at T=1005 (resume), E at T=1008 (finish).
3111        let b2_ts = subrun_b[1]["ts"].as_f64().unwrap();
3112        let e2_ts = subrun_e[1]["ts"].as_f64().unwrap();
3113        assert!(
3114            (b2_ts - 1_005_000_000.0).abs() < 1.0,
3115            "second sub-run B should be at T=1005 (resume)"
3116        );
3117        assert!(
3118            (e2_ts - 1_008_000_000.0).abs() < 1.0,
3119            "second sub-run E should be at T=1008 (finish)"
3120        );
3121
3122        // The test should also be split: 2 B + 2 E.
3123        let test_b: Vec<_> = trace_events
3124            .iter()
3125            .filter(|e| e["ph"] == "B" && e["cat"] == "test")
3126            .collect();
3127        let test_e: Vec<_> = trace_events
3128            .iter()
3129            .filter(|e| e["ph"] == "E" && e["cat"] == "test")
3130            .collect();
3131        assert_eq!(test_b.len(), 2, "expected 2 test B events (start + resume)");
3132        assert_eq!(test_e.len(), 2, "expected 2 test E events (pause + finish)");
3133
3134        // The run bar should also be split.
3135        let run_b: Vec<_> = trace_events
3136            .iter()
3137            .filter(|e| e["ph"] == "B" && e["cat"] == "run")
3138            .collect();
3139        let run_e: Vec<_> = trace_events
3140            .iter()
3141            .filter(|e| e["ph"] == "E" && e["cat"] == "run")
3142            .collect();
3143        assert_eq!(run_b.len(), 2, "expected 2 run B events (start + resume)");
3144        assert_eq!(run_e.len(), 2, "expected 2 run E events (pause + finish)");
3145    }
3146
3147    /// Verifies that the "test results" counter emits cumulative
3148    /// pass/flaky/failed counts from `current_stats`.
3149    #[test]
3150    fn results_counter_events() {
3151        // Build stats that represent: 3 passed (including 1 flaky), 1 failed,
3152        // 1 exec_failed. The counter should show passed=3, flaky=1, failed=2.
3153        let stats = RunStats {
3154            initial_run_count: 5,
3155            finished_count: 5,
3156            passed: 3,
3157            flaky: 1,
3158            failed: 1,
3159            exec_failed: 1,
3160            ..RunStats::default()
3161        };
3162
3163        let events = vec![
3164            Ok(test_started(ts(1000), "crate::bin/test", "test_a", 0, 1)),
3165            Ok(output_event(
3166                ts(1001),
3167                OutputEventKind::TestFinished {
3168                    stress_index: None,
3169                    test_instance: test_id("crate::bin/test", "test_a"),
3170                    success_output: TestOutputDisplay::Never,
3171                    failure_output: TestOutputDisplay::Never,
3172                    junit_store_success_output: false,
3173                    junit_store_failure_output: false,
3174                    run_statuses: ExecutionStatuses::new(
3175                        vec![passing_status(ts(1000), Duration::from_millis(500), 1, 1)],
3176                        FlakyResult::Pass,
3177                    ),
3178                    current_stats: stats,
3179                    running: 0,
3180                },
3181            )),
3182        ];
3183
3184        let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
3185
3186        // Find the "test results" counter event.
3187        let results_counters: Vec<_> = trace_events
3188            .iter()
3189            .filter(|e| e["ph"] == "C" && e["name"] == "test results")
3190            .collect();
3191        assert_eq!(
3192            results_counters.len(),
3193            1,
3194            "expected 1 results counter event"
3195        );
3196
3197        let args = &results_counters[0]["args"];
3198        // passed = 3.
3199        assert_eq!(args["passed"], 3);
3200        // flaky = 1.
3201        assert_eq!(args["flaky"], 1);
3202        // failed = 1 failed + 1 exec_failed = 2.
3203        assert_eq!(args["failed"], 2, "failed should include exec_failed");
3204    }
3205
3206    /// Verifies both grouping modes for multi-binary runs: binary mode assigns
3207    /// different pids per binary, while slot mode groups all tests under a
3208    /// single pid with qualified names.
3209    #[test]
3210    fn multiple_binaries_grouping_modes() {
3211        let make_events = || {
3212            vec![
3213                Ok(run_started(ts(1000))),
3214                Ok(test_started(
3215                    ts(1000),
3216                    "crate-a::bin/test-a",
3217                    "test_1",
3218                    0,
3219                    1,
3220                )),
3221                Ok(test_started(
3222                    ts(1000),
3223                    "crate-b::bin/test-b",
3224                    "test_2",
3225                    1,
3226                    2,
3227                )),
3228                Ok(test_finished_pass(
3229                    ts(1001),
3230                    "crate-a::bin/test-a",
3231                    "test_1",
3232                    ts(1000),
3233                    Duration::from_millis(100),
3234                    1,
3235                )),
3236                Ok(test_finished_pass(
3237                    ts(1001),
3238                    "crate-b::bin/test-b",
3239                    "test_2",
3240                    ts(1000),
3241                    Duration::from_millis(100),
3242                    0,
3243                )),
3244                Ok(run_finished(ts(1002), ts(1000), Duration::from_secs(2))),
3245            ]
3246        };
3247
3248        // Binary mode: different binaries get different pids.
3249        {
3250            let (_parsed, trace_events) =
3251                convert_and_parse(make_events(), ChromeTraceGroupBy::Binary);
3252
3253            let b_events: Vec<_> = trace_events
3254                .iter()
3255                .filter(|e| e["ph"] == "B" && e["cat"] == "test")
3256                .collect();
3257            assert_eq!(b_events.len(), 2);
3258
3259            // Different binaries should have different pids, assigned in
3260            // order starting from FIRST_BINARY_PID.
3261            assert_eq!(b_events[0]["pid"], FIRST_BINARY_PID);
3262            assert_eq!(b_events[1]["pid"], FIRST_BINARY_PID + 1);
3263        }
3264
3265        // Slot mode: all tests share ALL_TESTS_PID with qualified names.
3266        {
3267            let (_parsed, trace_events) =
3268                convert_and_parse(make_events(), ChromeTraceGroupBy::Slot);
3269
3270            // All test B events should share ALL_TESTS_PID.
3271            let test_b: Vec<_> = trace_events
3272                .iter()
3273                .filter(|e| e["ph"] == "B" && e["cat"] == "test")
3274                .collect();
3275            assert_eq!(test_b.len(), 2);
3276            for b in &test_b {
3277                assert_eq!(
3278                    b["pid"], ALL_TESTS_PID,
3279                    "slot mode: all tests should share ALL_TESTS_PID"
3280                );
3281            }
3282
3283            // Event names should include the binary ID.
3284            let names: Vec<&str> = test_b.iter().map(|e| e["name"].as_str().unwrap()).collect();
3285            assert!(
3286                names.contains(&"crate-a::bin/test-a test_1"),
3287                "expected qualified name for test_1, got: {names:?}"
3288            );
3289            assert!(
3290                names.contains(&"crate-b::bin/test-b test_2"),
3291                "expected qualified name for test_2, got: {names:?}"
3292            );
3293
3294            // E event names should also be qualified.
3295            let test_e: Vec<_> = trace_events
3296                .iter()
3297                .filter(|e| e["ph"] == "E" && e["cat"] == "test")
3298                .collect();
3299            for e in &test_e {
3300                assert_eq!(
3301                    e["pid"], ALL_TESTS_PID,
3302                    "slot mode: all test E events should share ALL_TESTS_PID"
3303                );
3304                let name = e["name"].as_str().unwrap();
3305                assert!(
3306                    name.contains("crate-a::bin/test-a") || name.contains("crate-b::bin/test-b"),
3307                    "E event name should be qualified: {name}"
3308                );
3309            }
3310
3311            // Process metadata for the tests pid should be "tests".
3312            let proc_names: Vec<_> = trace_events
3313                .iter()
3314                .filter(|e| e["name"] == "process_name" && e["pid"] == ALL_TESTS_PID)
3315                .collect();
3316            assert_eq!(proc_names.len(), 1);
3317            assert_eq!(proc_names[0]["args"]["name"], "tests");
3318        }
3319    }
3320
3321    #[test]
3322    fn snapshot_slot_mode_chrome_trace() {
3323        let events = vec![
3324            Ok(run_started(ts(1000))),
3325            Ok(test_started(
3326                ts(1000),
3327                "crate-a::bin/test-a",
3328                "test_alpha",
3329                0,
3330                1,
3331            )),
3332            Ok(test_started(
3333                ts(1000),
3334                "crate-b::bin/test-b",
3335                "test_beta",
3336                1,
3337                2,
3338            )),
3339            Ok(test_finished_pass(
3340                ts(1002),
3341                "crate-a::bin/test-a",
3342                "test_alpha",
3343                ts(1000),
3344                Duration::from_millis(500),
3345                1,
3346            )),
3347            Ok(test_finished_pass(
3348                ts(1003),
3349                "crate-b::bin/test-b",
3350                "test_beta",
3351                ts(1000),
3352                Duration::from_millis(800),
3353                0,
3354            )),
3355            Ok(run_finished(ts(1004), ts(1000), Duration::from_secs(4))),
3356        ];
3357
3358        let result = convert_to_chrome_trace(
3359            &test_version(),
3360            events,
3361            ChromeTraceGroupBy::Slot,
3362            ChromeTraceMessageFormat::JsonPretty,
3363        );
3364        let json_bytes = result.expect("conversion succeeded");
3365        let json_str = String::from_utf8(json_bytes).expect("valid UTF-8");
3366
3367        insta::assert_snapshot!("slot_mode_chrome_trace", json_str);
3368    }
3369}