266 lines
12 KiB
Rust
266 lines
12 KiB
Rust
// file: crates/ksp-logging-lib/unit_tests/runtime.rs
|
|
// version: 8
|
|
|
|
#[test]
|
|
fn level_mapping_covers_all_ksp_levels() {
|
|
assert_eq!(super::map_filter_level(crate::LogFilterLevel::Off), tracing_subscriber::filter::LevelFilter::OFF);
|
|
assert_eq!(super::map_filter_level(crate::LogFilterLevel::Error), tracing_subscriber::filter::LevelFilter::ERROR);
|
|
assert_eq!(super::map_filter_level(crate::LogFilterLevel::Warn), tracing_subscriber::filter::LevelFilter::WARN);
|
|
assert_eq!(super::map_filter_level(crate::LogFilterLevel::Info), tracing_subscriber::filter::LevelFilter::INFO);
|
|
assert_eq!(super::map_filter_level(crate::LogFilterLevel::Debug), tracing_subscriber::filter::LevelFilter::DEBUG);
|
|
assert_eq!(super::map_filter_level(crate::LogFilterLevel::Trace), tracing_subscriber::filter::LevelFilter::TRACE);
|
|
}
|
|
|
|
#[test]
|
|
fn takeover_filter_silences_external_targets_and_applies_ksp_overrides() {
|
|
let settings = crate::LoggingSettings::new(
|
|
crate::LogFilterLevel::Info,
|
|
crate::SpanEvents::Off,
|
|
std::option::Option::Some(crate::ConsoleSettings::stdout()),
|
|
std::vec::Vec::new(),
|
|
)
|
|
.with_target_filter(crate::TargetFilter::new("ksp-logging-lib", crate::LogFilterLevel::Trace));
|
|
let filter = super::build_target_filter(&settings);
|
|
assert!(filter.would_enable("ksp-store-lib", &tracing::Level::INFO));
|
|
assert!(!filter.would_enable("ksp-store-lib", &tracing::Level::DEBUG));
|
|
assert!(filter.would_enable("ksp-logging-lib", &tracing::Level::TRACE));
|
|
assert!(!filter.would_enable("sqlx", &tracing::Level::ERROR));
|
|
assert!(!filter.would_enable("hyper", &tracing::Level::ERROR));
|
|
}
|
|
|
|
#[test]
|
|
fn span_event_mapping_supports_disabled_timing_and_full_lifecycle() {
|
|
assert_eq!(super::map_span_events(crate::SpanEvents::Off), tracing_subscriber::fmt::format::FmtSpan::NONE);
|
|
assert_eq!(
|
|
super::map_span_events(crate::SpanEvents::NewAndClose),
|
|
tracing_subscriber::fmt::format::FmtSpan::NEW | tracing_subscriber::fmt::format::FmtSpan::CLOSE,
|
|
);
|
|
assert_eq!(super::map_span_events(crate::SpanEvents::Full), tracing_subscriber::fmt::format::FmtSpan::FULL);
|
|
}
|
|
|
|
#[test]
|
|
fn file_rotation_mapping_covers_supported_cadences() {
|
|
assert_eq!(super::map_file_rotation(crate::FileRotation::Never), tracing_appender::rolling::Rotation::NEVER);
|
|
assert_eq!(super::map_file_rotation(crate::FileRotation::Hourly), tracing_appender::rolling::Rotation::HOURLY);
|
|
assert_eq!(super::map_file_rotation(crate::FileRotation::Daily), tracing_appender::rolling::Rotation::DAILY);
|
|
}
|
|
|
|
#[test]
|
|
fn disabled_runtime_has_no_layers_or_outputs() {
|
|
let settings = crate::LoggingSettings::new(crate::LogFilterLevel::Info, crate::SpanEvents::Off, std::option::Option::None, std::vec::Vec::new());
|
|
let result = super::prepare_runtime(&settings);
|
|
assert!(result.is_ok());
|
|
let prepared = match result {
|
|
std::result::Result::Ok(prepared) => prepared,
|
|
std::result::Result::Err(_) => return,
|
|
};
|
|
assert!(prepared.layers.is_empty());
|
|
assert!(prepared.outputs.console.is_none());
|
|
assert!(prepared.outputs.files.is_empty());
|
|
}
|
|
|
|
#[test]
|
|
fn console_runtime_composes_takeover_filter_before_formatter_and_owns_guard() {
|
|
let settings = crate::LoggingSettings::new(
|
|
crate::LogFilterLevel::Info,
|
|
crate::SpanEvents::Off,
|
|
std::option::Option::Some(crate::ConsoleSettings::stdout()),
|
|
std::vec::Vec::new(),
|
|
);
|
|
let result = super::prepare_runtime(&settings);
|
|
assert!(result.is_ok());
|
|
let prepared = match result {
|
|
std::result::Result::Ok(prepared) => prepared,
|
|
std::result::Result::Err(_) => return,
|
|
};
|
|
assert_eq!(prepared.layers.len(), 1);
|
|
assert!(prepared.outputs.console.is_some());
|
|
assert!(prepared.outputs.files.is_empty());
|
|
assert_eq!(prepared.outputs.dropped_lines(), crate::DroppedLines::zero());
|
|
}
|
|
|
|
#[test]
|
|
fn dropped_line_snapshots_add_saturating_by_sink() {
|
|
let first = crate::DroppedLines { console: usize::MAX, file: 4 };
|
|
let second = crate::DroppedLines { console: 1, file: 7 };
|
|
let combined = first.saturating_add(second);
|
|
assert_eq!(combined.console(), usize::MAX);
|
|
assert_eq!(combined.file(), 11);
|
|
assert_eq!(combined.total(), usize::MAX);
|
|
}
|
|
|
|
#[test]
|
|
fn takeover_filter_prefers_more_specific_ksp_prefixes_and_supports_off() {
|
|
let settings = crate::LoggingSettings::new(crate::LogFilterLevel::Info, crate::SpanEvents::Off, std::option::Option::None, std::vec::Vec::new())
|
|
.with_target_filter(crate::TargetFilter::new("ksp-store-", crate::LogFilterLevel::Debug))
|
|
.with_target_filter(crate::TargetFilter::new("ksp-store-lib", crate::LogFilterLevel::Trace))
|
|
.with_target_filter(crate::TargetFilter::new("ksp-wallet-lib", crate::LogFilterLevel::Off));
|
|
let filter = super::build_target_filter(&settings);
|
|
assert!(filter.would_enable("ksp-store-other", &tracing::Level::DEBUG));
|
|
assert!(!filter.would_enable("ksp-store-other", &tracing::Level::TRACE));
|
|
assert!(filter.would_enable("ksp-store-lib", &tracing::Level::TRACE));
|
|
assert!(!filter.would_enable("ksp-wallet-lib", &tracing::Level::ERROR));
|
|
}
|
|
|
|
#[test]
|
|
fn multi_sink_runtime_accepts_metadata_routing_formats_and_console_ansi() {
|
|
let root = std::env::temp_dir().join(format!("ksp-pre005-unit-{}", std::process::id()));
|
|
let _cleanup_before = std::fs::remove_dir_all(root.as_path());
|
|
let console = crate::ConsoleSettings::new(
|
|
true,
|
|
crate::ConsoleOutput::Stdout,
|
|
true,
|
|
crate::LogFormat::Compact,
|
|
crate::OutputFilter::new(crate::LogFilterLevel::Debug, std::vec!["ksp-logging-lib".to_string()], std::vec!["*".to_string()]),
|
|
);
|
|
let first_file = crate::FileSettings::new(
|
|
"file.first",
|
|
true,
|
|
root.join("first"),
|
|
"first.log",
|
|
crate::FileRotation::Never,
|
|
crate::LogFormat::Pretty,
|
|
crate::OutputFilter::new(crate::LogFilterLevel::Info, std::vec!["ksp-logging-lib".to_string()], std::vec!["*".to_string()]),
|
|
);
|
|
let second_file = crate::FileSettings::new(
|
|
"file.second",
|
|
true,
|
|
root.join("second"),
|
|
"second.jsonl",
|
|
crate::FileRotation::Never,
|
|
crate::LogFormat::Json,
|
|
crate::OutputFilter::new(crate::LogFilterLevel::Error, std::vec!["*".to_string()], std::vec!["*".to_string()]),
|
|
);
|
|
let settings = crate::LoggingSettings::new(
|
|
crate::LogFilterLevel::Trace,
|
|
crate::SpanEvents::Off,
|
|
std::option::Option::Some(console),
|
|
std::vec![first_file, second_file],
|
|
);
|
|
let result = super::prepare_runtime(&settings);
|
|
assert!(result.is_ok());
|
|
let prepared = match result {
|
|
std::result::Result::Ok(prepared) => prepared,
|
|
std::result::Result::Err(_) => return,
|
|
};
|
|
assert_eq!(prepared.layers.len(), 1);
|
|
assert!(prepared.outputs.console.is_some());
|
|
assert_eq!(prepared.outputs.files.len(), 2);
|
|
assert_eq!(prepared.outputs.file_dropped_lines("file.first"), std::option::Option::Some(0));
|
|
assert_eq!(prepared.outputs.file_dropped_lines("file.second"), std::option::Option::Some(0));
|
|
drop(prepared);
|
|
let cleanup_after = std::fs::remove_dir_all(root.as_path());
|
|
assert!(cleanup_after.is_ok());
|
|
}
|
|
|
|
#[test]
|
|
fn domain_routing_is_explicitly_deferred_instead_of_ignored() {
|
|
let console = crate::ConsoleSettings::new(
|
|
true,
|
|
crate::ConsoleOutput::Stdout,
|
|
false,
|
|
crate::LogFormat::Human,
|
|
crate::OutputFilter::new(crate::LogFilterLevel::Debug, std::vec!["*".to_string()], std::vec!["logging".to_string()]),
|
|
);
|
|
let settings = crate::LoggingSettings::new(crate::LogFilterLevel::Info, crate::SpanEvents::Off, std::option::Option::Some(console), std::vec::Vec::new());
|
|
assert!(settings.validate().is_ok());
|
|
let result = super::prepare_runtime(&settings);
|
|
assert!(result.is_err());
|
|
let error = match result {
|
|
std::result::Result::Ok(_) => return,
|
|
std::result::Result::Err(error) => error,
|
|
};
|
|
assert_eq!(error.code(), crate::ERROR_CODE_INVALID_SETTINGS);
|
|
}
|
|
|
|
struct BlockingWriter {
|
|
first_write: bool,
|
|
started: std::sync::mpsc::SyncSender<()>,
|
|
release: std::sync::Arc<(std::sync::Mutex<bool>, std::sync::Condvar)>,
|
|
}
|
|
|
|
impl BlockingWriter {
|
|
fn new(started: std::sync::mpsc::SyncSender<()>, release: std::sync::Arc<(std::sync::Mutex<bool>, std::sync::Condvar)>) -> Self {
|
|
return Self { first_write: true, started, release };
|
|
}
|
|
}
|
|
|
|
impl std::io::Write for BlockingWriter {
|
|
fn write(&mut self, buffer: &[u8]) -> std::io::Result<usize> {
|
|
if self.first_write {
|
|
self.first_write = false;
|
|
if self.started.send(()).is_err() {
|
|
return std::result::Result::Err(std::io::Error::other("unable to notify saturation test that the writer is blocked"));
|
|
}
|
|
let (lock, condition) = self.release.as_ref();
|
|
let lock_result = lock.lock();
|
|
let mut released = match lock_result {
|
|
std::result::Result::Ok(released) => released,
|
|
std::result::Result::Err(_) => {
|
|
return std::result::Result::Err(std::io::Error::other("saturation test release lock is poisoned"));
|
|
},
|
|
};
|
|
while !*released {
|
|
let wait_result = condition.wait(released);
|
|
released = match wait_result {
|
|
std::result::Result::Ok(released) => released,
|
|
std::result::Result::Err(_) => {
|
|
return std::result::Result::Err(std::io::Error::other("saturation test release wait is poisoned"));
|
|
},
|
|
};
|
|
}
|
|
}
|
|
return std::result::Result::Ok(buffer.len());
|
|
}
|
|
|
|
fn flush(&mut self) -> std::io::Result<()> {
|
|
return std::result::Result::Ok(());
|
|
}
|
|
}
|
|
|
|
fn release_blocked_writer(release: &std::sync::Arc<(std::sync::Mutex<bool>, std::sync::Condvar)>) {
|
|
let (lock, condition) = release.as_ref();
|
|
let lock_result = lock.lock();
|
|
let mut released = match lock_result {
|
|
std::result::Result::Ok(released) => released,
|
|
std::result::Result::Err(error) => error.into_inner(),
|
|
};
|
|
*released = true;
|
|
condition.notify_all();
|
|
}
|
|
|
|
#[test]
|
|
fn lossy_non_blocking_builder_drops_lines_instead_of_blocking_a_stalled_producer() {
|
|
let (started_sender, started_receiver) = std::sync::mpsc::sync_channel(1);
|
|
let release = std::sync::Arc::new((std::sync::Mutex::new(false), std::sync::Condvar::new()));
|
|
let writer = BlockingWriter::new(started_sender, std::sync::Arc::clone(&release));
|
|
let (mut non_blocking, worker_guard) = super::non_blocking_builder("ksp-logging-saturation-test").buffered_lines_limit(1).finish(writer);
|
|
let error_counter = non_blocking.error_counter();
|
|
let first_write = std::io::Write::write_all(&mut non_blocking, b"block worker\n");
|
|
assert!(first_write.is_ok());
|
|
let writer_started = started_receiver.recv_timeout(std::time::Duration::from_secs(2));
|
|
assert!(writer_started.is_ok());
|
|
let mut producer = non_blocking.clone();
|
|
let (finished_sender, finished_receiver) = std::sync::mpsc::sync_channel(1);
|
|
let producer_thread = std::thread::spawn(move || {
|
|
let mut succeeded = true;
|
|
for _ in 0..1_024 {
|
|
let write_result = std::io::Write::write_all(&mut producer, b"queued line\n");
|
|
if write_result.is_err() {
|
|
succeeded = false;
|
|
break;
|
|
}
|
|
}
|
|
let _send_result = finished_sender.send(succeeded);
|
|
return;
|
|
});
|
|
let producer_finished = finished_receiver.recv_timeout(std::time::Duration::from_secs(2));
|
|
release_blocked_writer(&release);
|
|
let join_result = producer_thread.join();
|
|
assert!(join_result.is_ok());
|
|
assert_eq!(producer_finished, std::result::Result::Ok(true));
|
|
assert!(error_counter.dropped_lines() > 0);
|
|
drop(non_blocking);
|
|
drop(worker_guard);
|
|
}
|