1use super::summary::{
15 CoreEventKind, OutputEventKind, StressConditionSummary, StressIndexSummary,
16 TestEventKindSummary, TestEventSummary, TestsNotSeenSummary,
17};
18use crate::{
19 config::elements::FlakyResult,
20 errors::{ChromeTraceError, RecordReadError},
21 list::OwnedTestInstanceId,
22 output_spec::RecordingSpec,
23 reporter::events::{
24 CancelReason, ErrorSummary, ExecuteStatus, ExecutionResultDescription, RunFinishedStats,
25 RunStats, StressProgress, TestSlotAssignment,
26 },
27};
28use chrono::{DateTime, FixedOffset};
29use debug_ignore::DebugIgnore;
30use nextest_metadata::{RustBinaryId, TestCaseName};
31use quick_junit::ReportUuid;
32use semver::Version;
33use serde::Serialize;
34use std::{
35 collections::{BTreeMap, HashMap, HashSet},
36 time::Duration,
37};
38#[derive(Copy, Clone, Debug, PartialEq, Eq)]
40pub enum ChromeTraceMessageFormat {
41 Json,
43
44 JsonPretty,
46}
47
48#[derive(Copy, Clone, Debug, PartialEq, Eq)]
50pub enum ChromeTraceGroupBy {
51 Binary,
54
55 Slot,
59}
60
61impl ChromeTraceGroupBy {
62 fn test_event_name(self, id: &OwnedTestInstanceId) -> String {
68 match self {
69 Self::Binary => id.test_name.as_ref().to_string(),
70 Self::Slot => format!("{} {}", id.binary_id, id.test_name.as_ref()),
71 }
72 }
73
74 fn test_process_display_name(self, binary_id: &RustBinaryId) -> String {
79 match self {
80 Self::Binary => binary_id.to_string(),
81 Self::Slot => "tests".to_string(),
82 }
83 }
84}
85
86pub fn convert_to_chrome_trace<I>(
119 nextest_version: &Version,
120 events: I,
121 group_by: ChromeTraceGroupBy,
122 message_format: ChromeTraceMessageFormat,
123) -> Result<Vec<u8>, ChromeTraceError>
124where
125 I: IntoIterator<Item = Result<TestEventSummary<RecordingSpec>, RecordReadError>>,
126{
127 let mut converter = ChromeTraceConverter::new(nextest_version.clone(), group_by);
128
129 for event_result in events {
130 let event = event_result.map_err(ChromeTraceError::ReadError)?;
131 converter.process_event(event)?;
132 }
133
134 converter.finish(message_format)
135}
136
137#[derive(Debug)]
139enum RunBarState {
140 Closed,
142 Open,
144 Paused,
147}
148
149#[derive(Debug)]
155struct ChromeTraceConverter {
156 slot_assignments: HashMap<OwnedTestInstanceId, TestSlotAssignment>,
159
160 running_scripts: BTreeMap<usize, String>,
164
165 stress_subrun_open: bool,
167
168 run_bar_state: RunBarState,
170
171 group_by: ChromeTraceGroupBy,
173
174 binary_pid_map: HashMap<RustBinaryId, u64>,
176
177 next_pid: u64,
180
181 nextest_version: Version,
183 run_id: Option<ReportUuid>,
184 profile_name: Option<String>,
185 cli_args: Vec<String>,
186 stress_condition: Option<StressConditionSummary>,
187
188 next_flow_id: u64,
190
191 pending_retry_flows: HashMap<OwnedTestInstanceId, u64>,
195
196 running_test_count: usize,
200
201 running_script_count: usize,
207
208 trace_events: DebugIgnore<Vec<ChromeTraceEvent>>,
210
211 emitted_process_names: HashSet<u64>,
213
214 emitted_thread_names: HashSet<(u64, u64)>,
217}
218
219impl ChromeTraceConverter {
220 fn new(nextest_version: Version, group_by: ChromeTraceGroupBy) -> Self {
221 Self {
222 slot_assignments: HashMap::new(),
223 running_scripts: BTreeMap::new(),
224 stress_subrun_open: false,
225 run_bar_state: RunBarState::Closed,
226 group_by,
227 binary_pid_map: HashMap::new(),
228 next_pid: FIRST_BINARY_PID,
229 nextest_version,
230 run_id: None,
231 profile_name: None,
232 cli_args: Vec::new(),
233 stress_condition: None,
234 next_flow_id: 0,
235 pending_retry_flows: HashMap::new(),
236 running_test_count: 0,
237 running_script_count: 0,
238 trace_events: DebugIgnore(Vec::new()),
239 emitted_process_names: HashSet::new(),
240 emitted_thread_names: HashSet::new(),
241 }
242 }
243
244 fn process_event(
245 &mut self,
246 event: TestEventSummary<RecordingSpec>,
247 ) -> Result<(), ChromeTraceError> {
248 let timestamp = event.timestamp;
249 match event.kind {
250 TestEventKindSummary::Core(core) => self.process_core_event(core, timestamp)?,
251 TestEventKindSummary::Output(output) => self.process_output_event(output, timestamp)?,
252 }
253 Ok(())
254 }
255
256 fn process_core_event(
257 &mut self,
258 event: CoreEventKind,
259 timestamp: DateTime<FixedOffset>,
260 ) -> Result<(), ChromeTraceError> {
261 match event {
262 CoreEventKind::RunStarted {
263 run_id,
264 profile_name,
265 cli_args,
266 stress_condition,
267 } => {
268 let process_name = format!("nextest run ({profile_name})");
271 self.ensure_metadata_events(
272 RUN_LIFECYCLE_PID,
273 RUN_LIFECYCLE_TID,
274 &process_name,
275 "run",
276 );
277
278 let begin_args = ChromeTraceArgs::RunBegin(RunBeginArgs {
279 nextest_version: self.nextest_version.to_string(),
280 run_id: run_id.to_string(),
281 profile: profile_name.clone(),
282 cli_args: cli_args.clone(),
283 stress_condition: stress_condition.clone(),
284 });
285
286 self.emit_begin(
288 RUN_LIFECYCLE_PID,
289 RUN_LIFECYCLE_TID,
290 "test run",
291 Category::Run,
292 datetime_to_microseconds(timestamp),
293 Some(begin_args),
294 );
295 self.run_bar_state = RunBarState::Open;
296 self.run_id = Some(run_id);
297 self.profile_name = Some(profile_name);
298 self.cli_args = cli_args;
299 self.stress_condition = stress_condition;
300 }
301 CoreEventKind::RunFinished {
302 run_id: _,
303 start_time: _,
304 elapsed,
305 run_stats,
306 outstanding_not_seen,
307 } => {
308 let ts_us = datetime_to_microseconds(timestamp);
310 match self.run_bar_state {
311 RunBarState::Open => {
312 let args = self.run_finished_args(
314 elapsed,
315 run_stats,
316 outstanding_not_seen.as_ref(),
317 );
318 self.emit_end(
319 RUN_LIFECYCLE_PID,
320 RUN_LIFECYCLE_TID,
321 "test run",
322 Category::Run,
323 ts_us,
324 Some(args),
325 );
326 self.run_bar_state = RunBarState::Closed;
327 }
328 RunBarState::Paused => {
329 self.emit_begin(
333 RUN_LIFECYCLE_PID,
334 RUN_LIFECYCLE_TID,
335 "test run",
336 Category::Run,
337 ts_us,
338 None,
339 );
340 let args = self.run_finished_args(
341 elapsed,
342 run_stats,
343 outstanding_not_seen.as_ref(),
344 );
345 self.emit_end(
346 RUN_LIFECYCLE_PID,
347 RUN_LIFECYCLE_TID,
348 "test run",
349 Category::Run,
350 ts_us,
351 Some(args),
352 );
353 self.run_bar_state = RunBarState::Closed;
354 }
355 RunBarState::Closed => {}
356 }
357 }
358 CoreEventKind::RunBeginCancel {
359 reason,
360 setup_scripts_running,
361 running,
362 } => {
363 self.running_test_count = running;
364 self.running_script_count = setup_scripts_running;
365 let ts_us = datetime_to_microseconds(timestamp);
366 self.emit_counter_event(ts_us);
367
368 self.emit_run_instant_event(
369 timestamp,
370 "cancel",
371 Some(reason),
372 running,
373 setup_scripts_running,
374 );
375 }
376 CoreEventKind::RunPaused {
377 setup_scripts_running,
378 running,
379 } => {
380 self.running_test_count = running;
381 self.running_script_count = setup_scripts_running;
382 let ts_us = datetime_to_microseconds(timestamp);
383 self.emit_counter_event(ts_us);
384
385 self.close_all_open_spans(ts_us);
387
388 self.emit_run_instant_event(
389 timestamp,
390 "paused",
391 None,
392 running,
393 setup_scripts_running,
394 );
395 }
396 CoreEventKind::RunContinued {
397 setup_scripts_running,
398 running,
399 } => {
400 self.running_test_count = running;
401 self.running_script_count = setup_scripts_running;
402 let ts_us = datetime_to_microseconds(timestamp);
403 self.emit_counter_event(ts_us);
404
405 self.emit_run_instant_event(
406 timestamp,
407 "continued",
408 None,
409 running,
410 setup_scripts_running,
411 );
412
413 self.reopen_all_spans(ts_us);
415 }
416 CoreEventKind::TestStarted {
417 test_instance,
418 slot_assignment,
419 stress_index: _,
420 current_stats: _,
421 running,
422 command_line,
423 } => {
424 let pid = self.pid_for_test(&test_instance.binary_id);
425 let tid = slot_assignment.global_slot + TID_OFFSET;
426 let ts_us = datetime_to_microseconds(timestamp);
427
428 let process_name = self
429 .group_by
430 .test_process_display_name(&test_instance.binary_id);
431 self.ensure_metadata_events(
432 pid,
433 tid,
434 &process_name,
435 &format!("slot-{}", slot_assignment.global_slot),
436 );
437
438 let event_name = self.group_by.test_event_name(&test_instance);
439 self.emit_begin(
440 pid,
441 tid,
442 &event_name,
443 Category::Test,
444 ts_us,
445 Some(ChromeTraceArgs::TestBegin(TestBeginArgs {
446 binary_id: test_instance.binary_id.clone(),
447 test_name: test_instance.test_name.clone(),
448 command_line,
449 })),
450 );
451
452 self.running_test_count = running;
453 self.emit_counter_event(ts_us);
454
455 self.slot_assignments.insert(test_instance, slot_assignment);
456 }
457 CoreEventKind::TestRetryStarted {
458 test_instance,
459 slot_assignment,
460 stress_index: _,
461 retry_data,
462 running,
463 command_line,
464 } => {
465 let pid = self.pid_for_test(&test_instance.binary_id);
466 let tid = slot_assignment.global_slot + TID_OFFSET;
467 let ts_us = datetime_to_microseconds(timestamp);
468
469 let process_name = self
473 .group_by
474 .test_process_display_name(&test_instance.binary_id);
475 self.ensure_metadata_events(
476 pid,
477 tid,
478 &process_name,
479 &format!("slot-{}", slot_assignment.global_slot),
480 );
481
482 let event_name = self.group_by.test_event_name(&test_instance);
483 self.emit_begin(
484 pid,
485 tid,
486 &event_name,
487 Category::Test,
488 ts_us,
489 Some(ChromeTraceArgs::TestRetryBegin(TestRetryBeginArgs {
490 binary_id: test_instance.binary_id.clone(),
491 test_name: test_instance.test_name.clone(),
492 attempt: retry_data.attempt,
493 total_attempts: retry_data.total_attempts,
494 command_line,
495 })),
496 );
497
498 if let Some(flow_id) = self.pending_retry_flows.remove(&test_instance) {
500 self.emit_flow_finish(pid, tid, ts_us, flow_id);
501 }
502
503 self.running_test_count = running;
504 self.emit_counter_event(ts_us);
505
506 self.slot_assignments.insert(test_instance, slot_assignment);
507 }
508 CoreEventKind::SetupScriptStarted {
509 index,
510 script_id,
511 stress_index: _,
512 total: _,
513 program: _,
514 args: _,
515 no_capture: _,
516 } => {
517 let tid = index as u64 + TID_OFFSET;
518 let name = script_id.to_string();
519 let ts_us = datetime_to_microseconds(timestamp);
520
521 self.ensure_metadata_events(
522 SETUP_SCRIPT_PID,
523 tid,
524 "setup-scripts",
525 &format!("script-{index}"),
526 );
527
528 self.emit_begin(
529 SETUP_SCRIPT_PID,
530 tid,
531 &name,
532 Category::SetupScript,
533 ts_us,
534 None,
535 );
536
537 self.running_script_count += 1;
538 self.emit_counter_event(ts_us);
539
540 self.running_scripts.insert(index, name);
541 }
542 CoreEventKind::TestSlow {
543 stress_index,
544 test_instance,
545 retry_data,
546 elapsed,
547 will_terminate,
548 } => {
549 let pid = self.pid_for_test(&test_instance.binary_id);
550 let tid = self.tid_for_test(&test_instance)?;
551 let ts_us = datetime_to_microseconds(timestamp);
552
553 self.trace_events.push(ChromeTraceEvent {
554 name: "slow".to_string(),
555 cat: Category::Test,
556 ph: Phase::Instant,
557 ts: ts_us,
558 pid,
559 tid,
560 s: Some(InstantScope::Thread),
561 id: None,
562 bp: None,
563 args: Some(ChromeTraceArgs::TestSlow(TestSlowArgs {
564 binary_id: test_instance.binary_id.clone(),
565 test_name: test_instance.test_name.clone(),
566 elapsed_secs: elapsed.as_secs_f64(),
567 will_terminate,
568 attempt: retry_data.attempt,
569 stress_index: stress_index.as_ref().map(StressIndexArgs::new),
570 })),
571 });
572 }
573 CoreEventKind::StressSubRunStarted { progress } => {
574 let ts_us = datetime_to_microseconds(timestamp);
575
576 self.ensure_metadata_events(
577 RUN_LIFECYCLE_PID,
578 STRESS_SUBRUN_TID,
579 &self.run_process_name(),
580 "stress sub-runs",
581 );
582
583 self.emit_begin(
584 RUN_LIFECYCLE_PID,
585 STRESS_SUBRUN_TID,
586 "sub-run",
587 Category::Stress,
588 ts_us,
589 Some(ChromeTraceArgs::StressSubRunBegin(StressSubRunBeginArgs {
590 progress,
591 })),
592 );
593 self.stress_subrun_open = true;
594 }
595 CoreEventKind::StressSubRunFinished {
596 progress,
597 sub_elapsed,
598 sub_stats,
599 } => {
600 if !self.stress_subrun_open {
601 return Err(ChromeTraceError::MissingStressSubRunStart);
602 }
603
604 let ts_us = datetime_to_microseconds(timestamp);
605
606 self.emit_end(
607 RUN_LIFECYCLE_PID,
608 STRESS_SUBRUN_TID,
609 "sub-run",
610 Category::Stress,
611 ts_us,
612 Some(ChromeTraceArgs::StressSubRunEnd(StressSubRunEndArgs {
613 progress,
614 time_taken_ms: duration_to_millis(sub_elapsed),
615 sub_stats,
616 })),
617 );
618 self.stress_subrun_open = false;
619 }
620 CoreEventKind::SetupScriptSlow {
621 stress_index,
622 script_id,
623 program: _,
624 args: _,
625 elapsed,
626 will_terminate,
627 } => {
628 let script_name = script_id.to_string();
629 let tid = self
630 .running_scripts
631 .iter()
632 .find(|(_, name)| **name == script_name)
633 .map(|(&index, _)| index as u64 + TID_OFFSET)
634 .ok_or_else(|| ChromeTraceError::MissingScriptStart {
635 script_id: script_id.clone(),
636 })?;
637 let ts_us = datetime_to_microseconds(timestamp);
638
639 self.trace_events.push(ChromeTraceEvent {
640 name: "slow".to_string(),
641 cat: Category::SetupScript,
642 ph: Phase::Instant,
643 ts: ts_us,
644 pid: SETUP_SCRIPT_PID,
645 tid,
646 s: Some(InstantScope::Thread),
647 id: None,
648 bp: None,
649 args: Some(ChromeTraceArgs::SetupScriptSlow(SetupScriptSlowArgs {
650 script_id: script_id.as_identifier().as_str().to_string(),
651 elapsed_secs: elapsed.as_secs_f64(),
652 will_terminate,
653 stress_index: stress_index.as_ref().map(StressIndexArgs::new),
654 })),
655 });
656 }
657 CoreEventKind::TestSkipped { .. } => {}
659 }
660 Ok(())
661 }
662
663 fn process_output_event(
664 &mut self,
665 event: OutputEventKind<RecordingSpec>,
666 timestamp: DateTime<FixedOffset>,
667 ) -> Result<(), ChromeTraceError> {
668 let end_us = datetime_to_microseconds(timestamp);
674
675 match event {
676 OutputEventKind::TestAttemptFailedWillRetry {
677 stress_index,
678 test_instance,
679 run_status,
680 delay_before_next_attempt,
681 failure_output: _,
682 running,
683 } => {
684 let pid = self.pid_for_test(&test_instance.binary_id);
685 let tid = self.tid_for_test(&test_instance)?;
686
687 let end_args = self.test_end_args(
688 &test_instance,
689 &run_status,
690 stress_index.as_ref(),
691 Some(delay_before_next_attempt),
692 None,
693 );
694
695 let event_name = self.group_by.test_event_name(&test_instance);
696 self.emit_end(
697 pid,
698 tid,
699 &event_name,
700 Category::Test,
701 end_us,
702 Some(end_args),
703 );
704
705 let flow_id = self.next_flow_id;
707 self.next_flow_id += 1;
708 self.emit_flow_start(pid, tid, end_us, flow_id);
709 self.pending_retry_flows
710 .insert(test_instance.clone(), flow_id);
711
712 self.running_test_count = running;
713 self.emit_counter_event(end_us);
714
715 self.slot_assignments.remove(&test_instance);
717 }
718 OutputEventKind::TestFinished {
719 stress_index,
720 test_instance,
721 run_statuses,
722 success_output: _,
723 failure_output: _,
724 junit_store_success_output: _,
725 junit_store_failure_output: _,
726 junit_flaky_fail_status: _,
727 current_stats,
728 running,
729 } => {
730 let last = run_statuses.last_status();
733 let pid = self.pid_for_test(&test_instance.binary_id);
734 let tid = self.tid_for_test(&test_instance)?;
735
736 let flaky_result = (run_statuses.len() > 1 && last.result.is_success())
739 .then(|| run_statuses.flaky_result());
740
741 let end_args = self.test_end_args(
742 &test_instance,
743 last,
744 stress_index.as_ref(),
745 None,
746 flaky_result,
747 );
748
749 let event_name = self.group_by.test_event_name(&test_instance);
750 self.emit_end(
751 pid,
752 tid,
753 &event_name,
754 Category::Test,
755 end_us,
756 Some(end_args),
757 );
758
759 self.running_test_count = running;
760 self.emit_counter_event(end_us);
761 self.emit_results_counter_event(end_us, ¤t_stats);
762
763 self.slot_assignments.remove(&test_instance);
764 }
765 OutputEventKind::SetupScriptFinished {
766 stress_index,
767 index,
768 total: _,
769 script_id,
770 program: _,
771 args: _,
772 no_capture: _,
773 run_status,
774 } => {
775 if !self.running_scripts.contains_key(&index) {
777 return Err(ChromeTraceError::MissingScriptStart {
778 script_id: script_id.clone(),
779 });
780 }
781
782 let tid = index as u64 + TID_OFFSET;
783 let script_id_str = script_id.as_identifier().as_str().to_string();
784 let script_name = script_id.to_string();
785
786 let end_args = ChromeTraceArgs::SetupScriptEnd(SetupScriptEndArgs {
787 script_id: script_id_str,
788 time_taken_ms: duration_to_millis(run_status.time_taken),
789 result: run_status.result.clone(),
790 is_slow: run_status.is_slow,
791 stress_index: stress_index.as_ref().map(StressIndexArgs::new),
792 error: run_status.error_summary.as_ref().map(ErrorSummaryArgs::new),
793 });
794
795 self.emit_end(
796 SETUP_SCRIPT_PID,
797 tid,
798 &script_name,
799 Category::SetupScript,
800 end_us,
801 Some(end_args),
802 );
803
804 self.running_script_count = self.running_script_count.saturating_sub(1);
805 self.emit_counter_event(end_us);
806
807 self.running_scripts.remove(&index);
808 }
809 }
810 Ok(())
811 }
812
813 fn close_all_open_spans(&mut self, ts_us: f64) {
818 match self.run_bar_state {
819 RunBarState::Open => {
820 self.emit_end(
821 RUN_LIFECYCLE_PID,
822 RUN_LIFECYCLE_TID,
823 "test run",
824 Category::Run,
825 ts_us,
826 None,
827 );
828 self.run_bar_state = RunBarState::Paused;
829 }
830 RunBarState::Paused | RunBarState::Closed => {}
831 }
832
833 if self.stress_subrun_open {
834 self.emit_end(
835 RUN_LIFECYCLE_PID,
836 STRESS_SUBRUN_TID,
837 "sub-run",
838 Category::Stress,
839 ts_us,
840 None,
841 );
842 }
843
844 self.emit_test_and_script_span_events(Phase::End, ts_us);
845 }
846
847 fn reopen_all_spans(&mut self, ts_us: f64) {
850 match self.run_bar_state {
851 RunBarState::Paused => {
852 self.emit_begin(
853 RUN_LIFECYCLE_PID,
854 RUN_LIFECYCLE_TID,
855 "test run",
856 Category::Run,
857 ts_us,
858 None,
859 );
860 self.run_bar_state = RunBarState::Open;
861 }
862 RunBarState::Open | RunBarState::Closed => {}
863 }
864
865 if self.stress_subrun_open {
866 self.emit_begin(
867 RUN_LIFECYCLE_PID,
868 STRESS_SUBRUN_TID,
869 "sub-run",
870 Category::Stress,
871 ts_us,
872 None,
873 );
874 }
875
876 self.emit_test_and_script_span_events(Phase::Begin, ts_us);
877 }
878
879 fn emit_test_and_script_span_events(&mut self, ph: Phase, ts_us: f64) {
889 let mut test_spans: Vec<(u64, u64, String)> = self
891 .slot_assignments
892 .iter()
893 .map(|(id, sa)| {
894 let pid = match self.group_by {
895 ChromeTraceGroupBy::Binary => *self
896 .binary_pid_map
897 .get(&id.binary_id)
898 .expect("binary pid already assigned by TestStarted"),
899 ChromeTraceGroupBy::Slot => ALL_TESTS_PID,
900 };
901 let tid = sa.global_slot + TID_OFFSET;
902 let name = self.group_by.test_event_name(id);
903 (pid, tid, name)
904 })
905 .collect();
906 test_spans.sort_by_key(|&(_, tid, _)| tid);
907 for (pid, tid, name) in &test_spans {
908 self.emit_duration_event(*pid, *tid, name, Category::Test, ph, ts_us, None);
909 }
910
911 let script_spans: Vec<(u64, String)> = self
913 .running_scripts
914 .iter()
915 .map(|(&index, name)| (index as u64 + TID_OFFSET, name.clone()))
916 .collect();
917 for (tid, name) in &script_spans {
918 self.emit_duration_event(
919 SETUP_SCRIPT_PID,
920 *tid,
921 name,
922 Category::SetupScript,
923 ph,
924 ts_us,
925 None,
926 );
927 }
928 }
929
930 fn emit_begin(
933 &mut self,
934 pid: u64,
935 tid: u64,
936 name: &str,
937 cat: Category,
938 ts_us: f64,
939 args: Option<ChromeTraceArgs>,
940 ) {
941 self.emit_duration_event(pid, tid, name, cat, Phase::Begin, ts_us, args);
942 }
943
944 fn emit_end(
945 &mut self,
946 pid: u64,
947 tid: u64,
948 name: &str,
949 cat: Category,
950 ts_us: f64,
951 args: Option<ChromeTraceArgs>,
952 ) {
953 self.emit_duration_event(pid, tid, name, cat, Phase::End, ts_us, args);
954 }
955
956 #[expect(clippy::too_many_arguments)]
958 fn emit_duration_event(
959 &mut self,
960 pid: u64,
961 tid: u64,
962 name: &str,
963 cat: Category,
964 ph: Phase,
965 ts_us: f64,
966 args: Option<ChromeTraceArgs>,
967 ) {
968 self.trace_events.push(ChromeTraceEvent {
969 name: name.to_string(),
970 cat,
971 ph,
972 ts: ts_us,
973 pid,
974 tid,
975 s: None,
976 id: None,
977 bp: None,
978 args,
979 });
980 }
981
982 fn emit_counter_event(&mut self, ts_us: f64) {
984 self.trace_events.push(ChromeTraceEvent {
985 name: "concurrency".to_string(),
986 cat: Category::Run,
987 ph: Phase::Counter,
988 ts: ts_us,
989 pid: RUN_LIFECYCLE_PID,
990 tid: 0,
991 s: None,
992 id: None,
993 bp: None,
994 args: Some(ChromeTraceArgs::Counter(CounterArgs {
995 running_tests: self.running_test_count,
996 running_scripts: self.running_script_count,
997 })),
998 });
999 }
1000
1001 fn emit_results_counter_event(&mut self, ts_us: f64, stats: &RunStats) {
1004 self.trace_events.push(ChromeTraceEvent {
1005 name: "test results".to_string(),
1006 cat: Category::Run,
1007 ph: Phase::Counter,
1008 ts: ts_us,
1009 pid: RUN_LIFECYCLE_PID,
1010 tid: 0,
1011 s: None,
1012 id: None,
1013 bp: None,
1014 args: Some(ChromeTraceArgs::ResultsCounter(ResultsCounterArgs {
1015 passed: stats.passed,
1016 flaky: stats.flaky,
1017 failed: stats.failed_count(),
1018 })),
1019 });
1020 }
1021
1022 fn emit_flow_start(&mut self, pid: u64, tid: u64, ts_us: f64, flow_id: u64) {
1024 self.trace_events.push(ChromeTraceEvent {
1025 name: "retry".to_string(),
1026 cat: Category::Test,
1027 ph: Phase::FlowStart,
1028 ts: ts_us,
1029 pid,
1030 tid,
1031 s: None,
1032 id: Some(flow_id),
1033 bp: None,
1034 args: None,
1035 });
1036 }
1037
1038 fn emit_flow_finish(&mut self, pid: u64, tid: u64, ts_us: f64, flow_id: u64) {
1040 self.trace_events.push(ChromeTraceEvent {
1041 name: "retry".to_string(),
1042 cat: Category::Test,
1043 ph: Phase::FlowFinish,
1044 ts: ts_us,
1045 pid,
1046 tid,
1047 s: None,
1048 id: Some(flow_id),
1049 bp: Some(FlowBindingPoint::EnclosingSlice),
1050 args: None,
1051 });
1052 }
1053
1054 fn emit_run_instant_event(
1058 &mut self,
1059 timestamp: DateTime<FixedOffset>,
1060 name: &str,
1061 cancel_reason: Option<CancelReason>,
1062 running: usize,
1063 setup_scripts_running: usize,
1064 ) {
1065 let pid = RUN_LIFECYCLE_PID;
1066 let tid = RUN_LIFECYCLE_TID;
1067 let ts_us = datetime_to_microseconds(timestamp);
1068
1069 self.ensure_metadata_events(pid, tid, &self.run_process_name(), "run");
1073
1074 self.trace_events.push(ChromeTraceEvent {
1075 name: name.to_string(),
1076 cat: Category::Run,
1077 ph: Phase::Instant,
1078 ts: ts_us,
1079 pid,
1080 tid,
1081 s: Some(InstantScope::Process),
1082 id: None,
1083 bp: None,
1084 args: Some(ChromeTraceArgs::RunInstant(RunInstantArgs {
1085 running,
1086 setup_scripts_running,
1087 reason: cancel_reason,
1088 })),
1089 });
1090 }
1091
1092 fn run_process_name(&self) -> String {
1098 match &self.profile_name {
1099 Some(name) => format!("nextest run ({name})"),
1100 None => "nextest run".to_string(),
1101 }
1102 }
1103
1104 fn test_end_args(
1110 &self,
1111 test_instance: &OwnedTestInstanceId,
1112 status: &ExecuteStatus<RecordingSpec>,
1113 stress_index: Option<&StressIndexSummary>,
1114 delay_before_next_attempt: Option<Duration>,
1115 flaky_result: Option<FlakyResult>,
1116 ) -> ChromeTraceArgs {
1117 let error = match (
1120 status.error_summary.as_ref(),
1121 flaky_result.and_then(|fr| {
1122 fr.fail_message(status.retry_data.attempt, status.retry_data.total_attempts)
1123 }),
1124 ) {
1125 (Some(summary), _) => Some(ErrorSummaryArgs::new(summary)),
1126 (None, Some(flaky_msg)) => Some(ErrorSummaryArgs {
1127 short_message: "flaky failure".to_string(),
1128 description: flaky_msg,
1129 }),
1130 (None, None) => None,
1131 };
1132
1133 ChromeTraceArgs::TestEnd(TestEndArgs {
1134 binary_id: test_instance.binary_id.clone(),
1135 test_name: test_instance.test_name.clone(),
1136 time_taken_ms: duration_to_millis(status.time_taken),
1137 result: status.result.clone(),
1138 attempt: status.retry_data.attempt,
1139 total_attempts: status.retry_data.total_attempts,
1140 is_slow: status.is_slow,
1141 test_group: self
1142 .slot_assignments
1143 .get(test_instance)
1144 .map(|s| s.test_group.to_string()),
1145 stress_index: stress_index.map(StressIndexArgs::new),
1146 delay_before_start_secs: non_zero_duration_secs(status.delay_before_start),
1147 error,
1148 delay_before_next_attempt_secs: delay_before_next_attempt
1149 .and_then(non_zero_duration_secs),
1150 flaky_result,
1151 })
1152 }
1153
1154 fn run_finished_args(
1156 &self,
1157 elapsed: Duration,
1158 run_stats: RunFinishedStats,
1159 outstanding_not_seen: Option<&TestsNotSeenSummary>,
1160 ) -> ChromeTraceArgs {
1161 ChromeTraceArgs::RunEnd(RunEndArgs {
1162 nextest_version: self.nextest_version.to_string(),
1163 time_taken_ms: duration_to_millis(elapsed),
1164 profile: self.profile_name.clone(),
1165 run_stats,
1166 outstanding_not_seen: outstanding_not_seen.map(|ns| OutstandingNotSeenArgs {
1167 total_not_seen: ns.total_not_seen,
1168 }),
1169 })
1170 }
1171
1172 fn pid_for_binary(&mut self, binary_id: &RustBinaryId) -> u64 {
1174 if let Some(&pid) = self.binary_pid_map.get(binary_id) {
1175 pid
1176 } else {
1177 let pid = self.next_pid;
1178 self.next_pid += 1;
1179 self.binary_pid_map.insert(binary_id.clone(), pid);
1180 pid
1181 }
1182 }
1183
1184 fn pid_for_test(&mut self, binary_id: &RustBinaryId) -> u64 {
1189 match self.group_by {
1190 ChromeTraceGroupBy::Binary => self.pid_for_binary(binary_id),
1191 ChromeTraceGroupBy::Slot => ALL_TESTS_PID,
1192 }
1193 }
1194
1195 fn tid_for_test(&self, test_instance: &OwnedTestInstanceId) -> Result<u64, ChromeTraceError> {
1200 match self.slot_assignments.get(test_instance) {
1201 Some(sa) => Ok(sa.global_slot + TID_OFFSET),
1202 None => Err(ChromeTraceError::MissingTestStart {
1203 test_name: test_instance.test_name.clone(),
1204 binary_id: test_instance.binary_id.clone(),
1205 }),
1206 }
1207 }
1208
1209 fn ensure_metadata_events(
1216 &mut self,
1217 pid: u64,
1218 tid: u64,
1219 process_display_name: &str,
1220 thread_display_name: &str,
1221 ) {
1222 if !self.emitted_process_names.contains(&pid) {
1223 self.emit_m_event(
1224 pid,
1225 0,
1226 "process_name",
1227 ChromeTraceArgs::MetadataName(MetadataNameArgs {
1228 name: process_display_name.to_string(),
1229 }),
1230 );
1231 self.emit_m_event(
1232 pid,
1233 0,
1234 "process_sort_index",
1235 ChromeTraceArgs::MetadataSortIndex(MetadataSortIndexArgs { sort_index: pid }),
1236 );
1237 self.emitted_process_names.insert(pid);
1238 }
1239
1240 if !self.emitted_thread_names.contains(&(pid, tid)) {
1241 self.emit_m_event(
1242 pid,
1243 tid,
1244 "thread_name",
1245 ChromeTraceArgs::MetadataName(MetadataNameArgs {
1246 name: thread_display_name.to_string(),
1247 }),
1248 );
1249 self.emit_m_event(
1250 pid,
1251 tid,
1252 "thread_sort_index",
1253 ChromeTraceArgs::MetadataSortIndex(MetadataSortIndexArgs { sort_index: tid }),
1254 );
1255 self.emitted_thread_names.insert((pid, tid));
1256 }
1257 }
1258
1259 fn emit_m_event(&mut self, pid: u64, tid: u64, event_name: &str, args: ChromeTraceArgs) {
1261 self.trace_events.push(ChromeTraceEvent {
1262 name: event_name.to_string(),
1263 cat: Category::Empty,
1264 ph: Phase::Metadata,
1265 ts: 0.0,
1266 pid,
1267 tid,
1268 s: None,
1269 id: None,
1270 bp: None,
1271 args: Some(args),
1272 });
1273 }
1274
1275 fn finish(self, message_format: ChromeTraceMessageFormat) -> Result<Vec<u8>, ChromeTraceError> {
1277 let other_data = ChromeTraceOtherData {
1280 nextest_version: self.nextest_version.to_string(),
1281 run_id: self.run_id.map(|id| id.to_string()),
1282 profile_name: self.profile_name,
1283 cli_args: self.cli_args,
1284 stress_condition: self.stress_condition,
1285 };
1286
1287 let output = ChromeTraceOutput {
1288 trace_events: self.trace_events.0,
1289 display_time_unit: "ms",
1290 other_data,
1291 };
1292
1293 let serialize_fn = match message_format {
1294 ChromeTraceMessageFormat::Json => serde_json::to_vec,
1295 ChromeTraceMessageFormat::JsonPretty => serde_json::to_vec_pretty,
1296 };
1297 serialize_fn(&output).map_err(ChromeTraceError::SerializeError)
1298 }
1299}
1300
1301const RUN_LIFECYCLE_PID: u64 = 0;
1303
1304const SETUP_SCRIPT_PID: u64 = 1;
1306
1307const ALL_TESTS_PID: u64 = 2;
1309
1310const FIRST_BINARY_PID: u64 = 2;
1314
1315const RUN_LIFECYCLE_TID: u64 = 1;
1317
1318const STRESS_SUBRUN_TID: u64 = 2;
1320
1321const TID_OFFSET: u64 = 10_000;
1327
1328#[derive(Copy, Clone, Serialize)]
1330enum Phase {
1331 #[serde(rename = "B")]
1332 Begin,
1333 #[serde(rename = "E")]
1334 End,
1335 #[serde(rename = "M")]
1336 Metadata,
1337 #[serde(rename = "i")]
1338 Instant,
1339 #[serde(rename = "C")]
1340 Counter,
1341 #[serde(rename = "s")]
1342 FlowStart,
1343 #[serde(rename = "f")]
1344 FlowFinish,
1345}
1346
1347#[derive(Copy, Clone, Serialize)]
1349enum Category {
1350 #[serde(rename = "test")]
1351 Test,
1352 #[serde(rename = "setup-script")]
1353 SetupScript,
1354 #[serde(rename = "stress")]
1355 Stress,
1356 #[serde(rename = "run")]
1357 Run,
1358 #[serde(rename = "")]
1359 Empty,
1360}
1361
1362#[derive(Copy, Clone, Serialize)]
1364enum InstantScope {
1365 #[serde(rename = "p")]
1366 Process,
1367 #[serde(rename = "t")]
1368 Thread,
1369}
1370
1371#[derive(Copy, Clone, Serialize)]
1373enum FlowBindingPoint {
1374 #[serde(rename = "e")]
1375 EnclosingSlice,
1376}
1377
1378#[derive(Serialize)]
1380struct ChromeTraceEvent {
1381 name: String,
1383
1384 cat: Category,
1386
1387 ph: Phase,
1389
1390 ts: f64,
1392
1393 pid: u64,
1395
1396 tid: u64,
1398
1399 #[serde(skip_serializing_if = "Option::is_none")]
1401 s: Option<InstantScope>,
1402
1403 #[serde(skip_serializing_if = "Option::is_none")]
1405 id: Option<u64>,
1406
1407 #[serde(skip_serializing_if = "Option::is_none")]
1409 bp: Option<FlowBindingPoint>,
1410
1411 #[serde(skip_serializing_if = "Option::is_none")]
1413 args: Option<ChromeTraceArgs>,
1414}
1415
1416#[derive(Serialize)]
1430#[serde(untagged)]
1431enum ChromeTraceArgs {
1432 RunBegin(RunBeginArgs),
1433 RunEnd(RunEndArgs),
1434 RunInstant(RunInstantArgs),
1435 TestBegin(TestBeginArgs),
1436 TestRetryBegin(TestRetryBeginArgs),
1437 TestEnd(TestEndArgs),
1438 TestSlow(TestSlowArgs),
1439 SetupScriptEnd(SetupScriptEndArgs),
1440 SetupScriptSlow(SetupScriptSlowArgs),
1441 StressSubRunBegin(StressSubRunBeginArgs),
1442 StressSubRunEnd(StressSubRunEndArgs),
1443 Counter(CounterArgs),
1444 ResultsCounter(ResultsCounterArgs),
1445 MetadataName(MetadataNameArgs),
1446 MetadataSortIndex(MetadataSortIndexArgs),
1447}
1448
1449#[derive(Serialize)]
1454struct StressIndexArgs {
1455 current: u32,
1456 total: Option<u32>,
1457}
1458
1459impl StressIndexArgs {
1460 fn new(si: &StressIndexSummary) -> Self {
1461 Self {
1462 current: si.current,
1463 total: si.total.map(|t| t.get()),
1464 }
1465 }
1466}
1467
1468#[derive(Serialize)]
1470struct ErrorSummaryArgs {
1471 short_message: String,
1472 description: String,
1473}
1474
1475impl ErrorSummaryArgs {
1476 fn new(summary: &ErrorSummary) -> Self {
1477 Self {
1478 short_message: summary.short_message.clone(),
1479 description: summary.description.clone(),
1480 }
1481 }
1482}
1483
1484#[derive(Serialize)]
1486struct OutstandingNotSeenArgs {
1487 total_not_seen: usize,
1488}
1489
1490#[derive(Serialize)]
1494struct RunBeginArgs {
1495 nextest_version: String,
1496 run_id: String,
1497 profile: String,
1498 cli_args: Vec<String>,
1499 #[serde(skip_serializing_if = "Option::is_none")]
1500 stress_condition: Option<StressConditionSummary>,
1501}
1502
1503#[derive(Serialize)]
1505struct RunEndArgs {
1506 nextest_version: String,
1507 time_taken_ms: f64,
1508 #[serde(skip_serializing_if = "Option::is_none")]
1509 profile: Option<String>,
1510 run_stats: RunFinishedStats,
1511 #[serde(skip_serializing_if = "Option::is_none")]
1512 outstanding_not_seen: Option<OutstandingNotSeenArgs>,
1513}
1514
1515#[derive(Serialize)]
1517struct RunInstantArgs {
1518 running: usize,
1519 setup_scripts_running: usize,
1520 #[serde(skip_serializing_if = "Option::is_none")]
1521 reason: Option<CancelReason>,
1522}
1523
1524#[derive(Serialize)]
1528struct TestBeginArgs {
1529 binary_id: RustBinaryId,
1530 test_name: TestCaseName,
1531 #[serde(skip_serializing_if = "Vec::is_empty")]
1532 command_line: Vec<String>,
1533}
1534
1535#[derive(Serialize)]
1537struct TestRetryBeginArgs {
1538 binary_id: RustBinaryId,
1539 test_name: TestCaseName,
1540 attempt: u32,
1541 total_attempts: u32,
1542 #[serde(skip_serializing_if = "Vec::is_empty")]
1543 command_line: Vec<String>,
1544}
1545
1546#[derive(Serialize)]
1548struct TestEndArgs {
1549 binary_id: RustBinaryId,
1550 test_name: TestCaseName,
1551 time_taken_ms: f64,
1552 result: ExecutionResultDescription,
1553 attempt: u32,
1554 total_attempts: u32,
1555 is_slow: bool,
1556 #[serde(skip_serializing_if = "Option::is_none")]
1557 test_group: Option<String>,
1558 #[serde(skip_serializing_if = "Option::is_none")]
1559 stress_index: Option<StressIndexArgs>,
1560 #[serde(skip_serializing_if = "Option::is_none")]
1561 delay_before_start_secs: Option<f64>,
1562 #[serde(skip_serializing_if = "Option::is_none")]
1563 error: Option<ErrorSummaryArgs>,
1564 #[serde(skip_serializing_if = "Option::is_none")]
1565 delay_before_next_attempt_secs: Option<f64>,
1566 #[serde(skip_serializing_if = "Option::is_none")]
1567 flaky_result: Option<FlakyResult>,
1568}
1569
1570#[derive(Serialize)]
1572struct TestSlowArgs {
1573 binary_id: RustBinaryId,
1574 test_name: TestCaseName,
1575 elapsed_secs: f64,
1576 will_terminate: bool,
1577 attempt: u32,
1578 #[serde(skip_serializing_if = "Option::is_none")]
1579 stress_index: Option<StressIndexArgs>,
1580}
1581
1582#[derive(Serialize)]
1586struct SetupScriptEndArgs {
1587 script_id: String,
1588 time_taken_ms: f64,
1589 result: ExecutionResultDescription,
1590 is_slow: bool,
1591 #[serde(skip_serializing_if = "Option::is_none")]
1592 stress_index: Option<StressIndexArgs>,
1593 #[serde(skip_serializing_if = "Option::is_none")]
1594 error: Option<ErrorSummaryArgs>,
1595}
1596
1597#[derive(Serialize)]
1599struct SetupScriptSlowArgs {
1600 script_id: String,
1601 elapsed_secs: f64,
1602 will_terminate: bool,
1603 #[serde(skip_serializing_if = "Option::is_none")]
1604 stress_index: Option<StressIndexArgs>,
1605}
1606
1607#[derive(Serialize)]
1611struct StressSubRunBeginArgs {
1612 progress: StressProgress,
1613}
1614
1615#[derive(Serialize)]
1617struct StressSubRunEndArgs {
1618 progress: StressProgress,
1619 time_taken_ms: f64,
1620 sub_stats: RunStats,
1621}
1622
1623#[derive(Serialize)]
1627struct CounterArgs {
1628 running_tests: usize,
1629 running_scripts: usize,
1630}
1631
1632#[derive(Serialize)]
1635struct ResultsCounterArgs {
1636 passed: usize,
1638 flaky: usize,
1640 failed: usize,
1642}
1643
1644#[derive(Serialize)]
1648struct MetadataNameArgs {
1649 name: String,
1650}
1651
1652#[derive(Serialize)]
1656struct MetadataSortIndexArgs {
1657 sort_index: u64,
1658}
1659
1660#[derive(Serialize)]
1662#[serde(rename_all = "camelCase")] struct ChromeTraceOutput {
1664 trace_events: Vec<ChromeTraceEvent>,
1665 display_time_unit: &'static str,
1666 other_data: ChromeTraceOtherData,
1670}
1671
1672#[derive(Serialize)]
1674struct ChromeTraceOtherData {
1675 nextest_version: String,
1676 #[serde(skip_serializing_if = "Option::is_none")]
1677 run_id: Option<String>,
1678 #[serde(skip_serializing_if = "Option::is_none")]
1679 profile_name: Option<String>,
1680 #[serde(skip_serializing_if = "Vec::is_empty")]
1681 cli_args: Vec<String>,
1682 #[serde(skip_serializing_if = "Option::is_none")]
1683 stress_condition: Option<StressConditionSummary>,
1684}
1685
1686fn datetime_to_microseconds(dt: DateTime<FixedOffset>) -> f64 {
1688 dt.timestamp_micros() as f64
1692}
1693
1694fn duration_to_millis(d: Duration) -> f64 {
1696 d.as_secs_f64() * 1000.0
1697}
1698
1699fn non_zero_duration_secs(d: Duration) -> Option<f64> {
1701 if d.is_zero() {
1702 None
1703 } else {
1704 Some(d.as_secs_f64())
1705 }
1706}
1707
1708#[cfg(test)]
1709mod tests {
1710 use super::*;
1711 use crate::{
1712 config::{
1713 elements::{FlakyResult, JunitFlakyFailStatus, TestGroup},
1714 scripts::ScriptId,
1715 },
1716 list::OwnedTestInstanceId,
1717 output_spec::RecordingSpec,
1718 record::summary::{
1719 CoreEventKind, OutputEventKind, TestEventKindSummary, TestEventSummary,
1720 ZipStoreOutputDescription,
1721 },
1722 reporter::{
1723 TestOutputDisplay,
1724 events::{
1725 ChildExecutionOutputDescription, ExecuteStatus, ExecutionResultDescription,
1726 ExecutionStatuses, FailureDescription, RetryData, RunFinishedStats, RunStats,
1727 SetupScriptExecuteStatus, TestSlotAssignment,
1728 },
1729 },
1730 runner::StressCount,
1731 };
1732 use chrono::{FixedOffset, TimeZone};
1733 use nextest_metadata::{RustBinaryId, TestCaseName};
1734 use std::{
1735 collections::{BTreeSet, HashMap},
1736 num::NonZero,
1737 time::Duration,
1738 };
1739
1740 fn assert_be_balanced(trace_events: &[serde_json::Value]) {
1744 let mut b_counts: HashMap<(u64, u64, &str), usize> = HashMap::new();
1745 let mut e_counts: HashMap<(u64, u64, &str), usize> = HashMap::new();
1746
1747 for event in trace_events {
1748 let ph = event["ph"].as_str().unwrap_or("");
1749 let cat = event["cat"].as_str().unwrap_or("");
1750 let pid = event["pid"].as_u64().unwrap_or(0);
1751 let tid = event["tid"].as_u64().unwrap_or(0);
1752 match ph {
1753 "B" => *b_counts.entry((pid, tid, cat)).or_default() += 1,
1754 "E" => *e_counts.entry((pid, tid, cat)).or_default() += 1,
1755 _ => {}
1756 }
1757 }
1758
1759 let all_keys: BTreeSet<_> = b_counts.keys().chain(e_counts.keys()).copied().collect();
1761
1762 for key in all_keys {
1763 let b = b_counts.get(&key).copied().unwrap_or(0);
1764 let e = e_counts.get(&key).copied().unwrap_or(0);
1765 assert_eq!(
1766 b, e,
1767 "B/E mismatch for (pid={}, tid={}, cat={:?}): {} B events vs {} E events",
1768 key.0, key.1, key.2, b, e,
1769 );
1770 }
1771 }
1772
1773 fn test_version() -> Version {
1774 Version::new(0, 9, 9999)
1775 }
1776
1777 fn ts(secs: i64) -> DateTime<FixedOffset> {
1780 FixedOffset::east_opt(0)
1781 .unwrap()
1782 .timestamp_opt(secs, 0)
1783 .unwrap()
1784 }
1785
1786 fn test_id(binary: &str, test: &str) -> OwnedTestInstanceId {
1787 OwnedTestInstanceId {
1788 binary_id: RustBinaryId::new(binary),
1789 test_name: TestCaseName::new(test),
1790 }
1791 }
1792
1793 fn slot(global: u64) -> TestSlotAssignment {
1794 TestSlotAssignment {
1795 global_slot: global,
1796 group_slot: None,
1797 test_group: TestGroup::Global,
1798 }
1799 }
1800
1801 fn core_event(
1802 timestamp: DateTime<FixedOffset>,
1803 kind: CoreEventKind,
1804 ) -> TestEventSummary<RecordingSpec> {
1805 TestEventSummary {
1806 timestamp,
1807 elapsed: Duration::ZERO,
1808 kind: TestEventKindSummary::Core(kind),
1809 }
1810 }
1811
1812 fn output_event(
1813 timestamp: DateTime<FixedOffset>,
1814 kind: OutputEventKind<RecordingSpec>,
1815 ) -> TestEventSummary<RecordingSpec> {
1816 TestEventSummary {
1817 timestamp,
1818 elapsed: Duration::ZERO,
1819 kind: TestEventKindSummary::Output(kind),
1820 }
1821 }
1822
1823 fn empty_output() -> ChildExecutionOutputDescription<RecordingSpec> {
1824 ChildExecutionOutputDescription::Output {
1825 result: Some(ExecutionResultDescription::Pass),
1826 output: ZipStoreOutputDescription::Split {
1827 stdout: None,
1828 stderr: None,
1829 },
1830 errors: None,
1831 }
1832 }
1833
1834 fn passing_status(
1835 start_time: DateTime<FixedOffset>,
1836 time_taken: Duration,
1837 attempt: u32,
1838 total_attempts: u32,
1839 ) -> ExecuteStatus<RecordingSpec> {
1840 ExecuteStatus {
1841 retry_data: RetryData {
1842 attempt,
1843 total_attempts,
1844 },
1845 output: empty_output(),
1846 result: ExecutionResultDescription::Pass,
1847 start_time,
1848 time_taken,
1849 is_slow: false,
1850 delay_before_start: Duration::ZERO,
1851 error_summary: None,
1852 output_error_slice: None,
1853 }
1854 }
1855
1856 fn failing_status(
1857 start_time: DateTime<FixedOffset>,
1858 time_taken: Duration,
1859 attempt: u32,
1860 total_attempts: u32,
1861 ) -> ExecuteStatus<RecordingSpec> {
1862 ExecuteStatus {
1863 retry_data: RetryData {
1864 attempt,
1865 total_attempts,
1866 },
1867 output: empty_output(),
1868 result: ExecutionResultDescription::Fail {
1869 failure: FailureDescription::ExitCode { code: 1 },
1870 leaked: false,
1871 },
1872 start_time,
1873 time_taken,
1874 is_slow: false,
1875 delay_before_start: Duration::ZERO,
1876 error_summary: None,
1877 output_error_slice: None,
1878 }
1879 }
1880
1881 fn convert_and_parse(
1884 events: Vec<Result<TestEventSummary<RecordingSpec>, RecordReadError>>,
1885 group_by: ChromeTraceGroupBy,
1886 ) -> (serde_json::Value, Vec<serde_json::Value>) {
1887 let json_bytes = convert_to_chrome_trace(
1888 &test_version(),
1889 events,
1890 group_by,
1891 ChromeTraceMessageFormat::JsonPretty,
1892 )
1893 .expect("conversion succeeded");
1894 let parsed: serde_json::Value = serde_json::from_slice(&json_bytes).expect("valid JSON");
1895 let trace_events = parsed["traceEvents"]
1896 .as_array()
1897 .expect("traceEvents is an array")
1898 .clone();
1899 assert_be_balanced(&trace_events);
1900 (parsed, trace_events)
1901 }
1902
1903 fn run_started(timestamp: DateTime<FixedOffset>) -> TestEventSummary<RecordingSpec> {
1904 core_event(
1905 timestamp,
1906 CoreEventKind::RunStarted {
1907 run_id: quick_junit::ReportUuid::nil(),
1908 profile_name: "default".to_string(),
1909 cli_args: vec![],
1910 stress_condition: None,
1911 },
1912 )
1913 }
1914
1915 fn run_finished(
1916 timestamp: DateTime<FixedOffset>,
1917 start_time: DateTime<FixedOffset>,
1918 elapsed: Duration,
1919 ) -> TestEventSummary<RecordingSpec> {
1920 core_event(
1921 timestamp,
1922 CoreEventKind::RunFinished {
1923 run_id: quick_junit::ReportUuid::nil(),
1924 start_time,
1925 elapsed,
1926 run_stats: RunFinishedStats::Single(RunStats::default()),
1927 outstanding_not_seen: None,
1928 },
1929 )
1930 }
1931
1932 fn test_started(
1933 timestamp: DateTime<FixedOffset>,
1934 binary: &str,
1935 test: &str,
1936 global_slot: u64,
1937 running: usize,
1938 ) -> TestEventSummary<RecordingSpec> {
1939 core_event(
1940 timestamp,
1941 CoreEventKind::TestStarted {
1942 stress_index: None,
1943 test_instance: test_id(binary, test),
1944 slot_assignment: slot(global_slot),
1945 current_stats: RunStats::default(),
1946 running,
1947 command_line: vec![],
1948 },
1949 )
1950 }
1951
1952 fn test_finished_pass(
1953 timestamp: DateTime<FixedOffset>,
1954 binary: &str,
1955 test: &str,
1956 start_time: DateTime<FixedOffset>,
1957 time_taken: Duration,
1958 running: usize,
1959 ) -> TestEventSummary<RecordingSpec> {
1960 output_event(
1961 timestamp,
1962 OutputEventKind::TestFinished {
1963 stress_index: None,
1964 test_instance: test_id(binary, test),
1965 success_output: TestOutputDisplay::Never,
1966 failure_output: TestOutputDisplay::Never,
1967 junit_store_success_output: false,
1968 junit_store_failure_output: false,
1969 junit_flaky_fail_status: JunitFlakyFailStatus::default(),
1970 run_statuses: ExecutionStatuses::new(
1971 vec![passing_status(start_time, time_taken, 1, 1)],
1972 FlakyResult::Pass,
1973 ),
1974 current_stats: RunStats::default(),
1975 running,
1976 },
1977 )
1978 }
1979
1980 #[test]
1981 fn basic_test_run() {
1982 let events = vec![
1983 Ok(run_started(ts(1000))),
1984 Ok(test_started(
1985 ts(1000),
1986 "my-crate::bin/my-test",
1987 "tests::basic",
1988 0,
1989 1,
1990 )),
1991 Ok(test_finished_pass(
1992 ts(1001),
1993 "my-crate::bin/my-test",
1994 "tests::basic",
1995 ts(1000),
1996 Duration::from_millis(500),
1997 0,
1998 )),
1999 Ok(run_finished(ts(1002), ts(1000), Duration::from_secs(2))),
2000 ];
2001
2002 let (parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
2003
2004 assert_eq!(
2011 trace_events.len(),
2012 15,
2013 "expected 15 trace events, got: {trace_events:#?}"
2014 );
2015
2016 let test_begins: Vec<_> = trace_events
2018 .iter()
2019 .filter(|e| e["ph"] == "B" && e["cat"] == "test")
2020 .collect();
2021 let test_ends: Vec<_> = trace_events
2022 .iter()
2023 .filter(|e| e["ph"] == "E" && e["cat"] == "test")
2024 .collect();
2025 assert_eq!(test_begins.len(), 1);
2026 assert_eq!(test_ends.len(), 1);
2027
2028 let test_b = test_begins[0];
2029 assert_eq!(test_b["name"], "tests::basic");
2030 assert_eq!(test_b["pid"], 2); assert_eq!(test_b["tid"], TID_OFFSET); let b_ts = test_b["ts"].as_f64().unwrap();
2035 assert!(
2036 (b_ts - 1_000_000_000.0).abs() < 1.0,
2037 "expected ~1e9 us, got {b_ts}"
2038 );
2039
2040 let test_e = test_ends[0];
2042 let e_ts = test_e["ts"].as_f64().unwrap();
2043 assert!(
2044 (e_ts - 1_001_000_000.0).abs() < 1.0,
2045 "expected ~1001000000 us, got {e_ts}"
2046 );
2047
2048 assert_eq!(test_e["args"]["attempt"], 1);
2050
2051 let run_begins: Vec<_> = trace_events
2053 .iter()
2054 .filter(|e| e["ph"] == "B" && e["cat"] == "run")
2055 .collect();
2056 let run_ends: Vec<_> = trace_events
2057 .iter()
2058 .filter(|e| e["ph"] == "E" && e["cat"] == "run")
2059 .collect();
2060 assert_eq!(run_begins.len(), 1);
2061 assert_eq!(run_ends.len(), 1);
2062 assert_eq!(run_ends[0]["args"]["profile"], "default");
2063
2064 assert_eq!(parsed["displayTimeUnit"], "ms");
2065
2066 let other_data = &parsed["otherData"];
2068 assert_eq!(other_data["profile_name"], "default");
2069 assert!(!other_data["run_id"].is_null(), "runId should be present");
2070 assert!(
2071 !other_data["nextest_version"].is_null(),
2072 "nextest version should be present"
2073 );
2074
2075 let proc_sort: Vec<_> = trace_events
2077 .iter()
2078 .filter(|e| e["name"] == "process_sort_index")
2079 .collect();
2080 assert!(
2081 proc_sort.len() >= 2,
2082 "should have sort indexes for run lifecycle and test binary"
2083 );
2084
2085 let run_sort = proc_sort
2087 .iter()
2088 .find(|e| e["pid"] == 0)
2089 .expect("run lifecycle sort index");
2090 assert_eq!(run_sort["args"]["sort_index"], 0);
2091
2092 let binary_sort = proc_sort
2094 .iter()
2095 .find(|e| e["pid"] == 2)
2096 .expect("binary sort index");
2097 assert_eq!(binary_sort["args"]["sort_index"], 2);
2098
2099 let thread_sort: Vec<_> = trace_events
2101 .iter()
2102 .filter(|e| e["name"] == "thread_sort_index")
2103 .collect();
2104 assert!(!thread_sort.is_empty(), "should have thread sort indexes");
2105 }
2106
2107 #[test]
2108 fn setup_script() {
2109 let script_id = ScriptId::new("db-setup".into()).expect("valid script ID");
2110
2111 let events = vec![
2112 Ok(core_event(
2113 ts(1000),
2114 CoreEventKind::SetupScriptStarted {
2115 stress_index: None,
2116 index: 0,
2117 total: 1,
2118 script_id: script_id.clone(),
2119 program: "/bin/setup".to_string(),
2120 args: vec![],
2121 no_capture: false,
2122 },
2123 )),
2124 Ok(core_event(
2126 ts(1005),
2127 CoreEventKind::SetupScriptSlow {
2128 stress_index: None,
2129 script_id: script_id.clone(),
2130 program: "/bin/setup".to_string(),
2131 args: vec![],
2132 elapsed: Duration::from_secs(5),
2133 will_terminate: true,
2134 },
2135 )),
2136 Ok(output_event(
2137 ts(1010),
2138 OutputEventKind::SetupScriptFinished {
2139 stress_index: None,
2140 index: 0,
2141 total: 1,
2142 script_id: script_id.clone(),
2143 program: "/bin/setup".to_string(),
2144 args: vec![],
2145 no_capture: false,
2146 run_status: SetupScriptExecuteStatus {
2147 output: empty_output(),
2148 result: ExecutionResultDescription::Pass,
2149 start_time: ts(1000),
2150 time_taken: Duration::from_secs(10),
2151 is_slow: true,
2152 env_map: None,
2153 error_summary: None,
2154 },
2155 },
2156 )),
2157 ];
2158
2159 let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
2160
2161 let b_events: Vec<_> = trace_events
2162 .iter()
2163 .filter(|e| e["ph"] == "B" && e["cat"] == "setup-script")
2164 .collect();
2165 let e_events: Vec<_> = trace_events
2166 .iter()
2167 .filter(|e| e["ph"] == "E" && e["cat"] == "setup-script")
2168 .collect();
2169 assert_eq!(b_events.len(), 1);
2170 assert_eq!(e_events.len(), 1);
2171
2172 assert_eq!(b_events[0]["name"], "db-setup");
2173 assert_eq!(b_events[0]["pid"], 1); assert_eq!(b_events[0]["tid"], TID_OFFSET); assert_eq!(e_events[0]["args"]["script_id"], "db-setup");
2178
2179 let slow_events: Vec<_> = trace_events
2181 .iter()
2182 .filter(|e| e["ph"] == "i" && e["name"] == "slow")
2183 .collect();
2184 assert_eq!(slow_events.len(), 1, "expected 1 slow instant event");
2185
2186 let slow = slow_events[0];
2187 assert_eq!(slow["cat"], "setup-script");
2188 assert_eq!(slow["s"], "t", "should be thread-scoped");
2189 assert_eq!(slow["args"]["will_terminate"], true);
2190 assert_eq!(slow["args"]["elapsed_secs"], 5.0);
2191 assert_eq!(slow["args"]["script_id"], "db-setup");
2192 assert_eq!(slow["pid"], SETUP_SCRIPT_PID);
2193 }
2194
2195 #[test]
2196 fn empty_run_produces_only_run_lifecycle() {
2197 let events = vec![
2198 Ok(run_started(ts(1000))),
2199 Ok(run_finished(ts(1000), ts(1000), Duration::ZERO)),
2200 ];
2201
2202 let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
2203
2204 assert_eq!(
2208 trace_events.len(),
2209 6,
2210 "empty run should produce only run lifecycle events, got: {trace_events:#?}"
2211 );
2212
2213 let b_events: Vec<_> = trace_events
2214 .iter()
2215 .filter(|e| e["ph"] == "B" && e["cat"] == "run")
2216 .collect();
2217 let e_events: Vec<_> = trace_events
2218 .iter()
2219 .filter(|e| e["ph"] == "E" && e["cat"] == "run")
2220 .collect();
2221 assert_eq!(b_events.len(), 1);
2222 assert_eq!(e_events.len(), 1);
2223 assert_eq!(b_events[0]["name"], "test run");
2224 }
2225
2226 #[test]
2229 fn pause_resume_splits_events() {
2230 let events = vec![
2231 Ok(core_event(
2233 ts(1000),
2234 CoreEventKind::RunStarted {
2235 run_id: quick_junit::ReportUuid::nil(),
2236 profile_name: "ci".to_string(),
2237 cli_args: vec!["--run-ignored".to_string()],
2238 stress_condition: None,
2239 },
2240 )),
2241 Ok(test_started(ts(1000), "crate::bin/test", "test_a", 0, 1)),
2242 Ok(core_event(
2244 ts(1001),
2245 CoreEventKind::RunPaused {
2246 setup_scripts_running: 0,
2247 running: 1,
2248 },
2249 )),
2250 Ok(core_event(
2252 ts(1005),
2253 CoreEventKind::RunContinued {
2254 setup_scripts_running: 0,
2255 running: 1,
2256 },
2257 )),
2258 Ok(test_finished_pass(
2259 ts(1010),
2260 "crate::bin/test",
2261 "test_a",
2262 ts(1000),
2263 Duration::from_secs(10),
2264 0,
2265 )),
2266 Ok(core_event(
2267 ts(1011),
2268 CoreEventKind::RunBeginCancel {
2269 setup_scripts_running: 0,
2270 running: 0,
2271 reason: CancelReason::TestFailure,
2272 },
2273 )),
2274 Ok(run_finished(ts(1012), ts(1000), Duration::from_secs(12))),
2275 ];
2276
2277 let (parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
2278
2279 let test_b: Vec<_> = trace_events
2282 .iter()
2283 .filter(|e| e["ph"] == "B" && e["cat"] == "test")
2284 .collect();
2285 let test_e: Vec<_> = trace_events
2286 .iter()
2287 .filter(|e| e["ph"] == "E" && e["cat"] == "test")
2288 .collect();
2289 assert_eq!(test_b.len(), 2, "expected 2 test B events (start + resume)");
2290 assert_eq!(test_e.len(), 2, "expected 2 test E events (pause + finish)");
2291
2292 let b1_ts = test_b[0]["ts"].as_f64().unwrap();
2294 let e1_ts = test_e[0]["ts"].as_f64().unwrap();
2295 assert!(
2296 (b1_ts - 1_000_000_000.0).abs() < 1.0,
2297 "first B should be at T=1000"
2298 );
2299 assert!(
2300 (e1_ts - 1_001_000_000.0).abs() < 1.0,
2301 "first E should be at T=1001 (pause)"
2302 );
2303
2304 let b2_ts = test_b[1]["ts"].as_f64().unwrap();
2306 let e2_ts = test_e[1]["ts"].as_f64().unwrap();
2307 assert!(
2308 (b2_ts - 1_005_000_000.0).abs() < 1.0,
2309 "second B should be at T=1005 (resume)"
2310 );
2311 assert!(
2312 (e2_ts - 1_010_000_000.0).abs() < 1.0,
2313 "second E should be at T=1010 (finish)"
2314 );
2315
2316 let run_b: Vec<_> = trace_events
2318 .iter()
2319 .filter(|e| e["ph"] == "B" && e["cat"] == "run")
2320 .collect();
2321 let run_e: Vec<_> = trace_events
2322 .iter()
2323 .filter(|e| e["ph"] == "E" && e["cat"] == "run")
2324 .collect();
2325 assert_eq!(run_b.len(), 2, "expected 2 run B events (start + resume)");
2326 assert_eq!(run_e.len(), 2, "expected 2 run E events (pause + finish)");
2327
2328 let instant_events: Vec<_> = trace_events.iter().filter(|e| e["ph"] == "i").collect();
2330 assert_eq!(instant_events.len(), 3);
2331 let names: Vec<&str> = instant_events
2332 .iter()
2333 .map(|e| e["name"].as_str().unwrap())
2334 .collect();
2335 assert_eq!(names, vec!["paused", "continued", "cancel"]);
2336
2337 assert_eq!(instant_events[2]["args"]["reason"], "test-failure");
2339
2340 let process_meta: Vec<_> = trace_events
2342 .iter()
2343 .filter(|e| e["name"] == "process_name" && e["pid"] == 0)
2344 .collect();
2345 assert_eq!(process_meta.len(), 1);
2346 assert_eq!(process_meta[0]["args"]["name"], "nextest run (ci)");
2347
2348 assert!(parsed["metadata"].is_null(), "metadata should not exist");
2351 let other_data = &parsed["otherData"];
2352 assert!(!other_data.is_null(), "otherData should exist");
2353 let version = other_data["nextest_version"].as_str().unwrap();
2354 assert!(!version.is_empty(), "nextest version should be non-empty");
2355 assert_eq!(other_data["profile_name"], "ci");
2356 assert_eq!(other_data["cli_args"][0], "--run-ignored");
2357 }
2358
2359 #[test]
2362 fn pause_resume_with_setup_scripts() {
2363 let script_id = ScriptId::new("db-setup".into()).expect("valid script ID");
2364
2365 let events = vec![
2366 Ok(run_started(ts(1000))),
2367 Ok(core_event(
2368 ts(1000),
2369 CoreEventKind::SetupScriptStarted {
2370 stress_index: None,
2371 index: 0,
2372 total: 1,
2373 script_id: script_id.clone(),
2374 program: "/bin/setup".to_string(),
2375 args: vec![],
2376 no_capture: false,
2377 },
2378 )),
2379 Ok(core_event(
2381 ts(1002),
2382 CoreEventKind::RunPaused {
2383 setup_scripts_running: 1,
2384 running: 0,
2385 },
2386 )),
2387 Ok(core_event(
2389 ts(1005),
2390 CoreEventKind::RunContinued {
2391 setup_scripts_running: 1,
2392 running: 0,
2393 },
2394 )),
2395 Ok(output_event(
2397 ts(1010),
2398 OutputEventKind::SetupScriptFinished {
2399 stress_index: None,
2400 index: 0,
2401 total: 1,
2402 script_id: script_id.clone(),
2403 program: "/bin/setup".to_string(),
2404 args: vec![],
2405 no_capture: false,
2406 run_status: SetupScriptExecuteStatus {
2407 output: empty_output(),
2408 result: ExecutionResultDescription::Pass,
2409 start_time: ts(1000),
2410 time_taken: Duration::from_secs(10),
2411 is_slow: false,
2412 env_map: None,
2413 error_summary: None,
2414 },
2415 },
2416 )),
2417 Ok(run_finished(ts(1012), ts(1000), Duration::from_secs(12))),
2418 ];
2419
2420 let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
2421
2422 let script_b: Vec<_> = trace_events
2425 .iter()
2426 .filter(|e| e["ph"] == "B" && e["cat"] == "setup-script")
2427 .collect();
2428 let script_e: Vec<_> = trace_events
2429 .iter()
2430 .filter(|e| e["ph"] == "E" && e["cat"] == "setup-script")
2431 .collect();
2432 assert_eq!(
2433 script_b.len(),
2434 2,
2435 "expected 2 setup-script B events (start + resume)"
2436 );
2437 assert_eq!(
2438 script_e.len(),
2439 2,
2440 "expected 2 setup-script E events (pause + finish)"
2441 );
2442
2443 let b1_ts = script_b[0]["ts"].as_f64().unwrap();
2445 let e1_ts = script_e[0]["ts"].as_f64().unwrap();
2446 assert!(
2447 (b1_ts - 1_000_000_000.0).abs() < 1.0,
2448 "first B should be at T=1000"
2449 );
2450 assert!(
2451 (e1_ts - 1_002_000_000.0).abs() < 1.0,
2452 "first E should be at T=1002 (pause)"
2453 );
2454
2455 let b2_ts = script_b[1]["ts"].as_f64().unwrap();
2457 assert!(
2458 (b2_ts - 1_005_000_000.0).abs() < 1.0,
2459 "second B should be at T=1005 (resume)"
2460 );
2461
2462 for e in script_b.iter().chain(script_e.iter()) {
2464 assert_eq!(
2465 e["pid"], 1,
2466 "setup script events should use SETUP_SCRIPT_PID"
2467 );
2468 }
2469
2470 let run_b: Vec<_> = trace_events
2472 .iter()
2473 .filter(|e| e["ph"] == "B" && e["cat"] == "run")
2474 .collect();
2475 let run_e: Vec<_> = trace_events
2476 .iter()
2477 .filter(|e| e["ph"] == "E" && e["cat"] == "run")
2478 .collect();
2479 assert_eq!(run_b.len(), 2, "expected 2 run B events (start + resume)");
2480 assert_eq!(run_e.len(), 2, "expected 2 run E events (pause + finish)");
2481 }
2482
2483 #[test]
2487 fn run_bar_uses_event_timestamp() {
2488 let events = vec![
2489 Ok(run_started(ts(1000))),
2490 Ok(test_started(ts(1000), "crate::bin/test", "slow_test", 0, 1)),
2491 Ok(test_finished_pass(
2492 ts(1010),
2493 "crate::bin/test",
2494 "slow_test",
2495 ts(1000),
2496 Duration::from_secs(10),
2497 0,
2498 )),
2499 Ok(run_finished(ts(1012), ts(1000), Duration::from_secs(8))),
2503 ];
2504
2505 let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
2506
2507 let run_b = trace_events
2509 .iter()
2510 .find(|e| e["ph"] == "B" && e["cat"] == "run")
2511 .expect("run B event");
2512 let run_e = trace_events
2513 .iter()
2514 .find(|e| e["ph"] == "E" && e["cat"] == "run")
2515 .expect("run E event");
2516
2517 let run_b_ts = run_b["ts"].as_f64().unwrap();
2518 let run_e_ts = run_e["ts"].as_f64().unwrap();
2519
2520 assert!(
2522 (run_b_ts - 1_000_000_000.0).abs() < 1.0,
2523 "run B should be at ts(1000)"
2524 );
2525 assert!(
2526 (run_e_ts - 1_012_000_000.0).abs() < 1.0,
2527 "run E should be at ts(1012), not ts(1008)"
2528 );
2529
2530 let test_e = trace_events
2532 .iter()
2533 .find(|e| e["ph"] == "E" && e["cat"] == "test")
2534 .expect("test E event");
2535 let test_e_ts = test_e["ts"].as_f64().unwrap();
2536 assert!(
2537 test_e_ts <= run_e_ts,
2538 "test E ({test_e_ts}) should not exceed run E ({run_e_ts})"
2539 );
2540 }
2541
2542 #[test]
2545 fn run_finished_while_paused() {
2546 let events = vec![
2547 Ok(run_started(ts(1000))),
2548 Ok(test_started(ts(1000), "crate::bin/test", "test_a", 0, 1)),
2549 Ok(core_event(
2551 ts(1002),
2552 CoreEventKind::RunPaused {
2553 setup_scripts_running: 0,
2554 running: 1,
2555 },
2556 )),
2557 Ok(run_finished(ts(1005), ts(1000), Duration::from_secs(5))),
2560 ];
2561
2562 let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
2563
2564 let run_b: Vec<_> = trace_events
2567 .iter()
2568 .filter(|e| e["ph"] == "B" && e["cat"] == "run")
2569 .collect();
2570 let run_e: Vec<_> = trace_events
2571 .iter()
2572 .filter(|e| e["ph"] == "E" && e["cat"] == "run")
2573 .collect();
2574
2575 assert_eq!(run_b.len(), 2, "expected 2 run B events, got {run_b:#?}");
2578 assert_eq!(run_e.len(), 2, "expected 2 run E events, got {run_e:#?}");
2579
2580 let last_e = run_e.last().unwrap();
2582 assert!(
2583 !last_e["args"]["run_stats"].is_null(),
2584 "final E should have run_stats"
2585 );
2586
2587 for (b, e) in run_b.iter().zip(run_e.iter()) {
2590 let b_ts = b["ts"].as_f64().unwrap();
2591 let e_ts = e["ts"].as_f64().unwrap();
2592 assert!(
2593 b_ts <= e_ts,
2594 "B timestamp ({b_ts}) should not exceed E timestamp ({e_ts})"
2595 );
2596 }
2597 }
2598
2599 #[test]
2603 fn snapshot_retry_flow_events() {
2604 let events = vec![
2605 Ok(test_started(
2607 ts(1000),
2608 "crate::bin/test",
2609 "flaky_pass",
2610 0,
2611 1,
2612 )),
2613 Ok(output_event(
2614 ts(1001),
2615 OutputEventKind::TestAttemptFailedWillRetry {
2616 stress_index: None,
2617 test_instance: test_id("crate::bin/test", "flaky_pass"),
2618 run_status: failing_status(ts(1000), Duration::from_millis(200), 1, 3),
2619 delay_before_next_attempt: Duration::ZERO,
2620 failure_output: TestOutputDisplay::Never,
2621 running: 1,
2622 },
2623 )),
2624 Ok(core_event(
2625 ts(1001),
2626 CoreEventKind::TestRetryStarted {
2627 stress_index: None,
2628 test_instance: test_id("crate::bin/test", "flaky_pass"),
2629 slot_assignment: slot(0),
2630 retry_data: RetryData {
2631 attempt: 2,
2632 total_attempts: 3,
2633 },
2634 running: 1,
2635 command_line: vec![],
2636 },
2637 )),
2638 Ok(output_event(
2639 ts(1002),
2640 OutputEventKind::TestFinished {
2641 stress_index: None,
2642 test_instance: test_id("crate::bin/test", "flaky_pass"),
2643 success_output: TestOutputDisplay::Never,
2644 failure_output: TestOutputDisplay::Never,
2645 junit_store_success_output: false,
2646 junit_store_failure_output: false,
2647 junit_flaky_fail_status: JunitFlakyFailStatus::default(),
2648 run_statuses: ExecutionStatuses::new(
2649 vec![
2650 failing_status(ts(1000), Duration::from_millis(200), 1, 3),
2651 passing_status(ts(1001), Duration::from_millis(300), 2, 3),
2652 ],
2653 FlakyResult::Pass,
2654 ),
2655 current_stats: RunStats::default(),
2656 running: 0,
2657 },
2658 )),
2659 Ok(test_started(
2662 ts(1003),
2663 "crate::bin/test",
2664 "flaky_fail",
2665 1,
2666 1,
2667 )),
2668 Ok(output_event(
2669 ts(1004),
2670 OutputEventKind::TestAttemptFailedWillRetry {
2671 stress_index: None,
2672 test_instance: test_id("crate::bin/test", "flaky_fail"),
2673 run_status: failing_status(ts(1003), Duration::from_millis(150), 1, 2),
2674 delay_before_next_attempt: Duration::ZERO,
2675 failure_output: TestOutputDisplay::Never,
2676 running: 1,
2677 },
2678 )),
2679 Ok(core_event(
2680 ts(1004),
2681 CoreEventKind::TestRetryStarted {
2682 stress_index: None,
2683 test_instance: test_id("crate::bin/test", "flaky_fail"),
2684 slot_assignment: slot(1),
2685 retry_data: RetryData {
2686 attempt: 2,
2687 total_attempts: 2,
2688 },
2689 running: 1,
2690 command_line: vec![],
2691 },
2692 )),
2693 Ok(output_event(
2694 ts(1005),
2695 OutputEventKind::TestFinished {
2696 stress_index: None,
2697 test_instance: test_id("crate::bin/test", "flaky_fail"),
2698 success_output: TestOutputDisplay::Never,
2699 failure_output: TestOutputDisplay::Never,
2700 junit_store_success_output: false,
2701 junit_store_failure_output: false,
2702 junit_flaky_fail_status: JunitFlakyFailStatus::default(),
2703 run_statuses: ExecutionStatuses::new(
2704 vec![
2705 failing_status(ts(1003), Duration::from_millis(150), 1, 2),
2706 passing_status(ts(1004), Duration::from_millis(250), 2, 2),
2707 ],
2708 FlakyResult::Fail,
2709 ),
2710 current_stats: RunStats::default(),
2711 running: 0,
2712 },
2713 )),
2714 ];
2715
2716 let result = convert_to_chrome_trace(
2717 &test_version(),
2718 events,
2719 ChromeTraceGroupBy::Binary,
2720 ChromeTraceMessageFormat::JsonPretty,
2721 );
2722 let json_bytes = result.expect("conversion succeeded");
2723 let json_str = String::from_utf8(json_bytes).expect("valid UTF-8");
2724
2725 insta::assert_snapshot!("retry_flow_chrome_trace", json_str);
2726 }
2727
2728 #[test]
2730 fn retry_across_pause_boundary() {
2731 let events = vec![
2732 Ok(run_started(ts(1000))),
2733 Ok(test_started(ts(1000), "crate::bin/test", "flaky", 0, 1)),
2734 Ok(output_event(
2736 ts(1001),
2737 OutputEventKind::TestAttemptFailedWillRetry {
2738 stress_index: None,
2739 test_instance: test_id("crate::bin/test", "flaky"),
2740 run_status: failing_status(ts(1000), Duration::from_millis(200), 1, 2),
2741 delay_before_next_attempt: Duration::from_secs(1),
2742 failure_output: TestOutputDisplay::Never,
2743 running: 1,
2744 },
2745 )),
2746 Ok(core_event(
2748 ts(1002),
2749 CoreEventKind::RunPaused {
2750 setup_scripts_running: 0,
2751 running: 1,
2752 },
2753 )),
2754 Ok(core_event(
2756 ts(1005),
2757 CoreEventKind::RunContinued {
2758 setup_scripts_running: 0,
2759 running: 1,
2760 },
2761 )),
2762 Ok(core_event(
2764 ts(1005),
2765 CoreEventKind::TestRetryStarted {
2766 stress_index: None,
2767 test_instance: test_id("crate::bin/test", "flaky"),
2768 slot_assignment: slot(0),
2769 retry_data: RetryData {
2770 attempt: 2,
2771 total_attempts: 2,
2772 },
2773 running: 1,
2774 command_line: vec![],
2775 },
2776 )),
2777 Ok(output_event(
2778 ts(1006),
2779 OutputEventKind::TestFinished {
2780 stress_index: None,
2781 test_instance: test_id("crate::bin/test", "flaky"),
2782 success_output: TestOutputDisplay::Never,
2783 failure_output: TestOutputDisplay::Never,
2784 junit_store_success_output: false,
2785 junit_store_failure_output: false,
2786 junit_flaky_fail_status: JunitFlakyFailStatus::default(),
2787 run_statuses: ExecutionStatuses::new(
2788 vec![
2789 failing_status(ts(1000), Duration::from_millis(200), 1, 2),
2790 passing_status(ts(1005), Duration::from_millis(300), 2, 2),
2791 ],
2792 FlakyResult::Pass,
2793 ),
2794 current_stats: RunStats::default(),
2795 running: 0,
2796 },
2797 )),
2798 Ok(run_finished(ts(1007), ts(1000), Duration::from_secs(7))),
2799 ];
2800
2801 let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
2802
2803 let flow_starts: Vec<_> = trace_events.iter().filter(|e| e["ph"] == "s").collect();
2805 let flow_finishes: Vec<_> = trace_events.iter().filter(|e| e["ph"] == "f").collect();
2806 assert_eq!(flow_starts.len(), 1);
2807 assert_eq!(flow_finishes.len(), 1);
2808 assert_eq!(
2809 flow_starts[0]["id"].as_u64(),
2810 flow_finishes[0]["id"].as_u64(),
2811 "flow events should be paired"
2812 );
2813
2814 let test_b: Vec<_> = trace_events
2822 .iter()
2823 .filter(|e| e["ph"] == "B" && e["cat"] == "test")
2824 .collect();
2825 let test_e: Vec<_> = trace_events
2826 .iter()
2827 .filter(|e| e["ph"] == "E" && e["cat"] == "test")
2828 .collect();
2829 assert_eq!(test_b.len(), 2, "2 B events: initial + retry");
2830 assert_eq!(test_e.len(), 2, "2 E events: attempt failed + finished");
2831 }
2832
2833 #[test]
2835 fn test_slow_instant_event() {
2836 let events = vec![
2837 Ok(test_started(ts(1000), "crate::bin/test", "slow_test", 0, 1)),
2838 Ok(core_event(
2839 ts(1005),
2840 CoreEventKind::TestSlow {
2841 stress_index: None,
2842 test_instance: test_id("crate::bin/test", "slow_test"),
2843 retry_data: RetryData {
2844 attempt: 1,
2845 total_attempts: 1,
2846 },
2847 elapsed: Duration::from_secs(5),
2848 will_terminate: false,
2849 },
2850 )),
2851 Ok(test_finished_pass(
2852 ts(1010),
2853 "crate::bin/test",
2854 "slow_test",
2855 ts(1000),
2856 Duration::from_secs(10),
2857 0,
2858 )),
2859 ];
2860
2861 let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
2862
2863 let slow_events: Vec<_> = trace_events
2865 .iter()
2866 .filter(|e| e["ph"] == "i" && e["name"] == "slow")
2867 .collect();
2868 assert_eq!(slow_events.len(), 1, "expected 1 slow instant event");
2869
2870 let slow = slow_events[0];
2871 assert_eq!(slow["cat"], "test");
2872 assert_eq!(slow["s"], "t", "should be thread-scoped");
2873 assert_eq!(slow["args"]["will_terminate"], false);
2874 assert_eq!(slow["args"]["elapsed_secs"], 5.0);
2875 assert_eq!(slow["args"]["attempt"], 1);
2876
2877 let test_b = trace_events
2879 .iter()
2880 .find(|e| e["ph"] == "B" && e["cat"] == "test")
2881 .expect("test B event");
2882 assert_eq!(slow["pid"], test_b["pid"]);
2883 assert_eq!(slow["tid"], test_b["tid"]);
2884 }
2885
2886 #[test]
2887 fn snapshot_basic_trace() {
2888 let events = vec![
2890 Ok(test_started(
2891 ts(1000),
2892 "my-crate::bin/my-test",
2893 "tests::it_works",
2894 0,
2895 1,
2896 )),
2897 Ok(test_finished_pass(
2901 ts(1002),
2902 "my-crate::bin/my-test",
2903 "tests::it_works",
2904 ts(1000),
2905 Duration::from_millis(500),
2906 0,
2907 )),
2908 ];
2909
2910 let result = convert_to_chrome_trace(
2911 &test_version(),
2912 events,
2913 ChromeTraceGroupBy::Binary,
2914 ChromeTraceMessageFormat::JsonPretty,
2915 );
2916 let json_bytes = result.expect("conversion succeeded");
2917 let json_str = String::from_utf8(json_bytes).expect("valid UTF-8");
2918
2919 insta::assert_snapshot!("basic_chrome_trace", json_str);
2920 }
2921
2922 #[test]
2923 fn snapshot_pause_resume_trace() {
2924 let events = vec![
2925 Ok(run_started(ts(1000))),
2926 Ok(test_started(
2927 ts(1000),
2928 "my-crate::bin/my-test",
2929 "tests::slow",
2930 0,
2931 1,
2932 )),
2933 Ok(core_event(
2935 ts(1002),
2936 CoreEventKind::RunPaused {
2937 setup_scripts_running: 0,
2938 running: 1,
2939 },
2940 )),
2941 Ok(core_event(
2943 ts(1008),
2944 CoreEventKind::RunContinued {
2945 setup_scripts_running: 0,
2946 running: 1,
2947 },
2948 )),
2949 Ok(test_finished_pass(
2955 ts(1010),
2956 "my-crate::bin/my-test",
2957 "tests::slow",
2958 ts(1000),
2959 Duration::from_secs(4),
2960 0,
2961 )),
2962 Ok(run_finished(ts(1010), ts(1000), Duration::from_secs(10))),
2963 ];
2964
2965 let result = convert_to_chrome_trace(
2966 &test_version(),
2967 events,
2968 ChromeTraceGroupBy::Binary,
2969 ChromeTraceMessageFormat::JsonPretty,
2970 );
2971 let json_bytes = result.expect("conversion succeeded");
2972 let json_str = String::from_utf8(json_bytes).expect("valid UTF-8");
2973
2974 insta::assert_snapshot!("pause_resume_chrome_trace", json_str);
2975 }
2976
2977 fn stress_progress(completed: u32, total: u32) -> StressProgress {
2979 StressProgress::Count {
2980 total: StressCount::Count {
2981 count: NonZero::new(total).expect("total is non-zero"),
2982 },
2983 elapsed: Duration::from_secs(completed as u64),
2984 completed,
2985 }
2986 }
2987
2988 #[test]
2991 fn stress_subrun_events() {
2992 let events = vec![
2993 Ok(run_started(ts(1000))),
2994 Ok(core_event(
2996 ts(1000),
2997 CoreEventKind::StressSubRunStarted {
2998 progress: stress_progress(0, 3),
2999 },
3000 )),
3001 Ok(test_started(ts(1000), "crate::bin/test", "test_a", 0, 1)),
3002 Ok(test_finished_pass(
3003 ts(1002),
3004 "crate::bin/test",
3005 "test_a",
3006 ts(1000),
3007 Duration::from_secs(2),
3008 0,
3009 )),
3010 Ok(core_event(
3011 ts(1002),
3012 CoreEventKind::StressSubRunFinished {
3013 progress: stress_progress(1, 3),
3014 sub_elapsed: Duration::from_secs(2),
3015 sub_stats: RunStats::default(),
3016 },
3017 )),
3018 Ok(core_event(
3020 ts(1003),
3021 CoreEventKind::StressSubRunStarted {
3022 progress: stress_progress(1, 3),
3023 },
3024 )),
3025 Ok(test_started(ts(1003), "crate::bin/test", "test_a", 0, 1)),
3026 Ok(test_finished_pass(
3027 ts(1005),
3028 "crate::bin/test",
3029 "test_a",
3030 ts(1003),
3031 Duration::from_secs(2),
3032 0,
3033 )),
3034 Ok(core_event(
3035 ts(1005),
3036 CoreEventKind::StressSubRunFinished {
3037 progress: stress_progress(2, 3),
3038 sub_elapsed: Duration::from_secs(2),
3039 sub_stats: RunStats::default(),
3040 },
3041 )),
3042 Ok(run_finished(ts(1006), ts(1000), Duration::from_secs(6))),
3043 ];
3044
3045 let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
3046
3047 let subrun_b: Vec<_> = trace_events
3049 .iter()
3050 .filter(|e| e["ph"] == "B" && e["cat"] == "stress")
3051 .collect();
3052 let subrun_e: Vec<_> = trace_events
3053 .iter()
3054 .filter(|e| e["ph"] == "E" && e["cat"] == "stress")
3055 .collect();
3056 assert_eq!(subrun_b.len(), 2, "expected 2 sub-run B events");
3057 assert_eq!(subrun_e.len(), 2, "expected 2 sub-run E events");
3058
3059 for e in subrun_b.iter().chain(subrun_e.iter()) {
3062 assert_eq!(e["pid"], RUN_LIFECYCLE_PID);
3063 assert_eq!(e["tid"], STRESS_SUBRUN_TID);
3064 assert_eq!(e["name"], "sub-run");
3065 }
3066
3067 assert!(
3069 !subrun_b[0]["args"]["progress"].is_null(),
3070 "sub-run B should have progress args"
3071 );
3072
3073 assert!(
3075 !subrun_e[0]["args"]["sub_stats"].is_null(),
3076 "sub-run E should have sub-stats"
3077 );
3078
3079 let thread_meta: Vec<_> = trace_events
3081 .iter()
3082 .filter(|e| {
3083 e["name"] == "thread_name"
3084 && e["pid"] == RUN_LIFECYCLE_PID
3085 && e["tid"] == STRESS_SUBRUN_TID
3086 })
3087 .collect();
3088 assert_eq!(
3089 thread_meta.len(),
3090 1,
3091 "stress sub-run thread_name metadata should be emitted once"
3092 );
3093 assert_eq!(thread_meta[0]["args"]["name"], "stress sub-runs");
3094 }
3095
3096 #[test]
3099 fn pause_resume_with_stress_subrun() {
3100 let events = vec![
3101 Ok(run_started(ts(1000))),
3102 Ok(core_event(
3103 ts(1000),
3104 CoreEventKind::StressSubRunStarted {
3105 progress: stress_progress(0, 2),
3106 },
3107 )),
3108 Ok(test_started(ts(1000), "crate::bin/test", "test_a", 0, 1)),
3109 Ok(core_event(
3111 ts(1002),
3112 CoreEventKind::RunPaused {
3113 setup_scripts_running: 0,
3114 running: 1,
3115 },
3116 )),
3117 Ok(core_event(
3119 ts(1005),
3120 CoreEventKind::RunContinued {
3121 setup_scripts_running: 0,
3122 running: 1,
3123 },
3124 )),
3125 Ok(test_finished_pass(
3127 ts(1008),
3128 "crate::bin/test",
3129 "test_a",
3130 ts(1000),
3131 Duration::from_secs(5),
3132 0,
3133 )),
3134 Ok(core_event(
3135 ts(1008),
3136 CoreEventKind::StressSubRunFinished {
3137 progress: stress_progress(1, 2),
3138 sub_elapsed: Duration::from_secs(5),
3139 sub_stats: RunStats::default(),
3140 },
3141 )),
3142 Ok(run_finished(ts(1009), ts(1000), Duration::from_secs(9))),
3143 ];
3144
3145 let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
3146
3147 let subrun_b: Vec<_> = trace_events
3150 .iter()
3151 .filter(|e| e["ph"] == "B" && e["cat"] == "stress")
3152 .collect();
3153 let subrun_e: Vec<_> = trace_events
3154 .iter()
3155 .filter(|e| e["ph"] == "E" && e["cat"] == "stress")
3156 .collect();
3157 assert_eq!(
3158 subrun_b.len(),
3159 2,
3160 "expected 2 sub-run B events (start + resume)"
3161 );
3162 assert_eq!(
3163 subrun_e.len(),
3164 2,
3165 "expected 2 sub-run E events (pause + finish)"
3166 );
3167
3168 let b1_ts = subrun_b[0]["ts"].as_f64().unwrap();
3170 let e1_ts = subrun_e[0]["ts"].as_f64().unwrap();
3171 assert!(
3172 (b1_ts - 1_000_000_000.0).abs() < 1.0,
3173 "first sub-run B should be at T=1000"
3174 );
3175 assert!(
3176 (e1_ts - 1_002_000_000.0).abs() < 1.0,
3177 "first sub-run E should be at T=1002 (pause)"
3178 );
3179
3180 let b2_ts = subrun_b[1]["ts"].as_f64().unwrap();
3182 let e2_ts = subrun_e[1]["ts"].as_f64().unwrap();
3183 assert!(
3184 (b2_ts - 1_005_000_000.0).abs() < 1.0,
3185 "second sub-run B should be at T=1005 (resume)"
3186 );
3187 assert!(
3188 (e2_ts - 1_008_000_000.0).abs() < 1.0,
3189 "second sub-run E should be at T=1008 (finish)"
3190 );
3191
3192 let test_b: Vec<_> = trace_events
3194 .iter()
3195 .filter(|e| e["ph"] == "B" && e["cat"] == "test")
3196 .collect();
3197 let test_e: Vec<_> = trace_events
3198 .iter()
3199 .filter(|e| e["ph"] == "E" && e["cat"] == "test")
3200 .collect();
3201 assert_eq!(test_b.len(), 2, "expected 2 test B events (start + resume)");
3202 assert_eq!(test_e.len(), 2, "expected 2 test E events (pause + finish)");
3203
3204 let run_b: Vec<_> = trace_events
3206 .iter()
3207 .filter(|e| e["ph"] == "B" && e["cat"] == "run")
3208 .collect();
3209 let run_e: Vec<_> = trace_events
3210 .iter()
3211 .filter(|e| e["ph"] == "E" && e["cat"] == "run")
3212 .collect();
3213 assert_eq!(run_b.len(), 2, "expected 2 run B events (start + resume)");
3214 assert_eq!(run_e.len(), 2, "expected 2 run E events (pause + finish)");
3215 }
3216
3217 #[test]
3220 fn results_counter_events() {
3221 let stats = RunStats {
3224 initial_run_count: 5,
3225 finished_count: 5,
3226 passed: 3,
3227 flaky: 1,
3228 failed: 1,
3229 exec_failed: 1,
3230 ..RunStats::default()
3231 };
3232
3233 let events = vec![
3234 Ok(test_started(ts(1000), "crate::bin/test", "test_a", 0, 1)),
3235 Ok(output_event(
3236 ts(1001),
3237 OutputEventKind::TestFinished {
3238 stress_index: None,
3239 test_instance: test_id("crate::bin/test", "test_a"),
3240 success_output: TestOutputDisplay::Never,
3241 failure_output: TestOutputDisplay::Never,
3242 junit_store_success_output: false,
3243 junit_store_failure_output: false,
3244 junit_flaky_fail_status: JunitFlakyFailStatus::default(),
3245 run_statuses: ExecutionStatuses::new(
3246 vec![passing_status(ts(1000), Duration::from_millis(500), 1, 1)],
3247 FlakyResult::Pass,
3248 ),
3249 current_stats: stats,
3250 running: 0,
3251 },
3252 )),
3253 ];
3254
3255 let (_parsed, trace_events) = convert_and_parse(events, ChromeTraceGroupBy::Binary);
3256
3257 let results_counters: Vec<_> = trace_events
3259 .iter()
3260 .filter(|e| e["ph"] == "C" && e["name"] == "test results")
3261 .collect();
3262 assert_eq!(
3263 results_counters.len(),
3264 1,
3265 "expected 1 results counter event"
3266 );
3267
3268 let args = &results_counters[0]["args"];
3269 assert_eq!(args["passed"], 3);
3271 assert_eq!(args["flaky"], 1);
3273 assert_eq!(args["failed"], 2, "failed should include exec_failed");
3275 }
3276
3277 #[test]
3281 fn multiple_binaries_grouping_modes() {
3282 let make_events = || {
3283 vec![
3284 Ok(run_started(ts(1000))),
3285 Ok(test_started(
3286 ts(1000),
3287 "crate-a::bin/test-a",
3288 "test_1",
3289 0,
3290 1,
3291 )),
3292 Ok(test_started(
3293 ts(1000),
3294 "crate-b::bin/test-b",
3295 "test_2",
3296 1,
3297 2,
3298 )),
3299 Ok(test_finished_pass(
3300 ts(1001),
3301 "crate-a::bin/test-a",
3302 "test_1",
3303 ts(1000),
3304 Duration::from_millis(100),
3305 1,
3306 )),
3307 Ok(test_finished_pass(
3308 ts(1001),
3309 "crate-b::bin/test-b",
3310 "test_2",
3311 ts(1000),
3312 Duration::from_millis(100),
3313 0,
3314 )),
3315 Ok(run_finished(ts(1002), ts(1000), Duration::from_secs(2))),
3316 ]
3317 };
3318
3319 {
3321 let (_parsed, trace_events) =
3322 convert_and_parse(make_events(), ChromeTraceGroupBy::Binary);
3323
3324 let b_events: Vec<_> = trace_events
3325 .iter()
3326 .filter(|e| e["ph"] == "B" && e["cat"] == "test")
3327 .collect();
3328 assert_eq!(b_events.len(), 2);
3329
3330 assert_eq!(b_events[0]["pid"], FIRST_BINARY_PID);
3333 assert_eq!(b_events[1]["pid"], FIRST_BINARY_PID + 1);
3334 }
3335
3336 {
3338 let (_parsed, trace_events) =
3339 convert_and_parse(make_events(), ChromeTraceGroupBy::Slot);
3340
3341 let test_b: Vec<_> = trace_events
3343 .iter()
3344 .filter(|e| e["ph"] == "B" && e["cat"] == "test")
3345 .collect();
3346 assert_eq!(test_b.len(), 2);
3347 for b in &test_b {
3348 assert_eq!(
3349 b["pid"], ALL_TESTS_PID,
3350 "slot mode: all tests should share ALL_TESTS_PID"
3351 );
3352 }
3353
3354 let names: Vec<&str> = test_b.iter().map(|e| e["name"].as_str().unwrap()).collect();
3356 assert!(
3357 names.contains(&"crate-a::bin/test-a test_1"),
3358 "expected qualified name for test_1, got: {names:?}"
3359 );
3360 assert!(
3361 names.contains(&"crate-b::bin/test-b test_2"),
3362 "expected qualified name for test_2, got: {names:?}"
3363 );
3364
3365 let test_e: Vec<_> = trace_events
3367 .iter()
3368 .filter(|e| e["ph"] == "E" && e["cat"] == "test")
3369 .collect();
3370 for e in &test_e {
3371 assert_eq!(
3372 e["pid"], ALL_TESTS_PID,
3373 "slot mode: all test E events should share ALL_TESTS_PID"
3374 );
3375 let name = e["name"].as_str().unwrap();
3376 assert!(
3377 name.contains("crate-a::bin/test-a") || name.contains("crate-b::bin/test-b"),
3378 "E event name should be qualified: {name}"
3379 );
3380 }
3381
3382 let proc_names: Vec<_> = trace_events
3384 .iter()
3385 .filter(|e| e["name"] == "process_name" && e["pid"] == ALL_TESTS_PID)
3386 .collect();
3387 assert_eq!(proc_names.len(), 1);
3388 assert_eq!(proc_names[0]["args"]["name"], "tests");
3389 }
3390 }
3391
3392 #[test]
3393 fn snapshot_slot_mode_chrome_trace() {
3394 let events = vec![
3395 Ok(run_started(ts(1000))),
3396 Ok(test_started(
3397 ts(1000),
3398 "crate-a::bin/test-a",
3399 "test_alpha",
3400 0,
3401 1,
3402 )),
3403 Ok(test_started(
3404 ts(1000),
3405 "crate-b::bin/test-b",
3406 "test_beta",
3407 1,
3408 2,
3409 )),
3410 Ok(test_finished_pass(
3411 ts(1002),
3412 "crate-a::bin/test-a",
3413 "test_alpha",
3414 ts(1000),
3415 Duration::from_millis(500),
3416 1,
3417 )),
3418 Ok(test_finished_pass(
3419 ts(1003),
3420 "crate-b::bin/test-b",
3421 "test_beta",
3422 ts(1000),
3423 Duration::from_millis(800),
3424 0,
3425 )),
3426 Ok(run_finished(ts(1004), ts(1000), Duration::from_secs(4))),
3427 ];
3428
3429 let result = convert_to_chrome_trace(
3430 &test_version(),
3431 events,
3432 ChromeTraceGroupBy::Slot,
3433 ChromeTraceMessageFormat::JsonPretty,
3434 );
3435 let json_bytes = result.expect("conversion succeeded");
3436 let json_str = String::from_utf8(json_bytes).expect("valid UTF-8");
3437
3438 insta::assert_snapshot!("slot_mode_chrome_trace", json_str);
3439 }
3440}