Make logging test output more legible

Presently when this test fails you just get "5 items instead of 6" but
not which item was lost.

test/integration-test/src/tests/log.rs

@@ -1,69 +1,29 @@
-use std::sync::{Arc, LockResult, Mutex, MutexGuard};
+use std::sync::{Arc, Mutex};
 
 use aya::{programs::UProbe, Bpf};
 use aya_log::BpfLogger;
 use log::{Level, Log, Record};
-use tokio::time::{sleep, Duration};
-
-const MAX_ATTEMPTS: usize = 10;
-const TIMEOUT_MS: u64 = 10;
 
 #[no_mangle]
 #[inline(never)]
 pub extern "C" fn trigger_ebpf_program() {}
 
-struct CapturedLogs(Arc<Mutex<Vec<CapturedLog>>>);
-
-impl CapturedLogs {
-    fn with_capacity(capacity: usize) -> Self {
-        Self(Arc::new(Mutex::new(Vec::with_capacity(capacity))))
-    }
-
-    fn clone(&self) -> Self {
-        Self(self.0.clone())
-    }
-
-    fn lock(&self) -> LockResult<MutexGuard<'_, Vec<CapturedLog>>> {
-        self.0.lock()
-    }
-
-    async fn wait_expected_len(&self, expected_len: usize) {
-        for _ in 0..MAX_ATTEMPTS {
-            {
-                let captured_logs = self.0.lock().expect("Failed to lock captured logs");
-                if captured_logs.len() == expected_len {
-                    return;
-                }
-            }
-            sleep(Duration::from_millis(TIMEOUT_MS)).await;
-        }
-        panic!(
-            "Expected {} captured logs, but got {}",
-            expected_len,
-            self.0.lock().unwrap().len()
-        );
-    }
-}
-
+#[derive(Debug, PartialEq)]
 struct CapturedLog {
     pub body: String,
     pub level: Level,
     pub target: String,
 }
 
+#[derive(Default)]
 struct TestingLogger {
-    captured_logs: CapturedLogs,
+    captured_logs: Arc<Mutex<Vec<CapturedLog>>>,
 }
 
 impl TestingLogger {
-    pub fn with_capacity(capacity: usize) -> (Self, CapturedLogs) {
-        let captured_logs = CapturedLogs::with_capacity(capacity);
-        (
-            Self {
-                captured_logs: captured_logs.clone(),
-            },
-            captured_logs,
-        )
+    fn logs(&self) -> Arc<Mutex<Vec<CapturedLog>>> {
+        let Self { captured_logs } = self;
+        captured_logs.clone()
     }
 }
 
@@ -75,23 +35,21 @@ impl Log for TestingLogger {
     fn flush(&self) {}
 
     fn log(&self, record: &Record) {
-        let captured_record = CapturedLog {
+        let Self { captured_logs } = self;
+        captured_logs.lock().unwrap().push(CapturedLog {
             body: format!("{}", record.args()),
             level: record.level(),
             target: record.target().to_string(),
-        };
-        self.captured_logs
-            .lock()
-            .expect("Failed to acquire a lock for storing a log")
-            .push(captured_record);
+        });
     }
 }
 
 #[tokio::test]
 async fn log() {
     let mut bpf = Bpf::load(crate::LOG).unwrap();
 
-    let (logger, captured_logs) = TestingLogger::with_capacity(5);
+    let logger = TestingLogger::default();
+    let captured_logs = logger.logs();
     BpfLogger::init_with_logger(&mut bpf, logger).unwrap();
 
     let prog: &mut UProbe = bpf.program_mut("test_log").unwrap().try_into().unwrap();
@@ -101,37 +59,72 @@ async fn log() {
 
     // Call the function that the uprobe is attached to, so it starts logging.
     trigger_ebpf_program();
-    captured_logs.wait_expected_len(6).await;
 
-    let records = captured_logs
-        .lock()
-        .expect("Failed to acquire a lock for reading logs");
-    assert_eq!(records.len(), 6);
-
-    assert_eq!(records[0].body, "Hello from eBPF!");
-    assert_eq!(records[0].level, Level::Debug);
-    assert_eq!(records[0].target, "log");
+    let mut logs = 0;
+    let records = loop {
+        tokio::time::sleep(std::time::Duration::from_millis(10)).await;
+        let records = captured_logs.lock().unwrap();
+        if records.len() == logs {
+            break records;
+        }
+        logs = records.len();
+    };
 
-    assert_eq!(records[1].body, "69, 420, wao");
-    assert_eq!(records[1].level, Level::Error);
-    assert_eq!(records[1].target, "log");
+    let mut records = records.iter();
 
-    assert_eq!(records[2].body, "ipv4: 10.0.0.1, ipv6: 2001:db8::1");
-    assert_eq!(records[2].level, Level::Info);
-    assert_eq!(records[2].target, "log");
+    assert_eq!(
+        records.next(),
+        Some(&CapturedLog {
+            body: "Hello from eBPF!".to_owned(),
+            level: Level::Debug,
+            target: "log".to_owned(),
+        })
+    );
 
     assert_eq!(
-        records[3].body,
-        "mac lc: 04:20:06:09:00:40, mac uc: 04:20:06:09:00:40"
+        records.next(),
+        Some(&CapturedLog {
+            body: "69, 420, wao".to_owned(),
+            level: Level::Error,
+            target: "log".to_owned(),
+        })
     );
-    assert_eq!(records[3].level, Level::Trace);
-    assert_eq!(records[3].target, "log");
 
-    assert_eq!(records[4].body, "hex lc: 2f, hex uc: 2F");
-    assert_eq!(records[4].level, Level::Warn);
-    assert_eq!(records[4].target, "log");
+    assert_eq!(
+        records.next(),
+        Some(&CapturedLog {
+            body: "ipv4: 10.0.0.1, ipv6: 2001:db8::1".to_owned(),
+            level: Level::Info,
+            target: "log".to_owned(),
+        },)
+    );
 
-    assert_eq!(records[5].body, "hex lc: deadbeef, hex uc: DEADBEEF");
-    assert_eq!(records[5].level, Level::Debug);
-    assert_eq!(records[5].target, "log");
+       assert_eq!(
+           records.next(),
+           Some(&CapturedLog {
+               body: "mac lc: 04:20:06:09:00:40, mac uc: 04:20:06:09:00:40".to_owned(),
+               level: Level::Trace,
+               target: "log".to_owned(),
+           },)
+       );
+
+       assert_eq!(
+           records.next(),
+           Some(&CapturedLog {
+               body: "hex lc: 2f, hex uc: 2F".to_owned(),
+               level: Level::Warn,
+               target: "log".to_owned(),
+           },)
+       );
+
+       assert_eq!(
+           records.next(),
+           Some(&CapturedLog {
+               body: "hex lc: deadbeef, hex uc: DEADBEEF".to_owned(),
+               level: Level::Debug,
+               target: "log".to_owned(),
+           },)
+       );
+
+    assert_eq!(records.next(), None);
 }