refactor checkpoint

This commit is contained in:
John Smith
2022-06-07 21:31:05 -04:00
parent 182af30b97
commit 1d8c63786a
28 changed files with 822 additions and 626 deletions
-150
View File
@@ -1,150 +0,0 @@
use crate::core_context::*;
use crate::veilid_api::*;
use crate::xx::*;
use log::{set_boxed_logger, set_max_level, Level, LevelFilter, Log, Metadata, Record};
use once_cell::sync::OnceCell;
cfg_if! {
if #[cfg(target_arch = "wasm32")] {
use send_wrapper::*;
struct ApiLoggerInner {
level: LevelFilter,
filter_ignore: Cow<'static, [Cow<'static, str>]>,
update_callback: SendWrapper<UpdateCallback>,
}
} else {
struct ApiLoggerInner {
level: LevelFilter,
filter_ignore: Cow<'static, [Cow<'static, str>]>,
update_callback: UpdateCallback,
}
}
}
#[derive(Clone)]
pub struct ApiLogger {
inner: Arc<Mutex<Option<ApiLoggerInner>>>,
}
static API_LOGGER: OnceCell<ApiLogger> = OnceCell::new();
impl ApiLogger {
fn new_inner(level: LevelFilter, update_callback: UpdateCallback) -> ApiLoggerInner {
cfg_if! {
if #[cfg(target_arch = "wasm32")] {
ApiLoggerInner {
level,
filter_ignore: Default::default(),
update_callback: SendWrapper::new(update_callback),
}
} else {
ApiLoggerInner {
level,
filter_ignore: Default::default(),
update_callback,
}
}
}
}
pub async fn init(log_level: LevelFilter, update_callback: UpdateCallback) {
set_max_level(log_level);
let api_logger = API_LOGGER.get_or_init(|| {
let api_logger = ApiLogger {
inner: Arc::new(Mutex::new(None)),
};
set_boxed_logger(Box::new(api_logger.clone())).expect("failed to set api logger");
api_logger
});
let apilogger_inner = Some(Self::new_inner(log_level, update_callback));
*api_logger.inner.lock() = apilogger_inner;
}
pub async fn terminate() {
if let Some(api_logger) = API_LOGGER.get() {
let mut inner = api_logger.inner.lock();
*inner = None;
// Clear everything and we're done
set_max_level(LevelFilter::Off);
}
}
pub fn change_log_level(log_level: LevelFilter) {
if let Some(api_logger) = API_LOGGER.get() {
if let Some(inner) = &mut *api_logger.inner.lock() {
set_max_level(log_level);
inner.level = log_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 Log for ApiLogger {
fn enabled(&self, metadata: &Metadata<'_>) -> bool {
if let Some(inner) = &mut *self.inner.lock() {
return metadata.level() <= inner.level;
}
false
}
fn log(&self, record: &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();
if level <= inner.level {
let ll = VeilidLogLevel::from_log_level(level);
let file = record.file().unwrap_or("<unknown>");
let loc = if level >= Level::Debug {
if let Some(line) = record.line() {
format!("[{}:{}] ", file, line)
} else {
format!("[{}:<unknown>] ", file)
}
} else {
"".to_owned()
};
let tgt = if record.target().is_empty() {
"".to_owned()
} else {
format!("{}: ", record.target())
};
let s = format!("{}{}{}", tgt, loc, record.args());
(inner.update_callback)(VeilidUpdate::Log(VeilidStateLog {
log_level: ll,
message: s,
}))
}
}
}
fn flush(&self) {
// always flushes
}
}
+310
View File
@@ -0,0 +1,310 @@
use crate::core_context::*;
use crate::veilid_api::*;
use crate::xx::*;
use core::fmt::Write;
use once_cell::sync::OnceCell;
use tracing_subscriber::*;
cfg_if! {
if #[cfg(target_arch = "wasm32")] {
use send_wrapper::*;
struct ApiLoggerInner {
max_level: Option<VeilidLogLevel>,
filter_ignore: Cow<'static, [Cow<'static, str>]>,
update_callback: SendWrapper<UpdateCallback>,
}
} else {
struct ApiLoggerInner {
max_level: Option<VeilidLogLevel>,
filter_ignore: Cow<'static, [Cow<'static, str>]>,
update_callback: UpdateCallback,
}
}
}
#[derive(Clone)]
pub struct ApiTracingLayer {
inner: Arc<Mutex<Option<ApiLoggerInner>>>,
}
static API_LOGGER: OnceCell<ApiTracingLayer> = OnceCell::new();
impl ApiTracingLayer {
fn new_inner(
max_level: Option<VeilidLogLevel>,
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,
}
}
}
}
pub async fn init(max_level: Option<VeilidLogLevel>, 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));
*api_logger.inner.lock() = apilogger_inner;
}
pub async fn terminate() {
if let Some(api_logger) = API_LOGGER.get() {
let mut inner = api_logger.inner.lock();
*inner = None;
}
}
pub fn get() -> ApiTracingLayer {
API_LOGGER
.get_or_init(|| ApiTracingLayer {
inner: Arc::new(Mutex::new(None)),
})
.clone()
}
pub fn change_api_log_level(max_level: Option<VeilidLogLevel>) {
if let Some(api_logger) = API_LOGGER.get() {
if let Some(inner) = &mut *api_logger.inner.lock() {
*inner = Self::new_inner(max_level, inner.update_callback.clone());
}
}
}
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);
}
}
}
}
fn display_current_thread_id() -> String {
cfg_if! {
if #[cfg(target_arch = "wasm32")] {
"".to_owned()
} else {
format!("({}:{:?})",
if let Some(n) = async_std::task::current().name() {
n.to_string()
}
else {
async_std::task::current().id().to_string()
},
std::thread::current().id()
)
}
}
}
impl<S: Subscriber + for<'a> registry::LookupSpan<'a>> Layer<S> 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<'_>,
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();
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 origin = meta
.file()
.and_then(|file| meta.line().map(|ln| format!("{}:{}", file, ln)))
.unwrap_or_default();
let message = format!("{}{} {}", origin, display_current_thread_id(), recorder);
(inner.update_callback)(VeilidUpdate::Log(VeilidStateLog {
log_level,
message,
}))
}
}
}
}
}
struct StringRecorder {
display: String,
is_following_args: bool,
}
impl StringRecorder {
fn new() -> Self {
StringRecorder {
display: String::new(),
is_following_args: false,
}
}
}
impl tracing::field::Visit for StringRecorder {
fn record_debug(&mut self, field: &tracing::field::Field, value: &dyn core::fmt::Debug) {
if field.name() == "message" {
if !self.display.is_empty() {
self.display = format!("{:?}\n{}", value, self.display)
} else {
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();
}
}
}
impl core::fmt::Display for StringRecorder {
fn fmt(&self, mut f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result {
if !self.display.is_empty() {
write!(&mut f, " {}", self.display)
} else {
Ok(())
}
}
}
impl core::default::Default for StringRecorder {
fn default() -> Self {
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("<unknown>");
let loc = if level >= log::Level::Debug {
if let Some(line) = record.line() {
format!("[{}:{}] ", file, line)
} else {
format!("[{}:<unknown>] ", 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
}
}
+10 -6
View File
@@ -1,4 +1,4 @@
use crate::api_logger::*;
use crate::api_tracing_layer::*;
use crate::attachment_manager::*;
use crate::dht::Crypto;
use crate::intf::*;
@@ -60,11 +60,15 @@ impl ServicesContext {
}
pub async fn startup(&mut self) -> Result<(), VeilidAPIError> {
let log_level: VeilidConfigLogLevel = self.config.get().log_level;
if log_level != VeilidConfigLogLevel::Off {
ApiLogger::init(log_level.to_level_filter(), self.update_callback.clone()).await;
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 {
ApiLogger::add_filter_ignore_str(ig);
ApiTracingLayer::add_filter_ignore_str(ig);
}
info!("Veilid logging initialized");
}
@@ -154,7 +158,7 @@ impl ServicesContext {
info!("Veilid API shutdown complete");
// api logger terminate is idempotent
ApiLogger::terminate().await;
ApiTracingLayer::terminate().await;
// send final shutdown update
(self.update_callback)(VeilidUpdate::Shutdown);
+2 -1
View File
@@ -4,7 +4,7 @@
#[macro_use]
extern crate alloc;
mod api_logger;
mod api_tracing_layer;
mod attachment_manager;
mod callback_state_machine;
mod core_context;
@@ -21,6 +21,7 @@ mod veilid_rng;
#[macro_use]
pub mod xx;
pub use self::api_tracing_layer::ApiTracingLayer;
pub use self::attachment_manager::AttachmentState;
pub use self::core_context::{api_startup, api_startup_json, UpdateCallback};
pub use self::veilid_api::*;
@@ -169,7 +169,7 @@ fn config_callback(key: String) -> ConfigCallbackReturn {
match key.as_str() {
"program_name" => Ok(Box::new(String::from("Veilid"))),
"namespace" => Ok(Box::new(String::from(""))),
"log_level" => Ok(Box::new(VeilidConfigLogLevel::Off)),
"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)),
@@ -291,7 +291,7 @@ pub async fn test_config() {
let inner = vc.get();
assert_eq!(inner.program_name, String::from("Veilid"));
assert_eq!(inner.namespace, String::from(""));
assert_eq!(inner.log_level, VeilidConfigLogLevel::Off);
assert_eq!(inner.api_log_level, VeilidConfigLogLevel::Off);
assert_eq!(inner.capabilities.protocol_udp, true);
assert_eq!(inner.capabilities.protocol_connect_tcp, true);
assert_eq!(inner.capabilities.protocol_accept_tcp, true);
+20 -15
View File
@@ -1,7 +1,9 @@
#![allow(dead_code)]
mod debug;
mod serialize_helpers;
pub use debug::*;
pub use serialize_helpers::*;
use crate::*;
@@ -21,6 +23,7 @@ pub use network_manager::NetworkManager;
pub use routing_table::RoutingTable;
pub use rpc_processor::StatusAnswer;
use api_tracing_layer::*;
use core::fmt;
use core_context::{api_shutdown, VeilidCoreContext};
use enumset::*;
@@ -146,7 +149,7 @@ macro_rules! parse_error {
/////////////////////////////////////////////////////////////////////////////////////////////////////
#[derive(Debug, Clone, Copy, Serialize, Deserialize)]
#[derive(Debug, Clone, PartialEq, Eq, PartialOrd, Ord, Copy, Serialize, Deserialize)]
pub enum VeilidLogLevel {
Error = 1,
Warn,
@@ -156,13 +159,22 @@ pub enum VeilidLogLevel {
}
impl VeilidLogLevel {
pub fn from_tracing_level(level: tracing::Level) -> VeilidLogLevel {
match level {
tracing::Level::ERROR => VeilidLogLevel::Error,
tracing::Level::WARN => VeilidLogLevel::Warn,
tracing::Level::INFO => VeilidLogLevel::Info,
tracing::Level::DEBUG => VeilidLogLevel::Debug,
tracing::Level::TRACE => VeilidLogLevel::Trace,
}
}
pub fn from_log_level(level: log::Level) -> VeilidLogLevel {
match level {
Level::Error => VeilidLogLevel::Error,
Level::Warn => VeilidLogLevel::Warn,
Level::Info => VeilidLogLevel::Info,
Level::Debug => VeilidLogLevel::Debug,
Level::Trace => VeilidLogLevel::Trace,
log::Level::Error => VeilidLogLevel::Error,
log::Level::Warn => VeilidLogLevel::Warn,
log::Level::Info => VeilidLogLevel::Info,
log::Level::Debug => VeilidLogLevel::Debug,
log::Level::Trace => VeilidLogLevel::Trace,
}
}
}
@@ -1804,15 +1816,8 @@ impl VeilidAPI {
}
// Change api logging level if it is enabled
pub async fn change_log_level(&self, log_level: VeilidConfigLogLevel) {
cfg_if! {
if #[cfg(target_arch = "wasm32")] {
set_max_level(log_level.to_level_filter());
} else {
use api_logger::ApiLogger;
ApiLogger::change_log_level(log_level.to_level_filter());
}
}
pub async fn change_api_log_level(&self, log_level: VeilidConfigLogLevel) {
ApiTracingLayer::change_api_log_level(log_level.to_veilid_log_level());
}
////////////////////////////////////////////////////////////////
@@ -0,0 +1,24 @@
use super::*;
pub fn deserialize_json<'a, T: de::Deserialize<'a>>(
arg: &'a str,
) -> Result<T, super::VeilidAPIError> {
serde_json::from_str(arg).map_err(|e| VeilidAPIError::ParseError {
message: e.to_string(),
value: String::new(),
})
}
pub fn deserialize_opt_json<T: de::DeserializeOwned>(
arg: Option<String>,
) -> Result<T, VeilidAPIError> {
let arg = arg.ok_or_else(|| VeilidAPIError::ParseError {
message: "invalid null string".to_owned(),
value: String::new(),
})?;
deserialize_json(&arg)
}
pub fn serialize_json<T: Serialize>(val: T) -> String {
serde_json::to_string(&val).expect("failed to serialize json value")
}
+21 -13
View File
@@ -1,7 +1,5 @@
use crate::dht::*;
use crate::intf;
use crate::xx::*;
use crate::*;
use serde::*;
////////////////////////////////////////////////////////////////////////////////////////////////
@@ -195,14 +193,24 @@ pub enum VeilidConfigLogLevel {
}
impl VeilidConfigLogLevel {
pub fn to_level_filter(&self) -> LevelFilter {
pub fn to_veilid_log_level(&self) -> Option<VeilidLogLevel> {
match self {
Self::Off => LevelFilter::Off,
Self::Error => LevelFilter::Error,
Self::Warn => LevelFilter::Warn,
Self::Info => LevelFilter::Info,
Self::Debug => LevelFilter::Debug,
Self::Trace => LevelFilter::Trace,
Self::Off => None,
Self::Error => Some(VeilidLogLevel::Error),
Self::Warn => Some(VeilidLogLevel::Warn),
Self::Info => Some(VeilidLogLevel::Info),
Self::Debug => Some(VeilidLogLevel::Debug),
Self::Trace => Some(VeilidLogLevel::Trace),
}
}
pub fn from_veilid_log_level(level: Option<VeilidLogLevel>) -> Self {
match level {
None => Self::Off,
Some(VeilidLogLevel::Error) => Self::Error,
Some(VeilidLogLevel::Warn) => Self::Warn,
Some(VeilidLogLevel::Info) => Self::Info,
Some(VeilidLogLevel::Debug) => Self::Debug,
Some(VeilidLogLevel::Trace) => Self::Trace,
}
}
}
@@ -216,7 +224,7 @@ impl Default for VeilidConfigLogLevel {
pub struct VeilidConfigInner {
pub program_name: String,
pub namespace: String,
pub log_level: VeilidConfigLogLevel,
pub api_log_level: VeilidConfigLogLevel,
pub capabilities: VeilidConfigCapabilities,
pub protected_store: VeilidConfigProtectedStore,
pub table_store: VeilidConfigTableStore,
@@ -272,7 +280,7 @@ impl VeilidConfig {
let mut inner = self.inner.write();
get_config!(inner.program_name);
get_config!(inner.namespace);
get_config!(inner.log_level);
get_config!(inner.api_log_level);
get_config!(inner.capabilities.protocol_udp);
get_config!(inner.capabilities.protocol_connect_tcp);
get_config!(inner.capabilities.protocol_accept_tcp);
@@ -552,7 +560,7 @@ impl VeilidConfig {
// If we have a node id from storage, check it
if node_id.valid && node_id_secret.valid {
// Validate node id
if !validate_key(&node_id, &node_id_secret) {
if !dht::validate_key(&node_id, &node_id_secret) {
return Err("node id secret and node id key don't match".to_owned());
}
}
+1 -1
View File
@@ -20,12 +20,12 @@ pub use futures_util::future::{select, Either};
pub use futures_util::select;
pub use futures_util::stream::FuturesUnordered;
pub use futures_util::{AsyncRead, AsyncWrite};
pub use log::*;
pub use log_thru::*;
pub use owo_colors::OwoColorize;
pub use parking_lot::*;
pub use split_url::*;
pub use static_assertions::*;
pub use tracing::*;
pub type PinBox<T> = Pin<Box<T>>;
pub type PinBoxFuture<T> = PinBox<dyn Future<Output = T> + 'static>;