From c106d324c80f2af3079b026147ed062c4901f33b Mon Sep 17 00:00:00 2001 From: John Smith Date: Fri, 1 Jul 2022 12:13:52 -0400 Subject: [PATCH] api and log refactor --- Cargo.lock | 1 - veilid-cli/src/client_api_connection.rs | 82 +++++++- veilid-cli/src/command_processor.rs | 54 ++++- veilid-core/src/api_tracing_layer.rs | 142 +------------ veilid-core/src/core_context.rs | 16 +- veilid-core/src/lib.rs | 2 + .../src/tests/common/test_veilid_config.rs | 1 - veilid-core/src/veilid_api/mod.rs | 6 - veilid-core/src/veilid_config.rs | 10 + veilid-core/src/veilid_layer_filter.rs | 91 ++++++++ veilid-flutter/example/lib/config.dart | 1 - veilid-flutter/example/lib/main.dart | 16 +- veilid-flutter/lib/veilid.dart | 75 +++++-- veilid-flutter/lib/veilid_ffi.dart | 37 ++-- veilid-flutter/lib/veilid_js.dart | 13 +- veilid-flutter/rust/src/dart_ffi.rs | 139 ++++++------- veilid-server/Cargo.toml | 1 - veilid-server/proto/veilid-client.capnp | 20 +- veilid-server/src/client_api.rs | 105 ++++++---- veilid-server/src/main.rs | 8 +- veilid-server/src/server.rs | 16 +- veilid-server/src/settings.rs | 23 +-- veilid-server/src/unix.rs | 4 +- veilid-server/src/veilid_logs.rs | 195 ++++++++++-------- veilid-wasm/src/lib.rs | 105 +++++----- 25 files changed, 662 insertions(+), 501 deletions(-) create mode 100644 veilid-core/src/veilid_layer_filter.rs diff --git a/Cargo.lock b/Cargo.lock index 278ac9c0..5cedf7e3 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -5155,7 +5155,6 @@ dependencies = [ "ctrlc", "daemonize", "directories", - "failure", "flume", "futures-util", "hostname", diff --git a/veilid-cli/src/client_api_connection.rs b/veilid-cli/src/client_api_connection.rs index 37b77555..bad5a1f8 100644 --- a/veilid-cli/src/client_api_connection.rs +++ b/veilid-cli/src/client_api_connection.rs @@ -3,6 +3,7 @@ use crate::tools::*; use crate::veilid_client_capnp::*; use capnp::capability::Promise; use capnp_rpc::{pry, rpc_twoparty_capnp, twoparty, Disconnector, RpcSystem}; +use serde::de::DeserializeOwned; use std::cell::RefCell; use std::net::SocketAddr; use std::rc::Rc; @@ -28,6 +29,30 @@ macro_rules! pry_result { }; } +fn map_to_internal_error(e: T) -> VeilidAPIError { + VeilidAPIError::Internal { + message: e.to_string(), + } +} + +fn decode_api_result( + reader: &api_result::Reader, +) -> Result { + match reader.which().map_err(map_to_internal_error)? { + api_result::Which::Ok(v) => { + let ok_val = v.map_err(map_to_internal_error)?; + let res: T = veilid_core::deserialize_json(ok_val).map_err(map_to_internal_error)?; + Ok(res) + } + api_result::Which::Err(e) => { + let err_val = e.map_err(map_to_internal_error)?; + let res: VeilidAPIError = + veilid_core::deserialize_json(err_val).map_err(map_to_internal_error)?; + Err(res) + } + } +} + struct VeilidClientImpl { comproc: CommandProcessor, } @@ -254,7 +279,13 @@ impl ClientApiConnection { }; let request = server.borrow().attach_request(); let response = request.send().promise.await.map_err(map_to_string)?; - response.get().map(drop).map_err(map_to_string) + let reader = response + .get() + .map_err(map_to_string)? + .get_result() + .map_err(map_to_string)?; + let res: Result<(), VeilidAPIError> = decode_api_result(&reader); + res.map_err(map_to_string) } pub async fn server_detach(&mut self) -> Result<(), String> { @@ -269,7 +300,13 @@ impl ClientApiConnection { }; let request = server.borrow().detach_request(); let response = request.send().promise.await.map_err(map_to_string)?; - response.get().map(drop).map_err(map_to_string) + let reader = response + .get() + .map_err(map_to_string)? + .get_result() + .map_err(map_to_string)?; + let res: Result<(), VeilidAPIError> = decode_api_result(&reader); + res.map_err(map_to_string) } pub async fn server_shutdown(&mut self) -> Result<(), String> { @@ -294,18 +331,47 @@ impl ClientApiConnection { inner .server .as_ref() - .ok_or_else(|| "Not connected, ignoring attach request".to_owned())? + .ok_or_else(|| "Not connected, ignoring debug request".to_owned())? .clone() }; let mut request = server.borrow().debug_request(); - request.get().set_what(&what); + request.get().set_command(&what); let response = request.send().promise.await.map_err(map_to_string)?; - response + let reader = response .get() .map_err(map_to_string)? - .get_output() - .map(|o| o.to_owned()) - .map_err(map_to_string) + .get_result() + .map_err(map_to_string)?; + let res: Result = decode_api_result(&reader); + res.map_err(map_to_string) + } + + pub async fn server_change_log_level( + &mut self, + layer: String, + log_level: VeilidConfigLogLevel, + ) -> Result<(), String> { + trace!("ClientApiConnection::change_log_level"); + let server = { + let inner = self.inner.borrow(); + inner + .server + .as_ref() + .ok_or_else(|| "Not connected, ignoring change_log_level request".to_owned())? + .clone() + }; + let mut request = server.borrow().change_log_level_request(); + request.get().set_layer(&layer); + let log_level_json = veilid_core::serialize_json(&log_level); + request.get().set_log_level(&log_level_json); + let response = request.send().promise.await.map_err(map_to_string)?; + let reader = response + .get() + .map_err(map_to_string)? + .get_result() + .map_err(map_to_string)?; + let res: Result<(), VeilidAPIError> = decode_api_result(&reader); + res.map_err(map_to_string) } // Start Client API connection diff --git a/veilid-cli/src/command_processor.rs b/veilid-cli/src/command_processor.rs index 3e160560..9227cdaa 100644 --- a/veilid-cli/src/command_processor.rs +++ b/veilid-cli/src/command_processor.rs @@ -8,6 +8,19 @@ use std::net::SocketAddr; use std::rc::Rc; use std::time::{Duration, SystemTime}; use veilid_core::xx::{Eventual, EventualCommon}; +use veilid_core::VeilidConfigLogLevel; + +pub fn convert_loglevel(s: &str) -> Result { + match s.to_ascii_lowercase().as_str() { + "off" => Ok(VeilidConfigLogLevel::Off), + "error" => Ok(VeilidConfigLogLevel::Error), + "warn" => Ok(VeilidConfigLogLevel::Warn), + "info" => Ok(VeilidConfigLogLevel::Info), + "debug" => Ok(VeilidConfigLogLevel::Debug), + "trace" => Ok(VeilidConfigLogLevel::Trace), + _ => Err(format!("Invalid log level: {}", s)), + } +} #[derive(PartialEq, Clone)] pub enum ConnectionState { @@ -97,6 +110,7 @@ shutdown - shut the server down attach - attach the server to the Veilid network detach - detach the server from the Veilid network debug - send a debugging command to the Veilid server +change_log_level - change the log level for a tracing layer "#, ); let ui = self.ui(); @@ -131,7 +145,7 @@ debug - send a debugging command to the Veilid server let ui = self.ui(); spawn_detached_local(async move { if let Err(e) = capi.server_attach().await { - error!("Server command 'attach' failed to execute: {}", e); + error!("Server command 'attach' failed: {}", e); } ui.send_callback(callback); }); @@ -144,7 +158,7 @@ debug - send a debugging command to the Veilid server let ui = self.ui(); spawn_detached_local(async move { if let Err(e) = capi.server_detach().await { - error!("Server command 'detach' failed to execute: {}", e); + error!("Server command 'detach' failed: {}", e); } ui.send_callback(callback); }); @@ -170,7 +184,40 @@ debug - send a debugging command to the Veilid server match capi.server_debug(rest.unwrap_or_default()).await { Ok(output) => ui.display_string_dialog("Debug Output", output, callback), Err(e) => { - error!("Server command 'debug' failed to execute: {}", e); + error!("Server command 'debug' failed: {}", e); + ui.send_callback(callback); + } + } + }); + Ok(()) + } + + pub fn cmd_change_log_level( + &self, + rest: Option, + callback: UICallback, + ) -> Result<(), String> { + trace!("CommandProcessor::cmd_change_log_level"); + let mut capi = self.capi(); + let ui = self.ui(); + spawn_detached_local(async move { + let (layer, rest) = Self::word_split(&rest.unwrap_or_default()); + let log_level = match convert_loglevel(&rest.unwrap_or_default()) { + Ok(v) => v, + Err(e) => { + error!("failed to change log level: {}", e); + ui.send_callback(callback); + return; + } + }; + + match capi.server_change_log_level(layer, log_level).await { + Ok(()) => { + info!("Log level changed"); + ui.send_callback(callback); + } + Err(e) => { + error!("Server command 'change_log_level' failed: {}", e); ui.send_callback(callback); } } @@ -190,6 +237,7 @@ debug - send a debugging command to the Veilid server "attach" => self.cmd_attach(callback), "detach" => self.cmd_detach(callback), "debug" => self.cmd_debug(rest, callback), + "change_log_level" => self.cmd_change_log_level(rest, callback), _ => { let ui = self.ui(); ui.send_callback(callback); diff --git a/veilid-core/src/api_tracing_layer.rs b/veilid-core/src/api_tracing_layer.rs index 8c3551d4..911925c3 100644 --- a/veilid-core/src/api_tracing_layer.rs +++ b/veilid-core/src/api_tracing_layer.rs @@ -10,14 +10,10 @@ cfg_if! { use send_wrapper::*; struct ApiLoggerInner { - max_level: Option, - filter_ignore: Cow<'static, [Cow<'static, str>]>, update_callback: SendWrapper, } } else { struct ApiLoggerInner { - max_level: Option, - filter_ignore: Cow<'static, [Cow<'static, str>]>, update_callback: UpdateCallback, } } @@ -31,21 +27,14 @@ pub struct ApiTracingLayer { static API_LOGGER: OnceCell = OnceCell::new(); impl ApiTracingLayer { - fn new_inner( - max_level: Option, - update_callback: UpdateCallback, - ) -> ApiLoggerInner { + fn new_inner(update_callback: UpdateCallback) -> ApiLoggerInner { cfg_if! { if #[cfg(target_arch = "wasm32")] { ApiLoggerInner { - max_level, - filter_ignore: Default::default(), update_callback: SendWrapper::new(update_callback), } } else { ApiLoggerInner { - max_level, - filter_ignore: Default::default(), update_callback, } } @@ -53,11 +42,11 @@ impl ApiTracingLayer { } #[instrument(level = "debug", skip(update_callback))] - pub async fn init(max_level: Option, update_callback: UpdateCallback) { + pub async fn init(update_callback: UpdateCallback) { let api_logger = API_LOGGER.get_or_init(|| ApiTracingLayer { inner: Arc::new(Mutex::new(None)), }); - let apilogger_inner = Some(Self::new_inner(max_level, update_callback)); + let apilogger_inner = Some(Self::new_inner(update_callback)); *api_logger.inner.lock() = apilogger_inner; } @@ -76,52 +65,9 @@ impl ApiTracingLayer { }) .clone() } - - #[instrument(level = "trace")] - pub fn change_api_log_level(max_level: Option) { - if let Some(api_logger) = API_LOGGER.get() { - if let Some(inner) = &mut *api_logger.inner.lock() { - inner.max_level = max_level; - } - } - } - - pub fn add_filter_ignore_str(filter_ignore: &'static str) { - if let Some(api_logger) = API_LOGGER.get() { - if let Some(inner) = &mut *api_logger.inner.lock() { - let mut list = Vec::from(&*inner.filter_ignore); - list.push(Cow::Borrowed(filter_ignore)); - inner.filter_ignore = Cow::Owned(list); - } - } - } } impl registry::LookupSpan<'a>> Layer for ApiTracingLayer { - fn enabled(&self, metadata: &tracing::Metadata<'_>, _: layer::Context<'_, S>) -> bool { - if let Some(inner) = &mut *self.inner.lock() { - // Skip things that are out of our level - if let Some(max_level) = inner.max_level { - if VeilidLogLevel::from_tracing_level(*metadata.level()) > max_level { - return false; - } - } else { - return false; - } - // Skip filtered targets - let skip = match (metadata.target(), &*inner.filter_ignore) { - (path, ignore) if !ignore.is_empty() => { - // Check that the module path does not match any ignore filters - ignore.iter().any(|v| path.starts_with(&**v)) - } - _ => false, - }; - !skip - } else { - false - } - } - fn on_new_span( &self, attrs: &tracing::span::Attributes<'_>, @@ -161,23 +107,16 @@ impl registry::LookupSpan<'a>> Layer for ApiTracingLa event.record(&mut recorder); let meta = event.metadata(); let level = meta.level(); - if let Some(max_level) = inner.max_level { - if VeilidLogLevel::from_tracing_level(*level) <= max_level { - let log_level = VeilidLogLevel::from_tracing_level(*level); + let log_level = VeilidLogLevel::from_tracing_level(*level); - let origin = meta - .file() - .and_then(|file| meta.line().map(|ln| format!("{}:{}", file, ln))) - .unwrap_or_default(); + let origin = meta + .file() + .and_then(|file| meta.line().map(|ln| format!("{}:{}", file, ln))) + .unwrap_or_default(); - let message = format!("{} {}", origin, recorder); + let message = format!("{} {}", origin, recorder); - (inner.update_callback)(VeilidUpdate::Log(VeilidStateLog { - log_level, - message, - })) - } - } + (inner.update_callback)(VeilidUpdate::Log(VeilidStateLog { log_level, message })) } } } @@ -232,64 +171,3 @@ impl core::default::Default for StringRecorder { StringRecorder::new() } } - -impl log::Log for ApiTracingLayer { - fn enabled(&self, metadata: &log::Metadata<'_>) -> bool { - if let Some(inner) = &mut *self.inner.lock() { - if let Some(max_level) = inner.max_level { - return VeilidLogLevel::from_log_level(metadata.level()) <= max_level; - } - } - false - } - - fn log(&self, record: &log::Record<'_>) { - if let Some(inner) = &mut *self.inner.lock() { - // Skip filtered targets - let skip = match (record.target(), &*inner.filter_ignore) { - (path, ignore) if !ignore.is_empty() => { - // Check that the module path does not match any ignore filters - ignore.iter().any(|v| path.starts_with(&**v)) - } - _ => false, - }; - if skip { - return; - } - - let metadata = record.metadata(); - let level = metadata.level(); - let log_level = VeilidLogLevel::from_log_level(level); - if let Some(max_level) = inner.max_level { - if log_level <= max_level { - let file = record.file().unwrap_or(""); - let loc = if level >= log::Level::Debug { - if let Some(line) = record.line() { - format!("[{}:{}] ", file, line) - } else { - format!("[{}:] ", file) - } - } else { - "".to_owned() - }; - let tgt = if record.target().is_empty() { - "".to_owned() - } else { - format!("{}: ", record.target()) - }; - - let message = format!("{}{}{}", tgt, loc, record.args()); - - (inner.update_callback)(VeilidUpdate::Log(VeilidStateLog { - log_level, - message, - })) - } - } - } - } - - fn flush(&self) { - // always flushes - } -} diff --git a/veilid-core/src/core_context.rs b/veilid-core/src/core_context.rs index bf86e6c9..1c0d8f76 100644 --- a/veilid-core/src/core_context.rs +++ b/veilid-core/src/core_context.rs @@ -59,21 +59,11 @@ impl ServicesContext { #[instrument(err, skip_all)] pub async fn startup(&mut self) -> Result<(), VeilidAPIError> { - let api_log_level: VeilidConfigLogLevel = self.config.get().api_log_level; - if api_log_level != VeilidConfigLogLevel::Off { - ApiTracingLayer::init( - api_log_level.to_veilid_log_level(), - self.update_callback.clone(), - ) - .await; - for ig in crate::DEFAULT_LOG_IGNORE_LIST { - ApiTracingLayer::add_filter_ignore_str(ig); - } - info!("Veilid API logging initialized"); - } - info!("Veilid API starting up"); + info!("init api tracing"); + ApiTracingLayer::init(self.update_callback.clone()).await; + // Set up protected store trace!("init protected store"); let protected_store = ProtectedStore::new(self.config.clone()); diff --git a/veilid-core/src/lib.rs b/veilid-core/src/lib.rs index 8e4b54f6..c861d556 100644 --- a/veilid-core/src/lib.rs +++ b/veilid-core/src/lib.rs @@ -30,6 +30,7 @@ mod routing_table; mod rpc_processor; mod veilid_api; mod veilid_config; +mod veilid_layer_filter; mod veilid_rng; #[macro_use] @@ -40,6 +41,7 @@ pub use self::attachment_manager::AttachmentState; pub use self::core_context::{api_startup, api_startup_json, UpdateCallback}; pub use self::veilid_api::*; pub use self::veilid_config::*; +pub use self::veilid_layer_filter::*; pub mod veilid_capnp { include!(concat!(env!("OUT_DIR"), "/proto/veilid_capnp.rs")); diff --git a/veilid-core/src/tests/common/test_veilid_config.rs b/veilid-core/src/tests/common/test_veilid_config.rs index 75d5b56c..b173cc67 100644 --- a/veilid-core/src/tests/common/test_veilid_config.rs +++ b/veilid-core/src/tests/common/test_veilid_config.rs @@ -169,7 +169,6 @@ fn config_callback(key: String) -> ConfigCallbackReturn { match key.as_str() { "program_name" => Ok(Box::new(String::from("Veilid"))), "namespace" => Ok(Box::new(String::from(""))), - "api_log_level" => Ok(Box::new(VeilidConfigLogLevel::Off)), "capabilities.protocol_udp" => Ok(Box::new(true)), "capabilities.protocol_connect_tcp" => Ok(Box::new(true)), "capabilities.protocol_accept_tcp" => Ok(Box::new(true)), diff --git a/veilid-core/src/veilid_api/mod.rs b/veilid-core/src/veilid_api/mod.rs index 58cf4702..28b4424d 100644 --- a/veilid-core/src/veilid_api/mod.rs +++ b/veilid-core/src/veilid_api/mod.rs @@ -1861,12 +1861,6 @@ impl VeilidAPI { .map_err(|e| VeilidAPIError::Internal { message: e }) } - // Change api logging level if it is enabled - #[instrument(skip(self))] - pub async fn change_api_log_level(&self, log_level: VeilidConfigLogLevel) { - ApiTracingLayer::change_api_log_level(log_level.to_veilid_log_level()); - } - //////////////////////////////////////////////////////////////// // Direct Node Access (pretty much for testing only) diff --git a/veilid-core/src/veilid_config.rs b/veilid-core/src/veilid_config.rs index 6f3ccb8c..c92efa33 100644 --- a/veilid-core/src/veilid_config.rs +++ b/veilid-core/src/veilid_config.rs @@ -223,6 +223,16 @@ impl VeilidConfigLogLevel { Some(VeilidLogLevel::Trace) => Self::Trace, } } + pub fn from_tracing_level_filter(level: level_filters::LevelFilter) -> Self { + match level { + level_filters::LevelFilter::OFF => Self::Off, + level_filters::LevelFilter::ERROR => Self::Error, + level_filters::LevelFilter::WARN => Self::Warn, + level_filters::LevelFilter::INFO => Self::Info, + level_filters::LevelFilter::DEBUG => Self::Debug, + level_filters::LevelFilter::TRACE => Self::Trace, + } + } } impl Default for VeilidConfigLogLevel { fn default() -> Self { diff --git a/veilid-core/src/veilid_layer_filter.rs b/veilid-core/src/veilid_layer_filter.rs new file mode 100644 index 00000000..727ba3ce --- /dev/null +++ b/veilid-core/src/veilid_layer_filter.rs @@ -0,0 +1,91 @@ +use super::*; +use crate::xx::*; +use tracing::level_filters::LevelFilter; +use tracing::subscriber; +use tracing_subscriber::layer; + +struct VeilidLayerFilterInner { + max_level: LevelFilter, + ignore_list: Vec, +} + +#[derive(Clone)] +pub struct VeilidLayerFilter { + inner: Arc>, +} + +impl VeilidLayerFilter { + pub fn new( + max_level: VeilidConfigLogLevel, + ignore_list: Option>, + ) -> VeilidLayerFilter { + Self { + inner: Arc::new(RwLock::new(VeilidLayerFilterInner { + max_level: max_level.to_tracing_level_filter(), + ignore_list: ignore_list + .unwrap_or_else(|| DEFAULT_LOG_IGNORE_LIST.map(|x| x.to_owned()).to_vec()), + })), + } + } + + pub fn max_level(&self) -> VeilidConfigLogLevel { + let inner = self.inner.read(); + VeilidConfigLogLevel::from_tracing_level_filter(inner.max_level) + } + + pub fn ignore_list(&self) -> Vec { + let inner = self.inner.read(); + inner.ignore_list.clone() + } + + pub fn set_max_level(&self, level: VeilidConfigLogLevel) { + { + let mut inner = self.inner.write(); + inner.max_level = level.to_tracing_level_filter(); + } + callsite::rebuild_interest_cache(); + } + + pub fn set_ignore_list(&self, ignore_list: Option>) { + { + 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()); + } + callsite::rebuild_interest_cache(); + } +} + +impl layer::Filter for VeilidLayerFilter { + fn enabled(&self, metadata: &tracing::Metadata<'_>, _: &layer::Context<'_, S>) -> bool { + let inner = self.inner.read(); + if *metadata.level() > inner.max_level { + false + } else { + true + } + } + + fn callsite_enabled( + &self, + metadata: &'static tracing::Metadata<'static>, + ) -> subscriber::Interest { + let inner = self.inner.read(); + let skip = inner + .ignore_list + .iter() + .any(|v| metadata.target().starts_with(&**v)); + if skip { + subscriber::Interest::never() + } else if *metadata.level() > inner.max_level { + subscriber::Interest::never() + } else { + subscriber::Interest::always() + } + } + + fn max_level_hint(&self) -> Option { + let inner = self.inner.read(); + Some(inner.max_level) + } +} diff --git a/veilid-flutter/example/lib/config.dart b/veilid-flutter/example/lib/config.dart index 295a7927..1b2eab2a 100644 --- a/veilid-flutter/example/lib/config.dart +++ b/veilid-flutter/example/lib/config.dart @@ -7,7 +7,6 @@ Future getDefaultVeilidConfig() async { return VeilidConfig( programName: "Veilid Plugin Test", namespace: "", - apiLogLevel: VeilidConfigLogLevel.info, capabilities: VeilidConfigCapabilities( protocolUDP: !kIsWeb, protocolConnectTCP: !kIsWeb, diff --git a/veilid-flutter/example/lib/main.dart b/veilid-flutter/example/lib/main.dart index a36456f6..5fa4cc17 100644 --- a/veilid-flutter/example/lib/main.dart +++ b/veilid-flutter/example/lib/main.dart @@ -59,7 +59,7 @@ VeilidConfigLogLevel convertToVeilidConfigLogLevel(LogLevel? level) { void setRootLogLevel(LogLevel? level) { Loggy('').level = getLogOptions(level); - Veilid.instance.changeApiLogLevel(convertToVeilidConfigLogLevel(level)); + Veilid.instance.changeLogLevel("all", convertToVeilidConfigLogLevel(level)); } void initLoggy() { @@ -81,22 +81,26 @@ void main() { logging: VeilidWASMConfigLogging( performance: VeilidWASMConfigLoggingPerformance( enabled: true, - level: VeilidLogLevel.trace, + level: VeilidConfigLogLevel.debug, logsInTimings: true, - logsInConsole: false))); + logsInConsole: true), + api: VeilidWASMConfigLoggingApi( + enabled: true, level: VeilidConfigLogLevel.info))); Veilid.instance.configureVeilidPlatform(platformConfig.json); } else { var platformConfig = VeilidFFIConfig( logging: VeilidFFIConfigLogging( terminal: VeilidFFIConfigLoggingTerminal( enabled: false, - level: VeilidLogLevel.trace, + level: VeilidConfigLogLevel.debug, ), otlp: VeilidFFIConfigLoggingOtlp( enabled: false, - level: VeilidLogLevel.trace, + level: VeilidConfigLogLevel.trace, grpcEndpoint: "localhost:4317", - serviceName: "VeilidExample"))); + serviceName: "VeilidExample"), + api: VeilidFFIConfigLoggingApi( + enabled: true, level: VeilidConfigLogLevel.info))); Veilid.instance.configureVeilidPlatform(platformConfig.json); } diff --git a/veilid-flutter/lib/veilid.dart b/veilid-flutter/lib/veilid.dart index 682492dc..e0c2ec28 100644 --- a/veilid-flutter/lib/veilid.dart +++ b/veilid-flutter/lib/veilid.dart @@ -13,7 +13,7 @@ import 'veilid_stub.dart' class VeilidFFIConfigLoggingTerminal { bool enabled; - VeilidLogLevel level; + VeilidConfigLogLevel level; VeilidFFIConfigLoggingTerminal({ required this.enabled, @@ -29,12 +29,12 @@ class VeilidFFIConfigLoggingTerminal { VeilidFFIConfigLoggingTerminal.fromJson(Map json) : enabled = json['enabled'], - level = veilidLogLevelFromJson(json['level']); + level = veilidConfigLogLevelFromJson(json['level']); } class VeilidFFIConfigLoggingOtlp { bool enabled; - VeilidLogLevel level; + VeilidConfigLogLevel level; String grpcEndpoint; String serviceName; @@ -56,27 +56,52 @@ class VeilidFFIConfigLoggingOtlp { VeilidFFIConfigLoggingOtlp.fromJson(Map json) : enabled = json['enabled'], - level = veilidLogLevelFromJson(json['level']), + level = veilidConfigLogLevelFromJson(json['level']), grpcEndpoint = json['grpc_endpoint'], serviceName = json['service_name']; } +class VeilidFFIConfigLoggingApi { + bool enabled; + VeilidConfigLogLevel level; + + VeilidFFIConfigLoggingApi({ + required this.enabled, + required this.level, + }); + + Map get json { + return { + 'enabled': enabled, + 'level': level.json, + }; + } + + VeilidFFIConfigLoggingApi.fromJson(Map json) + : enabled = json['enabled'], + level = veilidConfigLogLevelFromJson(json['level']); +} + class VeilidFFIConfigLogging { VeilidFFIConfigLoggingTerminal terminal; VeilidFFIConfigLoggingOtlp otlp; + VeilidFFIConfigLoggingApi api; - VeilidFFIConfigLogging({required this.terminal, required this.otlp}); + VeilidFFIConfigLogging( + {required this.terminal, required this.otlp, required this.api}); Map get json { return { 'terminal': terminal.json, 'otlp': otlp.json, + 'api': api.json, }; } VeilidFFIConfigLogging.fromJson(Map json) : terminal = VeilidFFIConfigLoggingTerminal.fromJson(json['terminal']), - otlp = VeilidFFIConfigLoggingOtlp.fromJson(json['otlp']); + otlp = VeilidFFIConfigLoggingOtlp.fromJson(json['otlp']), + api = VeilidFFIConfigLoggingApi.fromJson(json['api']); } class VeilidFFIConfig { @@ -101,7 +126,7 @@ class VeilidFFIConfig { class VeilidWASMConfigLoggingPerformance { bool enabled; - VeilidLogLevel level; + VeilidConfigLogLevel level; bool logsInTimings; bool logsInConsole; @@ -123,25 +148,49 @@ class VeilidWASMConfigLoggingPerformance { VeilidWASMConfigLoggingPerformance.fromJson(Map json) : enabled = json['enabled'], - level = veilidLogLevelFromJson(json['level']), + level = veilidConfigLogLevelFromJson(json['level']), logsInTimings = json['logs_in_timings'], logsInConsole = json['logs_in_console']; } +class VeilidWASMConfigLoggingApi { + bool enabled; + VeilidConfigLogLevel level; + + VeilidWASMConfigLoggingApi({ + required this.enabled, + required this.level, + }); + + Map get json { + return { + 'enabled': enabled, + 'level': level.json, + }; + } + + VeilidWASMConfigLoggingApi.fromJson(Map json) + : enabled = json['enabled'], + level = veilidConfigLogLevelFromJson(json['level']); +} + class VeilidWASMConfigLogging { VeilidWASMConfigLoggingPerformance performance; + VeilidWASMConfigLoggingApi api; - VeilidWASMConfigLogging({required this.performance}); + VeilidWASMConfigLogging({required this.performance, required this.api}); Map get json { return { 'performance': performance.json, + 'api': api.json, }; } VeilidWASMConfigLogging.fromJson(Map json) : performance = - VeilidWASMConfigLoggingPerformance.fromJson(json['performance']); + VeilidWASMConfigLoggingPerformance.fromJson(json['performance']), + api = VeilidWASMConfigLoggingApi.fromJson(json['api']); } class VeilidWASMConfig { @@ -899,7 +948,6 @@ class VeilidConfigCapabilities { class VeilidConfig { String programName; String namespace; - VeilidConfigLogLevel apiLogLevel; VeilidConfigCapabilities capabilities; VeilidConfigProtectedStore protectedStore; VeilidConfigTableStore tableStore; @@ -909,7 +957,6 @@ class VeilidConfig { VeilidConfig({ required this.programName, required this.namespace, - required this.apiLogLevel, required this.capabilities, required this.protectedStore, required this.tableStore, @@ -921,7 +968,6 @@ class VeilidConfig { return { 'program_name': programName, 'namespace': namespace, - 'api_log_level': apiLogLevel.json, 'capabilities': capabilities.json, 'protected_store': protectedStore.json, 'table_store': tableStore.json, @@ -933,7 +979,6 @@ class VeilidConfig { VeilidConfig.fromJson(Map json) : programName = json['program_name'], namespace = json['namespace'], - apiLogLevel = json['api_log_level'], capabilities = VeilidConfigCapabilities.fromJson(json['capabilities']), protectedStore = VeilidConfigProtectedStore.fromJson(json['protected_store']), @@ -1253,9 +1298,9 @@ abstract class Veilid { static late Veilid instance = getVeilid(); void configureVeilidPlatform(Map platformConfigJson); + void changeLogLevel(String layer, VeilidConfigLogLevel logLevel); Stream startupVeilidCore(VeilidConfig config); Future getVeilidState(); - Future changeApiLogLevel(VeilidConfigLogLevel logLevel); Future shutdownVeilidCore(); Future debug(String command); String veilidVersionString(); diff --git a/veilid-flutter/lib/veilid_ffi.dart b/veilid-flutter/lib/veilid_ffi.dart index 0dc257f9..9118c0a3 100644 --- a/veilid-flutter/lib/veilid_ffi.dart +++ b/veilid-flutter/lib/veilid_ffi.dart @@ -32,15 +32,15 @@ typedef _InitializeVeilidFlutterDart = void Function(Pointer<_DartPostCObject>); // fn configure_veilid_platform(platform_config: FfiStr) typedef _ConfigureVeilidPlatformC = Void Function(Pointer); typedef _ConfigureVeilidPlatformDart = void Function(Pointer); +// fn change_log_level(layer: FfiStr, log_level: FfiStr) +typedef _ChangeLogLevelC = Void Function(Pointer, Pointer); +typedef _ChangeLogLevelDart = void Function(Pointer, Pointer); // fn startup_veilid_core(port: i64, config: FfiStr) typedef _StartupVeilidCoreC = Void Function(Int64, Pointer); typedef _StartupVeilidCoreDart = void Function(int, Pointer); // fn get_veilid_state(port: i64) typedef _GetVeilidStateC = Void Function(Int64); typedef _GetVeilidStateDart = void Function(int); -// fn change_api_log_level(port: i64, log_level: FfiStr) -typedef _ChangeApiLogLevelC = Void Function(Int64, Pointer); -typedef _ChangeApiLogLevelDart = void Function(int, Pointer); // fn debug(port: i64, log_level: FfiStr) typedef _DebugC = Void Function(Int64, Pointer); typedef _DebugDart = void Function(int, Pointer); @@ -246,9 +246,9 @@ class VeilidFFI implements Veilid { // Shared library functions final _FreeStringDart _freeString; final _ConfigureVeilidPlatformDart _configureVeilidPlatform; + final _ChangeLogLevelDart _changeLogLevel; final _StartupVeilidCoreDart _startupVeilidCore; final _GetVeilidStateDart _getVeilidState; - final _ChangeApiLogLevelDart _changeApiLogLevel; final _ShutdownVeilidCoreDart _shutdownVeilidCore; final _DebugDart _debug; final _VeilidVersionStringDart _veilidVersionString; @@ -261,15 +261,15 @@ class VeilidFFI implements Veilid { _configureVeilidPlatform = dylib.lookupFunction< _ConfigureVeilidPlatformC, _ConfigureVeilidPlatformDart>('configure_veilid_platform'), + _changeLogLevel = + dylib.lookupFunction<_ChangeLogLevelC, _ChangeLogLevelDart>( + 'change_log_level'), _startupVeilidCore = dylib.lookupFunction<_StartupVeilidCoreC, _StartupVeilidCoreDart>( 'startup_veilid_core'), _getVeilidState = dylib.lookupFunction<_GetVeilidStateC, _GetVeilidStateDart>( 'get_veilid_state'), - _changeApiLogLevel = - dylib.lookupFunction<_ChangeApiLogLevelC, _ChangeApiLogLevelDart>( - 'change_api_log_level'), _shutdownVeilidCore = dylib.lookupFunction<_ShutdownVeilidCoreC, _ShutdownVeilidCoreDart>( 'shutdown_veilid_core'), @@ -297,6 +297,17 @@ class VeilidFFI implements Veilid { malloc.free(nativePlatformConfig); } + @override + void changeLogLevel(String layer, VeilidConfigLogLevel logLevel) { + var nativeLogLevel = + jsonEncode(logLevel.json, toEncodable: veilidApiToEncodable) + .toNativeUtf8(); + var nativeLayer = layer.toNativeUtf8(); + _changeLogLevel(nativeLayer, nativeLogLevel); + malloc.free(nativeLayer); + malloc.free(nativeLogLevel); + } + @override Stream startupVeilidCore(VeilidConfig config) { var nativeConfig = @@ -317,18 +328,6 @@ class VeilidFFI implements Veilid { return processFutureJson(VeilidState.fromJson, recvPort.first); } - @override - Future changeApiLogLevel(VeilidConfigLogLevel logLevel) async { - var nativeLogLevel = - jsonEncode(logLevel.json, toEncodable: veilidApiToEncodable) - .toNativeUtf8(); - final recvPort = ReceivePort("change_api_log_level"); - final sendPort = recvPort.sendPort; - _changeApiLogLevel(sendPort.nativePort, nativeLogLevel); - malloc.free(nativeLogLevel); - return processFutureVoid(recvPort.first); - } - @override Future shutdownVeilidCore() async { final recvPort = ReceivePort("shutdown_veilid_core"); diff --git a/veilid-flutter/lib/veilid_js.dart b/veilid-flutter/lib/veilid_js.dart index f73af88b..13d79329 100644 --- a/veilid-flutter/lib/veilid_js.dart +++ b/veilid-flutter/lib/veilid_js.dart @@ -27,6 +27,13 @@ class VeilidJS implements Veilid { wasm, "configure_veilid_platform", [platformConfigJsonString]); } + @override + void changeLogLevel(String layer, VeilidConfigLogLevel logLevel) { + var logLevelJsonString = + jsonEncode(logLevel.json, toEncodable: veilidApiToEncodable); + js_util.callMethod(wasm, "change_log_level", [layer, logLevelJsonString]); + } + @override Stream startupVeilidCore(VeilidConfig config) async* { var streamController = StreamController(); @@ -53,12 +60,6 @@ class VeilidJS implements Veilid { js_util.callMethod(wasm, "get_veilid_state", [])))); } - @override - Future changeApiLogLevel(VeilidConfigLogLevel logLevel) { - return _wrapApiPromise(js_util.callMethod(wasm, "change_api_log_level", - [jsonEncode(logLevel.json, toEncodable: veilidApiToEncodable)])); - } - @override Future shutdownVeilidCore() { return _wrapApiPromise( diff --git a/veilid-flutter/rust/src/dart_ffi.rs b/veilid-flutter/rust/src/dart_ffi.rs index 5f07aa06..10290f4a 100644 --- a/veilid-flutter/rust/src/dart_ffi.rs +++ b/veilid-flutter/rust/src/dart_ffi.rs @@ -7,7 +7,9 @@ use lazy_static::*; use opentelemetry::sdk::*; use opentelemetry::*; use opentelemetry_otlp::WithExportConfig; +use parking_lot::Mutex; use serde::*; +use std::collections::BTreeMap; use std::os::raw::c_char; use std::sync::Arc; use tracing::*; @@ -15,9 +17,10 @@ use tracing_subscriber::prelude::*; use tracing_subscriber::*; // Globals - lazy_static! { static ref VEILID_API: AsyncMutex> = AsyncMutex::new(None); + static ref FILTERS: Mutex> = + Mutex::new(BTreeMap::new()); } async fn get_veilid_api() -> Result { @@ -35,17 +38,6 @@ async fn take_veilid_api() -> Result, V: AsRef<[T]>>(metadata: &Metadata, ignore_list: V) -> bool { - // Skip filtered targets - !match (metadata.target(), ignore_list.as_ref()) { - (path, ignore) if !ignore.is_empty() => { - // Check that the module path does not match any ignore filters - ignore.iter().any(|v| path.starts_with(v.as_ref())) - } - _ => false, - } -} - ///////////////////////////////////////// // FFI Helpers @@ -75,21 +67,28 @@ macro_rules! check_err_json { #[derive(Debug, Deserialize, Serialize)] pub struct VeilidFFIConfigLoggingTerminal { pub enabled: bool, - pub level: veilid_core::VeilidLogLevel, + pub level: veilid_core::VeilidConfigLogLevel, } #[derive(Debug, Deserialize, Serialize)] pub struct VeilidFFIConfigLoggingOtlp { pub enabled: bool, - pub level: veilid_core::VeilidLogLevel, + pub level: veilid_core::VeilidConfigLogLevel, pub grpc_endpoint: String, pub service_name: String, } +#[derive(Debug, Deserialize, Serialize)] +pub struct VeilidFFIConfigLoggingApi { + pub enabled: bool, + pub level: veilid_core::VeilidConfigLogLevel, +} + #[derive(Debug, Deserialize, Serialize)] pub struct VeilidFFIConfigLogging { pub terminal: VeilidFFIConfigLoggingTerminal, pub otlp: VeilidFFIConfigLoggingOtlp, + pub api: VeilidFFIConfigLoggingApi, } #[derive(Debug, Deserialize, Serialize)] @@ -149,40 +148,24 @@ pub extern "C" fn configure_veilid_platform(platform_config: FfiStr) { .expect("failed to deserialize plaform config json"); // Set up subscriber and layers - let mut ignore_list = Vec::::new(); - for ig in veilid_core::DEFAULT_LOG_IGNORE_LIST { - ignore_list.push(ig.to_owned()); - } - let subscriber = Registry::default(); + let mut layers = Vec::new(); + let mut filters = (*FILTERS).lock(); // Terminal logger - let subscriber = subscriber.with(if platform_config.logging.terminal.enabled { - let terminal_max_log_level: level_filters::LevelFilter = platform_config - .logging - .terminal - .level - .to_tracing_level() - .into(); - - let ignore_list = ignore_list.clone(); - Some( - fmt::Layer::new() - .compact() - .with_writer(std::io::stdout) - .with_filter(terminal_max_log_level) - .with_filter(filter::FilterFn::new(move |metadata| { - logfilter(metadata, &ignore_list) - })), - ) - } else { - None - }); + if platform_config.logging.terminal.enabled { + let filter = + veilid_core::VeilidLayerFilter::new(platform_config.logging.terminal.level, None); + let layer = fmt::Layer::new() + .compact() + .with_writer(std::io::stdout) + .with_filter(filter.clone()); + filters.insert("terminal", filter); + layers.push(layer.boxed()); + }; // OpenTelemetry logger - let subscriber = subscriber.with(if platform_config.logging.otlp.enabled { - let otlp_max_log_level: level_filters::LevelFilter = - platform_config.logging.otlp.level.to_tracing_level().into(); + if platform_config.logging.otlp.enabled { let grpc_endpoint = platform_config.logging.otlp.grpc_endpoint.clone(); cfg_if! { @@ -218,21 +201,23 @@ pub extern "C" fn configure_veilid_platform(platform_config: FfiStr) { .map_err(|e| format!("failed to install OpenTelemetry tracer: {}", e)) .unwrap(); - let ignore_list = ignore_list.clone(); - Some( - tracing_opentelemetry::layer() - .with_tracer(tracer) - .with_filter(otlp_max_log_level) - .with_filter(filter::FilterFn::new(move |metadata| { - logfilter(metadata, &ignore_list) - })), - ) - } else { - None - }); + let filter = veilid_core::VeilidLayerFilter::new(platform_config.logging.otlp.level, None); + let layer = tracing_opentelemetry::layer() + .with_tracer(tracer) + .with_filter(filter.clone()); + filters.insert("otlp", filter); + layers.push(layer.boxed()); + } - // API logger (always add layer, startup will init this if it is enabled in settings) - let subscriber = subscriber.with(veilid_core::ApiTracingLayer::get()); + // API logger + if platform_config.logging.api.enabled { + let filter = veilid_core::VeilidLayerFilter::new(platform_config.logging.api.level, None); + let layer = veilid_core::ApiTracingLayer::get().with_filter(filter.clone()); + filters.insert("api", filter); + layers.push(layer.boxed()); + } + + let subscriber = subscriber.with(layers); subscriber .try_init() @@ -240,6 +225,32 @@ pub extern "C" fn configure_veilid_platform(platform_config: FfiStr) { .expect("failed to initalize ffi platform"); } +#[no_mangle] +#[instrument(level = "debug")] +pub extern "C" fn change_log_level(layer: FfiStr, log_level: FfiStr) { + // get layer to change level on + let layer = layer.into_opt_string().unwrap_or("all".to_owned()); + let layer = if layer == "all" { "".to_owned() } else { layer }; + + // get log level to change layer to + let log_level = log_level.into_opt_string(); + let log_level: veilid_core::VeilidConfigLogLevel = + veilid_core::deserialize_opt_json(log_level).unwrap(); + + // change log level on appropriate layer + let filters = (*FILTERS).lock(); + if layer.is_empty() { + // Change all layers + for f in filters.values() { + f.set_max_level(log_level); + } + } else { + // Change a specific layer + let f = filters.get(layer.as_str()).unwrap(); + f.set_max_level(log_level); + } +} + #[no_mangle] #[instrument] pub extern "C" fn startup_veilid_core(port: i64, config: FfiStr) { @@ -291,20 +302,6 @@ pub extern "C" fn get_veilid_state(port: i64) { }); } -#[no_mangle] -#[instrument(level = "debug")] -pub extern "C" fn change_api_log_level(port: i64, log_level: FfiStr) { - let log_level = log_level.into_opt_string(); - DartIsolateWrapper::new(port).spawn_result_json(async move { - let log_level: veilid_core::VeilidConfigLogLevel = - veilid_core::deserialize_opt_json(log_level)?; - //let veilid_api = get_veilid_api().await?; - //veilid_api.change_api_log_level(log_level).await; - veilid_core::ApiTracingLayer::change_api_log_level(log_level.to_veilid_log_level()); - APIRESULT_VOID - }); -} - #[no_mangle] #[instrument] pub extern "C" fn shutdown_veilid_core(port: i64) { diff --git a/veilid-server/Cargo.toml b/veilid-server/Cargo.toml index 806a7a13..49871349 100644 --- a/veilid-server/Cargo.toml +++ b/veilid-server/Cargo.toml @@ -36,7 +36,6 @@ capnp = "^0" parking_lot = "^0" capnp-rpc = "^0" config = { version = "^0", features = ["yaml"] } -failure = "^0" cfg-if = "^1" serde = "^1" serde_derive = "^1" diff --git a/veilid-server/proto/veilid-client.capnp b/veilid-server/proto/veilid-client.capnp index 5bf47382..1d4066b1 100644 --- a/veilid-server/proto/veilid-client.capnp +++ b/veilid-server/proto/veilid-client.capnp @@ -1,20 +1,24 @@ @0xd29582d26b2fb073; +struct ApiResult { + union { + ok @0 :Text; + err @1 :Text; + } +} + interface Registration {} interface VeilidServer { - register @0 (veilidClient: VeilidClient) -> (registration: Registration, state: Text); - debug @1 (what: Text) -> (output: Text); - - attach @2 (); - detach @3 (); + debug @1 (command: Text) -> (result :ApiResult); + attach @2 () -> (result :ApiResult); + detach @3 () -> (result :ApiResult); shutdown @4 (); - getState @5 () -> (state: Text); + getState @5 () -> (result :ApiResult); + changeLogLevel @6 (layer: Text, logLevel: Text) -> (result :ApiResult); } interface VeilidClient { - update @0 (veilidUpdate: Text); - } \ No newline at end of file diff --git a/veilid-server/src/client_api.rs b/veilid-server/src/client_api.rs index 348deb1d..f87df9f9 100644 --- a/veilid-server/src/client_api.rs +++ b/veilid-server/src/client_api.rs @@ -1,12 +1,14 @@ use crate::tools::*; use crate::veilid_client_capnp::*; +use crate::veilid_logs::VeilidLogs; use capnp::capability::Promise; use capnp_rpc::{pry, rpc_twoparty_capnp, twoparty, RpcSystem}; use cfg_if::*; -use failure::*; use futures_util::{future::try_join_all, FutureExt as FuturesFutureExt, StreamExt}; +use serde::*; use std::cell::RefCell; use std::collections::HashMap; +use std::fmt; use std::net::SocketAddr; use std::rc::Rc; use stop_token::future::FutureExt; @@ -14,9 +16,20 @@ use stop_token::*; use tracing::*; use veilid_core::*; -#[derive(Fail, Debug)] -#[fail(display = "Client API error: {}", _0)] -pub struct ClientAPIError(String); +// Encoding for ApiResult +fn encode_api_result( + result: &Result, + builder: &mut api_result::Builder, +) { + match result { + Ok(v) => { + builder.set_ok(&serialize_json(v)); + } + Err(e) => { + builder.set_err(&serialize_json(e)); + } + } +} // --- interface Registration --------------------------------- @@ -67,17 +80,19 @@ impl registration::Server for RegistrationImpl {} struct VeilidServerImpl { veilid_api: veilid_core::VeilidAPI, + veilid_logs: VeilidLogs, next_id: u64, pub registration_map: Rc>, } impl VeilidServerImpl { #[instrument(level = "trace", skip_all)] - pub fn new(veilid_api: veilid_core::VeilidAPI) -> Self { + pub fn new(veilid_api: veilid_core::VeilidAPI, veilid_logs: VeilidLogs) -> Self { Self { next_id: 0, registration_map: Rc::new(RefCell::new(RegistrationMap::new())), veilid_api, + veilid_logs, } } } @@ -115,13 +130,7 @@ impl veilid_server::Server for VeilidServerImpl { let mut res = results.get(); res.set_registration(registration); - let mut rpc_state = res.init_state( - state - .len() - .try_into() - .map_err(|e| ::capnp::Error::failed(format!("{:?}", e)))?, - ); - rpc_state.push_str(&state); + res.set_state(&state); Ok(()) }) @@ -135,14 +144,11 @@ impl veilid_server::Server for VeilidServerImpl { ) -> Promise<(), ::capnp::Error> { trace!("VeilidServerImpl::debug"); let veilid_api = self.veilid_api.clone(); - let what = pry!(pry!(params.get()).get_what()).to_owned(); + let command = pry!(pry!(params.get()).get_command()).to_owned(); Promise::from_future(async move { - let output = veilid_api - .debug(what) - .await - .map_err(|e| ::capnp::Error::failed(format!("{:?}", e)))?; - results.get().set_output(output.as_str()); + let result = veilid_api.debug(command).await; + encode_api_result(&result, &mut results.get().init_result()); Ok(()) }) } @@ -151,15 +157,14 @@ impl veilid_server::Server for VeilidServerImpl { fn attach( &mut self, _params: veilid_server::AttachParams, - mut _results: veilid_server::AttachResults, + mut results: veilid_server::AttachResults, ) -> Promise<(), ::capnp::Error> { trace!("VeilidServerImpl::attach"); let veilid_api = self.veilid_api.clone(); Promise::from_future(async move { - veilid_api - .attach() - .await - .map_err(|e| ::capnp::Error::failed(format!("{:?}", e))) + let result = veilid_api.attach().await; + encode_api_result(&result, &mut results.get().init_result()); + Ok(()) }) } @@ -167,15 +172,14 @@ impl veilid_server::Server for VeilidServerImpl { fn detach( &mut self, _params: veilid_server::DetachParams, - mut _results: veilid_server::DetachResults, + mut results: veilid_server::DetachResults, ) -> Promise<(), ::capnp::Error> { trace!("VeilidServerImpl::detach"); let veilid_api = self.veilid_api.clone(); Promise::from_future(async move { - veilid_api - .detach() - .await - .map_err(|e| ::capnp::Error::failed(format!("{:?}", e))) + let result = veilid_api.detach().await; + encode_api_result(&result, &mut results.get().init_result()); + Ok(()) }) } @@ -208,24 +212,30 @@ impl veilid_server::Server for VeilidServerImpl { trace!("VeilidServerImpl::get_state"); let veilid_api = self.veilid_api.clone(); Promise::from_future(async move { - let state = veilid_api - .get_state() - .await - .map_err(|e| ::capnp::Error::failed(format!("{:?}", e)))?; - let state = serialize_json(state); - - let res = results.get(); - let mut rpc_state = res.init_state( - state - .len() - .try_into() - .map_err(|e| ::capnp::Error::failed(format!("{:?}", e)))?, - ); - rpc_state.push_str(&state); - + let result = veilid_api.get_state().await; + encode_api_result(&result, &mut results.get().init_result()); Ok(()) }) } + + #[instrument(level = "trace", skip_all)] + fn change_log_level( + &mut self, + params: veilid_server::ChangeLogLevelParams, + mut results: veilid_server::ChangeLogLevelResults, + ) -> Promise<(), ::capnp::Error> { + trace!("VeilidServerImpl::change_log_level"); + + let layer = pry!(pry!(params.get()).get_layer()).to_owned(); + let log_level_json = pry!(pry!(params.get()).get_log_level()).to_owned(); + let log_level: veilid_core::VeilidConfigLogLevel = + pry!(veilid_core::deserialize_json(&log_level_json) + .map_err(|e| ::capnp::Error::failed(format!("{:?}", e)))); + + let result = self.veilid_logs.change_log_level(layer, log_level); + encode_api_result(&result, &mut results.get().init_result()); + Promise::ok(()) + } } // --- Client API Server-Side --------------------------------- @@ -235,6 +245,7 @@ type ClientApiAllFuturesJoinHandle = struct ClientApiInner { veilid_api: veilid_core::VeilidAPI, + veilid_logs: VeilidLogs, registration_map: Rc>, stop: Option, join_handle: Option, @@ -246,10 +257,11 @@ pub struct ClientApi { impl ClientApi { #[instrument(level = "trace", skip_all)] - pub fn new(veilid_api: veilid_core::VeilidAPI) -> Rc { + pub fn new(veilid_api: veilid_core::VeilidAPI, veilid_logs: VeilidLogs) -> Rc { Rc::new(Self { inner: RefCell::new(ClientApiInner { veilid_api, + veilid_logs, registration_map: Rc::new(RefCell::new(RegistrationMap::new())), stop: Some(StopSource::new()), join_handle: None, @@ -393,7 +405,10 @@ impl ClientApi { #[instrument(level = "trace", skip(self))] pub fn run(self: Rc, bind_addrs: Vec) { // Create client api VeilidServer - let veilid_server_impl = VeilidServerImpl::new(self.inner.borrow().veilid_api.clone()); + let veilid_server_impl = VeilidServerImpl::new( + self.inner.borrow().veilid_api.clone(), + self.inner.borrow().veilid_logs.clone(), + ); self.inner.borrow_mut().registration_map = veilid_server_impl.registration_map.clone(); // Make a client object for the server to send to each rpc client diff --git a/veilid-server/src/main.rs b/veilid-server/src/main.rs index 48ae3141..be0e6d12 100644 --- a/veilid-server/src/main.rs +++ b/veilid-server/src/main.rs @@ -62,9 +62,9 @@ fn main() -> Result<(), String> { // run the server to set the node id and quit return block_on(async { // Init combined console/file logger - let _logs = VeilidLogs::setup(settings.clone())?; + let veilid_logs = VeilidLogs::setup(settings.clone())?; - run_veilid_server(settings, server_mode).await + run_veilid_server(settings, server_mode, veilid_logs).await }) .map(|v| { println!("{}", success); @@ -96,8 +96,8 @@ fn main() -> Result<(), String> { // Run the server loop block_on(async { // Init combined console/file logger - let _logs = VeilidLogs::setup(settings.clone())?; + let veilid_logs = VeilidLogs::setup(settings.clone())?; - run_veilid_server(settings, server_mode).await + run_veilid_server(settings, server_mode, veilid_logs).await }) } diff --git a/veilid-server/src/server.rs b/veilid-server/src/server.rs index 6f76ff7e..b035deda 100644 --- a/veilid-server/src/server.rs +++ b/veilid-server/src/server.rs @@ -1,6 +1,7 @@ use crate::client_api; use crate::settings::*; use crate::tools::*; +use crate::veilid_logs::*; use flume::{unbounded, Receiver, Sender}; use lazy_static::*; use parking_lot::Mutex; @@ -29,14 +30,19 @@ pub fn shutdown() { } } -pub async fn run_veilid_server(settings: Settings, server_mode: ServerMode) -> Result<(), String> { - run_veilid_server_internal(settings, server_mode).await +pub async fn run_veilid_server( + settings: Settings, + server_mode: ServerMode, + veilid_logs: VeilidLogs, +) -> Result<(), String> { + run_veilid_server_internal(settings, server_mode, veilid_logs).await } #[instrument(err, skip_all)] pub async fn run_veilid_server_internal( settings: Settings, server_mode: ServerMode, + veilid_logs: VeilidLogs, ) -> Result<(), String> { trace!(?settings, ?server_mode); @@ -63,7 +69,7 @@ pub async fn run_veilid_server_internal( // Start client api if one is requested let mut capi = if settingsr.client_api.enabled && matches!(server_mode, ServerMode::Normal) { - let some_capi = client_api::ClientApi::new(veilid_api.clone()); + let some_capi = client_api::ClientApi::new(veilid_api.clone(), veilid_logs.clone()); some_capi .clone() .run(settingsr.client_api.listen_address.addrs.clone()); @@ -156,5 +162,9 @@ pub async fn run_veilid_server_internal( // Wait for update receiver to exit let _ = update_receiver_jh.await; + // Finally, drop logs + // this is explicit to ensure we don't accidentally drop them too soon via a move + drop(veilid_logs); + out } diff --git a/veilid-server/src/settings.rs b/veilid-server/src/settings.rs index 97eea6bc..b3154b61 100644 --- a/veilid-server/src/settings.rs +++ b/veilid-server/src/settings.rs @@ -192,6 +192,7 @@ pub fn load_config( #[derive(Copy, Clone, Debug, PartialEq)] pub enum LogLevel { + Off, Error, Warn, Info, @@ -205,6 +206,7 @@ impl<'de> serde::Deserialize<'de> for LogLevel { { let s = String::deserialize(deserializer)?; match s.to_ascii_lowercase().as_str() { + "off" => Ok(LogLevel::Off), "error" => Ok(LogLevel::Error), "warn" => Ok(LogLevel::Warn), "info" => Ok(LogLevel::Info), @@ -223,6 +225,7 @@ impl serde::Serialize for LogLevel { S: serde::Serializer, { let s = match self { + LogLevel::Off => "off", LogLevel::Error => "error", LogLevel::Warn => "warn", LogLevel::Info => "info", @@ -233,13 +236,14 @@ impl serde::Serialize for LogLevel { } } -pub fn convert_loglevel(log_level: LogLevel) -> veilid_core::VeilidLogLevel { +pub fn convert_loglevel(log_level: LogLevel) -> veilid_core::VeilidConfigLogLevel { match log_level { - LogLevel::Error => veilid_core::VeilidLogLevel::Error, - LogLevel::Warn => veilid_core::VeilidLogLevel::Warn, - LogLevel::Info => veilid_core::VeilidLogLevel::Info, - LogLevel::Debug => veilid_core::VeilidLogLevel::Debug, - LogLevel::Trace => veilid_core::VeilidLogLevel::Trace, + LogLevel::Off => veilid_core::VeilidConfigLogLevel::Off, + LogLevel::Error => veilid_core::VeilidConfigLogLevel::Error, + LogLevel::Warn => veilid_core::VeilidConfigLogLevel::Warn, + LogLevel::Info => veilid_core::VeilidConfigLogLevel::Info, + LogLevel::Debug => veilid_core::VeilidConfigLogLevel::Debug, + LogLevel::Trace => veilid_core::VeilidConfigLogLevel::Trace, } } @@ -1016,13 +1020,6 @@ impl Settings { } else { format!("subnode{}", inner.testing.subnode_index) })), - "api_log_level" => Ok(Box::new(if inner.logging.api.enabled { - veilid_core::VeilidConfigLogLevel::from_veilid_log_level(Some( - convert_loglevel(inner.logging.api.level), - )) - } else { - veilid_core::VeilidConfigLogLevel::Off - })), "capabilities.protocol_udp" => Ok(Box::new(true)), "capabilities.protocol_connect_tcp" => Ok(Box::new(true)), "capabilities.protocol_accept_tcp" => Ok(Box::new(true)), diff --git a/veilid-server/src/unix.rs b/veilid-server/src/unix.rs index 331e64eb..5ba7fa5b 100644 --- a/veilid-server/src/unix.rs +++ b/veilid-server/src/unix.rs @@ -98,7 +98,7 @@ pub fn run_daemon(settings: Settings, _matches: ArgMatches) -> Result<(), String // Now, run the server block_on(async { // Init combined console/file logger - let _logs = VeilidLogs::setup(settings.clone())?; + let veilid_logs = VeilidLogs::setup(settings.clone())?; // Daemonize daemon @@ -112,7 +112,7 @@ pub fn run_daemon(settings: Settings, _matches: ArgMatches) -> Result<(), String let signals_task = spawn(handle_signals(signals)); - let res = run_veilid_server(settings, ServerMode::Normal).await; + let res = run_veilid_server(settings, ServerMode::Normal, veilid_logs).await; // Terminate the signal stream. handle.close(); diff --git a/veilid-server/src/veilid_logs.rs b/veilid-server/src/veilid_logs.rs index 6877c9f0..9bfaaa15 100644 --- a/veilid-server/src/veilid_logs.rs +++ b/veilid-server/src/veilid_logs.rs @@ -3,25 +3,22 @@ use cfg_if::*; use opentelemetry::sdk::*; use opentelemetry::*; use opentelemetry_otlp::WithExportConfig; +use parking_lot::*; +use std::collections::BTreeMap; use std::path::*; -use tracing::*; +use std::sync::Arc; use tracing_appender::*; use tracing_subscriber::prelude::*; use tracing_subscriber::*; -pub struct VeilidLogs { - pub guard: Option, +struct VeilidLogsInner { + _guard: Option, + filters: BTreeMap<&'static str, veilid_core::VeilidLayerFilter>, } -fn logfilter, V: AsRef<[T]>>(metadata: &Metadata, ignore_list: V) -> bool { - // Skip filtered targets - !match (metadata.target(), ignore_list.as_ref()) { - (path, ignore) if !ignore.is_empty() => { - // Check that the module path does not match any ignore filters - ignore.iter().any(|v| path.starts_with(v.as_ref())) - } - _ => false, - } +#[derive(Clone)] +pub struct VeilidLogs { + inner: Arc>, } impl VeilidLogs { @@ -29,39 +26,26 @@ impl VeilidLogs { let settingsr = settings.read(); // Set up subscriber and layers - let mut ignore_list = Vec::::new(); - for ig in veilid_core::DEFAULT_LOG_IGNORE_LIST { - ignore_list.push(ig.to_owned()); - } - let subscriber = Registry::default(); + let mut layers = Vec::new(); + let mut filters = BTreeMap::new(); // Terminal logger - let subscriber = subscriber.with(if settingsr.logging.terminal.enabled { - let terminal_max_log_level: level_filters::LevelFilter = - convert_loglevel(settingsr.logging.terminal.level) - .to_tracing_level() - .into(); - let ignore_list = ignore_list.clone(); - Some( - fmt::Layer::new() - .compact() - .with_writer(std::io::stdout) - .with_filter(terminal_max_log_level) - .with_filter(filter::FilterFn::new(move |metadata| { - logfilter(metadata, &ignore_list) - })), - ) - } else { - None - }); + if settingsr.logging.terminal.enabled { + let filter = veilid_core::VeilidLayerFilter::new( + convert_loglevel(settingsr.logging.terminal.level), + None, + ); + let layer = fmt::Layer::new() + .compact() + .with_writer(std::io::stdout) + .with_filter(filter.clone()); + filters.insert("terminal", filter); + layers.push(layer.boxed()); + } // OpenTelemetry logger - let subscriber = subscriber.with(if settingsr.logging.otlp.enabled { - let otlp_max_log_level: level_filters::LevelFilter = - convert_loglevel(settingsr.logging.otlp.level) - .to_tracing_level() - .into(); + if settingsr.logging.otlp.enabled { let grpc_endpoint = settingsr.logging.otlp.grpc_endpoint.name.clone(); cfg_if! { @@ -95,27 +79,20 @@ impl VeilidLogs { .install_batch(batch) .map_err(|e| format!("failed to install OpenTelemetry tracer: {}", e))?; - let ignore_list = ignore_list.clone(); - Some( - tracing_opentelemetry::layer() - .with_tracer(tracer) - .with_filter(otlp_max_log_level) - .with_filter(filter::FilterFn::new(move |metadata| { - logfilter(metadata, &ignore_list) - })), - ) - } else { - None - }); + let filter = veilid_core::VeilidLayerFilter::new( + convert_loglevel(settingsr.logging.otlp.level), + None, + ); + let layer = tracing_opentelemetry::layer() + .with_tracer(tracer) + .with_filter(filter.clone()); + filters.insert("otlp", filter); + layers.push(layer.boxed()); + } // File logger let mut guard = None; - let subscriber = subscriber.with(if settingsr.logging.file.enabled { - let file_max_log_level: level_filters::LevelFilter = - convert_loglevel(settingsr.logging.file.level) - .to_tracing_level() - .into(); - + if settingsr.logging.file.enabled { let log_path = Path::new(&settingsr.logging.file.path); let full_path = std::env::current_dir() .unwrap_or(PathBuf::from(MAIN_SEPARATOR.to_string())) @@ -140,50 +117,88 @@ impl VeilidLogs { tracing_appender::non_blocking(appender); guard = Some(non_blocking_guard); - let ignore_list = ignore_list.clone(); - Some( - fmt::Layer::new() - .compact() - .with_writer(non_blocking_appender) - .with_filter(file_max_log_level) - .with_filter(filter::FilterFn::new(move |metadata| { - logfilter(metadata, &ignore_list) - })), - ) - } else { - None - }); + let filter = veilid_core::VeilidLayerFilter::new( + convert_loglevel(settingsr.logging.file.level), + None, + ); + let layer = fmt::Layer::new() + .compact() + .with_writer(non_blocking_appender) + .with_filter(filter.clone()); + + filters.insert("file", filter); + layers.push(layer.boxed()); + } // API logger - let subscriber = subscriber.with(if settingsr.logging.api.enabled { - // Get layer from veilid core, filtering is done by ApiTracingLayer automatically - Some(veilid_core::ApiTracingLayer::get()) - } else { - None - }); + if settingsr.logging.api.enabled { + let filter = veilid_core::VeilidLayerFilter::new( + convert_loglevel(settingsr.logging.api.level), + None, + ); + let layer = veilid_core::ApiTracingLayer::get().with_filter(filter.clone()); + filters.insert("api", filter); + layers.push(layer.boxed()); + } // Systemd Journal logger cfg_if! { if #[cfg(target_os = "linux")] { - let subscriber = subscriber.with(if settingsr.logging.system.enabled { - let ignore_list = ignore_list.clone(); - let system_max_log_level: level_filters::LevelFilter = convert_loglevel(settingsr.logging.system.level).to_tracing_level().into(); - Some(tracing_journald::layer().map_err(|e| format!("failed to set up journald logging: {}", e))? - .with_filter(system_max_log_level) - .with_filter(filter::FilterFn::new(move |metadata| { - logfilter(metadata, &ignore_list) - })) - ) - } else { - None - }); + if settingsr.logging.system.enabled { + let filter = veilid_core::VeilidLayerFilter::new( + convert_loglevel(settingsr.logging.system.level), + None, + ); + let layer =tracing_journald::layer().map_err(|e| format!("failed to set up journald logging: {}", e))? + .with_filter(filter.clone()); + filters.insert("system", filter); + layers.push(layer.boxed()); + } } } + let subscriber = subscriber.with(layers); subscriber .try_init() .map_err(|e| format!("failed to initialize logging: {}", e))?; - Ok(VeilidLogs { guard }) + Ok(VeilidLogs { + inner: Arc::new(Mutex::new(VeilidLogsInner { + _guard: guard, + filters, + })), + }) + } + + pub fn change_log_level( + &self, + layer: String, + log_level: veilid_core::VeilidConfigLogLevel, + ) -> Result<(), veilid_core::VeilidAPIError> { + // get layer to change level on + let layer = if layer == "all" { "".to_owned() } else { layer }; + + // change log level on appropriate layer + let inner = self.inner.lock(); + if layer.is_empty() { + // Change all layers + for f in inner.filters.values() { + f.set_max_level(log_level); + } + } else { + // Change a specific layer + let f = match inner.filters.get(layer.as_str()) { + Some(f) => f, + None => { + return Err(veilid_core::VeilidAPIError::InvalidArgument { + context: "change_log_level".to_owned(), + argument: "layer".to_owned(), + value: layer, + }); + } + }; + f.set_max_level(log_level); + } + Ok(()) } } diff --git a/veilid-wasm/src/lib.rs b/veilid-wasm/src/lib.rs index b7e3e76a..db22a989 100644 --- a/veilid-wasm/src/lib.rs +++ b/veilid-wasm/src/lib.rs @@ -32,22 +32,12 @@ pub fn setup() -> () { SETUP_ONCE.call_once(|| {}); } -// Log filtering -fn logfilter, V: AsRef<[T]>>(metadata: &Metadata, ignore_list: V) -> bool { - // Skip filtered targets - !match (metadata.target(), ignore_list.as_ref()) { - (path, ignore) if !ignore.is_empty() => { - // Check that the module path does not match any ignore filters - ignore.iter().any(|v| path.starts_with(v.as_ref())) - } - _ => false, - } -} - // API Singleton lazy_static! { static ref VEILID_API: SendWrapper>> = SendWrapper::new(RefCell::new(None)); + static ref FILTERS: SendWrapper>> = + SendWrapper::new(RefCell::new(BTreeMap::new())); } fn get_veilid_api() -> Result { @@ -123,9 +113,16 @@ pub struct VeilidWASMConfigLoggingPerformance { pub logs_in_console: bool, } +#[derive(Debug, Deserialize, Serialize)] +pub struct VeilidWASMConfigLoggingAPI { + pub enabled: bool, + pub level: veilid_core::VeilidLogLevel, +} + #[derive(Debug, Deserialize, Serialize)] pub struct VeilidWASMConfigLogging { pub performance: VeilidWASMConfigLoggingPerformance, + pub api: VeilidWASMConfigLoggingAPI, } #[derive(Debug, Deserialize, Serialize)] @@ -146,48 +143,61 @@ pub fn configure_veilid_platform(platform_config: String) { .expect("failed to deserialize plaform config json"); // Set up subscriber and layers - let mut ignore_list = Vec::::new(); - for ig in veilid_core::DEFAULT_LOG_IGNORE_LIST { - ignore_list.push(ig.to_owned()); - } - let subscriber = Registry::default(); + let mut layers = Vec::new(); + let handles = (*FILTER_RELOAD_HANDLES).borrow_mut(); // Performance logger - let subscriber = subscriber.with(if platform_config.logging.performance.enabled { - let performance_max_log_level = - platform_config.logging.performance.level.to_tracing_level(); - - let ignore_list = ignore_list.clone(); - Some( - WASMLayer::new( - WASMLayerConfigBuilder::new() - .set_report_logs_in_timings(platform_config.logging.performance.logs_in_timings) - .set_console_config(if platform_config.logging.performance.logs_in_console { - ConsoleConfig::ReportWithConsoleColor - } else { - ConsoleConfig::NoReporting - }) - .set_max_level(performance_max_log_level) - .build(), - ) - .with_filter(filter::FilterFn::new(move |metadata| { - logfilter(metadata, &ignore_list) - })), + if platform_config.logging.performance.enabled { + let filter = + veilid_core::VeilidLayerFilter::new(platform_config.logging.performance.level, None); + let layer = WASMLayer::new( + WASMLayerConfigBuilder::new() + .set_report_logs_in_timings(platform_config.logging.performance.logs_in_timings) + .set_console_config(if platform_config.logging.performance.logs_in_console { + ConsoleConfig::ReportWithConsoleColor + } else { + ConsoleConfig::NoReporting + }) + .build(), ) - } else { - None - }); + .with_filter(filter.clone()); + handles.insert("performance", filter); + layers.push(layer.boxed()); + }; - // API logger (always add layer, startup will init this if it is enabled in settings) - let subscriber = subscriber.with(veilid_core::ApiTracingLayer::get()); + // API logger + if platform_config.logging.api.enabled { + let filter = veilid_core::VeilidLayerFilter::new(platform_config.logging.api.level, None); + let layer = veilid_core::ApiTracingLayer::get().with_filter(filter.clone()); + handles.insert("api", filter); + layers.push(layer.boxed()); + } + let subscriber = subscriber.with(layers); subscriber .try_init() .map_err(|e| format!("failed to initialize logging: {}", e)) .expect("failed to initalize WASM platform"); } +#[wasm_bindgen()] +pub fn change_log_level(layer: String, log_level: String) { + let layer = if layer == "all" { "".to_owned() } else { layer }; + let log_level: veilid_core::VeilidConfigLogLevel = deserialize_json(&log_level).unwrap(); + let filters = (*FILTERS).borrow(); + if layer.is_empty() { + // Change all layers + for f in filters.values() { + f.set_max_level(log_level); + } + } else { + // Change a specific layer + let f = filters.get(layer.as_str()).unwrap(); + f.set_max_level(log_level); + } +} + #[wasm_bindgen()] pub fn startup_veilid_core(update_callback: Function, json_config: String) -> Promise { wrap_api_future(async move { @@ -221,17 +231,6 @@ pub fn get_veilid_state() -> Promise { }) } -#[wasm_bindgen()] -pub fn change_api_log_level(log_level: String) -> Promise { - wrap_api_future(async move { - let log_level: veilid_core::VeilidConfigLogLevel = deserialize_json(&log_level)?; - //let veilid_api = get_veilid_api()?; - //veilid_api.change_api_log_level(log_level).await; - veilid_core::ApiTracingLayer::change_api_log_level(log_level.to_veilid_log_level()); - APIRESULT_UNDEFINED - }) -} - #[wasm_bindgen()] pub fn shutdown_veilid_core() -> Promise { wrap_api_future(async move {