|
| 1 | +use std::fmt; |
| 2 | +use std::io; |
| 3 | +use std::sync::{Arc, RwLock}; |
| 4 | + |
| 5 | +use slog::{Drain, OwnedKVList, Record, KV}; |
| 6 | + |
| 7 | +/// A testing infrastructure for logging that consists of two main components: |
| 8 | +/// - [MemoryDrainForTest]: A slog Drain that stores records in memory |
| 9 | +/// - [MemoryDrainForTestInspector]: A component that provides methods to analyze stored logs |
| 10 | +/// |
| 11 | +/// Records are stored as formatted strings in a thread-safe vector using `Arc<RwLock>`. |
| 12 | +/// Each log record follows the format: |
| 13 | +/// |
| 14 | +/// `{LEVEL} {MESSAGE}; {KEY1}={VALUE1}, {KEY2}={VALUE2}, ...` |
| 15 | +/// |
| 16 | +/// where: |
| 17 | +/// - LEVEL: The log level (DEBUG, INFO, etc.) |
| 18 | +/// - MESSAGE: The main log message |
| 19 | +/// - KEY=VALUE pairs: Additional context values attached to the log |
| 20 | +/// |
| 21 | +/// # Performance Considerations |
| 22 | +/// |
| 23 | +/// This drain implementation is designed for testing purposes and is not optimized for performance. |
| 24 | +/// It uses an RwLock for each log operation and string formatting, which may introduce significant overhead. |
| 25 | +#[derive(Default, Clone)] |
| 26 | +pub struct MemoryDrainForTest { |
| 27 | + records: Arc<RwLock<Vec<String>>>, |
| 28 | +} |
| 29 | + |
| 30 | +impl MemoryDrainForTest { |
| 31 | + /// Creates a new instance of `MemoryDrainForTest` |
| 32 | + pub fn new() -> (Self, MemoryDrainForTestInspector) { |
| 33 | + let drain = Self::default(); |
| 34 | + let inspector = MemoryDrainForTestInspector::new(&drain); |
| 35 | + (drain, inspector) |
| 36 | + } |
| 37 | +} |
| 38 | + |
| 39 | +/// A component that provides methods to analyze logs stored by [MemoryDrainForTest]. |
| 40 | +pub struct MemoryDrainForTestInspector { |
| 41 | + records: Arc<RwLock<Vec<String>>>, |
| 42 | +} |
| 43 | + |
| 44 | +impl MemoryDrainForTestInspector { |
| 45 | + fn new(memory_drain: &MemoryDrainForTest) -> Self { |
| 46 | + Self { |
| 47 | + records: memory_drain.records.clone(), |
| 48 | + } |
| 49 | + } |
| 50 | + |
| 51 | + /// Returns all log records that contain the specified text |
| 52 | + /// |
| 53 | + /// This method performs a case-sensitive search through all stored log records |
| 54 | + /// and returns copies of the matching records. |
| 55 | + pub fn search_logs(&self, text: &str) -> Vec<String> { |
| 56 | + self.records |
| 57 | + .read() |
| 58 | + .unwrap() |
| 59 | + .iter() |
| 60 | + .filter(|record| record.contains(text)) |
| 61 | + .cloned() |
| 62 | + .collect() |
| 63 | + } |
| 64 | + |
| 65 | + /// Checks if any log record contains the specified text |
| 66 | + /// |
| 67 | + /// This method performs a case-sensitive search and returns true if any log |
| 68 | + /// record contains the specified text. |
| 69 | + pub fn contains_log(&self, text: &str) -> bool { |
| 70 | + self.records |
| 71 | + .read() |
| 72 | + .unwrap() |
| 73 | + .iter() |
| 74 | + .any(|record| record.contains(text)) |
| 75 | + } |
| 76 | +} |
| 77 | + |
| 78 | +impl fmt::Display for MemoryDrainForTestInspector { |
| 79 | + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { |
| 80 | + write!(f, "{}", self.records.read().unwrap().join("\n")) |
| 81 | + } |
| 82 | +} |
| 83 | + |
| 84 | +impl Drain for MemoryDrainForTest { |
| 85 | + type Ok = (); |
| 86 | + type Err = io::Error; |
| 87 | + |
| 88 | + fn log(&self, record: &Record, values: &OwnedKVList) -> Result<Self::Ok, Self::Err> { |
| 89 | + let mut kv_serializer = KVSerializer::default(); |
| 90 | + record.kv().serialize(record, &mut kv_serializer)?; |
| 91 | + values.serialize(record, &mut kv_serializer)?; |
| 92 | + |
| 93 | + let msg = format!( |
| 94 | + "{} {}; {}", |
| 95 | + record.level().as_str(), |
| 96 | + record.msg(), |
| 97 | + kv_serializer.content |
| 98 | + ); |
| 99 | + |
| 100 | + self.records.write().unwrap().push(msg); |
| 101 | + Ok(()) |
| 102 | + } |
| 103 | +} |
| 104 | + |
| 105 | +#[derive(Default)] |
| 106 | +struct KVSerializer { |
| 107 | + content: String, |
| 108 | +} |
| 109 | + |
| 110 | +impl slog::Serializer for KVSerializer { |
| 111 | + fn emit_arguments(&mut self, key: slog::Key, val: &std::fmt::Arguments) -> slog::Result { |
| 112 | + use std::fmt::Write; |
| 113 | + |
| 114 | + let prefix = if self.content.is_empty() { "" } else { ", " }; |
| 115 | + write!(self.content, "{prefix}{key}={val:?}") |
| 116 | + .map_err(|_| io::Error::new(io::ErrorKind::Other, "Failed to serialize log"))?; |
| 117 | + Ok(()) |
| 118 | + } |
| 119 | +} |
| 120 | + |
| 121 | +#[cfg(test)] |
| 122 | +mod tests { |
| 123 | + use slog::debug; |
| 124 | + |
| 125 | + use super::*; |
| 126 | + |
| 127 | + #[test] |
| 128 | + fn test_log_format() { |
| 129 | + let (drain, log_inspector) = MemoryDrainForTest::new(); |
| 130 | + let logger = slog::Logger::root(drain.clone().fuse(), slog::o!("shared" => "shared")); |
| 131 | + |
| 132 | + // Note: keys seem to be logged in invert order |
| 133 | + debug!(logger, "test format"; "key_3" => "value three", "key_2" => "value two", "key_1" => "value one"); |
| 134 | + |
| 135 | + let results = log_inspector.search_logs("test format"); |
| 136 | + assert_eq!( |
| 137 | + "DEBUG test format; key_1=value one, key_2=value two, key_3=value three, shared=shared", |
| 138 | + results[0] |
| 139 | + ); |
| 140 | + } |
| 141 | + |
| 142 | + #[test] |
| 143 | + fn displaying_inspector_returns_all_log_messages() { |
| 144 | + let (drain, log_inspector) = MemoryDrainForTest::new(); |
| 145 | + let logger = slog::Logger::root(drain.fuse(), slog::o!()); |
| 146 | + |
| 147 | + debug!(logger, "message one"; "key" => "value1"); |
| 148 | + debug!(logger, "message two"; "key" => "value2"); |
| 149 | + |
| 150 | + let display = format!("{log_inspector}"); |
| 151 | + assert_eq!( |
| 152 | + display, |
| 153 | + "DEBUG message one; key=value1\nDEBUG message two; key=value2" |
| 154 | + ); |
| 155 | + } |
| 156 | + |
| 157 | + #[test] |
| 158 | + fn can_search_for_log_messages() { |
| 159 | + let (drain, log_inspector) = MemoryDrainForTest::new(); |
| 160 | + let logger = slog::Logger::root(drain.clone().fuse(), slog::o!()); |
| 161 | + |
| 162 | + debug!(logger, "test message"; "key" => "value"); |
| 163 | + debug!(logger, "another message"; "key2" => "value2"); |
| 164 | + |
| 165 | + let results = log_inspector.search_logs("test"); |
| 166 | + assert_eq!(results.len(), 1); |
| 167 | + assert!(results[0].contains("test message")); |
| 168 | + assert!(log_inspector.contains_log("test message")); |
| 169 | + } |
| 170 | + |
| 171 | + #[tokio::test] |
| 172 | + async fn test_concurrent_logging_from_two_tasks() { |
| 173 | + let (drain, log_inspector) = MemoryDrainForTest::new(); |
| 174 | + let drain_clone1 = drain.clone(); |
| 175 | + let drain_clone2 = drain.clone(); |
| 176 | + |
| 177 | + let handle1 = tokio::spawn(async move { |
| 178 | + let logger = slog::Logger::root(drain_clone1.fuse(), slog::o!()); |
| 179 | + debug!(logger, "async test 1"; "key" => "value"); |
| 180 | + }); |
| 181 | + let handle2 = tokio::spawn(async move { |
| 182 | + let logger = slog::Logger::root(drain_clone2.fuse(), slog::o!()); |
| 183 | + debug!(logger, "async test 2"; "key" => "value"); |
| 184 | + }); |
| 185 | + |
| 186 | + handle1.await.unwrap(); |
| 187 | + handle2.await.unwrap(); |
| 188 | + |
| 189 | + let results = log_inspector.search_logs("async test"); |
| 190 | + assert_eq!(results.len(), 2); |
| 191 | + assert!(results.iter().any(|r| r.contains("async test 1"))); |
| 192 | + assert!(results.iter().any(|r| r.contains("async test 2"))); |
| 193 | + } |
| 194 | + |
| 195 | + #[tokio::test(flavor = "multi_thread", worker_threads = 4)] |
| 196 | + async fn test_concurrent_logging_from_multiple_threads() { |
| 197 | + let (drain, log_inspector) = MemoryDrainForTest::new(); |
| 198 | + let mut join_set = tokio::task::JoinSet::new(); |
| 199 | + |
| 200 | + for i in 0..10 { |
| 201 | + let drain_clone = drain.clone(); |
| 202 | + join_set.spawn(async move { |
| 203 | + let logger = slog::Logger::root(drain_clone.fuse(), slog::o!()); |
| 204 | + debug!(logger, "multi thread test {i}"; "thread_id" => i); |
| 205 | + }); |
| 206 | + } |
| 207 | + |
| 208 | + join_set.join_all().await; |
| 209 | + |
| 210 | + let results = log_inspector.search_logs("multi thread test"); |
| 211 | + assert_eq!(results.len(), 10); |
| 212 | + for i in 0..10 { |
| 213 | + assert!(results |
| 214 | + .iter() |
| 215 | + .any(|r| r.contains(&format!("multi thread test {i}")))); |
| 216 | + } |
| 217 | + } |
| 218 | +} |
0 commit comments