From 59074b0219a107d7fc4b9731e03670ea524913e3 Mon Sep 17 00:00:00 2001 From: evenyag Date: Sat, 3 Aug 2024 20:55:53 +0800 Subject: [PATCH 01/15] feat: init --- core/src/layers/logging.rs | 122 ++++++++++++++++++++++++++++++++++--- 1 file changed, 112 insertions(+), 10 deletions(-) diff --git a/core/src/layers/logging.rs b/core/src/layers/logging.rs index b56f71645569..8997a86713c3 100644 --- a/core/src/layers/logging.rs +++ b/core/src/layers/logging.rs @@ -82,19 +82,22 @@ use crate::*; /// ```shell /// RUST_LOG="info,opendal::services=debug" ./app /// ``` -#[derive(Debug, Copy, Clone)] +#[derive(Debug, Clone)] pub struct LoggingLayer { error_level: Option, failure_level: Option, backtrace_output: bool, + notify: Arc, } impl Default for LoggingLayer { fn default() -> Self { Self { + // FIXME(yingwen): Remove error_level: Some(Level::Warn), failure_level: Some(Level::Error), backtrace_output: false, + notify: Arc::new(DefaultLoggingInterceptor::default()), } } } @@ -162,6 +165,7 @@ impl Layer for LoggingLayer { failure_level: self.failure_level, backtrace_output: self.backtrace_output, }, + notify: self.notify.clone(), } } } @@ -200,11 +204,95 @@ impl LoggingContext { } } +/// LoggingInterceptor is used to intercept the log. +pub trait LoggingInterceptor: Debug { + /// Everytime there is a log, this function will be called. + // TODO(yingwen): docuement inputs. + fn log( + &self, + scheme: Scheme, + operation: &'static str, + path: &str, + message: &str, + err: Option<&Error>, + ); +} + +/// The DefaultLoggingInterceptor will log the message by the standard logging macro. +#[derive(Debug, Default)] +pub struct DefaultLoggingInterceptor { + error_level: Option, + failure_level: Option, + backtrace_output: bool, +} + +impl LoggingInterceptor for DefaultLoggingInterceptor { + fn log( + &self, + scheme: Scheme, + operation: &'static str, + path: &str, + message: &str, + err: Option<&Error>, + ) { + let Some(err) = err else { + debug!( + target: LOGGING_TARGET, + "service={} operation={} path={} -> {}", + scheme, + operation, + path, + message, + ); + return; + }; + + if let Some(lvl) = self.error_level(err) { + log!( + target: LOGGING_TARGET, + lvl, + "service={} operation={} path={} -> {}", + scheme, + operation, + path, + self.error_print(&err) + ) + } + } +} + +impl DefaultLoggingInterceptor { + #[inline] + fn error_level(&self, err: &Error) -> Option { + if err.kind() == ErrorKind::Unexpected { + self.failure_level + } else { + self.error_level + } + } + + /// Print error with backtrace if it's unexpected error. + #[inline] + fn error_print(&self, err: &Error) -> String { + // Don't print backtrace if it's not unexpected error. + if err.kind() != ErrorKind::Unexpected { + return format!("{err}"); + } + + if self.backtrace_output { + format!("{err:?}") + } else { + format!("{err}") + } + } +} + #[derive(Clone, Debug)] pub struct LoggingAccessor { inner: A, ctx: LoggingContext, + notify: Arc, } static LOGGING_TARGET: &str = "opendal::services"; @@ -223,19 +311,33 @@ impl LayeredAccess for LoggingAccessor { } fn metadata(&self) -> Arc { - debug!( - target: LOGGING_TARGET, - "service={} operation={} -> started", + self.notify.log( self.ctx.scheme, - Operation::Info + Operation::Info.into_static(), + "", + "started", + None, ); + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} -> started", + // self.ctx.scheme, + // Operation::Info + // ); let result = self.inner.info(); - debug!( - target: LOGGING_TARGET, - "service={} operation={} -> finished: {:?}", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} -> finished: {:?}", + // self.ctx.scheme, + // Operation::Info, + // result + // ); + self.notify.log( self.ctx.scheme, - Operation::Info, - result + Operation::Info.into_static(), + "", + &format!("finished: {:?}", result), + None, ); result From 5afb9a4f8ae7131db711835521f948312bc2b82a Mon Sep 17 00:00:00 2001 From: evenyag Date: Sat, 3 Aug 2024 20:56:08 +0800 Subject: [PATCH 02/15] feat: accessor log --- core/src/layers/logging.rs | 956 +++++++++++++++++++++++++------------ 1 file changed, 639 insertions(+), 317 deletions(-) diff --git a/core/src/layers/logging.rs b/core/src/layers/logging.rs index 8997a86713c3..570247b2f81d 100644 --- a/core/src/layers/logging.rs +++ b/core/src/layers/logging.rs @@ -164,21 +164,22 @@ impl Layer for LoggingLayer { error_level: self.error_level, failure_level: self.failure_level, backtrace_output: self.backtrace_output, + notify: self.notify.clone(), }, - notify: self.notify.clone(), } } } #[derive(Clone, Debug)] -pub struct LoggingContext { +pub struct LoggingContext { scheme: Scheme, error_level: Option, failure_level: Option, backtrace_output: bool, + notify: Arc, } -impl LoggingContext { +impl LoggingContext { #[inline] fn error_level(&self, err: &Error) -> Option { if err.kind() == ErrorKind::Unexpected { @@ -291,8 +292,7 @@ impl DefaultLoggingInterceptor { pub struct LoggingAccessor { inner: A, - ctx: LoggingContext, - notify: Arc, + ctx: LoggingContext, } static LOGGING_TARGET: &str = "opendal::services"; @@ -311,7 +311,7 @@ impl LayeredAccess for LoggingAccessor { } fn metadata(&self) -> Arc { - self.notify.log( + self.ctx.notify.log( self.ctx.scheme, Operation::Info.into_static(), "", @@ -332,7 +332,7 @@ impl LayeredAccess for LoggingAccessor { // Operation::Info, // result // ); - self.notify.log( + self.ctx.notify.log( self.ctx.scheme, Operation::Info.into_static(), "", @@ -344,62 +344,98 @@ impl LayeredAccess for LoggingAccessor { } async fn create_dir(&self, path: &str, args: OpCreateDir) -> Result { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> started", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> started", + // self.ctx.scheme, + // Operation::CreateDir, + // path + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::CreateDir, - path + Operation::CreateDir.into_static(), + path, + "started", + None, ); self.inner .create_dir(path, args) .await .map(|v| { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> finished", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> finished", + // self.ctx.scheme, + // Operation::CreateDir, + // path + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::CreateDir, - path + Operation::CreateDir.into_static(), + path, + "finished", + None, ); v }) .map_err(|err| { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} -> {}", - self.ctx.scheme, - Operation::CreateDir, - path, - self.ctx.error_print(&err) - ) - }; + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} -> {}", + // self.ctx.scheme, + // Operation::CreateDir, + // path, + // self.ctx.error_print(&err) + // ) + + // }; + self.ctx.notify.log( + self.ctx.scheme, + Operation::CreateDir.into_static(), + path, + "", + Some(&err), + ); err }) } async fn read(&self, path: &str, args: OpRead) -> Result<(RpRead, Self::Reader)> { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> started", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> started", + // self.ctx.scheme, + // Operation::Read, + // path, + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::Read, + Operation::Read.into_static(), path, + "started", + None, ); self.inner .read(path, args) .await .map(|(rp, r)| { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> got reader", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> got reader", + // self.ctx.scheme, + // Operation::Read, + // path, + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::Read, + Operation::Read.into_static(), path, + "got reader", + None, ); ( rp, @@ -407,253 +443,389 @@ impl LayeredAccess for LoggingAccessor { ) }) .map_err(|err| { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} -> {}", - self.ctx.scheme, - Operation::Read, - path, - self.ctx.error_print(&err) - ) - } + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} -> {}", + // self.ctx.scheme, + // Operation::Read, + // path, + // self.ctx.error_print(&err) + // ) + // } + self.ctx.notify.log( + self.ctx.scheme, + Operation::Read.into_static(), + path, + "", + Some(&err), + ); err }) } async fn write(&self, path: &str, args: OpWrite) -> Result<(RpWrite, Self::Writer)> { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> started", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> started", + // self.ctx.scheme, + // Operation::Write, + // path + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::Write, - path + Operation::Write.into_static(), + path, + "started", + None, ); self.inner .write(path, args) .await .map(|(rp, w)| { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> start writing", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> start writing", + // self.ctx.scheme, + // Operation::Write, + // path, + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::Write, + Operation::Write.into_static(), path, + "start writing", + None, ); let w = LoggingWriter::new(self.ctx.clone(), Operation::Write, path, w); (rp, w) }) .map_err(|err| { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} -> {}", - self.ctx.scheme, - Operation::Write, - path, - self.ctx.error_print(&err) - ) - }; + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} -> {}", + // self.ctx.scheme, + // Operation::Write, + // path, + // self.ctx.error_print(&err) + // ) + // }; + self.ctx.notify.log( + self.ctx.scheme, + Operation::Write.into_static(), + path, + "", + Some(&err), + ); err }) } async fn copy(&self, from: &str, to: &str, args: OpCopy) -> Result { - debug!( - target: LOGGING_TARGET, - "service={} operation={} from={} to={} -> started", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} from={} to={} -> started", + // self.ctx.scheme, + // Operation::Copy, + // from, + // to + // ); + + // FIXME(yingwen): from, to + self.ctx.notify.log( self.ctx.scheme, - Operation::Copy, + Operation::Copy.into_static(), from, - to + "started", + None, ); self.inner .copy(from, to, args) .await .map(|v| { - debug!( - target: LOGGING_TARGET, - "service={} operation={} from={} to={} -> finished", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} from={} to={} -> finished", + // self.ctx.scheme, + // Operation::Copy, + // from, + // to + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::Copy, + Operation::Copy.into_static(), from, - to + "finished", + None, ); v }) .map_err(|err| { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} from={} to={} -> {}", - self.ctx.scheme, - Operation::Copy, - from, - to, - self.ctx.error_print(&err), - ) - }; + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} from={} to={} -> {}", + // self.ctx.scheme, + // Operation::Copy, + // from, + // to, + // self.ctx.error_print(&err), + // ) + // }; + self.ctx.notify.log( + self.ctx.scheme, + Operation::Copy.into_static(), + from, + "", + Some(&err), + ); err }) } async fn rename(&self, from: &str, to: &str, args: OpRename) -> Result { - debug!( - target: LOGGING_TARGET, - "service={} operation={} from={} to={} -> started", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} from={} to={} -> started", + // self.ctx.scheme, + // Operation::Rename, + // from, + // to + // ); + // FIXME(yingwen): from, to + self.ctx.notify.log( self.ctx.scheme, - Operation::Rename, + Operation::Rename.into_static(), from, - to + "started", + None, ); self.inner .rename(from, to, args) .await .map(|v| { - debug!( - target: LOGGING_TARGET, - "service={} operation={} from={} to={} -> finished", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} from={} to={} -> finished", + // self.ctx.scheme, + // Operation::Rename, + // from, + // to + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::Rename, + Operation::Rename.into_static(), from, - to + "finished", + None, ); v }) .map_err(|err| { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} from={} to={} -> {}", - self.ctx.scheme, - Operation::Rename, - from, - to, - self.ctx.error_print(&err) - ) - }; + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} from={} to={} -> {}", + // self.ctx.scheme, + // Operation::Rename, + // from, + // to, + // self.ctx.error_print(&err) + // ) + // }; + self.ctx.notify.log( + self.ctx.scheme, + Operation::Rename.into_static(), + from, + "", + Some(&err), + ); err }) } async fn stat(&self, path: &str, args: OpStat) -> Result { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> started", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> started", + // self.ctx.scheme, + // Operation::Stat, + // path + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::Stat, - path + Operation::Stat.into_static(), + path, + "started", + None, ); self.inner .stat(path, args) .await .map(|v| { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> finished: {v:?}", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> finished: {v:?}", + // self.ctx.scheme, + // Operation::Stat, + // path + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::Stat, - path + Operation::Stat.into_static(), + path, + "finished", + None, ); v }) .map_err(|err| { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} -> {}", - self.ctx.scheme, - Operation::Stat, - path, - self.ctx.error_print(&err) - ); - }; + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} -> {}", + // self.ctx.scheme, + // Operation::Stat, + // path, + // self.ctx.error_print(&err) + // ); + // }; + self.ctx.notify.log( + self.ctx.scheme, + Operation::Stat.into_static(), + path, + "", + Some(&err), + ); err }) } async fn delete(&self, path: &str, args: OpDelete) -> Result { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> started", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> started", + // self.ctx.scheme, + // Operation::Delete, + // path + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::Delete, - path + Operation::Delete.into_static(), + path, + "started", + None, ); self.inner .delete(path, args.clone()) .inspect(|v| match v { Ok(_) => { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> finished", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> finished", + // self.ctx.scheme, + // Operation::Delete, + // path + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::Delete, - path + Operation::Delete.into_static(), + path, + "finished", + None, ); } Err(err) => { - if let Some(lvl) = self.ctx.error_level(err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} -> {}", - self.ctx.scheme, - Operation::Delete, - path, - self.ctx.error_print(err) - ); - } + // if let Some(lvl) = self.ctx.error_level(err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} -> {}", + // self.ctx.scheme, + // Operation::Delete, + // path, + // self.ctx.error_print(err) + // ); + // } + self.ctx.notify.log( + self.ctx.scheme, + Operation::Delete.into_static(), + path, + "", + Some(err), + ); } }) .await } async fn list(&self, path: &str, args: OpList) -> Result<(RpList, Self::Lister)> { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> started", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> started", + // self.ctx.scheme, + // Operation::List, + // path + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::List, - path + Operation::List.into_static(), + path, + "started", + None, ); self.inner .list(path, args) .map(|v| match v { Ok((rp, v)) => { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> start listing dir", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> start listing dir", + // self.ctx.scheme, + // Operation::List, + // path + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::List, - path + Operation::List.into_static(), + path, + "start listing dir", + None, ); let streamer = LoggingLister::new(self.ctx.clone(), path, Operation::List, v); Ok((rp, streamer)) } Err(err) => { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} -> {}", - self.ctx.scheme, - Operation::List, - path, - self.ctx.error_print(&err) - ); - } + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} -> {}", + // self.ctx.scheme, + // Operation::List, + // path, + // self.ctx.error_print(&err) + // ); + // } + self.ctx.notify.log( + self.ctx.scheme, + Operation::List.into_static(), + path, + "", + Some(&err), + ); Err(err) } }) @@ -661,39 +833,60 @@ impl LayeredAccess for LoggingAccessor { } async fn presign(&self, path: &str, args: OpPresign) -> Result { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> started", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> started", + // self.ctx.scheme, + // Operation::Presign, + // path + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::Presign, - path + Operation::Presign.into_static(), + path, + "started", + None, ); self.inner .presign(path, args) .await .map(|v| { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> finished: {v:?}", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> finished: {v:?}", + // self.ctx.scheme, + // Operation::Presign, + // path + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::Presign, - path + Operation::Presign.into_static(), + path, + "finished", + None, ); v }) .map_err(|err| { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} -> {}", - self.ctx.scheme, - Operation::Presign, - path, - self.ctx.error_print(&err) - ); - } + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} -> {}", + // self.ctx.scheme, + // Operation::Presign, + // path, + // self.ctx.error_print(&err) + // ); + // } + self.ctx.notify.log( + self.ctx.scheme, + Operation::Presign.into_static(), + path, + "", + Some(&err), + ); err }) } @@ -701,6 +894,7 @@ impl LayeredAccess for LoggingAccessor { async fn batch(&self, args: OpBatch) -> Result { let (op, count) = (args.operation()[0].1.operation(), args.operation().len()); + // FIXME: log op and count debug!( target: LOGGING_TARGET, "service={} operation={}-{op} count={count} -> started", @@ -739,119 +933,183 @@ impl LayeredAccess for LoggingAccessor { } fn blocking_create_dir(&self, path: &str, args: OpCreateDir) -> Result { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> started", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> started", + // self.ctx.scheme, + // Operation::BlockingCreateDir, + // path + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::BlockingCreateDir, - path + Operation::BlockingCreateDir.into_static(), + path, + "started", + None, ); self.inner .blocking_create_dir(path, args) .map(|v| { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> finished", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> finished", + // self.ctx.scheme, + // Operation::BlockingCreateDir, + // path + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::BlockingCreateDir, - path + Operation::BlockingCreateDir.into_static(), + path, + "finished", + None, ); v }) .map_err(|err| { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} -> {}", - self.ctx.scheme, - Operation::BlockingCreateDir, - path, - self.ctx.error_print(&err) - ); - } + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} -> {}", + // self.ctx.scheme, + // Operation::BlockingCreateDir, + // path, + // self.ctx.error_print(&err) + // ); + // } + self.ctx.notify.log( + self.ctx.scheme, + Operation::BlockingCreateDir.into_static(), + path, + "", + Some(&err), + ); err }) } fn blocking_read(&self, path: &str, args: OpRead) -> Result<(RpRead, Self::BlockingReader)> { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> started", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> started", + // self.ctx.scheme, + // Operation::BlockingRead, + // path, + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::BlockingRead, + Operation::BlockingRead.into_static(), path, + "started", + None, ); self.inner .blocking_read(path, args.clone()) .map(|(rp, r)| { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> got reader", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> got reader", + // self.ctx.scheme, + // Operation::BlockingRead, + // path, + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::BlockingRead, + Operation::BlockingRead.into_static(), path, + "got reader", + None, ); let r = LoggingReader::new(self.ctx.clone(), Operation::BlockingRead, path, r); (rp, r) }) .map_err(|err| { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} -> {}", - self.ctx.scheme, - Operation::BlockingRead, - path, - self.ctx.error_print(&err) - ); - } + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} -> {}", + // self.ctx.scheme, + // Operation::BlockingRead, + // path, + // self.ctx.error_print(&err) + // ); + // } + self.ctx.notify.log( + self.ctx.scheme, + Operation::BlockingRead.into_static(), + path, + "", + Some(&err), + ); err }) } fn blocking_write(&self, path: &str, args: OpWrite) -> Result<(RpWrite, Self::BlockingWriter)> { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> started", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> started", + // self.ctx.scheme, + // Operation::BlockingWrite, + // path, + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::BlockingWrite, + Operation::BlockingWrite.into_static(), path, + "started", + None, ); self.inner .blocking_write(path, args) .map(|(rp, w)| { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> start writing", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> start writing", + // self.ctx.scheme, + // Operation::BlockingWrite, + // path, + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::BlockingWrite, + Operation::BlockingWrite.into_static(), path, + "start writing", + None, ); let w = LoggingWriter::new(self.ctx.clone(), Operation::BlockingWrite, path, w); (rp, w) }) .map_err(|err| { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} -> {}", - self.ctx.scheme, - Operation::BlockingWrite, - path, - self.ctx.error_print(&err) - ); - } + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} -> {}", + // self.ctx.scheme, + // Operation::BlockingWrite, + // path, + // self.ctx.error_print(&err) + // ); + // } + self.ctx.notify.log( + self.ctx.scheme, + Operation::BlockingWrite.into_static(), + path, + "", + Some(&err), + ); err }) } fn blocking_copy(&self, from: &str, to: &str, args: OpCopy) -> Result { + // TODO(yingwen): from, to debug!( target: LOGGING_TARGET, "service={} operation={} from={} to={} -> started", @@ -892,6 +1150,7 @@ impl LayeredAccess for LoggingAccessor { } fn blocking_rename(&self, from: &str, to: &str, args: OpRename) -> Result { + // TODO(yingwen): from, to debug!( target: LOGGING_TARGET, "service={} operation={} from={} to={} -> started", @@ -932,113 +1191,176 @@ impl LayeredAccess for LoggingAccessor { } fn blocking_stat(&self, path: &str, args: OpStat) -> Result { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> started", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> started", + // self.ctx.scheme, + // Operation::BlockingStat, + // path + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::BlockingStat, - path + Operation::BlockingStat.into_static(), + path, + "started", + None, ); self.inner .blocking_stat(path, args) .map(|v| { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> finished: {v:?}", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> finished: {v:?}", + // self.ctx.scheme, + // Operation::BlockingStat, + // path + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::BlockingStat, - path + Operation::BlockingStat.into_static(), + path, + "finished", + Some(&v), ); v }) .map_err(|err| { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} -> {}", - self.ctx.scheme, - Operation::BlockingStat, - path, - self.ctx.error_print(&err) - ); - } + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} -> {}", + // self.ctx.scheme, + // Operation::BlockingStat, + // path, + // self.ctx.error_print(&err) + // ); + // } + self.ctx.notify.log( + self.ctx.scheme, + Operation::BlockingStat.into_static(), + path, + "", + Some(&err), + ); err }) } fn blocking_delete(&self, path: &str, args: OpDelete) -> Result { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> started", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> started", + // self.ctx.scheme, + // Operation::BlockingDelete, + // path + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::BlockingDelete, - path + Operation::BlockingDelete.into_static(), + path, + "started", + None, ); self.inner .blocking_delete(path, args) .map(|v| { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> finished", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> finished", + // self.ctx.scheme, + // Operation::BlockingDelete, + // path + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::BlockingDelete, - path + Operation::BlockingDelete.into_static(), + path, + "finished", + Some(&v), ); v }) .map_err(|err| { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} -> {}", - self.ctx.scheme, - Operation::BlockingDelete, - path, - self.ctx.error_print(&err) - ); - } + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} -> {}", + // self.ctx.scheme, + // Operation::BlockingDelete, + // path, + // self.ctx.error_print(&err) + // ); + // } + self.ctx.notify.log( + self.ctx.scheme, + Operation::BlockingDelete.into_static(), + path, + "", + Some(&err), + ); err }) } fn blocking_list(&self, path: &str, args: OpList) -> Result<(RpList, Self::BlockingLister)> { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> started", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> started", + // self.ctx.scheme, + // Operation::BlockingList, + // path + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::BlockingList, - path + Operation::BlockingList.into_static(), + path, + "started", + None, ); self.inner .blocking_list(path, args) .map(|(rp, v)| { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> got dir", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> got dir", + // self.ctx.scheme, + // Operation::BlockingList, + // path + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::BlockingList, - path + Operation::BlockingList.into_static(), + path, + "got dir", + Some(&rp), ); let li = LoggingLister::new(self.ctx.clone(), path, Operation::BlockingList, v); (rp, li) }) .map_err(|err| { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} -> {}", - self.ctx.scheme, - Operation::BlockingList, - path, - self.ctx.error_print(&err) - ); - } + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} -> {}", + // self.ctx.scheme, + // Operation::BlockingList, + // path, + // self.ctx.error_print(&err) + // ); + // } + self.ctx.notify.log( + self.ctx.scheme, + Operation::BlockingList.into_static(), + path, + "", + Some(&err), + ); err }) } From 4e578ed5b80a4461b50a0a21254545272f406c7d Mon Sep 17 00:00:00 2001 From: evenyag Date: Sat, 3 Aug 2024 21:42:57 +0800 Subject: [PATCH 03/15] feat: more logs --- core/src/layers/logging.rs | 905 +++++++++++++++++++++++-------------- 1 file changed, 572 insertions(+), 333 deletions(-) diff --git a/core/src/layers/logging.rs b/core/src/layers/logging.rs index 570247b2f81d..ceaf50777caa 100644 --- a/core/src/layers/logging.rs +++ b/core/src/layers/logging.rs @@ -236,10 +236,12 @@ impl LoggingInterceptor for DefaultLoggingInterceptor { message: &str, err: Option<&Error>, ) { + // TODO(yingwen): Use trace for reader/writer + // ReadOperation::Read/ReadOperation::BlockingRead/WriteOperation::Write/WriteOperation::Abort/WriteOperation::BlockingWrite let Some(err) = err else { debug!( target: LOGGING_TARGET, - "service={} operation={} path={} -> {}", + "service={} operation={} path={} {}", scheme, operation, path, @@ -249,13 +251,15 @@ impl LoggingInterceptor for DefaultLoggingInterceptor { }; if let Some(lvl) = self.error_level(err) { + // TODO(yingwen): don't print message if no message log!( target: LOGGING_TARGET, lvl, - "service={} operation={} path={} -> {}", + "service={} operation={} path={} {} {}", scheme, operation, path, + message, self.error_print(&err) ) } @@ -315,7 +319,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::Info.into_static(), "", - "started", + "-> started", None, ); // debug!( @@ -336,7 +340,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::Info.into_static(), "", - &format!("finished: {:?}", result), + &format!("-> finished: {:?}", result), None, ); @@ -355,7 +359,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::CreateDir.into_static(), path, - "started", + "-> started", None, ); @@ -374,7 +378,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::CreateDir.into_static(), path, - "finished", + "-> finished", None, ); v @@ -396,7 +400,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::CreateDir.into_static(), path, - "", + "->", Some(&err), ); err @@ -415,7 +419,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::Read.into_static(), path, - "started", + "-> started", None, ); @@ -434,7 +438,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::Read.into_static(), path, - "got reader", + "-> got reader", None, ); ( @@ -458,7 +462,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::Read.into_static(), path, - "", + "->", Some(&err), ); err @@ -477,7 +481,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::Write.into_static(), path, - "started", + "-> started", None, ); @@ -496,7 +500,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::Write.into_static(), path, - "start writing", + "-> start writing", None, ); let w = LoggingWriter::new(self.ctx.clone(), Operation::Write, path, w); @@ -518,7 +522,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::Write.into_static(), path, - "", + "->", Some(&err), ); err @@ -535,12 +539,11 @@ impl LayeredAccess for LoggingAccessor { // to // ); - // FIXME(yingwen): from, to self.ctx.notify.log( self.ctx.scheme, Operation::Copy.into_static(), - from, - "started", + "", + &format!("from={from} to={to} -> started"), None, ); @@ -559,8 +562,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.notify.log( self.ctx.scheme, Operation::Copy.into_static(), - from, - "finished", + &format!("from={from} to={to} -> finished"), None, ); v @@ -581,8 +583,8 @@ impl LayeredAccess for LoggingAccessor { self.ctx.notify.log( self.ctx.scheme, Operation::Copy.into_static(), - from, "", + &format!("from={from} to={to} ->"), Some(&err), ); err @@ -602,8 +604,8 @@ impl LayeredAccess for LoggingAccessor { self.ctx.notify.log( self.ctx.scheme, Operation::Rename.into_static(), - from, - "started", + "", + &format!("from={from} to={to} -> started"), None, ); @@ -622,8 +624,8 @@ impl LayeredAccess for LoggingAccessor { self.ctx.notify.log( self.ctx.scheme, Operation::Rename.into_static(), - from, - "finished", + "", + &format!("from={from} to={to} -> finished"), None, ); v @@ -644,8 +646,8 @@ impl LayeredAccess for LoggingAccessor { self.ctx.notify.log( self.ctx.scheme, Operation::Rename.into_static(), - from, "", + &format!("from={from} to={to} ->"), Some(&err), ); err @@ -664,7 +666,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::Stat.into_static(), path, - "started", + "-> started", None, ); @@ -683,7 +685,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::Stat.into_static(), path, - "finished", + "-> finished", None, ); v @@ -704,7 +706,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::Stat.into_static(), path, - "", + "->", Some(&err), ); err @@ -723,7 +725,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::Delete.into_static(), path, - "started", + "-> started", None, ); @@ -742,7 +744,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::Delete.into_static(), path, - "finished", + "-> finished", None, ); } @@ -762,7 +764,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::Delete.into_static(), path, - "", + "->", Some(err), ); } @@ -782,7 +784,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::List.into_static(), path, - "started", + "-> started", None, ); @@ -801,7 +803,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::List.into_static(), path, - "start listing dir", + "-> start listing dir", None, ); let streamer = LoggingLister::new(self.ctx.clone(), path, Operation::List, v); @@ -823,7 +825,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::List.into_static(), path, - "", + "->", Some(&err), ); Err(err) @@ -844,7 +846,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::Presign.into_static(), path, - "started", + "-> started", None, ); @@ -863,7 +865,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::Presign.into_static(), path, - "finished", + "-> finished", None, ); v @@ -884,7 +886,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::Presign.into_static(), path, - "", + "->", Some(&err), ); err @@ -894,39 +896,64 @@ impl LayeredAccess for LoggingAccessor { async fn batch(&self, args: OpBatch) -> Result { let (op, count) = (args.operation()[0].1.operation(), args.operation().len()); - // FIXME: log op and count - debug!( - target: LOGGING_TARGET, - "service={} operation={}-{op} count={count} -> started", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={}-{op} count={count} -> started", + // self.ctx.scheme, + // Operation::Batch, + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::Batch, + Operation::Batch.into_static(), + "", + &format!("op={op} count={count} -> started"), + None, ); self.inner .batch(args) .map_ok(|v| { - debug!( - target: LOGGING_TARGET, - "service={} operation={}-{op} count={count} -> finished: {}, succeed: {}, failed: {}", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={}-{op} count={count} -> finished: {}, succeed: {}, failed: {}", + // self.ctx.scheme, + // Operation::Batch, + // v.results().len(), + // v.results().iter().filter(|(_, v)|v.is_ok()).count(), + // v.results().iter().filter(|(_, v)|v.is_err()).count(), + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::Batch, - v.results().len(), - v.results().iter().filter(|(_, v)|v.is_ok()).count(), - v.results().iter().filter(|(_, v)|v.is_err()).count(), + Operation::Batch.into_static(), + "", + &format!( + "op={op} count={count} -> finished: {}, succeed: {}, failed: {}", + v.results().len(), + v.results().iter().filter(|(_, v)| v.is_ok()).count(), + v.results().iter().filter(|(_, v)| v.is_err()).count(), + ), + None, ); v }) .map_err(|err| { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={}-{op} count={count} -> {}", - self.ctx.scheme, - Operation::Batch, - self.ctx.error_print(&err) - ); - } + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={}-{op} count={count} -> {}", + // self.ctx.scheme, + // Operation::Batch, + // self.ctx.error_print(&err) + // ); + // } + self.ctx.notify.log( + self.ctx.scheme, + Operation::Batch.into_static(), + "", + &format!("op={op} count={count} ->"), + Some(&err), + ); err }) .await @@ -944,7 +971,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::BlockingCreateDir.into_static(), path, - "started", + "-> started", None, ); @@ -962,7 +989,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::BlockingCreateDir.into_static(), path, - "finished", + "-> finished", None, ); v @@ -983,7 +1010,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::BlockingCreateDir.into_static(), path, - "", + "->", Some(&err), ); err @@ -1002,7 +1029,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::BlockingRead.into_static(), path, - "started", + "-> started", None, ); @@ -1020,7 +1047,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::BlockingRead.into_static(), path, - "got reader", + "-> got reader", None, ); let r = LoggingReader::new(self.ctx.clone(), Operation::BlockingRead, path, r); @@ -1042,7 +1069,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::BlockingRead.into_static(), path, - "", + "->", Some(&err), ); err @@ -1061,7 +1088,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::BlockingWrite.into_static(), path, - "started", + "-> started", None, ); @@ -1079,7 +1106,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::BlockingWrite.into_static(), path, - "start writing", + "-> start writing", None, ); let w = LoggingWriter::new(self.ctx.clone(), Operation::BlockingWrite, path, w); @@ -1101,7 +1128,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::BlockingWrite.into_static(), path, - "", + "->", Some(&err), ); err @@ -1109,83 +1136,123 @@ impl LayeredAccess for LoggingAccessor { } fn blocking_copy(&self, from: &str, to: &str, args: OpCopy) -> Result { - // TODO(yingwen): from, to - debug!( - target: LOGGING_TARGET, - "service={} operation={} from={} to={} -> started", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} from={} to={} -> started", + // self.ctx.scheme, + // Operation::BlockingCopy, + // from, + // to, + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::BlockingCopy, - from, - to, + Operation::BlockingCopy.into_static(), + "", + &format!("from={from} to={to} -> started"), + None, ); self.inner .blocking_copy(from, to, args) .map(|v| { - debug!( - target: LOGGING_TARGET, - "service={} operation={} from={} to={} -> finished", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} from={} to={} -> finished", + // self.ctx.scheme, + // Operation::BlockingCopy, + // from, + // to, + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::BlockingCopy, - from, - to, + Operation::BlockingCopy.into_static(), + "", + &format!("from={from} to={to} -> finished"), + None, ); v }) .map_err(|err| { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} from={} to={} -> {}", - self.ctx.scheme, - Operation::BlockingCopy, - from, - to, - self.ctx.error_print(&err) - ); - } + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} from={} to={} -> {}", + // self.ctx.scheme, + // Operation::BlockingCopy, + // from, + // to, + // self.ctx.error_print(&err) + // ); + // } + self.ctx.notify.log( + self.ctx.scheme, + Operation::BlockingCopy.into_static(), + "", + &format!("from={from} to={to} ->"), + Some(&err), + ); err }) } fn blocking_rename(&self, from: &str, to: &str, args: OpRename) -> Result { - // TODO(yingwen): from, to - debug!( - target: LOGGING_TARGET, - "service={} operation={} from={} to={} -> started", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} from={} to={} -> started", + // self.ctx.scheme, + // Operation::BlockingRename, + // from, + // to, + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::BlockingRename, - from, - to, + Operation::BlockingRename.into_static(), + "", + &format!("from={from} to={to} -> started"), + None, ); self.inner .blocking_rename(from, to, args) .map(|v| { - debug!( - target: LOGGING_TARGET, - "service={} operation={} from={} to={} -> finished", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} from={} to={} -> finished", + // self.ctx.scheme, + // Operation::BlockingRename, + // from, + // to, + // ); + self.ctx.notify.log( self.ctx.scheme, - Operation::BlockingRename, - from, - to, + Operation::BlockingRename.into_static(), + "", + &format!("from={from} to={to} -> finished"), + None, ); v }) .map_err(|err| { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} from={} to={} -> {}", - self.ctx.scheme, - Operation::BlockingRename, - from, - to, - self.ctx.error_print(&err) - ); - } + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} from={} to={} -> {}", + // self.ctx.scheme, + // Operation::BlockingRename, + // from, + // to, + // self.ctx.error_print(&err) + // ); + // } + self.ctx.notify.log( + self.ctx.scheme, + Operation::BlockingRename.into_static(), + "", + &format!("from={from} to={to} ->"), + Some(&err), + ); err }) } @@ -1202,7 +1269,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::BlockingStat.into_static(), path, - "started", + "-> started", None, ); @@ -1220,8 +1287,8 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::BlockingStat.into_static(), path, - "finished", - Some(&v), + "-> finished", + None, ); v }) @@ -1241,7 +1308,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::BlockingStat.into_static(), path, - "", + "->", Some(&err), ); err @@ -1260,7 +1327,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::BlockingDelete.into_static(), path, - "started", + "-> started", None, ); @@ -1278,8 +1345,8 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::BlockingDelete.into_static(), path, - "finished", - Some(&v), + "-> finished", + None, ); v }) @@ -1299,7 +1366,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::BlockingDelete.into_static(), path, - "", + "->", Some(&err), ); err @@ -1318,7 +1385,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::BlockingList.into_static(), path, - "started", + "-> started", None, ); @@ -1336,7 +1403,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::BlockingList.into_static(), path, - "got dir", + "-> got dir", Some(&rp), ); let li = LoggingLister::new(self.ctx.clone(), path, Operation::BlockingList, v); @@ -1358,7 +1425,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.scheme, Operation::BlockingList.into_static(), path, - "", + "->", Some(&err), ); err @@ -1367,8 +1434,8 @@ impl LayeredAccess for LoggingAccessor { } /// `LoggingReader` is a wrapper of `BytesReader`, with logging functionality. -pub struct LoggingReader { - ctx: LoggingContext, +pub struct LoggingReader { + ctx: LoggingContext, path: String, op: Operation, @@ -1376,8 +1443,8 @@ pub struct LoggingReader { inner: R, } -impl LoggingReader { - fn new(ctx: LoggingContext, op: Operation, path: &str, reader: R) -> Self { +impl LoggingReader { + fn new(ctx: LoggingContext, op: Operation, path: &str, reader: R) -> Self { Self { ctx, op, @@ -1389,15 +1456,25 @@ impl LoggingReader { } } -impl Drop for LoggingReader { +impl Drop for LoggingReader { fn drop(&mut self) { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} read={} -> data read finished", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} read={} -> data read finished", + // self.ctx.scheme, + // self.op, + // self.path, + // self.read.load(Ordering::Relaxed) + // ); + self.ctx.notify.log( self.ctx.scheme, - self.op, - self.path, - self.read.load(Ordering::Relaxed) + self.op.into_static(), + &self.path, + &format!( + "read={} -> data read finished", + self.read.load(Ordering::Relaxed) + ), + None, ); } } @@ -1408,30 +1485,48 @@ impl oio::Read for LoggingReader { Ok(bs) => { self.read .fetch_add(bs.remaining() as u64, Ordering::Relaxed); - trace!( - target: LOGGING_TARGET, - "service={} operation={} path={} read={} -> read returns {}B", + // trace!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} read={} -> read returns {}B", + // self.ctx.scheme, + // ReadOperation::Read, + // self.path, + // self.read.load(Ordering::Relaxed), + // bs.remaining() + // ); + self.ctx.notify.log( self.ctx.scheme, - ReadOperation::Read, - self.path, - self.read.load(Ordering::Relaxed), - bs.remaining() + ReadOperation::Read.into_static(), + &self.path, + &format!( + "read={} -> read returns {}B", + self.read.load(Ordering::Relaxed), + bs.remaining() + ), + None, ); Ok(bs) } Err(err) => { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} read={} -> read failed: {}", - self.ctx.scheme, - ReadOperation::Read, - self.path, - self.read.load(Ordering::Relaxed), - self.ctx.error_print(&err), - ) - } + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} read={} -> read failed: {}", + // self.ctx.scheme, + // ReadOperation::Read, + // self.path, + // self.read.load(Ordering::Relaxed), + // self.ctx.error_print(&err), + // ) + // } + self.ctx.notify.log( + self.ctx.scheme, + ReadOperation::Read.into_static(), + &self.path, + &format!("read={} -> read failed:", self.read.load(Ordering::Relaxed)), + Some(&err), + ); Err(err) } } @@ -1444,38 +1539,56 @@ impl oio::BlockingRead for LoggingReader { Ok(bs) => { self.read .fetch_add(bs.remaining() as u64, Ordering::Relaxed); - trace!( - target: LOGGING_TARGET, - "service={} operation={} path={} read={} -> read returns {}B", + // trace!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} read={} -> read returns {}B", + // self.ctx.scheme, + // ReadOperation::BlockingRead, + // self.path, + // self.read.load(Ordering::Relaxed), + // bs.remaining() + // ); + self.ctx.notify.log( self.ctx.scheme, - ReadOperation::BlockingRead, - self.path, - self.read.load(Ordering::Relaxed), - bs.remaining() + ReadOperation::BlockingRead.into_static(), + &self.path, + &format!( + "read={} -> read returns {}B", + self.read.load(Ordering::Relaxed), + bs.remaining() + ), + None, ); Ok(bs) } Err(err) => { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} read={} -> read failed: {}", - self.ctx.scheme, - ReadOperation::BlockingRead, - self.path, - self.read.load(Ordering::Relaxed), - self.ctx.error_print(&err), - ); - } + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} read={} -> read failed: {}", + // self.ctx.scheme, + // ReadOperation::BlockingRead, + // self.path, + // self.read.load(Ordering::Relaxed), + // self.ctx.error_print(&err), + // ); + // } + self.ctx.notify.log( + self.ctx.scheme, + ReadOperation::BlockingRead.into_static(), + &self.path, + &format!("read={} -> read failed:", self.read.load(Ordering::Relaxed)), + Some(&err), + ); Err(err) } } } } -pub struct LoggingWriter { - ctx: LoggingContext, +pub struct LoggingWriter { + ctx: LoggingContext, op: Operation, path: String, @@ -1483,8 +1596,8 @@ pub struct LoggingWriter { inner: W, } -impl LoggingWriter { - fn new(ctx: LoggingContext, op: Operation, path: &str, writer: W) -> Self { +impl LoggingWriter { + fn new(ctx: LoggingContext, op: Operation, path: &str, writer: W) -> Self { Self { ctx, op, @@ -1496,35 +1609,49 @@ impl LoggingWriter { } } -impl oio::Write for LoggingWriter { +impl oio::Write for LoggingWriter { async fn write(&mut self, bs: Buffer) -> Result<()> { let size = bs.len(); match self.inner.write(bs).await { Ok(_) => { - trace!( - target: LOGGING_TARGET, - "service={} operation={} path={} written={}B -> data write {}B", + // trace!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} written={}B -> data write {}B", + // self.ctx.scheme, + // WriteOperation::Write, + // self.path, + // self.written, + // size, + // ); + self.ctx.notify.log( self.ctx.scheme, - WriteOperation::Write, - self.path, - self.written, - size, + WriteOperation::Write.into_static(), + &self.path, + &format!("written={}B -> data write {}B", self.written, size), + None, ); Ok(()) } Err(err) => { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} written={}B -> data write failed: {}", - self.ctx.scheme, - WriteOperation::Write, - self.path, - self.written, - self.ctx.error_print(&err), - ) - } + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} written={}B -> data write failed: {}", + // self.ctx.scheme, + // WriteOperation::Write, + // self.path, + // self.written, + // self.ctx.error_print(&err), + // ) + // } + self.ctx.notify.log( + self.ctx.scheme, + WriteOperation::Write.into_static(), + &self.path, + &format!("written={}B -> data write failed:", self.written), + Some(&err), + ); Err(err) } } @@ -1533,29 +1660,43 @@ impl oio::Write for LoggingWriter { async fn abort(&mut self) -> Result<()> { match self.inner.abort().await { Ok(_) => { - trace!( - target: LOGGING_TARGET, - "service={} operation={} path={} written={}B -> abort writer", + // trace!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} written={}B -> abort writer", + // self.ctx.scheme, + // WriteOperation::Abort, + // self.path, + // self.written, + // ); + self.ctx.notify.log( self.ctx.scheme, - WriteOperation::Abort, - self.path, - self.written, + WriteOperation::Abort.into_static(), + &self.path, + &format!("written={}B -> abort writer", self.written), + None, ); Ok(()) } Err(err) => { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} written={}B -> abort writer failed: {}", - self.ctx.scheme, - WriteOperation::Abort, - self.path, - self.written, - self.ctx.error_print(&err), - ) - } + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} written={}B -> abort writer failed: {}", + // self.ctx.scheme, + // WriteOperation::Abort, + // self.path, + // self.written, + // self.ctx.error_print(&err), + // ) + // } + self.ctx.notify.log( + self.ctx.scheme, + WriteOperation::Abort.into_static(), + &self.path, + &format!("written={}B -> abort writer failed:", self.written), + Some(&err), + ); Err(err) } } @@ -1564,29 +1705,43 @@ impl oio::Write for LoggingWriter { async fn close(&mut self) -> Result<()> { match self.inner.close().await { Ok(_) => { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} written={}B -> data written finished", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} written={}B -> data written finished", + // self.ctx.scheme, + // self.op, + // self.path, + // self.written + // ); + self.ctx.notify.log( self.ctx.scheme, - self.op, - self.path, - self.written + self.op.into_static(), + &self.path, + &format!("written={}B -> data written finished", self.written), + None, ); Ok(()) } Err(err) => { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} written={}B -> data close failed: {}", - self.ctx.scheme, - WriteOperation::Close, - self.path, - self.written, - self.ctx.error_print(&err), - ) - } + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} written={}B -> data close failed: {}", + // self.ctx.scheme, + // WriteOperation::Close, + // self.path, + // self.written, + // self.ctx.error_print(&err), + // ) + // } + self.ctx.notify.log( + self.ctx.scheme, + WriteOperation::Close.into_static(), + &self.path, + &format!("written={}B -> data close failed:", self.written), + Some(&err), + ); Err(err) } } @@ -1597,30 +1752,44 @@ impl oio::BlockingWrite for LoggingWriter { fn write(&mut self, bs: Buffer) -> Result<()> { match self.inner.write(bs.clone()) { Ok(_) => { - trace!( - target: LOGGING_TARGET, - "service={} operation={} path={} written={}B -> data write {}B", + // trace!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} written={}B -> data write {}B", + // self.ctx.scheme, + // WriteOperation::BlockingWrite, + // self.path, + // self.written, + // bs.len(), + // ); + self.ctx.notify.log( self.ctx.scheme, - WriteOperation::BlockingWrite, - self.path, - self.written, - bs.len(), + WriteOperation::BlockingWrite.into_static(), + &self.path, + &format!("written={}B -> data write {}B", self.written, bs.len()), + None, ); Ok(()) } Err(err) => { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} written={}B -> data write failed: {}", - self.ctx.scheme, - WriteOperation::BlockingWrite, - self.path, - self.written, - self.ctx.error_print(&err), - ) - } + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} written={}B -> data write failed: {}", + // self.ctx.scheme, + // WriteOperation::BlockingWrite, + // self.path, + // self.written, + // self.ctx.error_print(&err), + // ) + // } + self.ctx.notify.log( + self.ctx.scheme, + WriteOperation::BlockingWrite.into_static(), + &self.path, + &format!("written={}B -> data write failed:", self.written), + Some(&err), + ); Err(err) } } @@ -1629,37 +1798,51 @@ impl oio::BlockingWrite for LoggingWriter { fn close(&mut self) -> Result<()> { match self.inner.close() { Ok(_) => { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} written={}B -> data written finished", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} written={}B -> data written finished", + // self.ctx.scheme, + // self.op, + // self.path, + // self.written + // ); + self.ctx.notify.log( self.ctx.scheme, - self.op, - self.path, - self.written + self.op.into_static(), + &self.path, + &format!("written={}B -> data written finished", self.written), + None, ); Ok(()) } Err(err) => { - if let Some(lvl) = self.ctx.error_level(&err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} written={}B -> data close failed: {}", - self.ctx.scheme, - WriteOperation::BlockingClose, - self.path, - self.written, - self.ctx.error_print(&err), - ) - } + // if let Some(lvl) = self.ctx.error_level(&err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} written={}B -> data close failed: {}", + // self.ctx.scheme, + // WriteOperation::BlockingClose, + // self.path, + // self.written, + // self.ctx.error_print(&err), + // ) + // } + self.ctx.notify.log( + self.ctx.scheme, + WriteOperation::BlockingClose.into_static(), + &self.path, + &format!("written={}B -> data close failed:", self.written), + Some(&err), + ); Err(err) } } } } -pub struct LoggingLister

{ - ctx: LoggingContext, +pub struct LoggingLister { + ctx: LoggingContext, path: String, op: Operation, @@ -1667,8 +1850,8 @@ pub struct LoggingLister

{ inner: P, } -impl

LoggingLister

{ - fn new(ctx: LoggingContext, path: &str, op: Operation, inner: P) -> Self { +impl LoggingLister { + fn new(ctx: LoggingContext, path: &str, op: Operation, inner: P) -> Self { Self { ctx, path: path.to_string(), @@ -1679,23 +1862,37 @@ impl

LoggingLister

{ } } -impl

Drop for LoggingLister

{ +impl Drop for LoggingLister { fn drop(&mut self) { if self.finished { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> all entries read finished", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> all entries read finished", + // self.ctx.scheme, + // self.op, + // self.path + // ); + self.ctx.notify.log( self.ctx.scheme, - self.op, - self.path + self.op.into_static(), + &self.path, + "-> all entries read finished", + None, ); } else { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> partial entries read finished", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> partial entries read finished", + // self.ctx.scheme, + // self.op, + // self.path + // ); + self.ctx.notify.log( self.ctx.scheme, - self.op, - self.path + self.op.into_static(), + &self.path, + "-> partial entries read finished", + None, ); } } @@ -1707,37 +1904,58 @@ impl oio::List for LoggingLister

{ match &res { Ok(Some(de)) => { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> listed entry: {}", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> listed entry: {}", + // self.ctx.scheme, + // self.op, + // self.path, + // de.path(), + // ); + self.ctx.notify.log( self.ctx.scheme, - self.op, - self.path, - de.path(), + self.op.into_static(), + &self.path, + &format!("-> listed entry: {}", de.path()), + None, ); } Ok(None) => { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> finished", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> finished", + // self.ctx.scheme, + // self.op, + // self.path + // ); + self.ctx.notify.log( self.ctx.scheme, - self.op, - self.path + self.op.into_static(), + &self.path, + "-> finished", + None, ); self.finished = true; } Err(err) => { - if let Some(lvl) = self.ctx.error_level(err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} -> {}", - self.ctx.scheme, - self.op, - self.path, - self.ctx.error_print(err) - ) - } + // if let Some(lvl) = self.ctx.error_level(err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} -> {}", + // self.ctx.scheme, + // self.op, + // self.path, + // self.ctx.error_print(err) + // ) + // } + self.ctx.notify.log( + self.ctx.scheme, + self.op.into_static(), + &self.path, + "->", + Some(&err), + ); } }; @@ -1751,37 +1969,58 @@ impl oio::BlockingList for LoggingLister

{ match &res { Ok(Some(des)) => { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> listed entry: {}", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> listed entry: {}", + // self.ctx.scheme, + // self.op, + // self.path, + // des.path(), + // ); + self.ctx.notify.log( self.ctx.scheme, - self.op, - self.path, - des.path(), + self.op.into_static(), + &self.path, + &format!("-> listed entry: {}", des.path()), + None, ); } Ok(None) => { - debug!( - target: LOGGING_TARGET, - "service={} operation={} path={} -> finished", + // debug!( + // target: LOGGING_TARGET, + // "service={} operation={} path={} -> finished", + // self.ctx.scheme, + // self.op, + // self.path + // ); + self.ctx.notify.log( self.ctx.scheme, - self.op, - self.path + self.op.into_static(), + &self.path, + "-> finished", + None, ); self.finished = true; } Err(err) => { - if let Some(lvl) = self.ctx.error_level(err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} -> {}", - self.ctx.scheme, - self.op, - self.path, - self.ctx.error_print(err) - ) - } + // if let Some(lvl) = self.ctx.error_level(err) { + // log!( + // target: LOGGING_TARGET, + // lvl, + // "service={} operation={} path={} -> {}", + // self.ctx.scheme, + // self.op, + // self.path, + // self.ctx.error_print(err) + // ) + // } + self.ctx.notify.log( + self.ctx.scheme, + self.op.into_static(), + &self.path, + "->", + Some(&err), + ); } }; From 629c45d40d2a42e10c09898273f020bac38bed91 Mon Sep 17 00:00:00 2001 From: evenyag Date: Sat, 3 Aug 2024 21:55:35 +0800 Subject: [PATCH 04/15] feat: compile --- core/src/layers/logging.rs | 78 +++++++++++++++++++++++++------------- 1 file changed, 51 insertions(+), 27 deletions(-) diff --git a/core/src/layers/logging.rs b/core/src/layers/logging.rs index ceaf50777caa..f6b186e316b9 100644 --- a/core/src/layers/logging.rs +++ b/core/src/layers/logging.rs @@ -82,12 +82,23 @@ use crate::*; /// ```shell /// RUST_LOG="info,opendal::services=debug" ./app /// ``` -#[derive(Debug, Clone)] -pub struct LoggingLayer { +#[derive(Debug)] +pub struct LoggingLayer { error_level: Option, failure_level: Option, backtrace_output: bool, - notify: Arc, + notify: Arc, +} + +impl Clone for LoggingLayer { + fn clone(&self) -> Self { + Self { + error_level: self.error_level, + failure_level: self.failure_level, + backtrace_output: self.backtrace_output, + notify: self.notify.clone(), + } + } } impl Default for LoggingLayer { @@ -151,8 +162,8 @@ impl LoggingLayer { } } -impl Layer for LoggingLayer { - type LayeredAccess = LoggingAccessor; +impl Layer for LoggingLayer { + type LayeredAccess = LoggingAccessor; fn layer(&self, inner: A) -> Self::LayeredAccess { let meta = inner.info(); @@ -170,7 +181,7 @@ impl Layer for LoggingLayer { } } -#[derive(Clone, Debug)] +#[derive(Debug)] pub struct LoggingContext { scheme: Scheme, error_level: Option, @@ -179,6 +190,18 @@ pub struct LoggingContext { notify: Arc, } +impl Clone for LoggingContext { + fn clone(&self) -> Self { + Self { + scheme: self.scheme, + error_level: self.error_level, + failure_level: self.failure_level, + backtrace_output: self.backtrace_output, + notify: self.notify.clone(), + } + } +} + impl LoggingContext { #[inline] fn error_level(&self, err: &Error) -> Option { @@ -206,7 +229,7 @@ impl LoggingContext { } /// LoggingInterceptor is used to intercept the log. -pub trait LoggingInterceptor: Debug { +pub trait LoggingInterceptor: Debug + Send + Sync + 'static { /// Everytime there is a log, this function will be called. // TODO(yingwen): docuement inputs. fn log( @@ -293,22 +316,22 @@ impl DefaultLoggingInterceptor { } #[derive(Clone, Debug)] -pub struct LoggingAccessor { +pub struct LoggingAccessor { inner: A, - ctx: LoggingContext, + ctx: LoggingContext, } static LOGGING_TARGET: &str = "opendal::services"; -impl LayeredAccess for LoggingAccessor { +impl LayeredAccess for LoggingAccessor { type Inner = A; - type Reader = LoggingReader; - type BlockingReader = LoggingReader; - type Writer = LoggingWriter; - type BlockingWriter = LoggingWriter; - type Lister = LoggingLister; - type BlockingLister = LoggingLister; + type Reader = LoggingReader; + type BlockingReader = LoggingReader; + type Writer = LoggingWriter; + type BlockingWriter = LoggingWriter; + type Lister = LoggingLister; + type BlockingLister = LoggingLister; fn inner(&self) -> &Self::Inner { &self.inner @@ -562,6 +585,7 @@ impl LayeredAccess for LoggingAccessor { self.ctx.notify.log( self.ctx.scheme, Operation::Copy.into_static(), + "", &format!("from={from} to={to} -> finished"), None, ); @@ -1404,7 +1428,7 @@ impl LayeredAccess for LoggingAccessor { Operation::BlockingList.into_static(), path, "-> got dir", - Some(&rp), + None, ); let li = LoggingLister::new(self.ctx.clone(), path, Operation::BlockingList, v); (rp, li) @@ -1434,7 +1458,7 @@ impl LayeredAccess for LoggingAccessor { } /// `LoggingReader` is a wrapper of `BytesReader`, with logging functionality. -pub struct LoggingReader { +pub struct LoggingReader { ctx: LoggingContext, path: String, op: Operation, @@ -1443,7 +1467,7 @@ pub struct LoggingReader { inner: R, } -impl LoggingReader { +impl LoggingReader { fn new(ctx: LoggingContext, op: Operation, path: &str, reader: R) -> Self { Self { ctx, @@ -1479,7 +1503,7 @@ impl Drop for LoggingReader { } } -impl oio::Read for LoggingReader { +impl oio::Read for LoggingReader { async fn read(&mut self) -> Result { match self.inner.read().await { Ok(bs) => { @@ -1533,7 +1557,7 @@ impl oio::Read for LoggingReader { } } -impl oio::BlockingRead for LoggingReader { +impl oio::BlockingRead for LoggingReader { fn read(&mut self) -> Result { match self.inner.read() { Ok(bs) => { @@ -1748,7 +1772,7 @@ impl oio::Write for LoggingWriter { } } -impl oio::BlockingWrite for LoggingWriter { +impl oio::BlockingWrite for LoggingWriter { fn write(&mut self, bs: Buffer) -> Result<()> { match self.inner.write(bs.clone()) { Ok(_) => { @@ -1841,7 +1865,7 @@ impl oio::BlockingWrite for LoggingWriter { } } -pub struct LoggingLister { +pub struct LoggingLister { ctx: LoggingContext, path: String, op: Operation, @@ -1850,7 +1874,7 @@ pub struct LoggingLister { inner: P, } -impl LoggingLister { +impl LoggingLister { fn new(ctx: LoggingContext, path: &str, op: Operation, inner: P) -> Self { Self { ctx, @@ -1862,7 +1886,7 @@ impl LoggingLister { } } -impl Drop for LoggingLister { +impl Drop for LoggingLister { fn drop(&mut self) { if self.finished { // debug!( @@ -1898,7 +1922,7 @@ impl Drop for LoggingLister { } } -impl oio::List for LoggingLister

{ +impl oio::List for LoggingLister { async fn next(&mut self) -> Result> { let res = self.inner.next().await; @@ -1963,7 +1987,7 @@ impl oio::List for LoggingLister

{ } } -impl oio::BlockingList for LoggingLister

{ +impl oio::BlockingList for LoggingLister { fn next(&mut self) -> Result> { let res = self.inner.next(); From 9422ce47d17956ed61e7bdd647c838b0d43913ab Mon Sep 17 00:00:00 2001 From: evenyag Date: Sat, 3 Aug 2024 22:09:07 +0800 Subject: [PATCH 05/15] feat: use interceptor --- core/src/layers/logging.rs | 152 +++++++++++++++--------------------- core/src/layers/mod.rs | 1 + core/src/raw/tests/utils.rs | 6 +- 3 files changed, 68 insertions(+), 91 deletions(-) diff --git a/core/src/layers/logging.rs b/core/src/layers/logging.rs index f6b186e316b9..f5c93efe08ac 100644 --- a/core/src/layers/logging.rs +++ b/core/src/layers/logging.rs @@ -84,18 +84,13 @@ use crate::*; /// ``` #[derive(Debug)] pub struct LoggingLayer { - error_level: Option, - failure_level: Option, - backtrace_output: bool, + // TODO(yingwen): optional notify: Arc, } impl Clone for LoggingLayer { fn clone(&self) -> Self { Self { - error_level: self.error_level, - failure_level: self.failure_level, - backtrace_output: self.backtrace_output, notify: self.notify.clone(), } } @@ -104,61 +99,16 @@ impl Clone for LoggingLayer { impl Default for LoggingLayer { fn default() -> Self { Self { - // FIXME(yingwen): Remove - error_level: Some(Level::Warn), - failure_level: Some(Level::Error), - backtrace_output: false, notify: Arc::new(DefaultLoggingInterceptor::default()), } } } impl LoggingLayer { - /// Setting the log level while expected error happened. - /// - /// For example: accessor returns NotFound. - /// - /// `None` means disable the log for error. - pub fn with_error_level(mut self, level: Option<&str>) -> Result { - if let Some(level_str) = level { - let level = level_str.parse().map_err(|_| { - Error::new(ErrorKind::ConfigInvalid, "invalid log level") - .with_context("level", level_str) - })?; - self.error_level = Some(level); - } else { - self.error_level = None; - } - Ok(self) - } - - /// Setting the log level while unexpected failure happened. - /// - /// For example: accessor returns Unexpected network error. - /// - /// `None` means disable the log for failure. - pub fn with_failure_level(mut self, level: Option<&str>) -> Result { - if let Some(level_str) = level { - let level = level_str.parse().map_err(|_| { - Error::new(ErrorKind::ConfigInvalid, "invalid log level") - .with_context("level", level_str) - })?; - self.failure_level = Some(level); - } else { - self.failure_level = None; + pub fn with_notify(self, notify: I) -> LoggingLayer { + LoggingLayer { + notify: Arc::new(notify), } - Ok(self) - } - - /// Setting whether to output backtrace while unexpected failure happened. - /// - /// # Notes - /// - /// - When the error is an expected error, backtrace will not be output. - /// - backtrace output is disable by default. - pub fn with_backtrace_output(mut self, enable: bool) -> Self { - self.backtrace_output = enable; - self } } @@ -172,9 +122,6 @@ impl Layer for LoggingLayer { ctx: LoggingContext { scheme: meta.scheme(), - error_level: self.error_level, - failure_level: self.failure_level, - backtrace_output: self.backtrace_output, notify: self.notify.clone(), }, } @@ -184,9 +131,6 @@ impl Layer for LoggingLayer { #[derive(Debug)] pub struct LoggingContext { scheme: Scheme, - error_level: Option, - failure_level: Option, - backtrace_output: bool, notify: Arc, } @@ -194,40 +138,11 @@ impl Clone for LoggingContext { fn clone(&self) -> Self { Self { scheme: self.scheme, - error_level: self.error_level, - failure_level: self.failure_level, - backtrace_output: self.backtrace_output, notify: self.notify.clone(), } } } -impl LoggingContext { - #[inline] - fn error_level(&self, err: &Error) -> Option { - if err.kind() == ErrorKind::Unexpected { - self.failure_level - } else { - self.error_level - } - } - - /// Print error with backtrace if it's unexpected error. - #[inline] - fn error_print(&self, err: &Error) -> String { - // Don't print backtrace if it's not unexpected error. - if err.kind() != ErrorKind::Unexpected { - return format!("{err}"); - } - - if self.backtrace_output { - format!("{err:?}") - } else { - format!("{err}") - } - } -} - /// LoggingInterceptor is used to intercept the log. pub trait LoggingInterceptor: Debug + Send + Sync + 'static { /// Everytime there is a log, this function will be called. @@ -243,13 +158,23 @@ pub trait LoggingInterceptor: Debug + Send + Sync + 'static { } /// The DefaultLoggingInterceptor will log the message by the standard logging macro. -#[derive(Debug, Default)] +#[derive(Debug)] pub struct DefaultLoggingInterceptor { error_level: Option, failure_level: Option, backtrace_output: bool, } +impl Default for DefaultLoggingInterceptor { + fn default() -> Self { + Self { + error_level: Some(Level::Warn), + failure_level: Some(Level::Error), + backtrace_output: false, + } + } +} + impl LoggingInterceptor for DefaultLoggingInterceptor { fn log( &self, @@ -290,6 +215,53 @@ impl LoggingInterceptor for DefaultLoggingInterceptor { } impl DefaultLoggingInterceptor { + /// Setting the log level while expected error happened. + /// + /// For example: accessor returns NotFound. + /// + /// `None` means disable the log for error. + pub fn with_error_level(mut self, level: Option<&str>) -> Result { + if let Some(level_str) = level { + let level = level_str.parse().map_err(|_| { + Error::new(ErrorKind::ConfigInvalid, "invalid log level") + .with_context("level", level_str) + })?; + self.error_level = Some(level); + } else { + self.error_level = None; + } + Ok(self) + } + + /// Setting the log level while unexpected failure happened. + /// + /// For example: accessor returns Unexpected network error. + /// + /// `None` means disable the log for failure. + pub fn with_failure_level(mut self, level: Option<&str>) -> Result { + if let Some(level_str) = level { + let level = level_str.parse().map_err(|_| { + Error::new(ErrorKind::ConfigInvalid, "invalid log level") + .with_context("level", level_str) + })?; + self.failure_level = Some(level); + } else { + self.failure_level = None; + } + Ok(self) + } + + /// Setting whether to output backtrace while unexpected failure happened. + /// + /// # Notes + /// + /// - When the error is an expected error, backtrace will not be output. + /// - backtrace output is disable by default. + pub fn with_backtrace_output(mut self, enable: bool) -> Self { + self.backtrace_output = enable; + self + } + #[inline] fn error_level(&self, err: &Error) -> Option { if err.kind() == ErrorKind::Unexpected { diff --git a/core/src/layers/mod.rs b/core/src/layers/mod.rs index eff0bfb8b746..c183c64ed91b 100644 --- a/core/src/layers/mod.rs +++ b/core/src/layers/mod.rs @@ -33,6 +33,7 @@ mod immutable_index; pub use immutable_index::ImmutableIndexLayer; mod logging; +pub use logging::DefaultLoggingInterceptor; pub use logging::LoggingLayer; mod timeout; diff --git a/core/src/raw/tests/utils.rs b/core/src/raw/tests/utils.rs index c9eb875d2070..1360638e6e44 100644 --- a/core/src/raw/tests/utils.rs +++ b/core/src/raw/tests/utils.rs @@ -73,7 +73,11 @@ pub fn init_test_service() -> Result> { let op = { op.layer(layers::ChaosLayer::new(0.1)) }; let mut op = op - .layer(layers::LoggingLayer::default().with_backtrace_output(true)) + .layer( + layers::LoggingLayer::default().with_notify( + layers::DefaultLoggingInterceptor::default().with_backtrace_output(true), + ), + ) .layer(layers::TimeoutLayer::new()) .layer(layers::RetryLayer::new().with_max_times(4)); From abe248bc1f86afabffd3316dda24e195ed6ab631 Mon Sep 17 00:00:00 2001 From: evenyag Date: Sun, 4 Aug 2024 17:17:36 +0800 Subject: [PATCH 06/15] feat: use ctx to log --- core/src/layers/logging.rs | 1142 +++++------------------------------ core/src/layers/mod.rs | 1 + core/src/raw/tests/utils.rs | 8 +- 3 files changed, 167 insertions(+), 984 deletions(-) diff --git a/core/src/layers/logging.rs b/core/src/layers/logging.rs index f5c93efe08ac..55be67b5b4af 100644 --- a/core/src/layers/logging.rs +++ b/core/src/layers/logging.rs @@ -23,9 +23,7 @@ use std::sync::Arc; use bytes::Buf; use futures::FutureExt; use futures::TryFutureExt; -use log::debug; use log::log; -use log::trace; use log::Level; use crate::raw::oio::ReadOperation; @@ -84,7 +82,6 @@ use crate::*; /// ``` #[derive(Debug)] pub struct LoggingLayer { - // TODO(yingwen): optional notify: Arc, } @@ -105,7 +102,40 @@ impl Default for LoggingLayer { } impl LoggingLayer { - pub fn with_notify(self, notify: I) -> LoggingLayer { + /// Create the layer with specific logging interceptor. + /// + /// ```no_run + /// use crate::layers::LoggingInterceptor; + /// use crate::layers::LoggingLayer; + /// use crate::services; + /// use crate::Error; + /// use crate::Operator; + /// use crate::Scheme; + /// + /// #[derive(Debug, Clone)] + /// struct MyLoggingInterceptor; + /// + /// impl LoggingInterceptor for MyLoggingInterceptor { + /// fn log( + /// &self, + /// scheme: Scheme, + /// operation: &'static str, + /// path: &str, + /// message: &str, + /// err: Option<&Error>, + /// ) { + /// // log something + /// } + /// } + /// + /// let _ = Operator::new(services::Memory::default()) + /// .expect("must init") + /// .layer(LoggingLayer::new(MyLoggingInterceptor)) + /// .finish(); + /// ``` + /// + /// This allows customize the log format. + pub fn new(notify: I) -> LoggingLayer { LoggingLayer { notify: Arc::new(notify), } @@ -143,10 +173,24 @@ impl Clone for LoggingContext { } } +impl LoggingContext { + fn log(&self, operation: &'static str, path: &str, message: &str, err: Option<&Error>) { + self.notify.log(self.scheme, operation, path, message, err) + } +} + /// LoggingInterceptor is used to intercept the log. pub trait LoggingInterceptor: Debug + Send + Sync + 'static { /// Everytime there is a log, this function will be called. - // TODO(yingwen): docuement inputs. + /// + /// # Inputs + /// + /// - scheme: The service generates the log. + /// - operation: The operation to log. + /// - path: The path argument to the operator, maybe empty if the + /// current operation doesn't have a path argument. + /// - message: The log message. + /// - err: The error to log. fn log( &self, scheme: Scheme, @@ -184,11 +228,11 @@ impl LoggingInterceptor for DefaultLoggingInterceptor { message: &str, err: Option<&Error>, ) { - // TODO(yingwen): Use trace for reader/writer - // ReadOperation::Read/ReadOperation::BlockingRead/WriteOperation::Write/WriteOperation::Abort/WriteOperation::BlockingWrite let Some(err) = err else { - debug!( + let lvl = self.operation_level(operation); + log!( target: LOGGING_TARGET, + lvl, "service={} operation={} path={} {}", scheme, operation, @@ -199,7 +243,6 @@ impl LoggingInterceptor for DefaultLoggingInterceptor { }; if let Some(lvl) = self.error_level(err) { - // TODO(yingwen): don't print message if no message log!( target: LOGGING_TARGET, lvl, @@ -262,6 +305,16 @@ impl DefaultLoggingInterceptor { self } + fn operation_level(&self, operation: &str) -> Level { + match operation { + "ReadOperation::Read" + | "ReadOperation::BlockingRead" + | "WriteOperation::Write" + | "WriteOperation::BlockingWrite" => Level::Trace, + _ => Level::Debug, + } + } + #[inline] fn error_level(&self, err: &Error) -> Option { if err.kind() == ErrorKind::Unexpected { @@ -271,6 +324,7 @@ impl DefaultLoggingInterceptor { } } + // TODO(yingwen): avoid two format. /// Print error with backtrace if it's unexpected error. #[inline] fn error_print(&self, err: &Error) -> String { @@ -310,29 +364,10 @@ impl LayeredAccess for LoggingAccessor { } fn metadata(&self) -> Arc { - self.ctx.notify.log( - self.ctx.scheme, - Operation::Info.into_static(), - "", - "-> started", - None, - ); - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} -> started", - // self.ctx.scheme, - // Operation::Info - // ); + self.ctx + .log(Operation::Info.into_static(), "", "-> started", None); let result = self.inner.info(); - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} -> finished: {:?}", - // self.ctx.scheme, - // Operation::Info, - // result - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::Info.into_static(), "", &format!("-> finished: {:?}", result), @@ -343,34 +378,14 @@ impl LayeredAccess for LoggingAccessor { } async fn create_dir(&self, path: &str, args: OpCreateDir) -> Result { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> started", - // self.ctx.scheme, - // Operation::CreateDir, - // path - // ); - self.ctx.notify.log( - self.ctx.scheme, - Operation::CreateDir.into_static(), - path, - "-> started", - None, - ); + self.ctx + .log(Operation::CreateDir.into_static(), path, "-> started", None); self.inner .create_dir(path, args) .await .map(|v| { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> finished", - // self.ctx.scheme, - // Operation::CreateDir, - // path - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::CreateDir.into_static(), path, "-> finished", @@ -379,120 +394,43 @@ impl LayeredAccess for LoggingAccessor { v }) .map_err(|err| { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} -> {}", - // self.ctx.scheme, - // Operation::CreateDir, - // path, - // self.ctx.error_print(&err) - // ) - - // }; - self.ctx.notify.log( - self.ctx.scheme, - Operation::CreateDir.into_static(), - path, - "->", - Some(&err), - ); + self.ctx + .log(Operation::CreateDir.into_static(), path, "->", Some(&err)); err }) } async fn read(&self, path: &str, args: OpRead) -> Result<(RpRead, Self::Reader)> { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> started", - // self.ctx.scheme, - // Operation::Read, - // path, - // ); - self.ctx.notify.log( - self.ctx.scheme, - Operation::Read.into_static(), - path, - "-> started", - None, - ); + self.ctx + .log(Operation::Read.into_static(), path, "-> started", None); self.inner .read(path, args) .await .map(|(rp, r)| { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> got reader", - // self.ctx.scheme, - // Operation::Read, - // path, - // ); - self.ctx.notify.log( - self.ctx.scheme, - Operation::Read.into_static(), - path, - "-> got reader", - None, - ); + self.ctx + .log(Operation::Read.into_static(), path, "-> got reader", None); ( rp, LoggingReader::new(self.ctx.clone(), Operation::Read, path, r), ) }) .map_err(|err| { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} -> {}", - // self.ctx.scheme, - // Operation::Read, - // path, - // self.ctx.error_print(&err) - // ) - // } - self.ctx.notify.log( - self.ctx.scheme, - Operation::Read.into_static(), - path, - "->", - Some(&err), - ); + self.ctx + .log(Operation::Read.into_static(), path, "->", Some(&err)); err }) } async fn write(&self, path: &str, args: OpWrite) -> Result<(RpWrite, Self::Writer)> { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> started", - // self.ctx.scheme, - // Operation::Write, - // path - // ); - self.ctx.notify.log( - self.ctx.scheme, - Operation::Write.into_static(), - path, - "-> started", - None, - ); + self.ctx + .log(Operation::Write.into_static(), path, "-> started", None); self.inner .write(path, args) .await .map(|(rp, w)| { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> start writing", - // self.ctx.scheme, - // Operation::Write, - // path, - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::Write.into_static(), path, "-> start writing", @@ -502,40 +440,14 @@ impl LayeredAccess for LoggingAccessor { (rp, w) }) .map_err(|err| { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} -> {}", - // self.ctx.scheme, - // Operation::Write, - // path, - // self.ctx.error_print(&err) - // ) - // }; - self.ctx.notify.log( - self.ctx.scheme, - Operation::Write.into_static(), - path, - "->", - Some(&err), - ); + self.ctx + .log(Operation::Write.into_static(), path, "->", Some(&err)); err }) } async fn copy(&self, from: &str, to: &str, args: OpCopy) -> Result { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} from={} to={} -> started", - // self.ctx.scheme, - // Operation::Copy, - // from, - // to - // ); - - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::Copy.into_static(), "", &format!("from={from} to={to} -> started"), @@ -546,16 +458,7 @@ impl LayeredAccess for LoggingAccessor { .copy(from, to, args) .await .map(|v| { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} from={} to={} -> finished", - // self.ctx.scheme, - // Operation::Copy, - // from, - // to - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::Copy.into_static(), "", &format!("from={from} to={to} -> finished"), @@ -564,20 +467,7 @@ impl LayeredAccess for LoggingAccessor { v }) .map_err(|err| { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} from={} to={} -> {}", - // self.ctx.scheme, - // Operation::Copy, - // from, - // to, - // self.ctx.error_print(&err), - // ) - // }; - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::Copy.into_static(), "", &format!("from={from} to={to} ->"), @@ -588,17 +478,7 @@ impl LayeredAccess for LoggingAccessor { } async fn rename(&self, from: &str, to: &str, args: OpRename) -> Result { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} from={} to={} -> started", - // self.ctx.scheme, - // Operation::Rename, - // from, - // to - // ); - // FIXME(yingwen): from, to - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::Rename.into_static(), "", &format!("from={from} to={to} -> started"), @@ -609,16 +489,7 @@ impl LayeredAccess for LoggingAccessor { .rename(from, to, args) .await .map(|v| { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} from={} to={} -> finished", - // self.ctx.scheme, - // Operation::Rename, - // from, - // to - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::Rename.into_static(), "", &format!("from={from} to={to} -> finished"), @@ -627,20 +498,7 @@ impl LayeredAccess for LoggingAccessor { v }) .map_err(|err| { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} from={} to={} -> {}", - // self.ctx.scheme, - // Operation::Rename, - // from, - // to, - // self.ctx.error_print(&err) - // ) - // }; - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::Rename.into_static(), "", &format!("from={from} to={to} ->"), @@ -651,152 +509,49 @@ impl LayeredAccess for LoggingAccessor { } async fn stat(&self, path: &str, args: OpStat) -> Result { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> started", - // self.ctx.scheme, - // Operation::Stat, - // path - // ); - self.ctx.notify.log( - self.ctx.scheme, - Operation::Stat.into_static(), - path, - "-> started", - None, - ); + self.ctx + .log(Operation::Stat.into_static(), path, "-> started", None); self.inner .stat(path, args) .await .map(|v| { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> finished: {v:?}", - // self.ctx.scheme, - // Operation::Stat, - // path - // ); - self.ctx.notify.log( - self.ctx.scheme, - Operation::Stat.into_static(), - path, - "-> finished", - None, - ); + self.ctx + .log(Operation::Stat.into_static(), path, "-> finished", None); v }) .map_err(|err| { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} -> {}", - // self.ctx.scheme, - // Operation::Stat, - // path, - // self.ctx.error_print(&err) - // ); - // }; - self.ctx.notify.log( - self.ctx.scheme, - Operation::Stat.into_static(), - path, - "->", - Some(&err), - ); + self.ctx + .log(Operation::Stat.into_static(), path, "->", Some(&err)); err }) } async fn delete(&self, path: &str, args: OpDelete) -> Result { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> started", - // self.ctx.scheme, - // Operation::Delete, - // path - // ); - self.ctx.notify.log( - self.ctx.scheme, - Operation::Delete.into_static(), - path, - "-> started", - None, - ); + self.ctx + .log(Operation::Delete.into_static(), path, "-> started", None); self.inner .delete(path, args.clone()) .inspect(|v| match v { Ok(_) => { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> finished", - // self.ctx.scheme, - // Operation::Delete, - // path - // ); - self.ctx.notify.log( - self.ctx.scheme, - Operation::Delete.into_static(), - path, - "-> finished", - None, - ); + self.ctx + .log(Operation::Delete.into_static(), path, "-> finished", None); } Err(err) => { - // if let Some(lvl) = self.ctx.error_level(err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} -> {}", - // self.ctx.scheme, - // Operation::Delete, - // path, - // self.ctx.error_print(err) - // ); - // } - self.ctx.notify.log( - self.ctx.scheme, - Operation::Delete.into_static(), - path, - "->", - Some(err), - ); + self.ctx + .log(Operation::Delete.into_static(), path, "->", Some(err)); } }) .await } async fn list(&self, path: &str, args: OpList) -> Result<(RpList, Self::Lister)> { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> started", - // self.ctx.scheme, - // Operation::List, - // path - // ); - self.ctx.notify.log( - self.ctx.scheme, - Operation::List.into_static(), - path, - "-> started", - None, - ); - self.inner .list(path, args) .map(|v| match v { Ok((rp, v)) => { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> start listing dir", - // self.ctx.scheme, - // Operation::List, - // path - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::List.into_static(), path, "-> start listing dir", @@ -806,24 +561,8 @@ impl LayeredAccess for LoggingAccessor { Ok((rp, streamer)) } Err(err) => { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} -> {}", - // self.ctx.scheme, - // Operation::List, - // path, - // self.ctx.error_print(&err) - // ); - // } - self.ctx.notify.log( - self.ctx.scheme, - Operation::List.into_static(), - path, - "->", - Some(&err), - ); + self.ctx + .log(Operation::List.into_static(), path, "->", Some(&err)); Err(err) } }) @@ -831,60 +570,20 @@ impl LayeredAccess for LoggingAccessor { } async fn presign(&self, path: &str, args: OpPresign) -> Result { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> started", - // self.ctx.scheme, - // Operation::Presign, - // path - // ); - self.ctx.notify.log( - self.ctx.scheme, - Operation::Presign.into_static(), - path, - "-> started", - None, - ); + self.ctx + .log(Operation::Presign.into_static(), path, "-> started", None); self.inner .presign(path, args) .await .map(|v| { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> finished: {v:?}", - // self.ctx.scheme, - // Operation::Presign, - // path - // ); - self.ctx.notify.log( - self.ctx.scheme, - Operation::Presign.into_static(), - path, - "-> finished", - None, - ); + self.ctx + .log(Operation::Presign.into_static(), path, "-> finished", None); v }) .map_err(|err| { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} -> {}", - // self.ctx.scheme, - // Operation::Presign, - // path, - // self.ctx.error_print(&err) - // ); - // } - self.ctx.notify.log( - self.ctx.scheme, - Operation::Presign.into_static(), - path, - "->", - Some(&err), - ); + self.ctx + .log(Operation::Presign.into_static(), path, "->", Some(&err)); err }) } @@ -892,14 +591,7 @@ impl LayeredAccess for LoggingAccessor { async fn batch(&self, args: OpBatch) -> Result { let (op, count) = (args.operation()[0].1.operation(), args.operation().len()); - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={}-{op} count={count} -> started", - // self.ctx.scheme, - // Operation::Batch, - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::Batch.into_static(), "", &format!("op={op} count={count} -> started"), @@ -909,17 +601,7 @@ impl LayeredAccess for LoggingAccessor { self.inner .batch(args) .map_ok(|v| { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={}-{op} count={count} -> finished: {}, succeed: {}, failed: {}", - // self.ctx.scheme, - // Operation::Batch, - // v.results().len(), - // v.results().iter().filter(|(_, v)|v.is_ok()).count(), - // v.results().iter().filter(|(_, v)|v.is_err()).count(), - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::Batch.into_static(), "", &format!( @@ -933,18 +615,7 @@ impl LayeredAccess for LoggingAccessor { v }) .map_err(|err| { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={}-{op} count={count} -> {}", - // self.ctx.scheme, - // Operation::Batch, - // self.ctx.error_print(&err) - // ); - // } - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::Batch.into_static(), "", &format!("op={op} count={count} ->"), @@ -956,15 +627,7 @@ impl LayeredAccess for LoggingAccessor { } fn blocking_create_dir(&self, path: &str, args: OpCreateDir) -> Result { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> started", - // self.ctx.scheme, - // Operation::BlockingCreateDir, - // path - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingCreateDir.into_static(), path, "-> started", @@ -974,15 +637,7 @@ impl LayeredAccess for LoggingAccessor { self.inner .blocking_create_dir(path, args) .map(|v| { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> finished", - // self.ctx.scheme, - // Operation::BlockingCreateDir, - // path - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingCreateDir.into_static(), path, "-> finished", @@ -991,19 +646,7 @@ impl LayeredAccess for LoggingAccessor { v }) .map_err(|err| { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} -> {}", - // self.ctx.scheme, - // Operation::BlockingCreateDir, - // path, - // self.ctx.error_print(&err) - // ); - // } - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingCreateDir.into_static(), path, "->", @@ -1014,15 +657,7 @@ impl LayeredAccess for LoggingAccessor { } fn blocking_read(&self, path: &str, args: OpRead) -> Result<(RpRead, Self::BlockingReader)> { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> started", - // self.ctx.scheme, - // Operation::BlockingRead, - // path, - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingRead.into_static(), path, "-> started", @@ -1032,15 +667,7 @@ impl LayeredAccess for LoggingAccessor { self.inner .blocking_read(path, args.clone()) .map(|(rp, r)| { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> got reader", - // self.ctx.scheme, - // Operation::BlockingRead, - // path, - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingRead.into_static(), path, "-> got reader", @@ -1050,19 +677,7 @@ impl LayeredAccess for LoggingAccessor { (rp, r) }) .map_err(|err| { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} -> {}", - // self.ctx.scheme, - // Operation::BlockingRead, - // path, - // self.ctx.error_print(&err) - // ); - // } - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingRead.into_static(), path, "->", @@ -1073,15 +688,7 @@ impl LayeredAccess for LoggingAccessor { } fn blocking_write(&self, path: &str, args: OpWrite) -> Result<(RpWrite, Self::BlockingWriter)> { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> started", - // self.ctx.scheme, - // Operation::BlockingWrite, - // path, - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingWrite.into_static(), path, "-> started", @@ -1091,15 +698,7 @@ impl LayeredAccess for LoggingAccessor { self.inner .blocking_write(path, args) .map(|(rp, w)| { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> start writing", - // self.ctx.scheme, - // Operation::BlockingWrite, - // path, - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingWrite.into_static(), path, "-> start writing", @@ -1109,19 +708,7 @@ impl LayeredAccess for LoggingAccessor { (rp, w) }) .map_err(|err| { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} -> {}", - // self.ctx.scheme, - // Operation::BlockingWrite, - // path, - // self.ctx.error_print(&err) - // ); - // } - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingWrite.into_static(), path, "->", @@ -1132,16 +719,7 @@ impl LayeredAccess for LoggingAccessor { } fn blocking_copy(&self, from: &str, to: &str, args: OpCopy) -> Result { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} from={} to={} -> started", - // self.ctx.scheme, - // Operation::BlockingCopy, - // from, - // to, - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingCopy.into_static(), "", &format!("from={from} to={to} -> started"), @@ -1151,16 +729,7 @@ impl LayeredAccess for LoggingAccessor { self.inner .blocking_copy(from, to, args) .map(|v| { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} from={} to={} -> finished", - // self.ctx.scheme, - // Operation::BlockingCopy, - // from, - // to, - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingCopy.into_static(), "", &format!("from={from} to={to} -> finished"), @@ -1169,20 +738,7 @@ impl LayeredAccess for LoggingAccessor { v }) .map_err(|err| { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} from={} to={} -> {}", - // self.ctx.scheme, - // Operation::BlockingCopy, - // from, - // to, - // self.ctx.error_print(&err) - // ); - // } - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingCopy.into_static(), "", &format!("from={from} to={to} ->"), @@ -1193,16 +749,7 @@ impl LayeredAccess for LoggingAccessor { } fn blocking_rename(&self, from: &str, to: &str, args: OpRename) -> Result { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} from={} to={} -> started", - // self.ctx.scheme, - // Operation::BlockingRename, - // from, - // to, - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingRename.into_static(), "", &format!("from={from} to={to} -> started"), @@ -1212,16 +759,7 @@ impl LayeredAccess for LoggingAccessor { self.inner .blocking_rename(from, to, args) .map(|v| { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} from={} to={} -> finished", - // self.ctx.scheme, - // Operation::BlockingRename, - // from, - // to, - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingRename.into_static(), "", &format!("from={from} to={to} -> finished"), @@ -1230,20 +768,7 @@ impl LayeredAccess for LoggingAccessor { v }) .map_err(|err| { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} from={} to={} -> {}", - // self.ctx.scheme, - // Operation::BlockingRename, - // from, - // to, - // self.ctx.error_print(&err) - // ); - // } - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingRename.into_static(), "", &format!("from={from} to={to} ->"), @@ -1254,15 +779,7 @@ impl LayeredAccess for LoggingAccessor { } fn blocking_stat(&self, path: &str, args: OpStat) -> Result { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> started", - // self.ctx.scheme, - // Operation::BlockingStat, - // path - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingStat.into_static(), path, "-> started", @@ -1272,15 +789,7 @@ impl LayeredAccess for LoggingAccessor { self.inner .blocking_stat(path, args) .map(|v| { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> finished: {v:?}", - // self.ctx.scheme, - // Operation::BlockingStat, - // path - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingStat.into_static(), path, "-> finished", @@ -1289,19 +798,7 @@ impl LayeredAccess for LoggingAccessor { v }) .map_err(|err| { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} -> {}", - // self.ctx.scheme, - // Operation::BlockingStat, - // path, - // self.ctx.error_print(&err) - // ); - // } - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingStat.into_static(), path, "->", @@ -1312,15 +809,7 @@ impl LayeredAccess for LoggingAccessor { } fn blocking_delete(&self, path: &str, args: OpDelete) -> Result { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> started", - // self.ctx.scheme, - // Operation::BlockingDelete, - // path - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingDelete.into_static(), path, "-> started", @@ -1330,15 +819,7 @@ impl LayeredAccess for LoggingAccessor { self.inner .blocking_delete(path, args) .map(|v| { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> finished", - // self.ctx.scheme, - // Operation::BlockingDelete, - // path - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingDelete.into_static(), path, "-> finished", @@ -1347,19 +828,7 @@ impl LayeredAccess for LoggingAccessor { v }) .map_err(|err| { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} -> {}", - // self.ctx.scheme, - // Operation::BlockingDelete, - // path, - // self.ctx.error_print(&err) - // ); - // } - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingDelete.into_static(), path, "->", @@ -1370,15 +839,7 @@ impl LayeredAccess for LoggingAccessor { } fn blocking_list(&self, path: &str, args: OpList) -> Result<(RpList, Self::BlockingLister)> { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> started", - // self.ctx.scheme, - // Operation::BlockingList, - // path - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingList.into_static(), path, "-> started", @@ -1388,15 +849,7 @@ impl LayeredAccess for LoggingAccessor { self.inner .blocking_list(path, args) .map(|(rp, v)| { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> got dir", - // self.ctx.scheme, - // Operation::BlockingList, - // path - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingList.into_static(), path, "-> got dir", @@ -1406,19 +859,7 @@ impl LayeredAccess for LoggingAccessor { (rp, li) }) .map_err(|err| { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} -> {}", - // self.ctx.scheme, - // Operation::BlockingList, - // path, - // self.ctx.error_print(&err) - // ); - // } - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( Operation::BlockingList.into_static(), path, "->", @@ -1454,16 +895,7 @@ impl LoggingReader { impl Drop for LoggingReader { fn drop(&mut self) { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} read={} -> data read finished", - // self.ctx.scheme, - // self.op, - // self.path, - // self.read.load(Ordering::Relaxed) - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( self.op.into_static(), &self.path, &format!( @@ -1481,17 +913,7 @@ impl oio::Read for LoggingReader { Ok(bs) => { self.read .fetch_add(bs.remaining() as u64, Ordering::Relaxed); - // trace!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} read={} -> read returns {}B", - // self.ctx.scheme, - // ReadOperation::Read, - // self.path, - // self.read.load(Ordering::Relaxed), - // bs.remaining() - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( ReadOperation::Read.into_static(), &self.path, &format!( @@ -1504,20 +926,7 @@ impl oio::Read for LoggingReader { Ok(bs) } Err(err) => { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} read={} -> read failed: {}", - // self.ctx.scheme, - // ReadOperation::Read, - // self.path, - // self.read.load(Ordering::Relaxed), - // self.ctx.error_print(&err), - // ) - // } - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( ReadOperation::Read.into_static(), &self.path, &format!("read={} -> read failed:", self.read.load(Ordering::Relaxed)), @@ -1535,17 +944,7 @@ impl oio::BlockingRead for LoggingR Ok(bs) => { self.read .fetch_add(bs.remaining() as u64, Ordering::Relaxed); - // trace!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} read={} -> read returns {}B", - // self.ctx.scheme, - // ReadOperation::BlockingRead, - // self.path, - // self.read.load(Ordering::Relaxed), - // bs.remaining() - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( ReadOperation::BlockingRead.into_static(), &self.path, &format!( @@ -1558,20 +957,7 @@ impl oio::BlockingRead for LoggingR Ok(bs) } Err(err) => { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} read={} -> read failed: {}", - // self.ctx.scheme, - // ReadOperation::BlockingRead, - // self.path, - // self.read.load(Ordering::Relaxed), - // self.ctx.error_print(&err), - // ); - // } - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( ReadOperation::BlockingRead.into_static(), &self.path, &format!("read={} -> read failed:", self.read.load(Ordering::Relaxed)), @@ -1610,17 +996,7 @@ impl oio::Write for LoggingWriter { let size = bs.len(); match self.inner.write(bs).await { Ok(_) => { - // trace!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} written={}B -> data write {}B", - // self.ctx.scheme, - // WriteOperation::Write, - // self.path, - // self.written, - // size, - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( WriteOperation::Write.into_static(), &self.path, &format!("written={}B -> data write {}B", self.written, size), @@ -1629,20 +1005,7 @@ impl oio::Write for LoggingWriter { Ok(()) } Err(err) => { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} written={}B -> data write failed: {}", - // self.ctx.scheme, - // WriteOperation::Write, - // self.path, - // self.written, - // self.ctx.error_print(&err), - // ) - // } - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( WriteOperation::Write.into_static(), &self.path, &format!("written={}B -> data write failed:", self.written), @@ -1656,16 +1019,7 @@ impl oio::Write for LoggingWriter { async fn abort(&mut self) -> Result<()> { match self.inner.abort().await { Ok(_) => { - // trace!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} written={}B -> abort writer", - // self.ctx.scheme, - // WriteOperation::Abort, - // self.path, - // self.written, - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( WriteOperation::Abort.into_static(), &self.path, &format!("written={}B -> abort writer", self.written), @@ -1674,20 +1028,7 @@ impl oio::Write for LoggingWriter { Ok(()) } Err(err) => { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} written={}B -> abort writer failed: {}", - // self.ctx.scheme, - // WriteOperation::Abort, - // self.path, - // self.written, - // self.ctx.error_print(&err), - // ) - // } - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( WriteOperation::Abort.into_static(), &self.path, &format!("written={}B -> abort writer failed:", self.written), @@ -1701,16 +1042,7 @@ impl oio::Write for LoggingWriter { async fn close(&mut self) -> Result<()> { match self.inner.close().await { Ok(_) => { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} written={}B -> data written finished", - // self.ctx.scheme, - // self.op, - // self.path, - // self.written - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( self.op.into_static(), &self.path, &format!("written={}B -> data written finished", self.written), @@ -1719,20 +1051,7 @@ impl oio::Write for LoggingWriter { Ok(()) } Err(err) => { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} written={}B -> data close failed: {}", - // self.ctx.scheme, - // WriteOperation::Close, - // self.path, - // self.written, - // self.ctx.error_print(&err), - // ) - // } - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( WriteOperation::Close.into_static(), &self.path, &format!("written={}B -> data close failed:", self.written), @@ -1748,17 +1067,7 @@ impl oio::BlockingWrite for Loggin fn write(&mut self, bs: Buffer) -> Result<()> { match self.inner.write(bs.clone()) { Ok(_) => { - // trace!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} written={}B -> data write {}B", - // self.ctx.scheme, - // WriteOperation::BlockingWrite, - // self.path, - // self.written, - // bs.len(), - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( WriteOperation::BlockingWrite.into_static(), &self.path, &format!("written={}B -> data write {}B", self.written, bs.len()), @@ -1767,20 +1076,7 @@ impl oio::BlockingWrite for Loggin Ok(()) } Err(err) => { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} written={}B -> data write failed: {}", - // self.ctx.scheme, - // WriteOperation::BlockingWrite, - // self.path, - // self.written, - // self.ctx.error_print(&err), - // ) - // } - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( WriteOperation::BlockingWrite.into_static(), &self.path, &format!("written={}B -> data write failed:", self.written), @@ -1794,16 +1090,7 @@ impl oio::BlockingWrite for Loggin fn close(&mut self) -> Result<()> { match self.inner.close() { Ok(_) => { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} written={}B -> data written finished", - // self.ctx.scheme, - // self.op, - // self.path, - // self.written - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( self.op.into_static(), &self.path, &format!("written={}B -> data written finished", self.written), @@ -1812,20 +1099,7 @@ impl oio::BlockingWrite for Loggin Ok(()) } Err(err) => { - // if let Some(lvl) = self.ctx.error_level(&err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} written={}B -> data close failed: {}", - // self.ctx.scheme, - // WriteOperation::BlockingClose, - // self.path, - // self.written, - // self.ctx.error_print(&err), - // ) - // } - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( WriteOperation::BlockingClose.into_static(), &self.path, &format!("written={}B -> data close failed:", self.written), @@ -1861,30 +1135,14 @@ impl LoggingLister { impl Drop for LoggingLister { fn drop(&mut self) { if self.finished { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> all entries read finished", - // self.ctx.scheme, - // self.op, - // self.path - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( self.op.into_static(), &self.path, "-> all entries read finished", None, ); } else { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> partial entries read finished", - // self.ctx.scheme, - // self.op, - // self.path - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( self.op.into_static(), &self.path, "-> partial entries read finished", @@ -1900,16 +1158,7 @@ impl oio::List for LoggingLister { match &res { Ok(Some(de)) => { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> listed entry: {}", - // self.ctx.scheme, - // self.op, - // self.path, - // de.path(), - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( self.op.into_static(), &self.path, &format!("-> listed entry: {}", de.path()), @@ -1917,41 +1166,13 @@ impl oio::List for LoggingLister { ); } Ok(None) => { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> finished", - // self.ctx.scheme, - // self.op, - // self.path - // ); - self.ctx.notify.log( - self.ctx.scheme, - self.op.into_static(), - &self.path, - "-> finished", - None, - ); + self.ctx + .log(self.op.into_static(), &self.path, "-> finished", None); self.finished = true; } Err(err) => { - // if let Some(lvl) = self.ctx.error_level(err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} -> {}", - // self.ctx.scheme, - // self.op, - // self.path, - // self.ctx.error_print(err) - // ) - // } - self.ctx.notify.log( - self.ctx.scheme, - self.op.into_static(), - &self.path, - "->", - Some(&err), - ); + self.ctx + .log(self.op.into_static(), &self.path, "->", Some(&err)); } }; @@ -1965,16 +1186,7 @@ impl oio::BlockingList for LoggingL match &res { Ok(Some(des)) => { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> listed entry: {}", - // self.ctx.scheme, - // self.op, - // self.path, - // des.path(), - // ); - self.ctx.notify.log( - self.ctx.scheme, + self.ctx.log( self.op.into_static(), &self.path, &format!("-> listed entry: {}", des.path()), @@ -1982,41 +1194,13 @@ impl oio::BlockingList for LoggingL ); } Ok(None) => { - // debug!( - // target: LOGGING_TARGET, - // "service={} operation={} path={} -> finished", - // self.ctx.scheme, - // self.op, - // self.path - // ); - self.ctx.notify.log( - self.ctx.scheme, - self.op.into_static(), - &self.path, - "-> finished", - None, - ); + self.ctx + .log(self.op.into_static(), &self.path, "-> finished", None); self.finished = true; } Err(err) => { - // if let Some(lvl) = self.ctx.error_level(err) { - // log!( - // target: LOGGING_TARGET, - // lvl, - // "service={} operation={} path={} -> {}", - // self.ctx.scheme, - // self.op, - // self.path, - // self.ctx.error_print(err) - // ) - // } - self.ctx.notify.log( - self.ctx.scheme, - self.op.into_static(), - &self.path, - "->", - Some(&err), - ); + self.ctx + .log(self.op.into_static(), &self.path, "->", Some(&err)); } }; diff --git a/core/src/layers/mod.rs b/core/src/layers/mod.rs index c183c64ed91b..b1563b58c4b4 100644 --- a/core/src/layers/mod.rs +++ b/core/src/layers/mod.rs @@ -34,6 +34,7 @@ pub use immutable_index::ImmutableIndexLayer; mod logging; pub use logging::DefaultLoggingInterceptor; +pub use logging::LoggingInterceptor; pub use logging::LoggingLayer; mod timeout; diff --git a/core/src/raw/tests/utils.rs b/core/src/raw/tests/utils.rs index 1360638e6e44..da186b1ace75 100644 --- a/core/src/raw/tests/utils.rs +++ b/core/src/raw/tests/utils.rs @@ -73,11 +73,9 @@ pub fn init_test_service() -> Result> { let op = { op.layer(layers::ChaosLayer::new(0.1)) }; let mut op = op - .layer( - layers::LoggingLayer::default().with_notify( - layers::DefaultLoggingInterceptor::default().with_backtrace_output(true), - ), - ) + .layer(layers::LoggingLayer::new( + layers::DefaultLoggingInterceptor::default().with_backtrace_output(true), + )) .layer(layers::TimeoutLayer::new()) .layer(layers::RetryLayer::new().with_max_times(4)); From 6e56f3bf16169ef219e00dc5a6c6ca1ec4f73a09 Mon Sep 17 00:00:00 2001 From: evenyag Date: Sun, 4 Aug 2024 17:25:16 +0800 Subject: [PATCH 07/15] feat: avoid formatting err first --- core/src/layers/logging.rs | 47 +++++++++++++++++++++++--------------- 1 file changed, 28 insertions(+), 19 deletions(-) diff --git a/core/src/layers/logging.rs b/core/src/layers/logging.rs index 55be67b5b4af..598c0ed383b3 100644 --- a/core/src/layers/logging.rs +++ b/core/src/layers/logging.rs @@ -243,16 +243,29 @@ impl LoggingInterceptor for DefaultLoggingInterceptor { }; if let Some(lvl) = self.error_level(err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} {} {}", - scheme, - operation, - path, - message, - self.error_print(&err) - ) + if self.print_backtrace(err) { + log!( + target: LOGGING_TARGET, + lvl, + "service={} operation={} path={} {} {:?}", + scheme, + operation, + path, + message, + err, + ) + } else { + log!( + target: LOGGING_TARGET, + lvl, + "service={} operation={} path={} {} {}", + scheme, + operation, + path, + message, + err, + ) + } } } } @@ -324,20 +337,16 @@ impl DefaultLoggingInterceptor { } } - // TODO(yingwen): avoid two format. - /// Print error with backtrace if it's unexpected error. + /// Returns true if the error is unexpected and we need to + /// print the backtrace. #[inline] - fn error_print(&self, err: &Error) -> String { + fn print_backtrace(&self, err: &Error) -> bool { // Don't print backtrace if it's not unexpected error. if err.kind() != ErrorKind::Unexpected { - return format!("{err}"); + return false; } - if self.backtrace_output { - format!("{err:?}") - } else { - format!("{err}") - } + self.backtrace_output } } From d35fcac880b36888e7dba02d3fc155fdc7bf5ffa Mon Sep 17 00:00:00 2001 From: evenyag Date: Mon, 5 Aug 2024 21:59:23 +0800 Subject: [PATCH 08/15] style: fix clippy --- core/src/layers/logging.rs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/core/src/layers/logging.rs b/core/src/layers/logging.rs index 598c0ed383b3..16ac6924efd6 100644 --- a/core/src/layers/logging.rs +++ b/core/src/layers/logging.rs @@ -1181,7 +1181,7 @@ impl oio::List for LoggingLister { } Err(err) => { self.ctx - .log(self.op.into_static(), &self.path, "->", Some(&err)); + .log(self.op.into_static(), &self.path, "->", Some(err)); } }; @@ -1209,7 +1209,7 @@ impl oio::BlockingList for LoggingL } Err(err) => { self.ctx - .log(self.op.into_static(), &self.path, "->", Some(&err)); + .log(self.op.into_static(), &self.path, "->", Some(err)); } }; From 2c998968633257eb57b41c95ec2e26077f8c6577 Mon Sep 17 00:00:00 2001 From: evenyag Date: Tue, 6 Aug 2024 21:16:45 +0800 Subject: [PATCH 09/15] chore: update comments --- core/src/layers/logging.rs | 72 +++++++++++++++++++++----------------- 1 file changed, 40 insertions(+), 32 deletions(-) diff --git a/core/src/layers/logging.rs b/core/src/layers/logging.rs index 16ac6924efd6..816bec582155 100644 --- a/core/src/layers/logging.rs +++ b/core/src/layers/logging.rs @@ -80,6 +80,40 @@ use crate::*; /// ```shell /// RUST_LOG="info,opendal::services=debug" ./app /// ``` +/// +/// # Logging Interceptor +/// +/// You can implement your own logging interceptor to customize the logging behavior. +/// +/// ```no_run +/// use crate::layers::LoggingInterceptor; +/// use crate::layers::LoggingLayer; +/// use crate::services; +/// use crate::Error; +/// use crate::Operator; +/// use crate::Scheme; +/// +/// #[derive(Debug, Clone)] +/// struct MyLoggingInterceptor; +/// +/// impl LoggingInterceptor for MyLoggingInterceptor { +/// fn log( +/// &self, +/// scheme: Scheme, +/// operation: &'static str, +/// path: &str, +/// message: &str, +/// err: Option<&Error>, +/// ) { +/// // log something +/// } +/// } +/// +/// let _ = Operator::new(services::Memory::default()) +/// .expect("must init") +/// .layer(LoggingLayer::new(MyLoggingInterceptor)) +/// .finish(); +/// ``` #[derive(Debug)] pub struct LoggingLayer { notify: Arc, @@ -103,38 +137,6 @@ impl Default for LoggingLayer { impl LoggingLayer { /// Create the layer with specific logging interceptor. - /// - /// ```no_run - /// use crate::layers::LoggingInterceptor; - /// use crate::layers::LoggingLayer; - /// use crate::services; - /// use crate::Error; - /// use crate::Operator; - /// use crate::Scheme; - /// - /// #[derive(Debug, Clone)] - /// struct MyLoggingInterceptor; - /// - /// impl LoggingInterceptor for MyLoggingInterceptor { - /// fn log( - /// &self, - /// scheme: Scheme, - /// operation: &'static str, - /// path: &str, - /// message: &str, - /// err: Option<&Error>, - /// ) { - /// // log something - /// } - /// } - /// - /// let _ = Operator::new(services::Memory::default()) - /// .expect("must init") - /// .layer(LoggingLayer::new(MyLoggingInterceptor)) - /// .finish(); - /// ``` - /// - /// This allows customize the log format. pub fn new(notify: I) -> LoggingLayer { LoggingLayer { notify: Arc::new(notify), @@ -191,6 +193,12 @@ pub trait LoggingInterceptor: Debug + Send + Sync + 'static { /// current operation doesn't have a path argument. /// - message: The log message. /// - err: The error to log. + /// + /// # Note + /// + /// Users should avoid calling resource-intensive operations such as I/O or network + /// functions here, especially anything that takes longer than 10ms. Otherwise, Opendal + /// could perform unexpectedly slow. fn log( &self, scheme: Scheme, From e524609af55c2cc15852044ba9c67fc08506154e Mon Sep 17 00:00:00 2001 From: evenyag Date: Thu, 8 Aug 2024 19:08:11 +0800 Subject: [PATCH 10/15] refactor: pass operation --- core/src/layers/logging.rs | 327 +++++++++++++------------------------ 1 file changed, 109 insertions(+), 218 deletions(-) diff --git a/core/src/layers/logging.rs b/core/src/layers/logging.rs index 284e09a2152a..4e858131601b 100644 --- a/core/src/layers/logging.rs +++ b/core/src/layers/logging.rs @@ -174,11 +174,12 @@ impl Clone for LoggingContext { } impl LoggingContext { - fn log(&self, operation: &'static str, path: &str, message: &str, err: Option<&Error>) { + fn log(&self, operation: Operation, path: &str, message: &str, err: Option<&Error>) { self.notify.log(self.scheme, operation, path, message, err) } } +// TODO(yingwen): Update example. /// LoggingInterceptor is used to intercept the log. pub trait LoggingInterceptor: Debug + Send + Sync + 'static { /// Everytime there is a log, this function will be called. @@ -200,7 +201,7 @@ pub trait LoggingInterceptor: Debug + Send + Sync + 'static { fn log( &self, scheme: Scheme, - operation: &'static str, + operation: Operation, path: &str, message: &str, err: Option<&Error>, @@ -229,7 +230,7 @@ impl LoggingInterceptor for DefaultLoggingInterceptor { fn log( &self, scheme: Scheme, - operation: &'static str, + operation: Operation, path: &str, message: &str, err: Option<&Error>, @@ -324,12 +325,12 @@ impl DefaultLoggingInterceptor { self } - fn operation_level(&self, operation: &str) -> Level { + fn operation_level(&self, operation: Operation) -> Level { match operation { - "ReadOperation::Read" - | "ReadOperation::BlockingRead" - | "WriteOperation::Write" - | "WriteOperation::BlockingWrite" => Level::Trace, + Operation::ReaderRead + | Operation::BlockingReaderRead + | Operation::WriterWrite + | Operation::BlockingWriterWrite => Level::Trace, _ => Level::Debug, } } @@ -379,11 +380,10 @@ impl LayeredAccess for LoggingAccessor { } fn metadata(&self) -> Arc { - self.ctx - .log(Operation::Info.into_static(), "", "-> started", None); + self.ctx.log(Operation::Info, "", "-> started", None); let result = self.inner.info(); self.ctx.log( - Operation::Info.into_static(), + Operation::Info, "", &format!("-> finished: {:?}", result), None, @@ -393,77 +393,62 @@ impl LayeredAccess for LoggingAccessor { } async fn create_dir(&self, path: &str, args: OpCreateDir) -> Result { - self.ctx - .log(Operation::CreateDir.into_static(), path, "-> started", None); + self.ctx.log(Operation::CreateDir, path, "-> started", None); self.inner .create_dir(path, args) .await .map(|v| { - self.ctx.log( - Operation::CreateDir.into_static(), - path, - "-> finished", - None, - ); + self.ctx + .log(Operation::CreateDir, path, "-> finished", None); v }) .map_err(|err| { - self.ctx - .log(Operation::CreateDir.into_static(), path, "->", Some(&err)); + self.ctx.log(Operation::CreateDir, path, "->", Some(&err)); err }) } async fn read(&self, path: &str, args: OpRead) -> Result<(RpRead, Self::Reader)> { - self.ctx - .log(Operation::Read.into_static(), path, "-> started", None); + self.ctx.log(Operation::Read, path, "-> started", None); self.inner .read(path, args) .await .map(|(rp, r)| { - self.ctx - .log(Operation::Read.into_static(), path, "-> got reader", None); + self.ctx.log(Operation::Read, path, "-> got reader", None); ( rp, LoggingReader::new(self.ctx.clone(), Operation::Read, path, r), ) }) .map_err(|err| { - self.ctx - .log(Operation::Read.into_static(), path, "->", Some(&err)); + self.ctx.log(Operation::Read, path, "->", Some(&err)); err }) } async fn write(&self, path: &str, args: OpWrite) -> Result<(RpWrite, Self::Writer)> { - self.ctx - .log(Operation::Write.into_static(), path, "-> started", None); + self.ctx.log(Operation::Write, path, "-> started", None); self.inner .write(path, args) .await .map(|(rp, w)| { - self.ctx.log( - Operation::Write.into_static(), - path, - "-> start writing", - None, - ); + self.ctx + .log(Operation::Write, path, "-> start writing", None); let w = LoggingWriter::new(self.ctx.clone(), Operation::Write, path, w); (rp, w) }) .map_err(|err| { - self.ctx - .log(Operation::Write.into_static(), path, "->", Some(&err)); + self.ctx.log(Operation::Write, path, "->", Some(&err)); err }) } async fn copy(&self, from: &str, to: &str, args: OpCopy) -> Result { self.ctx.log( - Operation::Copy.into_static(), + Operation::Copy, "", &format!("from={from} to={to} -> started"), None, @@ -474,7 +459,7 @@ impl LayeredAccess for LoggingAccessor { .await .map(|v| { self.ctx.log( - Operation::Copy.into_static(), + Operation::Copy, "", &format!("from={from} to={to} -> finished"), None, @@ -483,7 +468,7 @@ impl LayeredAccess for LoggingAccessor { }) .map_err(|err| { self.ctx.log( - Operation::Copy.into_static(), + Operation::Copy, "", &format!("from={from} to={to} ->"), Some(&err), @@ -494,7 +479,7 @@ impl LayeredAccess for LoggingAccessor { async fn rename(&self, from: &str, to: &str, args: OpRename) -> Result { self.ctx.log( - Operation::Rename.into_static(), + Operation::Rename, "", &format!("from={from} to={to} -> started"), None, @@ -505,7 +490,7 @@ impl LayeredAccess for LoggingAccessor { .await .map(|v| { self.ctx.log( - Operation::Rename.into_static(), + Operation::Rename, "", &format!("from={from} to={to} -> finished"), None, @@ -514,7 +499,7 @@ impl LayeredAccess for LoggingAccessor { }) .map_err(|err| { self.ctx.log( - Operation::Rename.into_static(), + Operation::Rename, "", &format!("from={from} to={to} ->"), Some(&err), @@ -524,38 +509,32 @@ impl LayeredAccess for LoggingAccessor { } async fn stat(&self, path: &str, args: OpStat) -> Result { - self.ctx - .log(Operation::Stat.into_static(), path, "-> started", None); + self.ctx.log(Operation::Stat, path, "-> started", None); self.inner .stat(path, args) .await .map(|v| { - self.ctx - .log(Operation::Stat.into_static(), path, "-> finished", None); + self.ctx.log(Operation::Stat, path, "-> finished", None); v }) .map_err(|err| { - self.ctx - .log(Operation::Stat.into_static(), path, "->", Some(&err)); + self.ctx.log(Operation::Stat, path, "->", Some(&err)); err }) } async fn delete(&self, path: &str, args: OpDelete) -> Result { - self.ctx - .log(Operation::Delete.into_static(), path, "-> started", None); + self.ctx.log(Operation::Delete, path, "-> started", None); self.inner .delete(path, args.clone()) .inspect(|v| match v { Ok(_) => { - self.ctx - .log(Operation::Delete.into_static(), path, "-> finished", None); + self.ctx.log(Operation::Delete, path, "-> finished", None); } Err(err) => { - self.ctx - .log(Operation::Delete.into_static(), path, "->", Some(err)); + self.ctx.log(Operation::Delete, path, "->", Some(err)); } }) .await @@ -566,18 +545,13 @@ impl LayeredAccess for LoggingAccessor { .list(path, args) .map(|v| match v { Ok((rp, v)) => { - self.ctx.log( - Operation::List.into_static(), - path, - "-> start listing dir", - None, - ); + self.ctx + .log(Operation::List, path, "-> start listing dir", None); let streamer = LoggingLister::new(self.ctx.clone(), path, Operation::List, v); Ok((rp, streamer)) } Err(err) => { - self.ctx - .log(Operation::List.into_static(), path, "->", Some(&err)); + self.ctx.log(Operation::List, path, "->", Some(&err)); Err(err) } }) @@ -585,20 +559,17 @@ impl LayeredAccess for LoggingAccessor { } async fn presign(&self, path: &str, args: OpPresign) -> Result { - self.ctx - .log(Operation::Presign.into_static(), path, "-> started", None); + self.ctx.log(Operation::Presign, path, "-> started", None); self.inner .presign(path, args) .await .map(|v| { - self.ctx - .log(Operation::Presign.into_static(), path, "-> finished", None); + self.ctx.log(Operation::Presign, path, "-> finished", None); v }) .map_err(|err| { - self.ctx - .log(Operation::Presign.into_static(), path, "->", Some(&err)); + self.ctx.log(Operation::Presign, path, "->", Some(&err)); err }) } @@ -607,7 +578,7 @@ impl LayeredAccess for LoggingAccessor { let (op, count) = (args.operation()[0].1.operation(), args.operation().len()); self.ctx.log( - Operation::Batch.into_static(), + Operation::Batch, "", &format!("op={op} count={count} -> started"), None, @@ -617,7 +588,7 @@ impl LayeredAccess for LoggingAccessor { .batch(args) .map_ok(|v| { self.ctx.log( - Operation::Batch.into_static(), + Operation::Batch, "", &format!( "op={op} count={count} -> finished: {}, succeed: {}, failed: {}", @@ -631,7 +602,7 @@ impl LayeredAccess for LoggingAccessor { }) .map_err(|err| { self.ctx.log( - Operation::Batch.into_static(), + Operation::Batch, "", &format!("op={op} count={count} ->"), Some(&err), @@ -642,100 +613,64 @@ impl LayeredAccess for LoggingAccessor { } fn blocking_create_dir(&self, path: &str, args: OpCreateDir) -> Result { - self.ctx.log( - Operation::BlockingCreateDir.into_static(), - path, - "-> started", - None, - ); + self.ctx + .log(Operation::BlockingCreateDir, path, "-> started", None); self.inner .blocking_create_dir(path, args) .map(|v| { - self.ctx.log( - Operation::BlockingCreateDir.into_static(), - path, - "-> finished", - None, - ); + self.ctx + .log(Operation::BlockingCreateDir, path, "-> finished", None); v }) .map_err(|err| { - self.ctx.log( - Operation::BlockingCreateDir.into_static(), - path, - "->", - Some(&err), - ); + self.ctx + .log(Operation::BlockingCreateDir, path, "->", Some(&err)); err }) } fn blocking_read(&self, path: &str, args: OpRead) -> Result<(RpRead, Self::BlockingReader)> { - self.ctx.log( - Operation::BlockingRead.into_static(), - path, - "-> started", - None, - ); + self.ctx + .log(Operation::BlockingRead, path, "-> started", None); self.inner .blocking_read(path, args.clone()) .map(|(rp, r)| { - self.ctx.log( - Operation::BlockingRead.into_static(), - path, - "-> got reader", - None, - ); + self.ctx + .log(Operation::BlockingRead, path, "-> got reader", None); let r = LoggingReader::new(self.ctx.clone(), Operation::BlockingRead, path, r); (rp, r) }) .map_err(|err| { - self.ctx.log( - Operation::BlockingRead.into_static(), - path, - "->", - Some(&err), - ); + self.ctx + .log(Operation::BlockingRead, path, "->", Some(&err)); err }) } fn blocking_write(&self, path: &str, args: OpWrite) -> Result<(RpWrite, Self::BlockingWriter)> { - self.ctx.log( - Operation::BlockingWrite.into_static(), - path, - "-> started", - None, - ); + self.ctx + .log(Operation::BlockingWrite, path, "-> started", None); self.inner .blocking_write(path, args) .map(|(rp, w)| { - self.ctx.log( - Operation::BlockingWrite.into_static(), - path, - "-> start writing", - None, - ); + self.ctx + .log(Operation::BlockingWrite, path, "-> start writing", None); let w = LoggingWriter::new(self.ctx.clone(), Operation::BlockingWrite, path, w); (rp, w) }) .map_err(|err| { - self.ctx.log( - Operation::BlockingWrite.into_static(), - path, - "->", - Some(&err), - ); + self.ctx + .log(Operation::BlockingWrite, path, "->", Some(&err)); err }) } fn blocking_copy(&self, from: &str, to: &str, args: OpCopy) -> Result { self.ctx.log( - Operation::BlockingCopy.into_static(), + Operation::BlockingCopy, "", &format!("from={from} to={to} -> started"), None, @@ -745,7 +680,7 @@ impl LayeredAccess for LoggingAccessor { .blocking_copy(from, to, args) .map(|v| { self.ctx.log( - Operation::BlockingCopy.into_static(), + Operation::BlockingCopy, "", &format!("from={from} to={to} -> finished"), None, @@ -754,7 +689,7 @@ impl LayeredAccess for LoggingAccessor { }) .map_err(|err| { self.ctx.log( - Operation::BlockingCopy.into_static(), + Operation::BlockingCopy, "", &format!("from={from} to={to} ->"), Some(&err), @@ -765,7 +700,7 @@ impl LayeredAccess for LoggingAccessor { fn blocking_rename(&self, from: &str, to: &str, args: OpRename) -> Result { self.ctx.log( - Operation::BlockingRename.into_static(), + Operation::BlockingRename, "", &format!("from={from} to={to} -> started"), None, @@ -775,7 +710,7 @@ impl LayeredAccess for LoggingAccessor { .blocking_rename(from, to, args) .map(|v| { self.ctx.log( - Operation::BlockingRename.into_static(), + Operation::BlockingRename, "", &format!("from={from} to={to} -> finished"), None, @@ -784,7 +719,7 @@ impl LayeredAccess for LoggingAccessor { }) .map_err(|err| { self.ctx.log( - Operation::BlockingRename.into_static(), + Operation::BlockingRename, "", &format!("from={from} to={to} ->"), Some(&err), @@ -794,92 +729,56 @@ impl LayeredAccess for LoggingAccessor { } fn blocking_stat(&self, path: &str, args: OpStat) -> Result { - self.ctx.log( - Operation::BlockingStat.into_static(), - path, - "-> started", - None, - ); + self.ctx + .log(Operation::BlockingStat, path, "-> started", None); self.inner .blocking_stat(path, args) .map(|v| { - self.ctx.log( - Operation::BlockingStat.into_static(), - path, - "-> finished", - None, - ); + self.ctx + .log(Operation::BlockingStat, path, "-> finished", None); v }) .map_err(|err| { - self.ctx.log( - Operation::BlockingStat.into_static(), - path, - "->", - Some(&err), - ); + self.ctx + .log(Operation::BlockingStat, path, "->", Some(&err)); err }) } fn blocking_delete(&self, path: &str, args: OpDelete) -> Result { - self.ctx.log( - Operation::BlockingDelete.into_static(), - path, - "-> started", - None, - ); + self.ctx + .log(Operation::BlockingDelete, path, "-> started", None); self.inner .blocking_delete(path, args) .map(|v| { - self.ctx.log( - Operation::BlockingDelete.into_static(), - path, - "-> finished", - None, - ); + self.ctx + .log(Operation::BlockingDelete, path, "-> finished", None); v }) .map_err(|err| { - self.ctx.log( - Operation::BlockingDelete.into_static(), - path, - "->", - Some(&err), - ); + self.ctx + .log(Operation::BlockingDelete, path, "->", Some(&err)); err }) } fn blocking_list(&self, path: &str, args: OpList) -> Result<(RpList, Self::BlockingLister)> { - self.ctx.log( - Operation::BlockingList.into_static(), - path, - "-> started", - None, - ); + self.ctx + .log(Operation::BlockingList, path, "-> started", None); self.inner .blocking_list(path, args) .map(|(rp, v)| { - self.ctx.log( - Operation::BlockingList.into_static(), - path, - "-> got dir", - None, - ); + self.ctx + .log(Operation::BlockingList, path, "-> got dir", None); let li = LoggingLister::new(self.ctx.clone(), path, Operation::BlockingList, v); (rp, li) }) .map_err(|err| { - self.ctx.log( - Operation::BlockingList.into_static(), - path, - "->", - Some(&err), - ); + self.ctx + .log(Operation::BlockingList, path, "->", Some(&err)); err }) } @@ -911,7 +810,7 @@ impl LoggingReader { impl Drop for LoggingReader { fn drop(&mut self) { self.ctx.log( - self.op.into_static(), + self.op, &self.path, &format!( "read={} -> data read finished", @@ -929,7 +828,7 @@ impl oio::Read for LoggingReader { self.read .fetch_add(bs.remaining() as u64, Ordering::Relaxed); self.ctx.log( - Operation::ReaderRead.into_static(), + Operation::ReaderRead, &self.path, &format!( "read={} -> read returns {}B", @@ -942,7 +841,7 @@ impl oio::Read for LoggingReader { } Err(err) => { self.ctx.log( - Operation::ReaderRead.into_static(), + Operation::ReaderRead, &self.path, &format!("read={} -> read failed:", self.read.load(Ordering::Relaxed)), Some(&err), @@ -960,7 +859,7 @@ impl oio::BlockingRead for LoggingR self.read .fetch_add(bs.remaining() as u64, Ordering::Relaxed); self.ctx.log( - Operation::BlockingReaderRead.into_static(), + Operation::BlockingReaderRead, &self.path, &format!( "read={} -> read returns {}B", @@ -973,7 +872,7 @@ impl oio::BlockingRead for LoggingR } Err(err) => { self.ctx.log( - Operation::BlockingReaderRead.into_static(), + Operation::BlockingReaderRead, &self.path, &format!("read={} -> read failed:", self.read.load(Ordering::Relaxed)), Some(&err), @@ -1012,7 +911,7 @@ impl oio::Write for LoggingWriter { match self.inner.write(bs).await { Ok(_) => { self.ctx.log( - Operation::WriterWrite.into_static(), + Operation::WriterWrite, &self.path, &format!("written={}B -> data write {}B", self.written, size), None, @@ -1021,7 +920,7 @@ impl oio::Write for LoggingWriter { } Err(err) => { self.ctx.log( - Operation::WriterWrite.into_static(), + Operation::WriterWrite, &self.path, &format!("written={}B -> data write failed:", self.written), Some(&err), @@ -1035,7 +934,7 @@ impl oio::Write for LoggingWriter { match self.inner.abort().await { Ok(_) => { self.ctx.log( - Operation::WriterAbort.into_static(), + Operation::WriterAbort, &self.path, &format!("written={}B -> abort writer", self.written), None, @@ -1044,7 +943,7 @@ impl oio::Write for LoggingWriter { } Err(err) => { self.ctx.log( - Operation::WriterAbort.into_static(), + Operation::WriterAbort, &self.path, &format!("written={}B -> abort writer failed:", self.written), Some(&err), @@ -1058,7 +957,7 @@ impl oio::Write for LoggingWriter { match self.inner.close().await { Ok(_) => { self.ctx.log( - self.op.into_static(), + self.op, &self.path, &format!("written={}B -> data written finished", self.written), None, @@ -1067,7 +966,7 @@ impl oio::Write for LoggingWriter { } Err(err) => { self.ctx.log( - Operation::WriterClose.into_static(), + Operation::WriterClose, &self.path, &format!("written={}B -> data close failed:", self.written), Some(&err), @@ -1083,7 +982,7 @@ impl oio::BlockingWrite for Loggin match self.inner.write(bs.clone()) { Ok(_) => { self.ctx.log( - Operation::BlockingWriterWrite.into_static(), + Operation::BlockingWriterWrite, &self.path, &format!("written={}B -> data write {}B", self.written, bs.len()), None, @@ -1092,7 +991,7 @@ impl oio::BlockingWrite for Loggin } Err(err) => { self.ctx.log( - Operation::BlockingWriterWrite.into_static(), + Operation::BlockingWriterWrite, &self.path, &format!("written={}B -> data write failed:", self.written), Some(&err), @@ -1106,7 +1005,7 @@ impl oio::BlockingWrite for Loggin match self.inner.close() { Ok(_) => { self.ctx.log( - self.op.into_static(), + self.op, &self.path, &format!("written={}B -> data written finished", self.written), None, @@ -1115,7 +1014,7 @@ impl oio::BlockingWrite for Loggin } Err(err) => { self.ctx.log( - Operation::BlockingWriterClose.into_static(), + Operation::BlockingWriterClose, &self.path, &format!("written={}B -> data close failed:", self.written), Some(&err), @@ -1150,15 +1049,11 @@ impl LoggingLister { impl Drop for LoggingLister { fn drop(&mut self) { if self.finished { - self.ctx.log( - self.op.into_static(), - &self.path, - "-> all entries read finished", - None, - ); + self.ctx + .log(self.op, &self.path, "-> all entries read finished", None); } else { self.ctx.log( - self.op.into_static(), + self.op, &self.path, "-> partial entries read finished", None, @@ -1174,20 +1069,18 @@ impl oio::List for LoggingLister { match &res { Ok(Some(de)) => { self.ctx.log( - self.op.into_static(), + self.op, &self.path, &format!("-> listed entry: {}", de.path()), None, ); } Ok(None) => { - self.ctx - .log(self.op.into_static(), &self.path, "-> finished", None); + self.ctx.log(self.op, &self.path, "-> finished", None); self.finished = true; } Err(err) => { - self.ctx - .log(self.op.into_static(), &self.path, "->", Some(err)); + self.ctx.log(self.op, &self.path, "->", Some(err)); } }; @@ -1202,20 +1095,18 @@ impl oio::BlockingList for LoggingL match &res { Ok(Some(des)) => { self.ctx.log( - self.op.into_static(), + self.op, &self.path, &format!("-> listed entry: {}", des.path()), None, ); } Ok(None) => { - self.ctx - .log(self.op.into_static(), &self.path, "-> finished", None); + self.ctx.log(self.op, &self.path, "-> finished", None); self.finished = true; } Err(err) => { - self.ctx - .log(self.op.into_static(), &self.path, "->", Some(err)); + self.ctx.log(self.op, &self.path, "->", Some(err)); } }; From a44c5c33b278cf34b654db264bed5de98ff36471 Mon Sep 17 00:00:00 2001 From: evenyag Date: Thu, 8 Aug 2024 19:50:45 +0800 Subject: [PATCH 11/15] feat: add context --- core/src/layers/logging.rs | 299 ++++++++++++++++++++----------------- 1 file changed, 162 insertions(+), 137 deletions(-) diff --git a/core/src/layers/logging.rs b/core/src/layers/logging.rs index 4e858131601b..d18a6c0bc91e 100644 --- a/core/src/layers/logging.rs +++ b/core/src/layers/logging.rs @@ -174,8 +174,21 @@ impl Clone for LoggingContext { } impl LoggingContext { + fn log_with_context( + &self, + operation: Operation, + path: &str, + context: &str, + message: &str, + err: Option<&Error>, + ) { + self.notify + .log(self.scheme, operation, path, context, message, err) + } + fn log(&self, operation: Operation, path: &str, message: &str, err: Option<&Error>) { - self.notify.log(self.scheme, operation, path, message, err) + self.notify + .log(self.scheme, operation, path, "", message, err) } } @@ -190,6 +203,7 @@ pub trait LoggingInterceptor: Debug + Send + Sync + 'static { /// - operation: The operation to log. /// - path: The path argument to the operator, maybe empty if the /// current operation doesn't have a path argument. + /// - context: Additional context of the log. /// - message: The log message. /// - err: The error to log. /// @@ -203,11 +217,13 @@ pub trait LoggingInterceptor: Debug + Send + Sync + 'static { scheme: Scheme, operation: Operation, path: &str, + context: &str, message: &str, err: Option<&Error>, ); } +// TODO(yingwen): Remove fields. /// The DefaultLoggingInterceptor will log the message by the standard logging macro. #[derive(Debug)] pub struct DefaultLoggingInterceptor { @@ -232,6 +248,7 @@ impl LoggingInterceptor for DefaultLoggingInterceptor { scheme: Scheme, operation: Operation, path: &str, + context: &str, message: &str, err: Option<&Error>, ) { @@ -240,10 +257,11 @@ impl LoggingInterceptor for DefaultLoggingInterceptor { log!( target: LOGGING_TARGET, lvl, - "service={} operation={} path={} {}", + "service={} operation={} path={} {} -> {}", scheme, operation, path, + context, message, ); return; @@ -254,10 +272,11 @@ impl LoggingInterceptor for DefaultLoggingInterceptor { log!( target: LOGGING_TARGET, lvl, - "service={} operation={} path={} {} {:?}", + "service={} operation={} path={} {} -> {} {:?}", scheme, operation, path, + context, message, err, ) @@ -265,10 +284,11 @@ impl LoggingInterceptor for DefaultLoggingInterceptor { log!( target: LOGGING_TARGET, lvl, - "service={} operation={} path={} {} {}", + "service={} operation={} path={} {} -> {} {}", scheme, operation, path, + context, message, err, ) @@ -380,12 +400,12 @@ impl LayeredAccess for LoggingAccessor { } fn metadata(&self) -> Arc { - self.ctx.log(Operation::Info, "", "-> started", None); + self.ctx.log(Operation::Info, "", "started", None); let result = self.inner.info(); self.ctx.log( Operation::Info, "", - &format!("-> finished: {:?}", result), + &format!("finished: {:?}", result), None, ); @@ -393,64 +413,63 @@ impl LayeredAccess for LoggingAccessor { } async fn create_dir(&self, path: &str, args: OpCreateDir) -> Result { - self.ctx.log(Operation::CreateDir, path, "-> started", None); + self.ctx.log(Operation::CreateDir, path, "started", None); self.inner .create_dir(path, args) .await .map(|v| { - self.ctx - .log(Operation::CreateDir, path, "-> finished", None); + self.ctx.log(Operation::CreateDir, path, "finished", None); v }) .map_err(|err| { - self.ctx.log(Operation::CreateDir, path, "->", Some(&err)); + self.ctx.log(Operation::CreateDir, path, "", Some(&err)); err }) } async fn read(&self, path: &str, args: OpRead) -> Result<(RpRead, Self::Reader)> { - self.ctx.log(Operation::Read, path, "-> started", None); + self.ctx.log(Operation::Read, path, "started", None); self.inner .read(path, args) .await .map(|(rp, r)| { - self.ctx.log(Operation::Read, path, "-> got reader", None); + self.ctx.log(Operation::Read, path, "got reader", None); ( rp, LoggingReader::new(self.ctx.clone(), Operation::Read, path, r), ) }) .map_err(|err| { - self.ctx.log(Operation::Read, path, "->", Some(&err)); + self.ctx.log(Operation::Read, path, "", Some(&err)); err }) } async fn write(&self, path: &str, args: OpWrite) -> Result<(RpWrite, Self::Writer)> { - self.ctx.log(Operation::Write, path, "-> started", None); + self.ctx.log(Operation::Write, path, "started", None); self.inner .write(path, args) .await .map(|(rp, w)| { - self.ctx - .log(Operation::Write, path, "-> start writing", None); + self.ctx.log(Operation::Write, path, "start writing", None); let w = LoggingWriter::new(self.ctx.clone(), Operation::Write, path, w); (rp, w) }) .map_err(|err| { - self.ctx.log(Operation::Write, path, "->", Some(&err)); + self.ctx.log(Operation::Write, path, "", Some(&err)); err }) } async fn copy(&self, from: &str, to: &str, args: OpCopy) -> Result { - self.ctx.log( + self.ctx.log_with_context( Operation::Copy, "", - &format!("from={from} to={to} -> started"), + &format!("from={from} to={to}"), + "started", None, ); @@ -458,19 +477,21 @@ impl LayeredAccess for LoggingAccessor { .copy(from, to, args) .await .map(|v| { - self.ctx.log( + self.ctx.log_with_context( Operation::Copy, "", - &format!("from={from} to={to} -> finished"), + &format!("from={from} to={to}"), + "finished", None, ); v }) .map_err(|err| { - self.ctx.log( + self.ctx.log_with_context( Operation::Copy, "", - &format!("from={from} to={to} ->"), + &format!("from={from} to={to}"), + "", Some(&err), ); err @@ -478,10 +499,11 @@ impl LayeredAccess for LoggingAccessor { } async fn rename(&self, from: &str, to: &str, args: OpRename) -> Result { - self.ctx.log( + self.ctx.log_with_context( Operation::Rename, "", - &format!("from={from} to={to} -> started"), + &format!("from={from} to={to}"), + "started", None, ); @@ -489,19 +511,21 @@ impl LayeredAccess for LoggingAccessor { .rename(from, to, args) .await .map(|v| { - self.ctx.log( + self.ctx.log_with_context( Operation::Rename, "", - &format!("from={from} to={to} -> finished"), + &format!("from={from} to={to}"), + "finished", None, ); v }) .map_err(|err| { - self.ctx.log( + self.ctx.log_with_context( Operation::Rename, "", - &format!("from={from} to={to} ->"), + &format!("from={from} to={to}"), + "", Some(&err), ); err @@ -509,32 +533,32 @@ impl LayeredAccess for LoggingAccessor { } async fn stat(&self, path: &str, args: OpStat) -> Result { - self.ctx.log(Operation::Stat, path, "-> started", None); + self.ctx.log(Operation::Stat, path, "started", None); self.inner .stat(path, args) .await .map(|v| { - self.ctx.log(Operation::Stat, path, "-> finished", None); + self.ctx.log(Operation::Stat, path, "finished", None); v }) .map_err(|err| { - self.ctx.log(Operation::Stat, path, "->", Some(&err)); + self.ctx.log(Operation::Stat, path, "", Some(&err)); err }) } async fn delete(&self, path: &str, args: OpDelete) -> Result { - self.ctx.log(Operation::Delete, path, "-> started", None); + self.ctx.log(Operation::Delete, path, "started", None); self.inner .delete(path, args.clone()) .inspect(|v| match v { Ok(_) => { - self.ctx.log(Operation::Delete, path, "-> finished", None); + self.ctx.log(Operation::Delete, path, "finished", None); } Err(err) => { - self.ctx.log(Operation::Delete, path, "->", Some(err)); + self.ctx.log(Operation::Delete, path, "", Some(err)); } }) .await @@ -546,12 +570,12 @@ impl LayeredAccess for LoggingAccessor { .map(|v| match v { Ok((rp, v)) => { self.ctx - .log(Operation::List, path, "-> start listing dir", None); + .log(Operation::List, path, "start listing dir", None); let streamer = LoggingLister::new(self.ctx.clone(), path, Operation::List, v); Ok((rp, streamer)) } Err(err) => { - self.ctx.log(Operation::List, path, "->", Some(&err)); + self.ctx.log(Operation::List, path, "", Some(&err)); Err(err) } }) @@ -559,17 +583,17 @@ impl LayeredAccess for LoggingAccessor { } async fn presign(&self, path: &str, args: OpPresign) -> Result { - self.ctx.log(Operation::Presign, path, "-> started", None); + self.ctx.log(Operation::Presign, path, "started", None); self.inner .presign(path, args) .await .map(|v| { - self.ctx.log(Operation::Presign, path, "-> finished", None); + self.ctx.log(Operation::Presign, path, "finished", None); v }) .map_err(|err| { - self.ctx.log(Operation::Presign, path, "->", Some(&err)); + self.ctx.log(Operation::Presign, path, "", Some(&err)); err }) } @@ -577,21 +601,23 @@ impl LayeredAccess for LoggingAccessor { async fn batch(&self, args: OpBatch) -> Result { let (op, count) = (args.operation()[0].1.operation(), args.operation().len()); - self.ctx.log( + self.ctx.log_with_context( Operation::Batch, "", &format!("op={op} count={count} -> started"), + "started", None, ); self.inner .batch(args) .map_ok(|v| { - self.ctx.log( + self.ctx.log_with_context( Operation::Batch, "", + &format!("op={op} count={count}"), &format!( - "op={op} count={count} -> finished: {}, succeed: {}, failed: {}", + "finished: {}, succeed: {}, failed: {}", v.results().len(), v.results().iter().filter(|(_, v)| v.is_ok()).count(), v.results().iter().filter(|(_, v)| v.is_err()).count(), @@ -601,10 +627,11 @@ impl LayeredAccess for LoggingAccessor { v }) .map_err(|err| { - self.ctx.log( + self.ctx.log_with_context( Operation::Batch, "", - &format!("op={op} count={count} ->"), + &format!("op={op} count={count}"), + "", Some(&err), ); err @@ -614,84 +641,84 @@ impl LayeredAccess for LoggingAccessor { fn blocking_create_dir(&self, path: &str, args: OpCreateDir) -> Result { self.ctx - .log(Operation::BlockingCreateDir, path, "-> started", None); + .log(Operation::BlockingCreateDir, path, "started", None); self.inner .blocking_create_dir(path, args) .map(|v| { self.ctx - .log(Operation::BlockingCreateDir, path, "-> finished", None); + .log(Operation::BlockingCreateDir, path, "finished", None); v }) .map_err(|err| { self.ctx - .log(Operation::BlockingCreateDir, path, "->", Some(&err)); + .log(Operation::BlockingCreateDir, path, "", Some(&err)); err }) } fn blocking_read(&self, path: &str, args: OpRead) -> Result<(RpRead, Self::BlockingReader)> { - self.ctx - .log(Operation::BlockingRead, path, "-> started", None); + self.ctx.log(Operation::BlockingRead, path, "started", None); self.inner .blocking_read(path, args.clone()) .map(|(rp, r)| { self.ctx - .log(Operation::BlockingRead, path, "-> got reader", None); + .log(Operation::BlockingRead, path, "got reader", None); let r = LoggingReader::new(self.ctx.clone(), Operation::BlockingRead, path, r); (rp, r) }) .map_err(|err| { - self.ctx - .log(Operation::BlockingRead, path, "->", Some(&err)); + self.ctx.log(Operation::BlockingRead, path, "", Some(&err)); err }) } fn blocking_write(&self, path: &str, args: OpWrite) -> Result<(RpWrite, Self::BlockingWriter)> { self.ctx - .log(Operation::BlockingWrite, path, "-> started", None); + .log(Operation::BlockingWrite, path, "started", None); self.inner .blocking_write(path, args) .map(|(rp, w)| { self.ctx - .log(Operation::BlockingWrite, path, "-> start writing", None); + .log(Operation::BlockingWrite, path, "start writing", None); let w = LoggingWriter::new(self.ctx.clone(), Operation::BlockingWrite, path, w); (rp, w) }) .map_err(|err| { - self.ctx - .log(Operation::BlockingWrite, path, "->", Some(&err)); + self.ctx.log(Operation::BlockingWrite, path, "", Some(&err)); err }) } fn blocking_copy(&self, from: &str, to: &str, args: OpCopy) -> Result { - self.ctx.log( + self.ctx.log_with_context( Operation::BlockingCopy, "", - &format!("from={from} to={to} -> started"), + &format!("from={from} to={to}"), + "started", None, ); self.inner .blocking_copy(from, to, args) .map(|v| { - self.ctx.log( + self.ctx.log_with_context( Operation::BlockingCopy, "", - &format!("from={from} to={to} -> finished"), + &format!("from={from} to={to}"), + "finished", None, ); v }) .map_err(|err| { - self.ctx.log( + self.ctx.log_with_context( Operation::BlockingCopy, "", - &format!("from={from} to={to} ->"), + &format!("from={from} to={to}"), + "", Some(&err), ); err @@ -699,29 +726,32 @@ impl LayeredAccess for LoggingAccessor { } fn blocking_rename(&self, from: &str, to: &str, args: OpRename) -> Result { - self.ctx.log( + self.ctx.log_with_context( Operation::BlockingRename, "", - &format!("from={from} to={to} -> started"), + &format!("from={from} to={to}"), + "started", None, ); self.inner .blocking_rename(from, to, args) .map(|v| { - self.ctx.log( + self.ctx.log_with_context( Operation::BlockingRename, "", - &format!("from={from} to={to} -> finished"), + &format!("from={from} to={to}"), + "finished", None, ); v }) .map_err(|err| { - self.ctx.log( + self.ctx.log_with_context( Operation::BlockingRename, "", - &format!("from={from} to={to} ->"), + &format!("from={from} to={to}"), + "", Some(&err), ); err @@ -729,56 +759,51 @@ impl LayeredAccess for LoggingAccessor { } fn blocking_stat(&self, path: &str, args: OpStat) -> Result { - self.ctx - .log(Operation::BlockingStat, path, "-> started", None); + self.ctx.log(Operation::BlockingStat, path, "started", None); self.inner .blocking_stat(path, args) .map(|v| { self.ctx - .log(Operation::BlockingStat, path, "-> finished", None); + .log(Operation::BlockingStat, path, "finished", None); v }) .map_err(|err| { - self.ctx - .log(Operation::BlockingStat, path, "->", Some(&err)); + self.ctx.log(Operation::BlockingStat, path, "", Some(&err)); err }) } fn blocking_delete(&self, path: &str, args: OpDelete) -> Result { self.ctx - .log(Operation::BlockingDelete, path, "-> started", None); + .log(Operation::BlockingDelete, path, "started", None); self.inner .blocking_delete(path, args) .map(|v| { self.ctx - .log(Operation::BlockingDelete, path, "-> finished", None); + .log(Operation::BlockingDelete, path, "finished", None); v }) .map_err(|err| { self.ctx - .log(Operation::BlockingDelete, path, "->", Some(&err)); + .log(Operation::BlockingDelete, path, "", Some(&err)); err }) } fn blocking_list(&self, path: &str, args: OpList) -> Result<(RpList, Self::BlockingLister)> { - self.ctx - .log(Operation::BlockingList, path, "-> started", None); + self.ctx.log(Operation::BlockingList, path, "started", None); self.inner .blocking_list(path, args) .map(|(rp, v)| { - self.ctx - .log(Operation::BlockingList, path, "-> got dir", None); + self.ctx.log(Operation::BlockingList, path, "got dir", None); let li = LoggingLister::new(self.ctx.clone(), path, Operation::BlockingList, v); (rp, li) }) .map_err(|err| { - self.ctx - .log(Operation::BlockingList, path, "->", Some(&err)); + self.ctx.log(Operation::BlockingList, path, "", Some(&err)); err }) } @@ -809,13 +834,11 @@ impl LoggingReader { impl Drop for LoggingReader { fn drop(&mut self) { - self.ctx.log( + self.ctx.log_with_context( self.op, &self.path, - &format!( - "read={} -> data read finished", - self.read.load(Ordering::Relaxed) - ), + &format!("read={}", self.read.load(Ordering::Relaxed)), + "data read finished", None, ); } @@ -827,23 +850,21 @@ impl oio::Read for LoggingReader { Ok(bs) => { self.read .fetch_add(bs.remaining() as u64, Ordering::Relaxed); - self.ctx.log( + self.ctx.log_with_context( Operation::ReaderRead, &self.path, - &format!( - "read={} -> read returns {}B", - self.read.load(Ordering::Relaxed), - bs.remaining() - ), + &format!("read={}", self.read.load(Ordering::Relaxed),), + &format!("read returns {}B", bs.remaining()), None, ); Ok(bs) } Err(err) => { - self.ctx.log( + self.ctx.log_with_context( Operation::ReaderRead, &self.path, - &format!("read={} -> read failed:", self.read.load(Ordering::Relaxed)), + &format!("read={}", self.read.load(Ordering::Relaxed)), + "read failed:", Some(&err), ); Err(err) @@ -858,23 +879,21 @@ impl oio::BlockingRead for LoggingR Ok(bs) => { self.read .fetch_add(bs.remaining() as u64, Ordering::Relaxed); - self.ctx.log( + self.ctx.log_with_context( Operation::BlockingReaderRead, &self.path, - &format!( - "read={} -> read returns {}B", - self.read.load(Ordering::Relaxed), - bs.remaining() - ), + &format!("read={}", self.read.load(Ordering::Relaxed),), + &format!("read returns {}B", bs.remaining()), None, ); Ok(bs) } Err(err) => { - self.ctx.log( + self.ctx.log_with_context( Operation::BlockingReaderRead, &self.path, - &format!("read={} -> read failed:", self.read.load(Ordering::Relaxed)), + &format!("read={}", self.read.load(Ordering::Relaxed)), + "read failed:", Some(&err), ); Err(err) @@ -910,19 +929,21 @@ impl oio::Write for LoggingWriter { let size = bs.len(); match self.inner.write(bs).await { Ok(_) => { - self.ctx.log( + self.ctx.log_with_context( Operation::WriterWrite, &self.path, - &format!("written={}B -> data write {}B", self.written, size), + &format!("written={}B", self.written), + &format!("data write {}B", size), None, ); Ok(()) } Err(err) => { - self.ctx.log( + self.ctx.log_with_context( Operation::WriterWrite, &self.path, - &format!("written={}B -> data write failed:", self.written), + &format!("written={}B", self.written), + "data write failed:", Some(&err), ); Err(err) @@ -933,19 +954,21 @@ impl oio::Write for LoggingWriter { async fn abort(&mut self) -> Result<()> { match self.inner.abort().await { Ok(_) => { - self.ctx.log( + self.ctx.log_with_context( Operation::WriterAbort, &self.path, - &format!("written={}B -> abort writer", self.written), + &format!("written={}B", self.written), + "abort writer", None, ); Ok(()) } Err(err) => { - self.ctx.log( + self.ctx.log_with_context( Operation::WriterAbort, &self.path, - &format!("written={}B -> abort writer failed:", self.written), + &format!("written={}B", self.written), + "abort writer failed:", Some(&err), ); Err(err) @@ -956,19 +979,21 @@ impl oio::Write for LoggingWriter { async fn close(&mut self) -> Result<()> { match self.inner.close().await { Ok(_) => { - self.ctx.log( + self.ctx.log_with_context( self.op, &self.path, - &format!("written={}B -> data written finished", self.written), + &format!("written={}B", self.written), + "data written finished", None, ); Ok(()) } Err(err) => { - self.ctx.log( + self.ctx.log_with_context( Operation::WriterClose, &self.path, - &format!("written={}B -> data close failed:", self.written), + &format!("written={}B", self.written), + "data close failed:", Some(&err), ); Err(err) @@ -981,19 +1006,21 @@ impl oio::BlockingWrite for Loggin fn write(&mut self, bs: Buffer) -> Result<()> { match self.inner.write(bs.clone()) { Ok(_) => { - self.ctx.log( + self.ctx.log_with_context( Operation::BlockingWriterWrite, &self.path, - &format!("written={}B -> data write {}B", self.written, bs.len()), + &format!("written={}B", self.written), + &format!("data write {}B", bs.len()), None, ); Ok(()) } Err(err) => { - self.ctx.log( + self.ctx.log_with_context( Operation::BlockingWriterWrite, &self.path, - &format!("written={}B -> data write failed:", self.written), + &format!("written={}B", self.written), + "data write failed:", Some(&err), ); Err(err) @@ -1004,19 +1031,21 @@ impl oio::BlockingWrite for Loggin fn close(&mut self) -> Result<()> { match self.inner.close() { Ok(_) => { - self.ctx.log( + self.ctx.log_with_context( self.op, &self.path, - &format!("written={}B -> data written finished", self.written), + &format!("written={}B", self.written), + "data written finished", None, ); Ok(()) } Err(err) => { - self.ctx.log( + self.ctx.log_with_context( Operation::BlockingWriterClose, &self.path, - &format!("written={}B -> data close failed:", self.written), + &format!("written={}B", self.written), + "data close failed:", Some(&err), ); Err(err) @@ -1050,14 +1079,10 @@ impl Drop for LoggingLister { fn drop(&mut self) { if self.finished { self.ctx - .log(self.op, &self.path, "-> all entries read finished", None); + .log(self.op, &self.path, "all entries read finished", None); } else { - self.ctx.log( - self.op, - &self.path, - "-> partial entries read finished", - None, - ); + self.ctx + .log(self.op, &self.path, "partial entries read finished", None); } } } @@ -1071,16 +1096,16 @@ impl oio::List for LoggingLister { self.ctx.log( self.op, &self.path, - &format!("-> listed entry: {}", de.path()), + &format!("listed entry: {}", de.path()), None, ); } Ok(None) => { - self.ctx.log(self.op, &self.path, "-> finished", None); + self.ctx.log(self.op, &self.path, "finished", None); self.finished = true; } Err(err) => { - self.ctx.log(self.op, &self.path, "->", Some(err)); + self.ctx.log(self.op, &self.path, "", Some(err)); } }; @@ -1097,16 +1122,16 @@ impl oio::BlockingList for LoggingL self.ctx.log( self.op, &self.path, - &format!("-> listed entry: {}", des.path()), + &format!("listed entry: {}", des.path()), None, ); } Ok(None) => { - self.ctx.log(self.op, &self.path, "-> finished", None); + self.ctx.log(self.op, &self.path, "finished", None); self.finished = true; } Err(err) => { - self.ctx.log(self.op, &self.path, "->", Some(err)); + self.ctx.log(self.op, &self.path, "", Some(err)); } }; From 48fbec14b9a4c47adf716d394745c4ba21f6fc15 Mon Sep 17 00:00:00 2001 From: evenyag Date: Thu, 8 Aug 2024 20:29:51 +0800 Subject: [PATCH 12/15] feat: remove some apis from DefaultLoggingLayer --- core/src/layers/logging.rs | 128 ++++++------------------------------ core/src/layers/mod.rs | 1 - core/src/raw/tests/utils.rs | 73 +++++++++++++++++++- 3 files changed, 90 insertions(+), 112 deletions(-) diff --git a/core/src/layers/logging.rs b/core/src/layers/logging.rs index d18a6c0bc91e..1549270a9ef1 100644 --- a/core/src/layers/logging.rs +++ b/core/src/layers/logging.rs @@ -86,6 +86,7 @@ use crate::*; /// ```no_run /// use crate::layers::LoggingInterceptor; /// use crate::layers::LoggingLayer; +/// use crate::raw::Operation; /// use crate::services; /// use crate::Error; /// use crate::Operator; @@ -98,8 +99,9 @@ use crate::*; /// fn log( /// &self, /// scheme: Scheme, -/// operation: &'static str, +/// operation: Operation, /// path: &str, +/// context: &str, /// message: &str, /// err: Option<&Error>, /// ) { @@ -128,7 +130,7 @@ impl Clone for LoggingLayer { impl Default for LoggingLayer { fn default() -> Self { Self { - notify: Arc::new(DefaultLoggingInterceptor::default()), + notify: Arc::new(DefaultLoggingInterceptor), } } } @@ -192,7 +194,6 @@ impl LoggingContext { } } -// TODO(yingwen): Update example. /// LoggingInterceptor is used to intercept the log. pub trait LoggingInterceptor: Debug + Send + Sync + 'static { /// Everytime there is a log, this function will be called. @@ -223,24 +224,9 @@ pub trait LoggingInterceptor: Debug + Send + Sync + 'static { ); } -// TODO(yingwen): Remove fields. /// The DefaultLoggingInterceptor will log the message by the standard logging macro. #[derive(Debug)] -pub struct DefaultLoggingInterceptor { - error_level: Option, - failure_level: Option, - backtrace_output: bool, -} - -impl Default for DefaultLoggingInterceptor { - fn default() -> Self { - Self { - error_level: Some(Level::Warn), - failure_level: Some(Level::Error), - backtrace_output: false, - } - } -} +pub struct DefaultLoggingInterceptor; impl LoggingInterceptor for DefaultLoggingInterceptor { fn log( @@ -267,84 +253,22 @@ impl LoggingInterceptor for DefaultLoggingInterceptor { return; }; - if let Some(lvl) = self.error_level(err) { - if self.print_backtrace(err) { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} {} -> {} {:?}", - scheme, - operation, - path, - context, - message, - err, - ) - } else { - log!( - target: LOGGING_TARGET, - lvl, - "service={} operation={} path={} {} -> {} {}", - scheme, - operation, - path, - context, - message, - err, - ) - } - } + let lvl = self.error_level(err); + log!( + target: LOGGING_TARGET, + lvl, + "service={} operation={} path={} {} -> {} {}", + scheme, + operation, + path, + context, + message, + err, + ); } } impl DefaultLoggingInterceptor { - /// Setting the log level while expected error happened. - /// - /// For example: accessor returns NotFound. - /// - /// `None` means disable the log for error. - pub fn with_error_level(mut self, level: Option<&str>) -> Result { - if let Some(level_str) = level { - let level = level_str.parse().map_err(|_| { - Error::new(ErrorKind::ConfigInvalid, "invalid log level") - .with_context("level", level_str) - })?; - self.error_level = Some(level); - } else { - self.error_level = None; - } - Ok(self) - } - - /// Setting the log level while unexpected failure happened. - /// - /// For example: accessor returns Unexpected network error. - /// - /// `None` means disable the log for failure. - pub fn with_failure_level(mut self, level: Option<&str>) -> Result { - if let Some(level_str) = level { - let level = level_str.parse().map_err(|_| { - Error::new(ErrorKind::ConfigInvalid, "invalid log level") - .with_context("level", level_str) - })?; - self.failure_level = Some(level); - } else { - self.failure_level = None; - } - Ok(self) - } - - /// Setting whether to output backtrace while unexpected failure happened. - /// - /// # Notes - /// - /// - When the error is an expected error, backtrace will not be output. - /// - backtrace output is disable by default. - pub fn with_backtrace_output(mut self, enable: bool) -> Self { - self.backtrace_output = enable; - self - } - fn operation_level(&self, operation: Operation) -> Level { match operation { Operation::ReaderRead @@ -356,24 +280,12 @@ impl DefaultLoggingInterceptor { } #[inline] - fn error_level(&self, err: &Error) -> Option { + fn error_level(&self, err: &Error) -> Level { if err.kind() == ErrorKind::Unexpected { - self.failure_level + Level::Error } else { - self.error_level - } - } - - /// Returns true if the error is unexpected and we need to - /// print the backtrace. - #[inline] - fn print_backtrace(&self, err: &Error) -> bool { - // Don't print backtrace if it's not unexpected error. - if err.kind() != ErrorKind::Unexpected { - return false; + Level::Warn } - - self.backtrace_output } } diff --git a/core/src/layers/mod.rs b/core/src/layers/mod.rs index b1563b58c4b4..98372b220389 100644 --- a/core/src/layers/mod.rs +++ b/core/src/layers/mod.rs @@ -33,7 +33,6 @@ mod immutable_index; pub use immutable_index::ImmutableIndexLayer; mod logging; -pub use logging::DefaultLoggingInterceptor; pub use logging::LoggingInterceptor; pub use logging::LoggingLayer; diff --git a/core/src/raw/tests/utils.rs b/core/src/raw/tests/utils.rs index da186b1ace75..b7a5d83f4e71 100644 --- a/core/src/raw/tests/utils.rs +++ b/core/src/raw/tests/utils.rs @@ -19,8 +19,11 @@ use std::collections::HashMap; use std::env; use std::str::FromStr; +use log::{log, Level}; use once_cell::sync::Lazy; +use crate::layers::LoggingInterceptor; +use crate::raw::Operation; use crate::*; /// TEST_RUNTIME is the runtime used for running tests. @@ -73,9 +76,7 @@ pub fn init_test_service() -> Result> { let op = { op.layer(layers::ChaosLayer::new(0.1)) }; let mut op = op - .layer(layers::LoggingLayer::new( - layers::DefaultLoggingInterceptor::default().with_backtrace_output(true), - )) + .layer(layers::LoggingLayer::new(BacktraceLoggingInterceptor)) .layer(layers::TimeoutLayer::new()) .layer(layers::RetryLayer::new().with_max_times(4)); @@ -90,3 +91,69 @@ pub fn init_test_service() -> Result> { Ok(Some(op)) } + +/// A logging interceptor that logs the backtrace. +#[derive(Debug, Clone)] +struct BacktraceLoggingInterceptor; + +impl LoggingInterceptor for BacktraceLoggingInterceptor { + fn log( + &self, + scheme: Scheme, + operation: raw::Operation, + path: &str, + context: &str, + message: &str, + err: Option<&Error>, + ) { + let Some(err) = err else { + let lvl = self.operation_level(operation); + log!( + target: "opendal::services", + lvl, + "service={} operation={} path={} {} -> {}", + scheme, + operation, + path, + context, + message, + ); + return; + }; + + let err_msg = if err.kind() != ErrorKind::Unexpected { + format!("{err}") + } else { + format!("{err:?}") + }; + let lvl = if err.kind() == ErrorKind::Unexpected { + Level::Error + } else { + Level::Warn + }; + + log!( + target: "opendal::services", + lvl, + "service={} operation={} path={} {} -> {} {}", + scheme, + operation, + path, + context, + message, + err_msg, + ); + } +} + +impl BacktraceLoggingInterceptor { + fn operation_level(&self, operation: Operation) -> Level { + match operation { + Operation::ReaderRead + | Operation::BlockingReaderRead + | Operation::WriterWrite + | Operation::BlockingWriterWrite => Level::Trace, + _ => Level::Debug, + } + } +} From 9793d6898ee8511b4a5397bffea95d24a3ec41dc Mon Sep 17 00:00:00 2001 From: evenyag Date: Fri, 9 Aug 2024 15:26:03 +0800 Subject: [PATCH 13/15] refactor: remove path --- core/src/layers/logging.rs | 294 +++++++++++++++++++----------------- core/src/raw/tests/utils.rs | 7 +- 2 files changed, 154 insertions(+), 147 deletions(-) diff --git a/core/src/layers/logging.rs b/core/src/layers/logging.rs index 1549270a9ef1..cfa33a5fc0e2 100644 --- a/core/src/layers/logging.rs +++ b/core/src/layers/logging.rs @@ -100,7 +100,6 @@ use crate::*; /// &self, /// scheme: Scheme, /// operation: Operation, -/// path: &str, /// context: &str, /// message: &str, /// err: Option<&Error>, @@ -176,21 +175,19 @@ impl Clone for LoggingContext { } impl LoggingContext { - fn log_with_context( - &self, - operation: Operation, - path: &str, - context: &str, - message: &str, - err: Option<&Error>, - ) { + fn log(&self, operation: Operation, context: &str, message: &str, err: Option<&Error>) { self.notify - .log(self.scheme, operation, path, context, message, err) + .log(self.scheme, operation, context, message, err) } - fn log(&self, operation: Operation, path: &str, message: &str, err: Option<&Error>) { - self.notify - .log(self.scheme, operation, path, "", message, err) + fn log_with_path(&self, operation: Operation, path: &str, message: &str, err: Option<&Error>) { + self.notify.log( + self.scheme, + operation, + &format!("path={path}"), + message, + err, + ) } } @@ -202,8 +199,6 @@ pub trait LoggingInterceptor: Debug + Send + Sync + 'static { /// /// - scheme: The service generates the log. /// - operation: The operation to log. - /// - path: The path argument to the operator, maybe empty if the - /// current operation doesn't have a path argument. /// - context: Additional context of the log. /// - message: The log message. /// - err: The error to log. @@ -217,7 +212,6 @@ pub trait LoggingInterceptor: Debug + Send + Sync + 'static { &self, scheme: Scheme, operation: Operation, - path: &str, context: &str, message: &str, err: Option<&Error>, @@ -233,7 +227,6 @@ impl LoggingInterceptor for DefaultLoggingInterceptor { &self, scheme: Scheme, operation: Operation, - path: &str, context: &str, message: &str, err: Option<&Error>, @@ -243,10 +236,9 @@ impl LoggingInterceptor for DefaultLoggingInterceptor { log!( target: LOGGING_TARGET, lvl, - "service={} operation={} path={} {} -> {}", + "service={} operation={} {} -> {}", scheme, operation, - path, context, message, ); @@ -257,10 +249,9 @@ impl LoggingInterceptor for DefaultLoggingInterceptor { log!( target: LOGGING_TARGET, lvl, - "service={} operation={} path={} {} -> {} {}", + "service={} operation={} {} -> {} {}", scheme, operation, - path, context, message, err, @@ -325,61 +316,69 @@ impl LayeredAccess for LoggingAccessor { } async fn create_dir(&self, path: &str, args: OpCreateDir) -> Result { - self.ctx.log(Operation::CreateDir, path, "started", None); + self.ctx + .log_with_path(Operation::CreateDir, path, "started", None); self.inner .create_dir(path, args) .await .map(|v| { - self.ctx.log(Operation::CreateDir, path, "finished", None); + self.ctx + .log_with_path(Operation::CreateDir, path, "finished", None); v }) .map_err(|err| { - self.ctx.log(Operation::CreateDir, path, "", Some(&err)); + self.ctx + .log_with_path(Operation::CreateDir, path, "", Some(&err)); err }) } async fn read(&self, path: &str, args: OpRead) -> Result<(RpRead, Self::Reader)> { - self.ctx.log(Operation::Read, path, "started", None); + self.ctx + .log_with_path(Operation::Read, path, "started", None); self.inner .read(path, args) .await .map(|(rp, r)| { - self.ctx.log(Operation::Read, path, "got reader", None); + self.ctx + .log_with_path(Operation::Read, path, "got reader", None); ( rp, LoggingReader::new(self.ctx.clone(), Operation::Read, path, r), ) }) .map_err(|err| { - self.ctx.log(Operation::Read, path, "", Some(&err)); + self.ctx + .log_with_path(Operation::Read, path, "", Some(&err)); err }) } async fn write(&self, path: &str, args: OpWrite) -> Result<(RpWrite, Self::Writer)> { - self.ctx.log(Operation::Write, path, "started", None); + self.ctx + .log_with_path(Operation::Write, path, "started", None); self.inner .write(path, args) .await .map(|(rp, w)| { - self.ctx.log(Operation::Write, path, "start writing", None); + self.ctx + .log_with_path(Operation::Write, path, "start writing", None); let w = LoggingWriter::new(self.ctx.clone(), Operation::Write, path, w); (rp, w) }) .map_err(|err| { - self.ctx.log(Operation::Write, path, "", Some(&err)); + self.ctx + .log_with_path(Operation::Write, path, "", Some(&err)); err }) } async fn copy(&self, from: &str, to: &str, args: OpCopy) -> Result { - self.ctx.log_with_context( + self.ctx.log( Operation::Copy, - "", &format!("from={from} to={to}"), "started", None, @@ -389,9 +388,8 @@ impl LayeredAccess for LoggingAccessor { .copy(from, to, args) .await .map(|v| { - self.ctx.log_with_context( + self.ctx.log( Operation::Copy, - "", &format!("from={from} to={to}"), "finished", None, @@ -399,9 +397,8 @@ impl LayeredAccess for LoggingAccessor { v }) .map_err(|err| { - self.ctx.log_with_context( + self.ctx.log( Operation::Copy, - "", &format!("from={from} to={to}"), "", Some(&err), @@ -411,9 +408,8 @@ impl LayeredAccess for LoggingAccessor { } async fn rename(&self, from: &str, to: &str, args: OpRename) -> Result { - self.ctx.log_with_context( + self.ctx.log( Operation::Rename, - "", &format!("from={from} to={to}"), "started", None, @@ -423,9 +419,8 @@ impl LayeredAccess for LoggingAccessor { .rename(from, to, args) .await .map(|v| { - self.ctx.log_with_context( + self.ctx.log( Operation::Rename, - "", &format!("from={from} to={to}"), "finished", None, @@ -433,9 +428,8 @@ impl LayeredAccess for LoggingAccessor { v }) .map_err(|err| { - self.ctx.log_with_context( + self.ctx.log( Operation::Rename, - "", &format!("from={from} to={to}"), "", Some(&err), @@ -445,32 +439,38 @@ impl LayeredAccess for LoggingAccessor { } async fn stat(&self, path: &str, args: OpStat) -> Result { - self.ctx.log(Operation::Stat, path, "started", None); + self.ctx + .log_with_path(Operation::Stat, path, "started", None); self.inner .stat(path, args) .await .map(|v| { - self.ctx.log(Operation::Stat, path, "finished", None); + self.ctx + .log_with_path(Operation::Stat, path, "finished", None); v }) .map_err(|err| { - self.ctx.log(Operation::Stat, path, "", Some(&err)); + self.ctx + .log_with_path(Operation::Stat, path, "", Some(&err)); err }) } async fn delete(&self, path: &str, args: OpDelete) -> Result { - self.ctx.log(Operation::Delete, path, "started", None); + self.ctx + .log_with_path(Operation::Delete, path, "started", None); self.inner .delete(path, args.clone()) .inspect(|v| match v { Ok(_) => { - self.ctx.log(Operation::Delete, path, "finished", None); + self.ctx + .log_with_path(Operation::Delete, path, "finished", None); } Err(err) => { - self.ctx.log(Operation::Delete, path, "", Some(err)); + self.ctx + .log_with_path(Operation::Delete, path, "", Some(err)); } }) .await @@ -482,12 +482,13 @@ impl LayeredAccess for LoggingAccessor { .map(|v| match v { Ok((rp, v)) => { self.ctx - .log(Operation::List, path, "start listing dir", None); + .log_with_path(Operation::List, path, "start listing dir", None); let streamer = LoggingLister::new(self.ctx.clone(), path, Operation::List, v); Ok((rp, streamer)) } Err(err) => { - self.ctx.log(Operation::List, path, "", Some(&err)); + self.ctx + .log_with_path(Operation::List, path, "", Some(&err)); Err(err) } }) @@ -495,17 +496,20 @@ impl LayeredAccess for LoggingAccessor { } async fn presign(&self, path: &str, args: OpPresign) -> Result { - self.ctx.log(Operation::Presign, path, "started", None); + self.ctx + .log_with_path(Operation::Presign, path, "started", None); self.inner .presign(path, args) .await .map(|v| { - self.ctx.log(Operation::Presign, path, "finished", None); + self.ctx + .log_with_path(Operation::Presign, path, "finished", None); v }) .map_err(|err| { - self.ctx.log(Operation::Presign, path, "", Some(&err)); + self.ctx + .log_with_path(Operation::Presign, path, "", Some(&err)); err }) } @@ -513,9 +517,8 @@ impl LayeredAccess for LoggingAccessor { async fn batch(&self, args: OpBatch) -> Result { let (op, count) = (args.operation()[0].1.operation(), args.operation().len()); - self.ctx.log_with_context( + self.ctx.log( Operation::Batch, - "", &format!("op={op} count={count} -> started"), "started", None, @@ -524,9 +527,8 @@ impl LayeredAccess for LoggingAccessor { self.inner .batch(args) .map_ok(|v| { - self.ctx.log_with_context( + self.ctx.log( Operation::Batch, - "", &format!("op={op} count={count}"), &format!( "finished: {}, succeed: {}, failed: {}", @@ -539,9 +541,8 @@ impl LayeredAccess for LoggingAccessor { v }) .map_err(|err| { - self.ctx.log_with_context( + self.ctx.log( Operation::Batch, - "", &format!("op={op} count={count}"), "", Some(&err), @@ -553,61 +554,63 @@ impl LayeredAccess for LoggingAccessor { fn blocking_create_dir(&self, path: &str, args: OpCreateDir) -> Result { self.ctx - .log(Operation::BlockingCreateDir, path, "started", None); + .log_with_path(Operation::BlockingCreateDir, path, "started", None); self.inner .blocking_create_dir(path, args) .map(|v| { self.ctx - .log(Operation::BlockingCreateDir, path, "finished", None); + .log_with_path(Operation::BlockingCreateDir, path, "finished", None); v }) .map_err(|err| { self.ctx - .log(Operation::BlockingCreateDir, path, "", Some(&err)); + .log_with_path(Operation::BlockingCreateDir, path, "", Some(&err)); err }) } fn blocking_read(&self, path: &str, args: OpRead) -> Result<(RpRead, Self::BlockingReader)> { - self.ctx.log(Operation::BlockingRead, path, "started", None); + self.ctx + .log_with_path(Operation::BlockingRead, path, "started", None); self.inner .blocking_read(path, args.clone()) .map(|(rp, r)| { self.ctx - .log(Operation::BlockingRead, path, "got reader", None); + .log_with_path(Operation::BlockingRead, path, "got reader", None); let r = LoggingReader::new(self.ctx.clone(), Operation::BlockingRead, path, r); (rp, r) }) .map_err(|err| { - self.ctx.log(Operation::BlockingRead, path, "", Some(&err)); + self.ctx + .log_with_path(Operation::BlockingRead, path, "", Some(&err)); err }) } fn blocking_write(&self, path: &str, args: OpWrite) -> Result<(RpWrite, Self::BlockingWriter)> { self.ctx - .log(Operation::BlockingWrite, path, "started", None); + .log_with_path(Operation::BlockingWrite, path, "started", None); self.inner .blocking_write(path, args) .map(|(rp, w)| { self.ctx - .log(Operation::BlockingWrite, path, "start writing", None); + .log_with_path(Operation::BlockingWrite, path, "start writing", None); let w = LoggingWriter::new(self.ctx.clone(), Operation::BlockingWrite, path, w); (rp, w) }) .map_err(|err| { - self.ctx.log(Operation::BlockingWrite, path, "", Some(&err)); + self.ctx + .log_with_path(Operation::BlockingWrite, path, "", Some(&err)); err }) } fn blocking_copy(&self, from: &str, to: &str, args: OpCopy) -> Result { - self.ctx.log_with_context( + self.ctx.log( Operation::BlockingCopy, - "", &format!("from={from} to={to}"), "started", None, @@ -616,9 +619,8 @@ impl LayeredAccess for LoggingAccessor { self.inner .blocking_copy(from, to, args) .map(|v| { - self.ctx.log_with_context( + self.ctx.log( Operation::BlockingCopy, - "", &format!("from={from} to={to}"), "finished", None, @@ -626,9 +628,8 @@ impl LayeredAccess for LoggingAccessor { v }) .map_err(|err| { - self.ctx.log_with_context( + self.ctx.log( Operation::BlockingCopy, - "", &format!("from={from} to={to}"), "", Some(&err), @@ -638,9 +639,8 @@ impl LayeredAccess for LoggingAccessor { } fn blocking_rename(&self, from: &str, to: &str, args: OpRename) -> Result { - self.ctx.log_with_context( + self.ctx.log( Operation::BlockingRename, - "", &format!("from={from} to={to}"), "started", None, @@ -649,9 +649,8 @@ impl LayeredAccess for LoggingAccessor { self.inner .blocking_rename(from, to, args) .map(|v| { - self.ctx.log_with_context( + self.ctx.log( Operation::BlockingRename, - "", &format!("from={from} to={to}"), "finished", None, @@ -659,9 +658,8 @@ impl LayeredAccess for LoggingAccessor { v }) .map_err(|err| { - self.ctx.log_with_context( + self.ctx.log( Operation::BlockingRename, - "", &format!("from={from} to={to}"), "", Some(&err), @@ -671,51 +669,56 @@ impl LayeredAccess for LoggingAccessor { } fn blocking_stat(&self, path: &str, args: OpStat) -> Result { - self.ctx.log(Operation::BlockingStat, path, "started", None); + self.ctx + .log_with_path(Operation::BlockingStat, path, "started", None); self.inner .blocking_stat(path, args) .map(|v| { self.ctx - .log(Operation::BlockingStat, path, "finished", None); + .log_with_path(Operation::BlockingStat, path, "finished", None); v }) .map_err(|err| { - self.ctx.log(Operation::BlockingStat, path, "", Some(&err)); + self.ctx + .log_with_path(Operation::BlockingStat, path, "", Some(&err)); err }) } fn blocking_delete(&self, path: &str, args: OpDelete) -> Result { self.ctx - .log(Operation::BlockingDelete, path, "started", None); + .log_with_path(Operation::BlockingDelete, path, "started", None); self.inner .blocking_delete(path, args) .map(|v| { self.ctx - .log(Operation::BlockingDelete, path, "finished", None); + .log_with_path(Operation::BlockingDelete, path, "finished", None); v }) .map_err(|err| { self.ctx - .log(Operation::BlockingDelete, path, "", Some(&err)); + .log_with_path(Operation::BlockingDelete, path, "", Some(&err)); err }) } fn blocking_list(&self, path: &str, args: OpList) -> Result<(RpList, Self::BlockingLister)> { - self.ctx.log(Operation::BlockingList, path, "started", None); + self.ctx + .log_with_path(Operation::BlockingList, path, "started", None); self.inner .blocking_list(path, args) .map(|(rp, v)| { - self.ctx.log(Operation::BlockingList, path, "got dir", None); + self.ctx + .log_with_path(Operation::BlockingList, path, "got dir", None); let li = LoggingLister::new(self.ctx.clone(), path, Operation::BlockingList, v); (rp, li) }) .map_err(|err| { - self.ctx.log(Operation::BlockingList, path, "", Some(&err)); + self.ctx + .log_with_path(Operation::BlockingList, path, "", Some(&err)); err }) } @@ -746,10 +749,13 @@ impl LoggingReader { impl Drop for LoggingReader { fn drop(&mut self) { - self.ctx.log_with_context( + self.ctx.log( self.op, - &self.path, - &format!("read={}", self.read.load(Ordering::Relaxed)), + &format!( + "path={} read={}", + self.path, + self.read.load(Ordering::Relaxed) + ), "data read finished", None, ); @@ -762,20 +768,26 @@ impl oio::Read for LoggingReader { Ok(bs) => { self.read .fetch_add(bs.remaining() as u64, Ordering::Relaxed); - self.ctx.log_with_context( + self.ctx.log( Operation::ReaderRead, - &self.path, - &format!("read={}", self.read.load(Ordering::Relaxed),), + &format!( + "path={} read={}", + self.path, + self.read.load(Ordering::Relaxed), + ), &format!("read returns {}B", bs.remaining()), None, ); Ok(bs) } Err(err) => { - self.ctx.log_with_context( + self.ctx.log( Operation::ReaderRead, - &self.path, - &format!("read={}", self.read.load(Ordering::Relaxed)), + &format!( + "path={} read={}", + self.path, + self.read.load(Ordering::Relaxed) + ), "read failed:", Some(&err), ); @@ -791,20 +803,26 @@ impl oio::BlockingRead for LoggingR Ok(bs) => { self.read .fetch_add(bs.remaining() as u64, Ordering::Relaxed); - self.ctx.log_with_context( + self.ctx.log( Operation::BlockingReaderRead, - &self.path, - &format!("read={}", self.read.load(Ordering::Relaxed),), + &format!( + "path={} read={}", + self.path, + self.read.load(Ordering::Relaxed), + ), &format!("read returns {}B", bs.remaining()), None, ); Ok(bs) } Err(err) => { - self.ctx.log_with_context( + self.ctx.log( Operation::BlockingReaderRead, - &self.path, - &format!("read={}", self.read.load(Ordering::Relaxed)), + &format!( + "path={} read={}", + self.path, + self.read.load(Ordering::Relaxed) + ), "read failed:", Some(&err), ); @@ -841,20 +859,18 @@ impl oio::Write for LoggingWriter { let size = bs.len(); match self.inner.write(bs).await { Ok(_) => { - self.ctx.log_with_context( + self.ctx.log( Operation::WriterWrite, - &self.path, - &format!("written={}B", self.written), + &format!("path={} written={}B", self.path, self.written), &format!("data write {}B", size), None, ); Ok(()) } Err(err) => { - self.ctx.log_with_context( + self.ctx.log( Operation::WriterWrite, - &self.path, - &format!("written={}B", self.written), + &format!("path={} written={}B", self.path, self.written), "data write failed:", Some(&err), ); @@ -866,20 +882,18 @@ impl oio::Write for LoggingWriter { async fn abort(&mut self) -> Result<()> { match self.inner.abort().await { Ok(_) => { - self.ctx.log_with_context( + self.ctx.log( Operation::WriterAbort, - &self.path, - &format!("written={}B", self.written), + &format!("path={} written={}B", self.path, self.written), "abort writer", None, ); Ok(()) } Err(err) => { - self.ctx.log_with_context( + self.ctx.log( Operation::WriterAbort, - &self.path, - &format!("written={}B", self.written), + &format!("path={} written={}B", self.path, self.written), "abort writer failed:", Some(&err), ); @@ -891,20 +905,18 @@ impl oio::Write for LoggingWriter { async fn close(&mut self) -> Result<()> { match self.inner.close().await { Ok(_) => { - self.ctx.log_with_context( + self.ctx.log( self.op, - &self.path, - &format!("written={}B", self.written), + &format!("path={} written={}B", self.path, self.written), "data written finished", None, ); Ok(()) } Err(err) => { - self.ctx.log_with_context( + self.ctx.log( Operation::WriterClose, - &self.path, - &format!("written={}B", self.written), + &format!("path={} written={}B", self.path, self.written), "data close failed:", Some(&err), ); @@ -918,20 +930,18 @@ impl oio::BlockingWrite for Loggin fn write(&mut self, bs: Buffer) -> Result<()> { match self.inner.write(bs.clone()) { Ok(_) => { - self.ctx.log_with_context( + self.ctx.log( Operation::BlockingWriterWrite, - &self.path, - &format!("written={}B", self.written), + &format!("path={} written={}B", self.path, self.written), &format!("data write {}B", bs.len()), None, ); Ok(()) } Err(err) => { - self.ctx.log_with_context( + self.ctx.log( Operation::BlockingWriterWrite, - &self.path, - &format!("written={}B", self.written), + &format!("path={} written={}B", self.path, self.written), "data write failed:", Some(&err), ); @@ -943,20 +953,18 @@ impl oio::BlockingWrite for Loggin fn close(&mut self) -> Result<()> { match self.inner.close() { Ok(_) => { - self.ctx.log_with_context( + self.ctx.log( self.op, - &self.path, - &format!("written={}B", self.written), + &format!("path={} written={}B", self.path, self.written), "data written finished", None, ); Ok(()) } Err(err) => { - self.ctx.log_with_context( + self.ctx.log( Operation::BlockingWriterClose, - &self.path, - &format!("written={}B", self.written), + &format!("path={} written={}B", self.path, self.written), "data close failed:", Some(&err), ); @@ -991,10 +999,10 @@ impl Drop for LoggingLister { fn drop(&mut self) { if self.finished { self.ctx - .log(self.op, &self.path, "all entries read finished", None); + .log_with_path(self.op, &self.path, "all entries read finished", None); } else { self.ctx - .log(self.op, &self.path, "partial entries read finished", None); + .log_with_path(self.op, &self.path, "partial entries read finished", None); } } } @@ -1005,7 +1013,7 @@ impl oio::List for LoggingLister { match &res { Ok(Some(de)) => { - self.ctx.log( + self.ctx.log_with_path( self.op, &self.path, &format!("listed entry: {}", de.path()), @@ -1013,11 +1021,12 @@ impl oio::List for LoggingLister { ); } Ok(None) => { - self.ctx.log(self.op, &self.path, "finished", None); + self.ctx + .log_with_path(self.op, &self.path, "finished", None); self.finished = true; } Err(err) => { - self.ctx.log(self.op, &self.path, "", Some(err)); + self.ctx.log_with_path(self.op, &self.path, "", Some(err)); } }; @@ -1031,7 +1040,7 @@ impl oio::BlockingList for LoggingL match &res { Ok(Some(des)) => { - self.ctx.log( + self.ctx.log_with_path( self.op, &self.path, &format!("listed entry: {}", des.path()), @@ -1039,11 +1048,12 @@ impl oio::BlockingList for LoggingL ); } Ok(None) => { - self.ctx.log(self.op, &self.path, "finished", None); + self.ctx + .log_with_path(self.op, &self.path, "finished", None); self.finished = true; } Err(err) => { - self.ctx.log(self.op, &self.path, "", Some(err)); + self.ctx.log_with_path(self.op, &self.path, "", Some(err)); } }; diff --git a/core/src/raw/tests/utils.rs b/core/src/raw/tests/utils.rs index b7a5d83f4e71..18545764281e 100644 --- a/core/src/raw/tests/utils.rs +++ b/core/src/raw/tests/utils.rs @@ -101,7 +101,6 @@ impl LoggingInterceptor for BacktraceLoggingInterceptor { &self, scheme: Scheme, operation: raw::Operation, - path: &str, context: &str, message: &str, err: Option<&Error>, @@ -111,10 +110,9 @@ impl LoggingInterceptor for BacktraceLoggingInterceptor { log!( target: "opendal::services", lvl, - "service={} operation={} path={} {} -> {}", + "service={} operation={} {} -> {}", scheme, operation, - path, context, message, ); @@ -135,10 +133,9 @@ impl LoggingInterceptor for BacktraceLoggingInterceptor { log!( target: "opendal::services", lvl, - "service={} operation={} path={} {} -> {} {}", + "service={} operation={} {} -> {} {}", scheme, operation, - path, context, message, err_msg, From d207f491a5db9791954401b4193e722d70bb1051 Mon Sep 17 00:00:00 2001 From: evenyag Date: Fri, 9 Aug 2024 16:46:38 +0800 Subject: [PATCH 14/15] docs: fix example --- core/src/layers/logging.rs | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) diff --git a/core/src/layers/logging.rs b/core/src/layers/logging.rs index cfa33a5fc0e2..1dfdba85ef0d 100644 --- a/core/src/layers/logging.rs +++ b/core/src/layers/logging.rs @@ -84,13 +84,13 @@ use crate::*; /// You can implement your own logging interceptor to customize the logging behavior. /// /// ```no_run -/// use crate::layers::LoggingInterceptor; -/// use crate::layers::LoggingLayer; -/// use crate::raw::Operation; -/// use crate::services; -/// use crate::Error; -/// use crate::Operator; -/// use crate::Scheme; +/// use opendal::layers::LoggingInterceptor; +/// use opendal::layers::LoggingLayer; +/// use opendal::raw::Operation; +/// use opendal::services; +/// use opendal::Error; +/// use opendal::Operator; +/// use opendal::Scheme; /// /// #[derive(Debug, Clone)] /// struct MyLoggingInterceptor; From 9876d8333c9547626d38739182886eca439d23c0 Mon Sep 17 00:00:00 2001 From: evenyag Date: Fri, 9 Aug 2024 16:47:37 +0800 Subject: [PATCH 15/15] test: fix haskell test --- bindings/haskell/test/BasicTest.hs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/bindings/haskell/test/BasicTest.hs b/bindings/haskell/test/BasicTest.hs index 1311f9a05f2f..6c817d046e53 100644 --- a/bindings/haskell/test/BasicTest.hs +++ b/bindings/haskell/test/BasicTest.hs @@ -109,7 +109,7 @@ testLogger = do let logFn = LogAction $ logger state Right _ <- newOperator "memory" {ocLogAction = Just logFn} logStr <- readIORef state - T.take 77 logStr @?= "service=memory operation=metadata -> startedservice=memory operation=metadata" + T.take 78 logStr @?= "service=memory operation=metadata -> startedservice=memory operation=metadata" -- helper function