You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@opendal.apache.org by "Xuanwo (via GitHub)" <gi...@apache.org> on 2024/08/05 15:30:41 UTC

Re: [PR] feat(core): implement an interceptor for the logging layer [opendal]

Xuanwo commented on code in PR #4961:
URL: https://github.com/apache/opendal/pull/4961#discussion_r1704287566


##########
core/src/layers/logging.rs:
##########
@@ -82,14 +80,136 @@ use crate::*;
 /// ```shell
 /// RUST_LOG="info,opendal::services=debug" ./app
 /// ```
-#[derive(Debug, Copy, Clone)]
-pub struct LoggingLayer {
+#[derive(Debug)]
+pub struct LoggingLayer<I = DefaultLoggingInterceptor> {
+    notify: Arc<I>,
+}
+
+impl<I> Clone for LoggingLayer<I> {
+    fn clone(&self) -> Self {
+        Self {
+            notify: self.notify.clone(),
+        }
+    }
+}
+
+impl Default for LoggingLayer {
+    fn default() -> Self {
+        Self {
+            notify: Arc::new(DefaultLoggingInterceptor::default()),
+        }
+    }
+}
+
+impl LoggingLayer {
+    /// Create the layer with specific logging interceptor.

Review Comment:
   Maybe we can move this example to `LoggingLayer` type instead.



##########
core/src/layers/mod.rs:
##########
@@ -33,6 +33,8 @@ mod immutable_index;
 pub use immutable_index::ImmutableIndexLayer;
 
 mod logging;
+pub use logging::DefaultLoggingInterceptor;

Review Comment:
   Like mentioned before.



##########
core/src/layers/logging.rs:
##########
@@ -82,14 +80,136 @@ use crate::*;
 /// ```shell
 /// RUST_LOG="info,opendal::services=debug" ./app
 /// ```
-#[derive(Debug, Copy, Clone)]
-pub struct LoggingLayer {
+#[derive(Debug)]
+pub struct LoggingLayer<I = DefaultLoggingInterceptor> {
+    notify: Arc<I>,
+}
+
+impl<I> Clone for LoggingLayer<I> {
+    fn clone(&self) -> Self {
+        Self {
+            notify: self.notify.clone(),
+        }
+    }
+}
+
+impl Default for LoggingLayer {
+    fn default() -> Self {
+        Self {
+            notify: Arc::new(DefaultLoggingInterceptor::default()),
+        }
+    }
+}
+
+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<I: LoggingInterceptor>(notify: I) -> LoggingLayer<I> {
+        LoggingLayer {
+            notify: Arc::new(notify),
+        }
+    }
+}
+
+impl<A: Access, I: LoggingInterceptor> Layer<A> for LoggingLayer<I> {
+    type LayeredAccess = LoggingAccessor<A, I>;
+
+    fn layer(&self, inner: A) -> Self::LayeredAccess {
+        let meta = inner.info();
+        LoggingAccessor {
+            inner,
+
+            ctx: LoggingContext {
+                scheme: meta.scheme(),
+                notify: self.notify.clone(),
+            },
+        }
+    }
+}
+
+#[derive(Debug)]
+pub struct LoggingContext<I> {
+    scheme: Scheme,
+    notify: Arc<I>,
+}
+
+impl<I> Clone for LoggingContext<I> {
+    fn clone(&self) -> Self {
+        Self {
+            scheme: self.scheme,
+            notify: self.notify.clone(),
+        }
+    }
+}
+
+impl<I: LoggingInterceptor> LoggingContext<I> {
+    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.
+    ///

Review Comment:
   Let's clarify that 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.



##########
core/src/layers/logging.rs:
##########


Review Comment:
   After this refactor, the `LoggingLayer` is no longer limited to just `log`. Users can now employ `tracing` or any other logging libraries they prefer. We could potentially offer enhanced support for these use cases by providing default `tracing`/`log` support.
   
   It's not part of this PR, we can discuss them later.



##########
core/src/layers/logging.rs:
##########
@@ -82,14 +80,136 @@ use crate::*;
 /// ```shell
 /// RUST_LOG="info,opendal::services=debug" ./app
 /// ```
-#[derive(Debug, Copy, Clone)]
-pub struct LoggingLayer {
+#[derive(Debug)]
+pub struct LoggingLayer<I = DefaultLoggingInterceptor> {
+    notify: Arc<I>,
+}
+
+impl<I> Clone for LoggingLayer<I> {
+    fn clone(&self) -> Self {
+        Self {
+            notify: self.notify.clone(),
+        }
+    }
+}
+
+impl Default for LoggingLayer {
+    fn default() -> Self {
+        Self {
+            notify: Arc::new(DefaultLoggingInterceptor::default()),
+        }
+    }
+}
+
+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<I: LoggingInterceptor>(notify: I) -> LoggingLayer<I> {
+        LoggingLayer {
+            notify: Arc::new(notify),
+        }
+    }
+}
+
+impl<A: Access, I: LoggingInterceptor> Layer<A> for LoggingLayer<I> {
+    type LayeredAccess = LoggingAccessor<A, I>;
+
+    fn layer(&self, inner: A) -> Self::LayeredAccess {
+        let meta = inner.info();
+        LoggingAccessor {
+            inner,
+
+            ctx: LoggingContext {
+                scheme: meta.scheme(),
+                notify: self.notify.clone(),
+            },
+        }
+    }
+}
+
+#[derive(Debug)]
+pub struct LoggingContext<I> {
+    scheme: Scheme,
+    notify: Arc<I>,
+}
+
+impl<I> Clone for LoggingContext<I> {
+    fn clone(&self) -> Self {
+        Self {
+            scheme: self.scheme,
+            notify: self.notify.clone(),
+        }
+    }
+}
+
+impl<I: LoggingInterceptor> LoggingContext<I> {
+    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.
+    ///
+    /// # 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,
+        operation: &'static str,
+        path: &str,
+        message: &str,
+        err: Option<&Error>,
+    );
+}
+
+/// The DefaultLoggingInterceptor will log the message by the standard logging macro.
+#[derive(Debug)]
+pub struct DefaultLoggingInterceptor {

Review Comment:
   I believe we should not expose the `DefaultLoggingInterceptor`. Users with specific logging requirements can implement their own solutions.



##########
core/src/layers/logging.rs:
##########
@@ -184,776 +337,560 @@ impl LoggingContext {
         }
     }
 
-    /// 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
     }
 }
 
 #[derive(Clone, Debug)]
-pub struct LoggingAccessor<A: Access> {
+pub struct LoggingAccessor<A: Access, I: LoggingInterceptor> {
     inner: A,
 
-    ctx: LoggingContext,
+    ctx: LoggingContext<I>,
 }
 
 static LOGGING_TARGET: &str = "opendal::services";
 
-impl<A: Access> LayeredAccess for LoggingAccessor<A> {
+impl<A: Access, I: LoggingInterceptor> LayeredAccess for LoggingAccessor<A, I> {
     type Inner = A;
-    type Reader = LoggingReader<A::Reader>;
-    type BlockingReader = LoggingReader<A::BlockingReader>;
-    type Writer = LoggingWriter<A::Writer>;
-    type BlockingWriter = LoggingWriter<A::BlockingWriter>;
-    type Lister = LoggingLister<A::Lister>;
-    type BlockingLister = LoggingLister<A::BlockingLister>;
+    type Reader = LoggingReader<A::Reader, I>;
+    type BlockingReader = LoggingReader<A::BlockingReader, I>;
+    type Writer = LoggingWriter<A::Writer, I>;
+    type BlockingWriter = LoggingWriter<A::BlockingWriter, I>;
+    type Lister = LoggingLister<A::Lister, I>;
+    type BlockingLister = LoggingLister<A::BlockingLister, I>;
 
     fn inner(&self) -> &Self::Inner {
         &self.inner
     }
 
     fn metadata(&self) -> Arc<AccessorInfo> {
-        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.log(
+            Operation::Info.into_static(),
+            "",
+            &format!("-> finished: {:?}", result),
+            None,
         );
 
         result
     }
 
     async fn create_dir(&self, path: &str, args: OpCreateDir) -> Result<RpCreateDir> {
-        debug!(
-            target: LOGGING_TARGET,
-            "service={} operation={} path={} -> started",
-            self.ctx.scheme,
-            Operation::CreateDir,
-            path
-        );
+        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.log(
+                    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)
-                    )
-                };
+                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
+            .log(Operation::Read.into_static(), path, "-> started", None);

Review Comment:
   Maybe We can add `->` in the default logging?



-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: commits-unsubscribe@opendal.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org