run_test_suite_lib/output/shell/
mod.rs

1// Copyright 2021 The Fuchsia Authors. All rights reserved.
2// Use of this source code is governed by a BSD-style license that can be
3// found in the LICENSE file.
4
5use crate::output::noop::NoopDirectoryWriter;
6use crate::output::{
7    ArtifactType, DirectoryArtifactType, DynArtifact, DynDirectoryArtifact, EntityId, EntityInfo,
8    ReportedOutcome, Reporter, Timestamp,
9};
10use fuchsia_async as fasync;
11use fuchsia_sync::Mutex;
12use log::error;
13use std::collections::HashMap;
14use std::io::{Error, Write};
15use std::sync::atomic::AtomicU32;
16use std::sync::Arc;
17use std::time::Duration;
18
19mod writer;
20pub use writer::ShellWriterView;
21use writer::{ShellWriterHandle, ShellWriterHandleInner};
22
23/// Duration after which to emit an excessive duration log.
24const EXCESSIVE_DURATION: Duration = Duration::from_secs(60);
25/// Buffer stdout and stderr for this duration before dumping to console.
26const STDIO_BUFFERING_DURATION: Duration = Duration::from_secs(5);
27/// Dump stdout and stderr to console if it exceeds this size.
28const STDIO_BUFFER_SIZE: usize = 4096;
29
30/// A reporter that outputs results and artifacts to a single stream, usually stdout.
31/// This reporter is intended to provide "live" updates to a developer watching while
32/// tests are executed.
33pub struct ShellReporter<W: 'static + Write + Send + Sync> {
34    /// Arc around the writer and state, used to dispense more handles.
35    inner: Arc<Mutex<ShellWriterHandleInner<W>>>,
36    /// Map containing known information about each entity.
37    entity_state_map: Mutex<HashMap<EntityId, EntityState>>,
38    /// Number of completed suites, used to output
39    completed_suites: AtomicU32,
40    /// Number of suites expected in the run.
41    expected_suites: Mutex<Option<u32>>,
42    /// Size of the buffer used for stdio.
43    stdio_buffer_size: usize,
44    /// Length of time to buffer stdio before printing it to console.
45    stdio_buffer_duration: Duration,
46}
47
48/// All known state needed by a |ShellReporter| to display results.
49struct EntityState {
50    name: String,
51    excessive_duration_task: Option<fasync::Task<()>>,
52    children: Vec<EntityId>,
53    restricted_logs: Option<ShellWriterView<Vec<u8>>>,
54    run_state: EntityRunningState,
55}
56
57enum EntityRunningState {
58    NotRunning,
59    Started,
60    Finished(ReportedOutcome),
61}
62
63impl EntityState {
64    fn new<S: Into<String>>(name: S) -> Self {
65        Self {
66            name: name.into(),
67            excessive_duration_task: None,
68            children: vec![],
69            restricted_logs: None,
70            run_state: EntityRunningState::NotRunning,
71        }
72    }
73
74    fn name(&self) -> &str {
75        &self.name
76    }
77}
78
79impl ShellReporter<Vec<u8>> {
80    pub fn new_expose_writer_for_test() -> (Self, ShellWriterView<Vec<u8>>) {
81        let inner = Arc::new(Mutex::new(ShellWriterHandleInner::new(vec![])));
82        let mut entity_state_map = HashMap::new();
83        entity_state_map.insert(EntityId::TestRun, EntityState::new("TEST RUN"));
84        (
85            Self {
86                inner: inner.clone(),
87                entity_state_map: Mutex::new(entity_state_map),
88                completed_suites: AtomicU32::new(0),
89                expected_suites: Mutex::new(None),
90                // Disable buffering for most tests to simplify testing.
91                stdio_buffer_duration: Duration::ZERO,
92                stdio_buffer_size: 0,
93            },
94            ShellWriterView::new(inner),
95        )
96    }
97}
98
99impl<W: 'static + Write + Send + Sync> ShellReporter<W> {
100    pub fn new(inner: W) -> Self {
101        let inner = Arc::new(Mutex::new(ShellWriterHandleInner::new(inner)));
102        let mut entity_state_map = HashMap::new();
103        entity_state_map.insert(EntityId::TestRun, EntityState::new("TEST RUN"));
104        Self {
105            inner,
106            entity_state_map: Mutex::new(entity_state_map),
107            completed_suites: AtomicU32::new(0),
108            expected_suites: Mutex::new(None),
109            stdio_buffer_duration: STDIO_BUFFERING_DURATION,
110            stdio_buffer_size: STDIO_BUFFER_SIZE,
111        }
112    }
113
114    fn new_writer_handle(&self, prefix: Option<String>) -> ShellWriterHandle<W> {
115        ShellWriterHandle::new_handle(Arc::clone(&self.inner), prefix)
116    }
117}
118
119impl<W: 'static + Write + Send + Sync> Reporter for ShellReporter<W> {
120    fn new_entity(&self, entity: &EntityId, name: &str) -> Result<(), Error> {
121        let mut map = self.entity_state_map.lock();
122        map.insert(entity.clone(), EntityState::new(name));
123        if let EntityId::Case { suite, .. } = entity {
124            map.get_mut(&EntityId::Suite(*suite)).unwrap().children.push(entity.clone());
125        }
126        Ok(())
127    }
128
129    fn set_entity_info(&self, entity: &EntityId, info: &EntityInfo) {
130        match (entity, info.expected_children) {
131            (EntityId::TestRun, Some(children)) => {
132                self.expected_suites.lock().replace(children);
133            }
134            (_, _) => (),
135        }
136    }
137
138    fn entity_started(&self, entity: &EntityId, _: Timestamp) -> Result<(), Error> {
139        let mut writer = self.new_writer_handle(None);
140        let mut entity_map_lock = self.entity_state_map.lock();
141        let entity_entry = entity_map_lock.get_mut(entity).unwrap();
142        entity_entry.run_state = EntityRunningState::Started;
143        let name = entity_entry.name().to_string();
144        match entity {
145            EntityId::TestRun => (),
146            EntityId::Suite(_) => writeln!(writer, "Running test '{}'", name)?,
147            EntityId::Case { .. } => {
148                writeln!(writer, "[RUNNING]\t{}", name)?;
149                entity_entry.excessive_duration_task = Some(fasync::Task::spawn(async move {
150                    fasync::Timer::new(EXCESSIVE_DURATION).await;
151                    writeln!(
152                        writer,
153                        "[duration - {}]:\tStill running after {:?} seconds",
154                        name,
155                        EXCESSIVE_DURATION.as_secs()
156                    )
157                    .unwrap_or_else(|e| error!("Failed to write: {:?}", e));
158                }));
159            }
160        }
161        Ok(())
162    }
163
164    fn entity_stopped(
165        &self,
166        entity: &EntityId,
167        outcome: &ReportedOutcome,
168        _: Timestamp,
169    ) -> Result<(), Error> {
170        let mut writer = self.new_writer_handle(None);
171        let mut entity_map_lock = self.entity_state_map.lock();
172        entity_map_lock.get_mut(entity).unwrap().run_state = EntityRunningState::Finished(*outcome);
173        let entity_entry = entity_map_lock.get_mut(entity).unwrap();
174        let name = entity_entry.name().to_string();
175
176        // cancel any tasks for reporting excessive duration
177        let _ = entity_entry.excessive_duration_task.take();
178        match entity {
179            EntityId::TestRun => (),
180            EntityId::Suite(_) => (),
181            EntityId::Case { .. } => {
182                // We don't list error result as it indicates the test didn't finish.
183                if *outcome != ReportedOutcome::Error {
184                    writeln!(writer, "[{}]\t{}", outcome, name)?;
185                }
186            }
187        }
188        Ok(())
189    }
190
191    fn entity_finished(&self, entity: &EntityId) -> Result<(), Error> {
192        let mut writer = self.new_writer_handle(None);
193        let entity_map_lock = self.entity_state_map.lock();
194        let entity_entry = entity_map_lock.get(entity).unwrap();
195        let name = entity_entry.name().to_string();
196        let outcome = match &entity_entry.run_state {
197            EntityRunningState::Finished(outcome) => *outcome,
198            _ => ReportedOutcome::Inconclusive,
199        };
200        let children: Vec<_> = entity_entry.children.iter().cloned().collect();
201        match entity {
202            EntityId::TestRun => (),
203            EntityId::Suite(_) => {
204                if matches!(entity_entry.run_state, EntityRunningState::NotRunning) {
205                    // no need to output a report if the test wasn't even started.
206                    return Ok(());
207                }
208
209                let cases: Vec<_> =
210                    children.iter().map(|child| entity_map_lock.get(child).unwrap()).collect();
211                let executed: Vec<_> = cases
212                    .iter()
213                    .filter(|case| match &case.run_state {
214                        EntityRunningState::Started => true,
215                        EntityRunningState::Finished(ReportedOutcome::Skipped) => false,
216                        EntityRunningState::Finished(_) => true,
217                        EntityRunningState::NotRunning => false,
218                    })
219                    .collect();
220                let mut failed: Vec<_> = cases
221                    .iter()
222                    .filter(|case| {
223                        matches!(
224                            &case.run_state,
225                            EntityRunningState::Finished(
226                                ReportedOutcome::Failed | ReportedOutcome::Timedout
227                            )
228                        )
229                    })
230                    .map(|case| case.name())
231                    .collect();
232                failed.sort();
233                let mut not_finished: Vec<_> = cases
234                    .iter()
235                    .filter(|case| {
236                        matches!(
237                            &case.run_state,
238                            EntityRunningState::Started
239                                | EntityRunningState::Finished(ReportedOutcome::Error)
240                        )
241                    })
242                    .map(|case| case.name())
243                    .collect();
244                not_finished.sort();
245                let num_passed = cases
246                    .iter()
247                    .filter(|case| {
248                        matches!(
249                            &case.run_state,
250                            EntityRunningState::Finished(ReportedOutcome::Passed)
251                        )
252                    })
253                    .count();
254                let num_skipped = cases
255                    .iter()
256                    .filter(|case| {
257                        matches!(
258                            &case.run_state,
259                            EntityRunningState::Finished(ReportedOutcome::Skipped)
260                        )
261                    })
262                    .count();
263
264                let suite_number =
265                    self.completed_suites.fetch_add(1, std::sync::atomic::Ordering::Relaxed);
266                match &*self.expected_suites.lock() {
267                    Some(total_suites) if *total_suites > 1 => writeln!(
268                        writer,
269                        "\nTest suite count {}/{}",
270                        suite_number + 1,
271                        total_suites,
272                    )?,
273                    Some(_) | None => (),
274                }
275                writeln!(writer)?;
276                if !failed.is_empty() {
277                    writeln!(writer, "Failed tests: {}", failed.join(", "))?;
278                }
279                if !not_finished.is_empty() {
280                    writeln!(writer, "\nThe following test(s) never completed:")?;
281                    for t in not_finished {
282                        writeln!(writer, "{}", t)?;
283                    }
284                }
285                match num_skipped {
286                    0 => writeln!(
287                        writer,
288                        "{} out of {} tests passed...",
289                        num_passed,
290                        executed.len()
291                    )?,
292                    skipped => writeln!(
293                        writer,
294                        "{} out of {} attempted tests passed, {} tests skipped...",
295                        num_passed,
296                        executed.len(),
297                        skipped,
298                    )?,
299                }
300                if let Some(restricted_logs) = &entity_entry.restricted_logs {
301                    writeln!(writer, "\nTest {} produced unexpected high-severity logs:", &name)?;
302                    writeln!(writer, "----------------xxxxx----------------")?;
303                    writer.write_all(restricted_logs.lock().as_slice())?;
304                    writeln!(writer, "\n----------------xxxxx----------------")?;
305                    writeln!(writer, "Failing this test. See: https://fuchsia.dev/fuchsia-src/development/diagnostics/test_and_logs#restricting_log_severity\n")?;
306                }
307                match outcome {
308                    ReportedOutcome::Cancelled => {
309                        writeln!(writer, "{} was cancelled before completion.", &name)?
310                    }
311                    ReportedOutcome::DidNotFinish => {
312                        writeln!(writer, "{} did not complete successfully.", &name)?
313                    }
314                    other => writeln!(writer, "{} completed with result: {}", &name, other)?,
315                }
316            }
317            EntityId::Case { .. } => (),
318        }
319        Ok(())
320    }
321
322    fn new_artifact(
323        &self,
324        entity: &EntityId,
325        artifact_type: &ArtifactType,
326    ) -> Result<Box<DynArtifact>, Error> {
327        let mut lock = self.entity_state_map.lock();
328        let entity = lock.get_mut(entity).unwrap();
329        let name = entity.name();
330
331        Ok(match artifact_type {
332            ArtifactType::Stdout => Box::new(test_diagnostics::StdoutBuffer::new(
333                self.stdio_buffer_duration,
334                self.new_writer_handle(Some(format!("[stdout - {}]\n", name))),
335                self.stdio_buffer_size,
336            )),
337            ArtifactType::Stderr => Box::new(test_diagnostics::StdoutBuffer::new(
338                self.stdio_buffer_duration,
339                self.new_writer_handle(Some(format!("[stderr - {}]\n", name))),
340                self.stdio_buffer_size,
341            )),
342            ArtifactType::Syslog => Box::new(self.new_writer_handle(None)),
343            ArtifactType::RestrictedLog => {
344                // Restricted logs are saved for reporting when the entity completes.
345                let log_buffer = Arc::new(Mutex::new(ShellWriterHandleInner::new(vec![])));
346                entity.restricted_logs = Some(ShellWriterView::new(log_buffer.clone()));
347                Box::new(ShellWriterHandle::new_handle(log_buffer, None))
348            }
349        })
350    }
351
352    fn new_directory_artifact(
353        &self,
354        _entity: &EntityId,
355        _artifact_type: &DirectoryArtifactType,
356        _component_moniker: Option<String>,
357    ) -> Result<Box<DynDirectoryArtifact>, Error> {
358        // For the purpose of live reporting we don't display anything from a directory.
359        Ok(Box::new(NoopDirectoryWriter))
360    }
361}
362
363#[cfg(test)]
364mod test {
365    use super::*;
366    use crate::output::{CaseId, RunReporter, SuiteId};
367
368    #[fuchsia::test]
369    async fn report_case_events() {
370        let (shell_reporter, output) = ShellReporter::new_expose_writer_for_test();
371        let run_reporter = RunReporter::new(shell_reporter);
372        let suite_reporter =
373            run_reporter.new_suite("test-suite", &SuiteId(0)).expect("create suite");
374        suite_reporter.started(Timestamp::Unknown).expect("case started");
375        let mut expected = "Running test 'test-suite'\n".to_string();
376        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
377
378        let case_1_reporter = suite_reporter.new_case("case-1", &CaseId(0)).expect("create case");
379        let case_2_reporter = suite_reporter.new_case("case-2", &CaseId(1)).expect("create case");
380
381        case_1_reporter.started(Timestamp::Unknown).expect("case started");
382        expected.push_str("[RUNNING]\tcase-1\n");
383        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
384
385        case_2_reporter.started(Timestamp::Unknown).expect("case started");
386        expected.push_str("[RUNNING]\tcase-2\n");
387        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
388
389        case_1_reporter.stopped(&ReportedOutcome::Passed, Timestamp::Unknown).expect("stop case");
390        expected.push_str("[PASSED]\tcase-1\n");
391        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
392
393        case_2_reporter.stopped(&ReportedOutcome::Failed, Timestamp::Unknown).expect("stop case");
394        expected.push_str("[FAILED]\tcase-2\n");
395        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
396
397        case_1_reporter.finished().expect("finish case");
398        case_2_reporter.finished().expect("finish case");
399        suite_reporter.stopped(&ReportedOutcome::Failed, Timestamp::Unknown).expect("stop suite");
400        suite_reporter.finished().expect("finish suite");
401
402        expected.push_str("\n");
403        expected.push_str("Failed tests: case-2\n");
404        expected.push_str("1 out of 2 tests passed...\n");
405        expected.push_str("test-suite completed with result: FAILED\n");
406        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
407    }
408
409    #[fuchsia::test]
410    async fn report_multiple_suites() {
411        const NUM_SUITES: u32 = 5;
412        let (shell_reporter, output) = ShellReporter::new_expose_writer_for_test();
413        let run_reporter = RunReporter::new(shell_reporter);
414        run_reporter.set_expected_suites(NUM_SUITES);
415        run_reporter.started(Timestamp::Unknown).expect("run started");
416        let mut expected = "".to_string();
417
418        for suite_number in 0..4 {
419            let suite_name = format!("test-suite-{:?}", suite_number);
420            let suite_reporter =
421                run_reporter.new_suite(&suite_name, &SuiteId(0)).expect("create suite");
422            suite_reporter.started(Timestamp::Unknown).expect("case started");
423            expected.push_str(&format!("Running test '{}'\n", &suite_name));
424            assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
425
426            let case_reporter = suite_reporter.new_case("case-1", &CaseId(0)).expect("create case");
427            case_reporter.started(Timestamp::Unknown).expect("case started");
428            expected.push_str("[RUNNING]\tcase-1\n");
429            assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
430            case_reporter.stopped(&ReportedOutcome::Passed, Timestamp::Unknown).expect("stop case");
431            expected.push_str("[PASSED]\tcase-1\n");
432            assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
433
434            case_reporter.finished().expect("finish case");
435            suite_reporter
436                .stopped(&ReportedOutcome::Passed, Timestamp::Unknown)
437                .expect("stop suite");
438            suite_reporter.finished().expect("finish suite");
439
440            expected.push_str("\n");
441            expected.push_str(&format!(
442                "Test suite count {:?}/{:?}\n\n",
443                suite_number + 1,
444                NUM_SUITES
445            ));
446            expected.push_str("1 out of 1 tests passed...\n");
447            expected.push_str(&format!("{} completed with result: PASSED\n", suite_name));
448            assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
449        }
450    }
451
452    #[fuchsia::test]
453    async fn report_case_skipped() {
454        let (shell_reporter, output) = ShellReporter::new_expose_writer_for_test();
455        let run_reporter = RunReporter::new(shell_reporter);
456        let suite_reporter =
457            run_reporter.new_suite("test-suite", &SuiteId(0)).expect("create suite");
458        suite_reporter.started(Timestamp::Unknown).expect("case started");
459        let mut expected = "Running test 'test-suite'\n".to_string();
460        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
461
462        let case_1_reporter = suite_reporter.new_case("case-1", &CaseId(0)).expect("create case");
463        let case_2_reporter = suite_reporter.new_case("case-2", &CaseId(1)).expect("create case");
464
465        case_1_reporter.started(Timestamp::Unknown).expect("case started");
466        expected.push_str("[RUNNING]\tcase-1\n");
467        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
468
469        case_1_reporter.stopped(&ReportedOutcome::Passed, Timestamp::Unknown).expect("stop case");
470        expected.push_str("[PASSED]\tcase-1\n");
471        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
472
473        case_2_reporter.stopped(&ReportedOutcome::Skipped, Timestamp::Unknown).expect("stop case");
474        expected.push_str("[SKIPPED]\tcase-2\n");
475        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
476
477        case_1_reporter.finished().expect("finish case");
478        case_2_reporter.finished().expect("finish case");
479        suite_reporter.stopped(&ReportedOutcome::Passed, Timestamp::Unknown).expect("stop suite");
480        suite_reporter.finished().expect("finish suite");
481
482        expected.push_str("\n");
483        expected.push_str("1 out of 1 attempted tests passed, 1 tests skipped...\n");
484        expected.push_str("test-suite completed with result: PASSED\n");
485        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
486    }
487
488    #[fuchsia::test]
489    async fn syslog_artifacts() {
490        let (shell_reporter, output) = ShellReporter::new_expose_writer_for_test();
491        let run_reporter = RunReporter::new(shell_reporter);
492        let suite_reporter =
493            run_reporter.new_suite("test-suite", &SuiteId(0)).expect("create suite");
494        suite_reporter.started(Timestamp::Unknown).expect("case started");
495        let mut syslog_writer =
496            suite_reporter.new_artifact(&ArtifactType::Syslog).expect("create syslog");
497
498        writeln!(syslog_writer, "[log] test syslog").expect("write to syslog");
499        let mut expected = "Running test 'test-suite'\n".to_string();
500        expected.push_str("[log] test syslog\n");
501        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected);
502
503        suite_reporter.stopped(&ReportedOutcome::Passed, Timestamp::Unknown).expect("stop suite");
504        writeln!(syslog_writer, "[log] more test syslog").expect("write to syslog");
505        expected.push_str("[log] more test syslog\n");
506        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected);
507
508        suite_reporter.finished().expect("finish suite");
509        expected.push_str("\n");
510        expected.push_str("0 out of 0 tests passed...\n");
511        expected.push_str("test-suite completed with result: PASSED\n");
512        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
513    }
514
515    #[fuchsia::test]
516    async fn report_retricted_logs() {
517        let (shell_reporter, output) = ShellReporter::new_expose_writer_for_test();
518        let run_reporter = RunReporter::new(shell_reporter);
519        let suite_reporter =
520            run_reporter.new_suite("test-suite", &SuiteId(0)).expect("create suite");
521        suite_reporter.started(Timestamp::Unknown).expect("case started");
522
523        let case_reporter = suite_reporter.new_case("case-0", &CaseId(0)).expect("create case");
524        case_reporter.started(Timestamp::Unknown).expect("case started");
525        case_reporter.stopped(&ReportedOutcome::Passed, Timestamp::Unknown).expect("stop case");
526        case_reporter.finished().expect("finish case");
527
528        let mut expected = "Running test 'test-suite'\n".to_string();
529        expected.push_str("[RUNNING]\tcase-0\n");
530        expected.push_str("[PASSED]\tcase-0\n");
531        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
532
533        suite_reporter.stopped(&ReportedOutcome::Failed, Timestamp::Unknown).expect("stop suite");
534        let mut restricted_log = suite_reporter
535            .new_artifact(&ArtifactType::RestrictedLog)
536            .expect("create restricted log");
537        write!(restricted_log, "suite restricted log").expect("write to restricted log");
538        drop(restricted_log);
539
540        suite_reporter.finished().expect("finish suite");
541        expected.push_str("\n");
542        expected.push_str("1 out of 1 tests passed...\n");
543        expected.push_str("\nTest test-suite produced unexpected high-severity logs:\n");
544        expected.push_str("----------------xxxxx----------------\n");
545        expected.push_str("suite restricted log\n\n");
546        expected.push_str("----------------xxxxx----------------\n");
547        expected.push_str("Failing this test. See: https://fuchsia.dev/fuchsia-src/development/diagnostics/test_and_logs#restricting_log_severity\n");
548        expected.push_str("\ntest-suite completed with result: FAILED\n");
549        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
550    }
551
552    #[fuchsia::test]
553    async fn stdout_artifacts() {
554        let (shell_reporter, output) = ShellReporter::new_expose_writer_for_test();
555        let run_reporter = RunReporter::new(shell_reporter);
556        let suite_reporter =
557            run_reporter.new_suite("test-suite", &SuiteId(0)).expect("create suite");
558        suite_reporter.started(Timestamp::Unknown).expect("case started");
559
560        let case_0_reporter = suite_reporter.new_case("case-0", &CaseId(0)).expect("create case");
561        let case_1_reporter = suite_reporter.new_case("case-1", &CaseId(1)).expect("create case");
562        case_0_reporter.started(Timestamp::Unknown).expect("start case");
563        case_1_reporter.started(Timestamp::Unknown).expect("start case");
564        let mut expected = "Running test 'test-suite'\n".to_string();
565        expected.push_str("[RUNNING]\tcase-0\n[RUNNING]\tcase-1\n");
566        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
567
568        let mut case_0_stdout =
569            case_0_reporter.new_artifact(&ArtifactType::Stdout).expect("create artifact");
570        let mut case_1_stdout =
571            case_1_reporter.new_artifact(&ArtifactType::Stdout).expect("create artifact");
572
573        writeln!(case_0_stdout, "stdout from case 0").expect("write to stdout");
574        writeln!(case_1_stdout, "stdout from case 1").expect("write to stdout");
575
576        expected.push_str("[stdout - case-0]\nstdout from case 0\n");
577        expected.push_str("[stdout - case-1]\nstdout from case 1\n");
578        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
579
580        case_0_reporter.stopped(&ReportedOutcome::Passed, Timestamp::Unknown).expect("stop case");
581        case_1_reporter.stopped(&ReportedOutcome::Passed, Timestamp::Unknown).expect("stop case");
582        expected.push_str("[PASSED]\tcase-0\n");
583        expected.push_str("[PASSED]\tcase-1\n");
584        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
585
586        case_0_reporter.finished().expect("finish case");
587        case_1_reporter.finished().expect("finish case");
588        suite_reporter.stopped(&ReportedOutcome::Passed, Timestamp::Unknown).expect("stop suite");
589
590        suite_reporter.finished().expect("finish suite");
591        expected.push_str("\n");
592        expected.push_str("2 out of 2 tests passed...\n");
593        expected.push_str("test-suite completed with result: PASSED\n");
594        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
595    }
596
597    #[fuchsia::test]
598    async fn report_unfinished() {
599        let (shell_reporter, output) = ShellReporter::new_expose_writer_for_test();
600        let run_reporter = RunReporter::new(shell_reporter);
601        let suite_reporter =
602            run_reporter.new_suite("test-suite", &SuiteId(0)).expect("create suite");
603        suite_reporter.started(Timestamp::Unknown).expect("suite started");
604
605        let case_reporter = suite_reporter.new_case("case-0", &CaseId(0)).expect("create case");
606        case_reporter.started(Timestamp::Unknown).expect("case started");
607        case_reporter.stopped(&ReportedOutcome::Passed, Timestamp::Unknown).expect("stop case");
608        case_reporter.finished().expect("finish case");
609        let mut expected = "Running test 'test-suite'\n".to_string();
610        expected.push_str("[RUNNING]\tcase-0\n[PASSED]\tcase-0\n");
611        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
612
613        // add a case that finishes with ERROR
614        let unfinished_case_1 = suite_reporter.new_case("case-1", &CaseId(1)).expect("create case");
615        unfinished_case_1.started(Timestamp::Unknown).expect("case started");
616        unfinished_case_1.stopped(&ReportedOutcome::Error, Timestamp::Unknown).expect("stop case");
617        unfinished_case_1.finished().expect("finish case");
618        expected.push_str("[RUNNING]\tcase-1\n");
619        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
620
621        // add a case that doesn't finish at all
622        let unfinished_case_2 = suite_reporter.new_case("case-2", &CaseId(2)).expect("create case");
623        unfinished_case_2.started(Timestamp::Unknown).expect("case started");
624        unfinished_case_2.finished().expect("finish case");
625        expected.push_str("[RUNNING]\tcase-2\n");
626        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
627
628        suite_reporter.stopped(&ReportedOutcome::Failed, Timestamp::Unknown).expect("stop suite");
629        suite_reporter.finished().expect("finish suite");
630        expected.push_str("\n");
631        expected.push_str("\nThe following test(s) never completed:\n");
632        expected.push_str("case-1\n");
633        expected.push_str("case-2\n");
634        expected.push_str("1 out of 3 tests passed...\n");
635        expected.push_str("test-suite completed with result: FAILED\n");
636        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
637    }
638
639    #[fuchsia::test]
640    async fn report_cancelled_suite() {
641        let (shell_reporter, output) = ShellReporter::new_expose_writer_for_test();
642        let run_reporter = RunReporter::new(shell_reporter);
643        let suite_reporter =
644            run_reporter.new_suite("test-suite", &SuiteId(0)).expect("create suite");
645        suite_reporter.started(Timestamp::Unknown).expect("suite started");
646
647        let case_reporter = suite_reporter.new_case("case", &CaseId(0)).expect("create new case");
648        case_reporter.started(Timestamp::Unknown).expect("case started");
649        case_reporter.finished().expect("case finished");
650        suite_reporter
651            .stopped(&ReportedOutcome::Cancelled, Timestamp::Unknown)
652            .expect("stop suite");
653        suite_reporter.finished().expect("case finished");
654
655        let mut expected = "Running test 'test-suite'\n".to_string();
656        expected.push_str("[RUNNING]\tcase\n");
657        expected.push_str("\n");
658        expected.push_str("\nThe following test(s) never completed:\n");
659        expected.push_str("case\n");
660        expected.push_str("0 out of 1 tests passed...\n");
661        expected.push_str("test-suite was cancelled before completion.\n");
662        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
663    }
664
665    #[fuchsia::test]
666    async fn report_suite_did_not_finish() {
667        let (shell_reporter, output) = ShellReporter::new_expose_writer_for_test();
668        let run_reporter = RunReporter::new(shell_reporter);
669        let suite_reporter =
670            run_reporter.new_suite("test-suite", &SuiteId(0)).expect("create suite");
671        suite_reporter.started(Timestamp::Unknown).expect("suite started");
672
673        let case_reporter = suite_reporter.new_case("case", &CaseId(0)).expect("create new case");
674        case_reporter.started(Timestamp::Unknown).expect("case started");
675        case_reporter.finished().expect("case finished");
676        suite_reporter
677            .stopped(&ReportedOutcome::DidNotFinish, Timestamp::Unknown)
678            .expect("stop suite");
679        suite_reporter.finished().expect("case finished");
680
681        let mut expected = "Running test 'test-suite'\n".to_string();
682        expected.push_str("[RUNNING]\tcase\n");
683        expected.push_str("\n");
684        expected.push_str("\nThe following test(s) never completed:\n");
685        expected.push_str("case\n");
686        expected.push_str("0 out of 1 tests passed...\n");
687        expected.push_str("test-suite did not complete successfully.\n");
688        assert_eq!(String::from_utf8(output.lock().clone()).unwrap(), expected,);
689    }
690}