gwr_track/

test_helpers.rs

// Copyright (c) 2020 Graphcore Ltd. All rights reserved.

//! This module provides helper functions for testing logging output
//!
//! The aim of this module is to provide commonly-used functions that enable the
//! testing of the output that should appear from logging macros.
//!
//! *Note:* all tests should be run in a [serial](https://docs.rs/serial_test) manner because
//! the logger involves shared global state that will otherwise give
//! unpredictable results.

use std::cell::RefCell;
use std::fs;
use std::io::BufWriter;
use std::path::Path;
use std::rc::Rc;

use regex::Regex;

use crate::entity::Capacity;
use crate::tracker::aka::AlternativeNames;
use crate::tracker::{CapnProtoTracker, EntityManager};
use crate::{Id, Track, Tracker, Writer};

/// A tracker that keeps track events.
pub struct TestTracker {
    events: RefCell<Vec<String>>,

    unique_id: RefCell<u64>,
    level: log::Level,
}

impl TestTracker {
    /// Create a new [`Tracker`] for the tests.
    ///
    /// This keeps the track events in memory for checking later.
    #[must_use]
    pub fn new(initial_id: u64, level: log::Level) -> Self {
        Self {
            events: RefCell::new(Vec::new()),
            unique_id: RefCell::new(initial_id),
            level,
        }
    }

    fn add_event(&self, event: String) {
        println!("{event}");
        let mut events = self.events.borrow_mut();
        events.push(event);
    }

    /// Return a snapshot of the events recorded so far.
    #[must_use]
    pub fn events(&self) -> Vec<String> {
        self.events.borrow().clone()
    }
}

impl Track for TestTracker {
    fn unique_id(&self) -> Id {
        let mut guard = self.unique_id.borrow_mut();
        let id = *guard;
        *guard += 1;
        Id(id)
    }

    fn enabled_level(&self, _id: Id) -> log::Level {
        self.level
    }

    fn monitoring_window_size_for(&self, _id: Id) -> Option<u64> {
        None
    }

    fn add_entity(
        &self,
        _id: Id,
        _entity_name: &str,
        _alternative_names: AlternativeNames,
    ) -> log::Level {
        self.level
    }

    fn enter(&self, id: Id, item: Id) {
        self.add_event(format!("{id}: {item} entered"));
    }

    fn exit(&self, id: Id, item: Id) {
        self.add_event(format!("{id}: {item} exited"));
    }

    fn value(&self, id: Id, value: f64) {
        self.add_event(format!("{id}: {value}"));
    }

    fn begin_activity(&self, activity: Id, lane: Id, name: &str) {
        self.add_event(format!("{activity}: activity begin {name} on lane {lane}"));
    }

    fn end_activity(&self, activity: Id) {
        self.add_event(format!("{activity}: activity end"));
    }

    fn add_to_group(&self, activity: Id, group_id: Id) {
        self.add_event(format!("{activity}: added to group {group_id}"));
    }

    fn remove_from_group(&self, activity: Id, group_id: Id) {
        self.add_event(format!("{activity}: removed from group {group_id}"));
    }

    fn create_entity(&self, created_by: Id, id: Id, name: &str) {
        self.add_event(format!("{created_by}: created entity {id}, {name}"));
    }

    fn create_monitor(&self, created_by: Id, id: Id, name: &str) {
        self.add_event(format!("{created_by}: created monitor {id}, {name}"));
    }

    fn create_lane(&self, created_by: Id, id: Id, name: &str) {
        self.add_event(format!("{created_by}: created lane {id}, {name}"));
    }

    fn create_group(&self, created_by: Id, id: Id, name: &str) {
        self.add_event(format!("{created_by}: created group {id}, {name}"));
    }

    fn create_object(
        &self,
        created_by: Id,
        id: Id,
        size: usize,
        units: &str,
        req_type: u8,
        details: &str,
    ) {
        self.add_event(format!(
            "{created_by}: created object {id}, {req_type}, {size}, {units}, {details}"
        ));
    }

    fn capacity(&self, id: Id, capacity: Capacity) {
        self.add_event(format!(
            "{id}: capacity {} {}",
            capacity.value, capacity.units
        ));
    }

    fn destroy(&self, destroyed_by: Id, id: Id) {
        self.add_event(format!("{destroyed_by}: destroyed {id}"));
    }

    fn connect(&self, connect_from: Id, connect_to: Id) {
        self.add_event(format!("{connect_from}: connect to {connect_to}"));
    }

    fn log(&self, id: Id, level: log::Level, msg: std::fmt::Arguments) {
        self.add_event(format!("{id}:{level}: {msg}"));
    }

    fn time(&self, set_by: Id, time_ns: f64) {
        self.add_event(format!("{set_by}: set time {time_ns:.1}ns"));
    }

    fn shutdown(&self) {
        // Do nothing
    }
}

/// Initialise the logging system for tests
///
/// Install the logger that will capture all _log_ messages. This is done by
/// setting the default logging level to Trace and installing a logger that
/// records all _log_ messages to a global string.
///
/// *Note*: this is called `test_init` because macros are exported at the root
/// of the crate.
///
/// # Arguments
///
/// * `start_id` - The ID value to be set as the starting value
///
/// # Examples
///
/// ```
/// use gwr_track::test_helpers;
/// use serial_test::serial;
///
/// # /* Need to comment this out so that it is actually built/tested by the infrastructure
/// #[test]
/// # */
/// fn smoke() {
///     let (test_tracker, tracker) = gwr_track::test_init!(10);
///     let top = gwr_track::entity::toplevel(&tracker, "top");
///     test_helpers::check_and_clear(&test_tracker, &["10: top created"]);
/// }
/// ```
#[macro_export]
macro_rules! test_init {
    ($start_id:expr) => {{
        let test_tracker = std::rc::Rc::new($crate::test_helpers::TestTracker::new(
            $start_id,
            $crate::log::Level::Trace,
        ));
        let tracker: $crate::Tracker = test_tracker.clone();
        (test_tracker, tracker)
    }};
}

/// Check and clear the _trace_ and _log_ output
///
/// This function asserts that the logging output lines seen since the start or
/// the last time this function was called are expected. The
/// [test_init](../../gwr_track/macro.test_init.html) must have been called
/// before this function can be used.
///
/// It then also clears both the _trace_ and _log_ output recorded so far.
///
/// # Arguments
///
/// * `tracker`  - A reference to the [`TestTracker`] being used in the test.
///   This will have been keeping track of the trace and log events seen since
///   it was created or last cleared.
/// * `expected` - An array of expected regular expressions that the logging
///   output will be matched against.
///
/// # Examples
///
/// ```
/// use gwr_track::test_helpers;
/// use serial_test::serial;
///
/// # /* Need to comment this out so that it is actually built/tested by the infrastructure
/// #[test]
/// # */
/// fn smoke() {
///     let (test_tracker, tracker) = gwr_track::test_init!(20);
///     let top = gwr_track::entity::toplevel(&tracker, "top");
///     let id = gwr_track::create_id!(top);
///     test_helpers::check_and_clear(&test_tracker, &["20: top created"]);
/// }
/// ```
pub fn check_and_clear(tracker: &TestTracker, expected: &[&str]) {
    let mut log_contents_ref = tracker.events.borrow_mut();

    println!("Checking {:?} matches {:?}", expected, *log_contents_ref);

    // Check that there are the same number of strings produced as expected
    let num_strings = expected.len();
    assert_eq!(num_strings, log_contents_ref.len());

    for i in 0..num_strings {
        let log_expect = expected[i];
        let re = Regex::new(log_expect).unwrap();
        let actual = &(*log_contents_ref[i]);
        println!("Checking {i}: {log_expect:?} matches {actual:?}");
        assert!(re.is_match(actual));
    }

    log_contents_ref.clear();
}

/// Create a tracker for tests
#[must_use]
pub fn create_tracker(full_filepath: &str) -> Tracker {
    // Place all trace files in one folder
    const FOLDER: &str = "traces";

    // Create that folder if it doesn't exist yet
    fs::create_dir_all(FOLDER).unwrap();

    let filename_only = Path::new(full_filepath)
        .file_stem()
        .and_then(|s| s.to_str())
        .unwrap();

    let bin_writer: Writer = Box::new(BufWriter::new(
        fs::File::create(format!("{FOLDER}/{filename_only}.bin")).unwrap(),
    ));

    let default_log_level = log::Level::Trace;
    let entity_manger = EntityManager::new(default_log_level);
    let tracker: Tracker = Rc::new(CapnProtoTracker::new(entity_manger, bin_writer));
    tracker
}