0
2
Telemetry's tests keep what is logged through one global subscriber
Only what this pull adds. It is built on grain runs on a Rust server modelled on knotless, without hatk.
crates/grain/src/telemetry.rs+43−16
| @@ -150,33 +150,60 @@ fn error_type(err: &reqwest::Error) -> String { | ||
#[cfg(test)] | ||
pub(crate) mod tests { | ||
use super::*; | ||
use std::sync::{Arc, Mutex}; | ||
use std::cell::RefCell; | ||
use std::sync::{Arc, Mutex, Once}; | ||
use tracing_subscriber::layer::SubscriberExt; | ||
| ||
thread_local! { | ||
/// What is logged on this thread while `logged` runs. | ||
static KEPT: RefCell<Option<Vec<u8>>> = const { RefCell::new(None) }; | ||
} | ||
| ||
/// What is logged while `f` runs, at every level, as JSON lines. | ||
/// | ||
/// One subscriber, global and interested in everything, keeps the | ||
/// lines of whichever thread is in `logged`. A subscriber scoped to | ||
/// the test would not do: tracing caches each callsite's interest | ||
/// process-wide, and while a scoped one is the only one alive it asks | ||
/// only the default of the thread that reaches a callsite first. Other | ||
/// tests here make calls through `send` with no subscriber, so one | ||
/// of them reaching a callsite first marks it never, and the line | ||
/// this test waits for is never made. | ||
pub(crate) fn logged(f: impl FnOnce()) -> Vec<serde_json::Value> { | ||
let lines = Arc::new(Mutex::new(Vec::new())); | ||
let kept = lines.clone(); | ||
let writer = move || Kept(kept.clone()); | ||
let layer = tracing_subscriber::fmt::layer() | ||
.json() | ||
.flatten_event(true) | ||
.with_writer(writer); | ||
let subscriber = tracing_subscriber::registry() | ||
.with(tracing_subscriber::EnvFilter::new("trace")) | ||
.with(layer); | ||
tracing::subscriber::with_default(subscriber, f); | ||
let text = String::from_utf8(lines.lock().unwrap().clone()).unwrap(); | ||
static GLOBAL: Once = Once::new(); | ||
GLOBAL.call_once(|| { | ||
let layer = tracing_subscriber::fmt::layer() | ||
.json() | ||
.flatten_event(true) | ||
.with_writer(|| Kept); | ||
let subscriber = tracing_subscriber::registry() | ||
.with(tracing_subscriber::EnvFilter::new("trace")) | ||
.with(layer); | ||
tracing::subscriber::set_global_default(subscriber).unwrap(); | ||
}); | ||
// A callsite first reached while the subscriber was being set | ||
// may have cached the interest of none. | ||
tracing::callsite::rebuild_interest_cache(); | ||
KEPT.with(|k| *k.borrow_mut() = Some(Vec::new())); | ||
f(); | ||
let kept = KEPT.with(|k| k.borrow_mut().take()).unwrap_or_default(); | ||
let text = String::from_utf8(kept).unwrap(); | ||
text.lines() | ||
.map(|l| serde_json::from_str(l).unwrap()) | ||
.collect() | ||
} | ||
| ||
struct Kept(Arc<Mutex<Vec<u8>>>); | ||
/// Writes to the lines of the thread in `logged`, if it is; else | ||
/// nowhere. | ||
struct Kept; | ||
| ||
impl std::io::Write for Kept { | ||
fn write(&mut self, buf: &[u8]) -> std::io::Result<usize> { | ||
self.0.lock().unwrap().extend_from_slice(buf); | ||
KEPT.with(|k| { | ||
if let Some(kept) = k.borrow_mut().as_mut() { | ||
kept.extend_from_slice(buf); | ||
} | ||
}); | ||
Ok(buf.len()) | ||
} | ||
fn flush(&mut self) -> std::io::Result<()> { | ||
| @@ -188,7 +215,7 @@ pub(crate) mod tests { | ||
fn settings() { | ||
assert_eq!(millis(Duration::from_secs(2)), 2000); | ||
assert_eq!(short(&"a".repeat(500)).len(), 120); | ||
std::io::Write::flush(&mut Kept(Arc::default())).unwrap(); | ||
std::io::Write::flush(&mut Kept).unwrap(); | ||
} | ||
| ||
#[test] | ||