Git-Mirrors/veilid
1
0
Fork 0
mirror of https://gitlab.com/veilid/veilid.git synced 2024-10-01 01:26:08 -04:00
Code Issues Packages Projects Releases Wiki Activity

improve logging

Browse Source 
dart ffi has duration measurements for veilid_api calls
This commit is contained in:
Christien Rioux 2024-04-04 14:12:54 -04:00
parent 9eaa353d57
commit ad085ed15e
14 changed files with 574 additions and 553 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

39
veilid-core/src/lib.rs
View File

@ -59,7 +59,10 @@ mod veilid_config;
mod wasm_helpers;
pub use self::core_context::{api_startup, api_startup_config, api_startup_json, UpdateCallback};
pub use self::logging::{ApiTracingLayer, VeilidLayerFilter};
pub use self::logging::{
ApiTracingLayer, VeilidLayerFilter, DEFAULT_LOG_FACILITIES_ENABLED_LIST,
DEFAULT_LOG_FACILITIES_IGNORE_LIST, DURATION_LOG_FACILITIES,
};
pub use self::veilid_api::*;
pub use self::veilid_config::*;
pub use veilid_tools as tools;
@ -86,43 +89,9 @@ pub fn veilid_version() -> (u32, u32, u32) {
)
}
/// Return the default veilid config as a json object
pub fn default_veilid_config() -> String {
serialize_json(VeilidConfigInner::default())
}
#[cfg(target_os = "android")]
pub use intf::android::veilid_core_setup_android;
pub static DEFAULT_LOG_IGNORE_LIST: [&str; 26] = [
"mio",
"h2",
"hyper",
"tower",
"tonic",
"tokio",
"runtime",
"tokio_util",
"want",
"serial_test",
"async_std",
"async_io",
"polling",
"rustls",
"async_tungstenite",
"tungstenite",
"netlink_proto",
"netlink_sys",
"hickory_resolver",
"hickory_proto",
"attohttpc",
"ws_stream_wasm",
"keyvaluedb_web",
"veilid_api",
"network_result",
"dht",
];
use cfg_if::*;
use enumset::*;
use eyre::{bail, eyre, Report as EyreReport, Result as EyreResult, WrapErr};

165
veilid-core/src/logging/api_tracing_layer.rs
View File

@ -5,20 +5,20 @@ use core::fmt::Write;
use once_cell::sync::OnceCell;
use tracing_subscriber::*;
struct ApiLoggerInner {
struct ApiTracingLayerInner {
update_callback: UpdateCallback,
}
#[derive(Clone)]
pub struct ApiTracingLayer {
inner: Arc<Mutex<Option<ApiLoggerInner>>>,
inner: Arc<Mutex<Option<ApiTracingLayerInner>>>,
}
static API_LOGGER: OnceCell<ApiTracingLayer> = OnceCell::new();
impl ApiTracingLayer {
fn new_inner(update_callback: UpdateCallback) -> ApiLoggerInner {
ApiLoggerInner { update_callback }
fn new_inner(update_callback: UpdateCallback) -> ApiTracingLayerInner {
ApiTracingLayerInner { update_callback }
}
#[instrument(level = "debug", skip(update_callback))]
@ -45,60 +45,8 @@ impl ApiTracingLayer {
})
.clone()
}
}
fn simplify_file(file: &str) -> String {
let path = std::path::Path::new(file);
let path_component_count = path.iter().count();
if path.ends_with("mod.rs") && path_component_count >= 2 {
let outpath: std::path::PathBuf = path.iter().skip(path_component_count - 2).collect();
outpath.to_string_lossy().to_string()
} else if let Some(filename) = path.file_name() {
filename.to_string_lossy().to_string()
} else {
file.to_string()
}
}
impl<S: Subscriber + for<'a> registry::LookupSpan<'a>> Layer<S> for ApiTracingLayer {
fn on_new_span(
&self,
attrs: &tracing::span::Attributes<'_>,
id: &tracing::Id,
ctx: layer::Context<'_, S>,
) {
if let Some(_inner) = &mut *self.inner.lock() {
let mut new_debug_record = StringRecorder::new();
attrs.record(&mut new_debug_record);
if let Some(span_ref) = ctx.span(id) {
span_ref
.extensions_mut()
.insert::<StringRecorder>(new_debug_record);
}
}
}
fn on_record(
&self,
id: &tracing::Id,
values: &tracing::span::Record<'_>,
ctx: layer::Context<'_, S>,
) {
if let Some(_inner) = &mut *self.inner.lock() {
if let Some(span_ref) = ctx.span(id) {
if let Some(debug_record) = span_ref.extensions_mut().get_mut::<StringRecorder>() {
values.record(debug_record);
}
}
}
}
fn on_event(&self, event: &tracing::Event<'_>, _ctx: layer::Context<'_, S>) {
if let Some(inner) = &mut *self.inner.lock() {
let mut recorder = StringRecorder::new();
event.record(&mut recorder);
let meta = event.metadata();
fn emit_log(&self, inner: &mut ApiTracingLayerInner, meta: &Metadata<'_>, message: String) {
let level = *meta.level();
let target = meta.target();
let log_level = VeilidLogLevel::from_tracing_level(level);
@ -131,7 +79,7 @@ impl<S: Subscriber + for<'a> registry::LookupSpan<'a>> Layer<S> for ApiTracingLa
.unwrap_or_default(),
};
let message = format!("{}{}", origin, recorder).trim().to_owned();
let message = format!("{}{}", origin, message).trim().to_owned();
let backtrace = if log_level <= VeilidLogLevel::Error {
let bt = backtrace::Backtrace::new();
@ -146,6 +94,100 @@ impl<S: Subscriber + for<'a> registry::LookupSpan<'a>> Layer<S> for ApiTracingLa
backtrace,
})))
}
}
pub struct SpanDuration {
start: Timestamp,
end: Timestamp,
}
fn simplify_file(file: &str) -> String {
let path = std::path::Path::new(file);
let path_component_count = path.iter().count();
if path.ends_with("mod.rs") && path_component_count >= 2 {
let outpath: std::path::PathBuf = path.iter().skip(path_component_count - 2).collect();
outpath.to_string_lossy().to_string()
} else if let Some(filename) = path.file_name() {
filename.to_string_lossy().to_string()
} else {
file.to_string()
}
}
impl<S: Subscriber + for<'a> registry::LookupSpan<'a>> Layer<S> for ApiTracingLayer {
fn on_new_span(
&self,
attrs: &tracing::span::Attributes<'_>,
id: &tracing::Id,
ctx: layer::Context<'_, S>,
) {
if let Some(_inner) = &mut *self.inner.lock() {
let mut new_debug_record = StringRecorder::new();
attrs.record(&mut new_debug_record);
if let Some(span_ref) = ctx.span(id) {
span_ref
.extensions_mut()
.insert::<StringRecorder>(new_debug_record);
if crate::DURATION_LOG_FACILITIES.contains(&attrs.metadata().target()) {
span_ref
.extensions_mut()
.insert::<SpanDuration>(SpanDuration {
start: get_aligned_timestamp(),
end: Timestamp::default(),
});
}
}
}
}
fn on_close(&self, id: span::Id, ctx: layer::Context<'_, S>) {
if let Some(inner) = &mut *self.inner.lock() {
if let Some(span_ref) = ctx.span(&id) {
if let Some(span_duration) = span_ref.extensions_mut().get_mut::<SpanDuration>() {
span_duration.end = get_aligned_timestamp();
let duration = span_duration.end.saturating_sub(span_duration.start);
let meta = span_ref.metadata();
self.emit_log(
inner,
meta,
format!(
" {}{}: duration={}",
span_ref
.parent()
.map(|p| format!("{}::", p.name()))
.unwrap_or_default(),
span_ref.name(),
format_opt_ts(Some(duration))
),
);
}
}
}
}
fn on_record(
&self,
id: &tracing::Id,
values: &tracing::span::Record<'_>,
ctx: layer::Context<'_, S>,
) {
if let Some(_inner) = &mut *self.inner.lock() {
if let Some(span_ref) = ctx.span(id) {
if let Some(debug_record) = span_ref.extensions_mut().get_mut::<StringRecorder>() {
values.record(debug_record);
}
}
}
}
fn on_event(&self, event: &tracing::Event<'_>, _ctx: layer::Context<'_, S>) {
if let Some(inner) = &mut *self.inner.lock() {
let mut recorder = StringRecorder::new();
event.record(&mut recorder);
let meta = event.metadata();
self.emit_log(inner, meta, recorder.to_string());
}
}
}
@ -171,14 +213,7 @@ impl tracing::field::Visit for StringRecorder {
self.display = format!("{:?}", value)
}
} else {
//if self.is_following_args {
// following args
// writeln!(self.display).unwrap();
//} else {
// first arg
write!(self.display, " ").unwrap();
//self.is_following_args = true;
//}
write!(self.display, "{} = {:?};", field.name(), value).unwrap();
}
}

401
veilid-core/src/logging/facilities.rs Normal file
View File

@ -0,0 +1,401 @@
pub static DEFAULT_LOG_FACILITIES_IGNORE_LIST: [&str; 27] = [
"mio",
"h2",
"hyper",
"tower",
"tonic",
"tokio",
"runtime",
"tokio_util",
"want",
"serial_test",
"async_std",
"async_io",
"polling",
"rustls",
"async_tungstenite",
"tungstenite",
"netlink_proto",
"netlink_sys",
"hickory_resolver",
"hickory_proto",
"attohttpc",
"ws_stream_wasm",
"keyvaluedb_web",
"veilid_api",
"network_result",
"dht",
"fanout",
];
pub static DEFAULT_LOG_FACILITIES_ENABLED_LIST: [&str; 8] = [
"net",
"rpc",
"rtab",
"stor",
"client_api",
"pstore",
"tstore",
"crypto",
];
pub static DURATION_LOG_FACILITIES: [&str; 1] = ["veilid_api"];
#[macro_export]
macro_rules! fn_string {
($text:expr) => {
|| $text.to_string()
};
}
#[macro_export]
macro_rules! log_net {
(error $text:expr) => {error!(
target: "net",
"{}",
$text,
)};
(error $fmt:literal, $($arg:expr),+) => {
error!(target:"net", $fmt, $($arg),+);
};
(warn $text:expr) => {warn!(
target: "net",
"{}",
$text,
)};
(warn $fmt:literal, $($arg:expr),+) => {
warn!(target:"net", $fmt, $($arg),+);
};
(debug $text:expr) => {debug!(
target: "net",
"{}",
$text,
)};
(debug $fmt:literal, $($arg:expr),+) => {
debug!(target:"net", $fmt, $($arg),+);
};
($text:expr) => {trace!(
target: "net",
"{}",
$text,
)};
($fmt:literal, $($arg:expr),+) => {
trace!(target:"net", $fmt, $($arg),+);
}
}
#[macro_export]
macro_rules! log_client_api {
(error $text:expr) => {error!(
target: "client_api",
"{}",
$text,
)};
(error $fmt:literal, $($arg:expr),+) => {
error!(target:"client_api", $fmt, $($arg),+);
};
(warn $text:expr) => {warn!(
target: "client_api",
"{}",
$text,
)};
(warn $fmt:literal, $($arg:expr),+) => {
warn!(target:"client_api", $fmt, $($arg),+);
};
(debug $text:expr) => {debug!(
target: "client_api",
"{}",
$text,
)};
(debug $fmt:literal, $($arg:expr),+) => {
debug!(target:"client_api", $fmt, $($arg),+);
};
($text:expr) => {trace!(
target: "client_api",
"{}",
$text,
)};
($fmt:literal, $($arg:expr),+) => {
trace!(target:"client_api", $fmt, $($arg),+);
}
}
#[macro_export]
macro_rules! log_network_result {
(error $text:expr) => {error!(
target: "network_result",
"{}",
$text,
)};
(error $fmt:literal, $($arg:expr),+) => {
error!(target: "network_result", $fmt, $($arg),+);
};
(warn $text:expr) => {warn!(
target: "network_result",
"{}",
$text,
)};
(warn $fmt:literal, $($arg:expr),+) => {
warn!(target:"network_result", $fmt, $($arg),+);
};
(debug $text:expr) => {debug!(
target: "network_result",
"{}",
$text,
)};
(debug $fmt:literal, $($arg:expr),+) => {
debug!(target:"network_result", $fmt, $($arg),+);
};
($text:expr) => {trace!(
target: "network_result",
"{}",
$text,
)};
($fmt:literal, $($arg:expr),+) => {
trace!(target:"network_result", $fmt, $($arg),+);
}
}
#[macro_export]
macro_rules! log_rpc {
(error $text:expr) => { error!(
target: "rpc",
"{}",
$text,
)};
(error $fmt:literal, $($arg:expr),+) => {
error!(target:"rpc", $fmt, $($arg),+);
};
(warn $text:expr) => { warn!(
target: "rpc",
"{}",
$text,
)};
(warn $fmt:literal, $($arg:expr),+) => {
warn!(target:"rpc", $fmt, $($arg),+);
};
(debug $text:expr) => { debug!(
target: "rpc",
"{}",
$text,
)};
(debug $fmt:literal, $($arg:expr),+) => {
debug!(target:"rpc", $fmt, $($arg),+);
};
($text:expr) => {trace!(
target: "rpc",
"{}",
$text,
)};
($fmt:literal, $($arg:expr),+) => {
trace!(target:"rpc", $fmt, $($arg),+);
}
}
#[macro_export]
macro_rules! log_dht {
(error $text:expr) => { error!(
target: "dht",
"{}",
$text,
)};
(error $fmt:literal, $($arg:expr),+) => {
error!(target:"dht", $fmt, $($arg),+);
};
(warn $text:expr) => { warn!(
target: "dht",
"{}",
$text,
)};
(warn $fmt:literal, $($arg:expr),+) => {
warn!(target:"dht", $fmt, $($arg),+);
};
(debug $text:expr) => { debug!(
target: "dht",
"{}",
$text,
)};
(debug $fmt:literal, $($arg:expr),+) => {
debug!(target:"dht", $fmt, $($arg),+);
};
($text:expr) => {trace!(
target: "dht",
"{}",
$text,
)};
($fmt:literal, $($arg:expr),+) => {
trace!(target:"dht", $fmt, $($arg),+);
}
}
#[macro_export]
macro_rules! log_rtab {
(error $text:expr) => { error!(
target: "rtab",
"{}",
$text,
)};
(error $fmt:literal, $($arg:expr),+) => {
error!(target:"rtab", $fmt, $($arg),+);
};
(warn $text:expr) => { warn!(
target: "rtab",
"{}",
$text,
)};
(warn $fmt:literal, $($arg:expr),+) => {
warn!(target:"rtab", $fmt, $($arg),+);
};
(debug $text:expr) => { debug!(
target: "rtab",
"{}",
$text,
)};
(debug $fmt:literal, $($arg:expr),+) => {
debug!(target:"rtab", $fmt, $($arg),+);
};
($text:expr) => {trace!(
target: "rtab",
"{}",
$text,
)};
($fmt:literal, $($arg:expr),+) => {
trace!(target:"rtab", $fmt, $($arg),+);
}
}
#[macro_export]
macro_rules! log_stor {
(error $text:expr) => { error!(
target: "stor",
"{}",
$text,
)};
(error $fmt:literal, $($arg:expr),+) => {
error!(target:"stor", $fmt, $($arg),+);
};
(warn $text:expr) => { warn!(
target: "stor",
"{}",
$text,
)};
(warn $fmt:literal, $($arg:expr),+) => {
warn!(target:"stor", $fmt, $($arg),+);
};
(debug $text:expr) => { debug!(
target: "stor",
"{}",
$text,
)};
(debug $fmt:literal, $($arg:expr),+) => {
debug!(target:"stor", $fmt, $($arg),+);
};
($text:expr) => {trace!(
target: "stor",
"{}",
$text,
)};
($fmt:literal, $($arg:expr),+) => {
trace!(target:"stor", $fmt, $($arg),+);
}
}
#[macro_export]
macro_rules! log_pstore {
(error $text:expr) => { error!(
target: "pstore",
"{}",
$text,
)};
(error $fmt:literal, $($arg:expr),+) => {
error!(target:"pstore", $fmt, $($arg),+);
};
(warn $text:expr) => { warn!(
target: "pstore",
"{}",
$text,
)};
(warn $fmt:literal, $($arg:expr),+) => {
warn!(target:"pstore", $fmt, $($arg),+);
};
(debug $text:expr) => { debug!(
target: "pstore",
"{}",
$text,
)};
(debug $fmt:literal, $($arg:expr),+) => {
debug!(target:"pstore", $fmt, $($arg),+);
};
($text:expr) => {trace!(
target: "pstore",
"{}",
$text,
)};
($fmt:literal, $($arg:expr),+) => {
trace!(target:"pstore", $fmt, $($arg),+);
}
}
#[macro_export]
macro_rules! log_tstore {
(error $text:expr) => { error!(
target: "tstore",
"{}",
$text,
)};
(error $fmt:literal, $($arg:expr),+) => {
error!(target:"tstore", $fmt, $($arg),+);
};
(warn $text:expr) => { warn!(
target: "tstore",
"{}",
$text,
)};
(warn $fmt:literal, $($arg:expr),+) => {
warn!(target:"tstore", $fmt, $($arg),+);
};
(debug $text:expr) => { debug!(
target: "tstore",
"{}",
$text,
)};
(debug $fmt:literal, $($arg:expr),+) => {
debug!(target:"tstore", $fmt, $($arg),+);
};
($text:expr) => {trace!(
target: "tstore",
"{}",
$text,
)};
($fmt:literal, $($arg:expr),+) => {
trace!(target:"tstore", $fmt, $($arg),+);
}
}
#[macro_export]
macro_rules! log_crypto {
(error $text:expr) => { error!(
target: "crypto",
"{}",
$text,
)};
(error $fmt:literal, $($arg:expr),+) => {
error!(target:"crypto", $fmt, $($arg),+);
};
(warn $text:expr) => { warn!(
target: "crypto",
"{}",
$text,
)};
(warn $fmt:literal, $($arg:expr),+) => {
warn!(target:"crypto", $fmt, $($arg),+);
};
($text:expr) => {trace!(
target: "crypto",
"{}",
$text,
)};
($fmt:literal, $($arg:expr),+) => {
trace!(target:"crypto", $fmt, $($arg),+);
}
}

361
veilid-core/src/logging/mod.rs
View File

@ -1,366 +1,9 @@
mod api_tracing_layer;
mod facilities;
mod veilid_layer_filter;
use super::*;
pub use api_tracing_layer::*;
pub use facilities::*;
pub use veilid_layer_filter::*;
#[macro_export]
macro_rules! fn_string {
($text:expr) => {
|| $text.to_string()
};
}
#[macro_export]
macro_rules! log_net {
(error $text:expr) => {error!(
target: "net",
"{}",
$text,
)};
(error $fmt:literal, $($arg:expr),+) => {
error!(target:"net", $fmt, $($arg),+);
};
(warn $text:expr) => {warn!(
target: "net",
"{}",
$text,
)};
(warn $fmt:literal, $($arg:expr),+) => {
warn!(target:"net", $fmt, $($arg),+);
};
(debug $text:expr) => {debug!(
target: "net",
"{}",
$text,
)};
(debug $fmt:literal, $($arg:expr),+) => {
debug!(target:"net", $fmt, $($arg),+);
};
($text:expr) => {trace!(
target: "net",
"{}",
$text,
)};
($fmt:literal, $($arg:expr),+) => {
trace!(target:"net", $fmt, $($arg),+);
}
}
#[macro_export]
macro_rules! log_client_api {
(error $text:expr) => {error!(
target: "client_api",
"{}",
$text,
)};
(error $fmt:literal, $($arg:expr),+) => {
error!(target:"client_api", $fmt, $($arg),+);
};
(warn $text:expr) => {warn!(
target: "client_api",
"{}",
$text,
)};
(warn $fmt:literal, $($arg:expr),+) => {
warn!(target:"client_api", $fmt, $($arg),+);
};
(debug $text:expr) => {debug!(
target: "client_api",
"{}",
$text,
)};
(debug $fmt:literal, $($arg:expr),+) => {
debug!(target:"client_api", $fmt, $($arg),+);
};
($text:expr) => {trace!(
target: "client_api",
"{}",
$text,
)};
($fmt:literal, $($arg:expr),+) => {
trace!(target:"client_api", $fmt, $($arg),+);
}
}
#[macro_export]
macro_rules! log_network_result {
(error $text:expr) => {error!(
target: "network_result",
"{}",
$text,
)};
(error $fmt:literal, $($arg:expr),+) => {
error!(target: "network_result", $fmt, $($arg),+);
};
(warn $text:expr) => {warn!(
target: "network_result",
"{}",
$text,
)};
(warn $fmt:literal, $($arg:expr),+) => {
warn!(target:"network_result", $fmt, $($arg),+);
};
(debug $text:expr) => {debug!(
target: "network_result",
"{}",
$text,
)};
(debug $fmt:literal, $($arg:expr),+) => {
debug!(target:"network_result", $fmt, $($arg),+);
};
($text:expr) => {trace!(
target: "network_result",
"{}",
$text,
)};
($fmt:literal, $($arg:expr),+) => {
trace!(target:"network_result", $fmt, $($arg),+);
}
}
#[macro_export]
macro_rules! log_rpc {
(error $text:expr) => { error!(
target: "rpc",
"{}",
$text,
)};
(error $fmt:literal, $($arg:expr),+) => {
error!(target:"rpc", $fmt, $($arg),+);
};
(warn $text:expr) => { warn!(
target: "rpc",
"{}",
$text,
)};
(warn $fmt:literal, $($arg:expr),+) => {
warn!(target:"rpc", $fmt, $($arg),+);
};
(debug $text:expr) => { debug!(
target: "rpc",
"{}",
$text,
)};
(debug $fmt:literal, $($arg:expr),+) => {
debug!(target:"rpc", $fmt, $($arg),+);
};
($text:expr) => {trace!(
target: "rpc",
"{}",
$text,
)};
($fmt:literal, $($arg:expr),+) => {
trace!(target:"rpc", $fmt, $($arg),+);
}
}
#[macro_export]
macro_rules! log_dht {
(error $text:expr) => { error!(
target: "dht",
"{}",
$text,
)};
(error $fmt:literal, $($arg:expr),+) => {
error!(target:"dht", $fmt, $($arg),+);
};
(warn $text:expr) => { warn!(
target: "dht",
"{}",
$text,
)};
(warn $fmt:literal, $($arg:expr),+) => {
warn!(target:"dht", $fmt, $($arg),+);
};
(debug $text:expr) => { debug!(
target: "dht",
"{}",
$text,
)};
(debug $fmt:literal, $($arg:expr),+) => {
debug!(target:"dht", $fmt, $($arg),+);
};
($text:expr) => {trace!(
target: "dht",
"{}",
$text,
)};
($fmt:literal, $($arg:expr),+) => {
trace!(target:"dht", $fmt, $($arg),+);
}
}
#[macro_export]
macro_rules! log_rtab {
(error $text:expr) => { error!(
target: "rtab",
"{}",
$text,
)};
(error $fmt:literal, $($arg:expr),+) => {
error!(target:"rtab", $fmt, $($arg),+);
};
(warn $text:expr) => { warn!(
target: "rtab",
"{}",
$text,
)};
(warn $fmt:literal, $($arg:expr),+) => {
warn!(target:"rtab", $fmt, $($arg),+);
};
(debug $text:expr) => { debug!(
target: "rtab",
"{}",
$text,
)};
(debug $fmt:literal, $($arg:expr),+) => {
debug!(target:"rtab", $fmt, $($arg),+);
};
($text:expr) => {trace!(
target: "rtab",
"{}",
$text,
)};
($fmt:literal, $($arg:expr),+) => {
trace!(target:"rtab", $fmt, $($arg),+);
}
}
#[macro_export]
macro_rules! log_stor {
(error $text:expr) => { error!(
target: "stor",
"{}",
$text,
)};
(error $fmt:literal, $($arg:expr),+) => {
error!(target:"stor", $fmt, $($arg),+);
};
(warn $text:expr) => { warn!(
target: "stor",
"{}",
$text,
)};
(warn $fmt:literal, $($arg:expr),+) => {
warn!(target:"stor", $fmt, $($arg),+);
};
(debug $text:expr) => { debug!(
target: "stor",
"{}",
$text,
)};
(debug $fmt:literal, $($arg:expr),+) => {
debug!(target:"stor", $fmt, $($arg),+);
};
($text:expr) => {trace!(
target: "stor",
"{}",
$text,
)};
($fmt:literal, $($arg:expr),+) => {
trace!(target:"stor", $fmt, $($arg),+);
}
}
#[macro_export]
macro_rules! log_pstore {
(error $text:expr) => { error!(
target: "pstore",
"{}",
$text,
)};
(error $fmt:literal, $($arg:expr),+) => {
error!(target:"pstore", $fmt, $($arg),+);
};
(warn $text:expr) => { warn!(
target: "pstore",
"{}",
$text,
)};
(warn $fmt:literal, $($arg:expr),+) => {
warn!(target:"pstore", $fmt, $($arg),+);
};
(debug $text:expr) => { debug!(
target: "pstore",
"{}",
$text,
)};
(debug $fmt:literal, $($arg:expr),+) => {
debug!(target:"pstore", $fmt, $($arg),+);
};
($text:expr) => {trace!(
target: "pstore",
"{}",
$text,
)};
($fmt:literal, $($arg:expr),+) => {
trace!(target:"pstore", $fmt, $($arg),+);
}
}
#[macro_export]
macro_rules! log_tstore {
(error $text:expr) => { error!(
target: "tstore",
"{}",
$text,
)};
(error $fmt:literal, $($arg:expr),+) => {
error!(target:"tstore", $fmt, $($arg),+);
};
(warn $text:expr) => { warn!(
target: "tstore",
"{}",
$text,
)};
(warn $fmt:literal, $($arg:expr),+) => {
warn!(target:"tstore", $fmt, $($arg),+);
};
(debug $text:expr) => { debug!(
target: "tstore",
"{}",
$text,
)};
(debug $fmt:literal, $($arg:expr),+) => {
debug!(target:"tstore", $fmt, $($arg),+);
};
($text:expr) => {trace!(
target: "tstore",
"{}",
$text,
)};
($fmt:literal, $($arg:expr),+) => {
trace!(target:"tstore", $fmt, $($arg),+);
}
}
#[macro_export]
macro_rules! log_crypto {
(error $text:expr) => { error!(
target: "crypto",
"{}",
$text,
)};
(error $fmt:literal, $($arg:expr),+) => {
error!(target:"crypto", $fmt, $($arg),+);
};
(warn $text:expr) => { warn!(
target: "crypto",
"{}",
$text,
)};
(warn $fmt:literal, $($arg:expr),+) => {
warn!(target:"crypto", $fmt, $($arg),+);
};
($text:expr) => {trace!(
target: "crypto",
"{}",
$text,
)};
($fmt:literal, $($arg:expr),+) => {
trace!(target:"crypto", $fmt, $($arg),+);
}
}

64
veilid-core/src/logging/veilid_layer_filter.rs
View File

@ -18,19 +18,10 @@ impl VeilidLayerFilter {
max_level: VeilidConfigLogLevel,
ignore_log_targets: &[String],
) -> VeilidLayerFilter {
let mut ignore_list = DEFAULT_LOG_IGNORE_LIST.map(|x| x.to_owned()).to_vec();
for igedit in ignore_log_targets {
if let Some(rest) = igedit.strip_prefix('-') {
for i in 0..ignore_list.len() {
if ignore_list[i] == rest {
ignore_list.remove(i);
break;
}
}
} else {
ignore_list.push(igedit.clone());
}
}
let mut ignore_list = DEFAULT_LOG_FACILITIES_IGNORE_LIST
.map(|x| x.to_owned())
.to_vec();
Self::apply_ignore_change_list(&mut ignore_list, ignore_log_targets);
Self {
inner: Arc::new(RwLock::new(VeilidLayerFilterInner {
max_level: max_level.to_tracing_level_filter(),
@ -60,8 +51,11 @@ impl VeilidLayerFilter {
pub fn set_ignore_list(&self, ignore_list: Option<Vec<String>>) {
{
let mut inner = self.inner.write();
inner.ignore_list = ignore_list
.unwrap_or_else(|| DEFAULT_LOG_IGNORE_LIST.map(|x| x.to_owned()).to_vec());
inner.ignore_list = ignore_list.unwrap_or_else(|| {
DEFAULT_LOG_FACILITIES_IGNORE_LIST
.map(|x| x.to_owned())
.to_vec()
});
}
callsite::rebuild_interest_cache();
}
@ -82,6 +76,46 @@ impl VeilidLayerFilter {
true
}
pub fn apply_ignore_change(ignore_list: &[String], target_change: String) -> Vec<String> {
let mut ignore_list = ignore_list.to_vec();
let target_change = target_change
.split(',')
.map(|c| c.trim().to_owned())
.collect::<Vec<String>>();
Self::apply_ignore_change_list(&mut ignore_list, &target_change);
ignore_list
}
pub fn apply_ignore_change_list(ignore_list: &mut Vec<String>, target_change: &[String]) {
for change in target_change {
if change.is_empty() {
continue;
}
if change == "all" {
*ignore_list = [
DEFAULT_LOG_FACILITIES_ENABLED_LIST.to_vec(),
DEFAULT_LOG_FACILITIES_IGNORE_LIST.to_vec(),
]
.concat()
.into_iter()
.map(|x| x.to_owned())
.collect();
continue;
} else if change == "default" {
*ignore_list = [DEFAULT_LOG_FACILITIES_IGNORE_LIST.to_vec()]
.concat()
.into_iter()
.map(|x| x.to_owned())
.collect();
continue;
} else if let Some(target) = change.strip_prefix('-') {
ignore_list.retain(|x| x != target);
} else if !ignore_list.contains(change) {
ignore_list.push(change.to_string());
}
}
}
}
impl<S: tracing::Subscriber> layer::Filter<S> for VeilidLayerFilter {

5
veilid-core/src/rpc_processor/fanout_call.rs
View File

@ -145,7 +145,7 @@ where
}
fn add_to_fanout_queue(self: Arc<Self>, new_nodes: &[NodeRef]) {
info!(
event!(target: "fanout", Level::DEBUG,
"FanoutCall::add_to_fanout_queue:\n new_nodes={{\n{}}}\n",
new_nodes
.iter()
@ -210,7 +210,8 @@ where
#[allow(unused_variables)]
Ok(x) => {
// Call failed, node will not be considered again
log_network_result!(debug "Fanout result {}: {:?}", &next_node, x);
event!(target: "fanout", Level::DEBUG,
"Fanout result {}: {:?}", &next_node, x);
}
Err(e) => {
// Error happened, abort everything and return the error

5
veilid-core/src/rpc_processor/fanout_queue.rs
View File

@ -55,7 +55,7 @@ impl FanoutQueue {
self.current_nodes =
VecDeque::from_iter(cleanup(self.current_nodes.as_slices().0).iter().cloned());
info!(
event!(target: "fanout", Level::DEBUG,
"FanoutQueue::add:\n current_nodes={{\n{}}}\n returned_nodes={{\n{}}}\n",
self.current_nodes
.iter()
@ -79,7 +79,8 @@ impl FanoutQueue {
// Ensure we don't return this node again
self.returned_nodes.insert(key);
info!("FanoutQueue::next: => {}", cn);
event!(target: "fanout", Level::DEBUG,
"FanoutQueue::next: => {}", cn);
Some(cn)
}

2
veilid-core/src/tests/native/mod.rs
View File

@ -98,7 +98,7 @@ cfg_if! {
SETUP_ONCE.call_once(|| {
use tracing_subscriber::{EnvFilter, fmt, prelude::*};
let mut env_filter = EnvFilter::builder().from_env_lossy();
for ig in DEFAULT_LOG_IGNORE_LIST {
for ig in DEFAULT_LOG_FACILITIES_IGNORE_LIST {
env_filter = env_filter.add_directive(format!("{}=off", ig).parse().unwrap());
}
let fmt_layer = fmt::layer();

4
veilid-core/src/veilid_api/debug.rs
View File

@ -19,7 +19,7 @@ static DEBUG_CACHE: Mutex<DebugCache> = Mutex::new(DebugCache {
opened_record_contexts: Lazy::new(LinkedHashMap::new),
});
fn format_opt_ts(ts: Option<TimestampDuration>) -> String {
pub fn format_opt_ts(ts: Option<TimestampDuration>) -> String {
let Some(ts) = ts else {
return "---".to_owned();
};
@ -32,7 +32,7 @@ fn format_opt_ts(ts: Option<TimestampDuration>) -> String {
}
}
fn format_opt_bps(bps: Option<ByteCount>) -> String {
pub fn format_opt_bps(bps: Option<ByteCount>) -> String {
let Some(bps) = bps else {
return "---".to_owned();
};

5
veilid-core/src/veilid_config.rs
View File

@ -1262,3 +1262,8 @@ impl VeilidConfig {
Ok(())
}
}
/// Return the default veilid config as a json object
pub fn default_veilid_config() -> String {
serialize_json(VeilidConfigInner::default())
}

25
veilid-flutter/rust/src/dart_ffi.rs
View File

@ -341,23 +341,6 @@ pub extern "C" fn change_log_level(layer: FfiStr, log_level: FfiStr) {
}
}
fn apply_ignore_change(ignore_list: Vec<String>, target_change: String) -> Vec<String> {
let mut ignore_list = ignore_list.clone();
for change in target_change.split(',').map(|c| c.trim().to_owned()) {
if change.is_empty() {
continue;
}
if let Some(target) = change.strip_prefix('-') {
ignore_list.retain(|x| x != target);
} else if !ignore_list.contains(&change) {
ignore_list.push(change.to_string());
}
}
ignore_list
}
#[no_mangle]
pub extern "C" fn change_log_ignore(layer: FfiStr, log_ignore: FfiStr) {
// get layer to change level on
@ -372,16 +355,16 @@ pub extern "C" fn change_log_ignore(layer: FfiStr, log_ignore: FfiStr) {
if layer.is_empty() {
// Change all layers
for f in filters.values() {
f.set_ignore_list(Some(apply_ignore_change(
f.ignore_list(),
f.set_ignore_list(Some(veilid_core::VeilidLayerFilter::apply_ignore_change(
&f.ignore_list(),
log_ignore.clone(),
)));
}
} else {
// Change a specific layer
let f = filters.get(layer.as_str()).unwrap();
f.set_ignore_list(Some(apply_ignore_change(
f.ignore_list(),
f.set_ignore_list(Some(veilid_core::VeilidLayerFilter::apply_ignore_change(
&f.ignore_list(),
log_ignore.clone(),
)));
}

25
veilid-server/src/veilid_logs.rs
View File

@ -230,23 +230,6 @@ impl VeilidLogs {
Ok(())
}
fn apply_ignore_change(ignore_list: Vec<String>, target_change: String) -> Vec<String> {
let mut ignore_list = ignore_list.clone();
for change in target_change.split(',').map(|c| c.trim().to_owned()) {
if change.is_empty() {
continue;
}
if let Some(target) = change.strip_prefix('-') {
ignore_list.retain(|x| x != target);
} else if !ignore_list.contains(&change) {
ignore_list.push(change.to_string());
}
}
ignore_list
}
pub fn change_log_ignore(
&self,
layer: String,
@ -260,8 +243,8 @@ impl VeilidLogs {
if layer.is_empty() {
// Change all layers
for f in inner.filters.values() {
f.set_ignore_list(Some(Self::apply_ignore_change(
f.ignore_list(),
f.set_ignore_list(Some(veilid_core::VeilidLayerFilter::apply_ignore_change(
&f.ignore_list(),
log_ignore.clone(),
)));
}
@ -277,8 +260,8 @@ impl VeilidLogs {
});
}
};
f.set_ignore_list(Some(Self::apply_ignore_change(
f.ignore_list(),
f.set_ignore_list(Some(veilid_core::VeilidLayerFilter::apply_ignore_change(
&f.ignore_list(),
log_ignore.clone(),
)));
}

21
veilid-wasm/src/lib.rs
View File

@ -263,23 +263,6 @@ pub fn change_log_level(layer: String, log_level: String) {
}
}
fn apply_ignore_change(ignore_list: Vec<String>, target_change: String) -> Vec<String> {
let mut ignore_list = ignore_list.clone();
for change in target_change.split(',').map(|c| c.trim().to_owned()) {
if change.is_empty() {
continue;
}
if let Some(target) = change.strip_prefix('-') {
ignore_list.retain(|x| x != target);
} else if !ignore_list.contains(&change) {
ignore_list.push(change.to_string());
}
}
ignore_list
}
#[wasm_bindgen()]
pub fn change_log_ignore(layer: String, log_ignore: String) {
let layer = if layer == "all" { "".to_owned() } else { layer };
@ -288,7 +271,7 @@ pub fn change_log_ignore(layer: String, log_ignore: String) {
if layer.is_empty() {
// Change all layers
for f in filters.values() {
f.set_ignore_list(Some(apply_ignore_change(
f.set_ignore_list(Some(VeilidLayerFilter::apply_ignore_change(
f.ignore_list(),
log_ignore.clone(),
)));
@ -296,7 +279,7 @@ pub fn change_log_ignore(layer: String, log_ignore: String) {
} else {
// Change a specific layer
let f = filters.get(layer.as_str()).unwrap();
f.set_ignore_list(Some(apply_ignore_change(
f.set_ignore_list(Some(VeilidLayerFilter::apply_ignore_change(
f.ignore_list(),
log_ignore.clone(),
)));

21
veilid-wasm/src/veilid_client_js.rs
View File

@ -129,23 +129,6 @@ impl VeilidClient {
}
}
fn apply_ignore_change(ignore_list: Vec<String>, changes: Vec<String>) -> Vec<String> {
let mut ignore_list = ignore_list.clone();
for change in changes.iter().map(|c| c.trim().to_owned()) {
if change.is_empty() {
continue;
}
if let Some(target) = change.strip_prefix('-') {
ignore_list.retain(|x| x != target);
} else if !ignore_list.contains(&change) {
ignore_list.push(change.to_string());
}
}
ignore_list
}
// TODO: can we refine the TS type of `layer`?
pub fn changeLogIgnore(layer: String, changes: Vec<String>) {
let layer = if layer == "all" { "".to_owned() } else { layer };
@ -153,7 +136,7 @@ impl VeilidClient {
if layer.is_empty() {
// Change all layers
for f in filters.values() {
f.set_ignore_list(Some(Self::apply_ignore_change(
f.set_ignore_list(Some(VeilidLayerFilter::apply_ignore_change(
f.ignore_list(),
changes.clone(),
)));
@ -161,7 +144,7 @@ impl VeilidClient {
} else {
// Change a specific layer
let f = filters.get(layer.as_str()).unwrap();
f.set_ignore_list(Some(Self::apply_ignore_change(
f.set_ignore_list(Some(VeilidLayerFilter::apply_ignore_change(
f.ignore_list(),
changes.clone(),
)));