Browse Source

config rust flowy log

appflowy 3 years ago
parent
commit
26aa4e951e

+ 7 - 12
app_flowy/packages/flowy_editor/lib/src/model/document/document.dart

@@ -70,26 +70,24 @@ class Document {
       length: replaceLength,
     );
 
-    Log.trace('current document delta: $_delta');
-    Log.trace('insert delta: $delta');
     compose(delta, ChangeSource.LOCAL);
-    Log.trace('compose insert, current document $_delta');
-    Log.trace('compose end');
+    Log.trace('current document $_delta');
     return delta;
   }
 
   Delta delete(int index, int length) {
+    Log.trace('delete $length at $index');
     assert(index >= 0 && length > 0);
     final delta = _rules.apply(RuleType.DELETE, this, index, length: length);
     if (delta.isNotEmpty) {
-      Log.trace('current document delta: $_delta');
       compose(delta, ChangeSource.LOCAL);
-      Log.trace('compose delete, current document $_delta');
     }
+    Log.trace('current document $_delta');
     return delta;
   }
 
   Delta replace(int index, int length, Object? data) {
+    Log.trace('replace $length at $index with $data');
     assert(index >= 0);
     assert(data is String || data is Embeddable);
 
@@ -101,23 +99,21 @@ class Document {
     // We have to insert before applying delete rules
     // Otherwise delete would be operating on stale document snapshot.
     if (dataIsNotEmpty) {
-      Log.trace('insert $data at $index, replace len: $length');
       delta = insert(index, data, replaceLength: length);
     }
 
     if (length > 0) {
-      Log.trace('delete $length at $index, len: $length');
       final deleteDelta = delete(index, length);
       delta = delta.compose(deleteDelta);
     }
 
-    Log.trace('replace result $delta');
+    Log.trace('current document $delta');
     return delta;
   }
 
   Delta format(int index, int length, Attribute? attribute) {
     assert(index >= 0 && length >= 0 && attribute != null);
-
+    Log.trace('format $length at $index with $attribute');
     var delta = Delta();
 
     final formatDelta = _rules.apply(
@@ -128,9 +124,8 @@ class Document {
       attribute: attribute,
     );
     if (formatDelta.isNotEmpty) {
-      Log.trace('current document delta: $_delta');
       compose(formatDelta, ChangeSource.LOCAL);
-      Log.trace('compose format, current document $_delta');
+      Log.trace('current document $_delta');
       delta = delta.compose(formatDelta);
     }
 

+ 2 - 1
app_flowy/packages/flowy_editor/lib/src/model/heuristic/rule.dart

@@ -4,6 +4,7 @@ import '../quill_delta.dart';
 import 'insert.dart';
 import 'delete.dart';
 import 'format.dart';
+import 'package:flowy_log/flowy_log.dart';
 
 enum RuleType {
   INSERT,
@@ -70,7 +71,7 @@ class Rules {
         final result = rule.apply(delta, index,
             length: length, data: data, attribute: attribute);
         if (result != null) {
-          print('apply rule: $rule, result: $result');
+          Log.trace('apply rule: $rule, result: $result');
           return result..trim();
         }
       } catch (e) {

+ 4 - 0
rust-lib/flowy-log/Cargo.toml

@@ -12,8 +12,12 @@ tracing-futures = "0.2.4"
 tracing-subscriber = { version = "0.2.12", features = ["registry", "env-filter", "ansi", "json"] }
 tracing-bunyan-formatter = "0.2.2"
 tracing-appender = "0.1"
+tracing-core = "0.1"
 tracing = { version = "0.1", features = ["log"] }
 log = "0.4.14"
+serde_json = "1.0"
+serde = "1.0"
+chrono = "0.4"
 
 [features]
 use_bunyan = []

+ 207 - 0
rust-lib/flowy-log/src/layer.rs

@@ -0,0 +1,207 @@
+use serde::ser::{SerializeMap, Serializer};
+use serde_json::Value;
+use std::{fmt, io::Write};
+use tracing::{Event, Id, Subscriber};
+use tracing_bunyan_formatter::JsonStorage;
+use tracing_core::{metadata::Level, span::Attributes};
+use tracing_log::AsLog;
+use tracing_subscriber::{fmt::MakeWriter, layer::Context, registry::SpanRef, Layer};
+const LEVEL: &str = "level";
+const TIME: &str = "time";
+const MESSAGE: &str = "msg";
+
+const FLOWY_RESERVED_FIELDS: [&str; 3] = [LEVEL, TIME, MESSAGE];
+
+pub struct FlowyFormattingLayer<W: MakeWriter + 'static> {
+    make_writer: W,
+    with_target: bool,
+}
+
+impl<W: MakeWriter + 'static> FlowyFormattingLayer<W> {
+    pub fn new(make_writer: W) -> Self {
+        Self {
+            make_writer,
+            with_target: false,
+        }
+    }
+
+    fn serialize_flowy_core_fields(
+        &self,
+        map_serializer: &mut impl SerializeMap<Error = serde_json::Error>,
+        message: &str,
+        level: &Level,
+    ) -> Result<(), std::io::Error> {
+        map_serializer.serialize_entry(MESSAGE, &message)?;
+        map_serializer.serialize_entry(LEVEL, &format!("{}", level))?;
+        map_serializer.serialize_entry(TIME, &chrono::Utc::now().timestamp())?;
+        Ok(())
+    }
+
+    fn serialize_span<S: Subscriber + for<'a> tracing_subscriber::registry::LookupSpan<'a>>(
+        &self,
+        span: &SpanRef<S>,
+        ty: Type,
+    ) -> Result<Vec<u8>, std::io::Error> {
+        let mut buffer = Vec::new();
+        let mut serializer = serde_json::Serializer::new(&mut buffer);
+        let mut map_serializer = serializer.serialize_map(None)?;
+        let message = format_span_context(&span, ty);
+        self.serialize_flowy_core_fields(&mut map_serializer, &message, span.metadata().level())?;
+        if self.with_target {
+            map_serializer.serialize_entry("target", &span.metadata().target())?;
+        }
+
+        map_serializer.serialize_entry("line", &span.metadata().line())?;
+        map_serializer.serialize_entry("file", &span.metadata().file())?;
+
+        let extensions = span.extensions();
+        if let Some(visitor) = extensions.get::<JsonStorage>() {
+            for (key, value) in visitor.values() {
+                if !FLOWY_RESERVED_FIELDS.contains(key) {
+                    map_serializer.serialize_entry(key, value)?;
+                } else {
+                    tracing::debug!("{} is a reserved field in the bunyan log format. Skipping it.", key);
+                }
+            }
+        }
+        map_serializer.end()?;
+        Ok(buffer)
+    }
+
+    fn emit(&self, mut buffer: Vec<u8>) -> Result<(), std::io::Error> {
+        buffer.write_all(b"\n")?;
+        self.make_writer.make_writer().write_all(&buffer)
+    }
+}
+
+/// The type of record we are dealing with: entering a span, exiting a span, an
+/// event.
+#[derive(Clone, Debug)]
+pub enum Type {
+    EnterSpan,
+    ExitSpan,
+    Event,
+}
+
+impl fmt::Display for Type {
+    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
+        let repr = match self {
+            Type::EnterSpan => "START",
+            Type::ExitSpan => "END",
+            Type::Event => "EVENT",
+        };
+        write!(f, "{}", repr)
+    }
+}
+
+fn format_span_context<S: Subscriber + for<'a> tracing_subscriber::registry::LookupSpan<'a>>(span: &SpanRef<S>, ty: Type) -> String {
+    format!("[⛳ {} - {}]", span.metadata().name().to_uppercase(), ty)
+}
+
+fn format_event_message<S: Subscriber + for<'a> tracing_subscriber::registry::LookupSpan<'a>>(
+    current_span: &Option<SpanRef<S>>,
+    event: &Event,
+    event_visitor: &JsonStorage<'_>,
+) -> String {
+    // Extract the "message" field, if provided. Fallback to the target, if missing.
+    let mut message = event_visitor
+        .values()
+        .get("message")
+        .map(|v| match v {
+            Value::String(s) => Some(s.as_str()),
+            _ => None,
+        })
+        .flatten()
+        .unwrap_or_else(|| event.metadata().target())
+        .to_owned();
+
+    // If the event is in the context of a span, prepend the span name to the
+    // message.
+    if let Some(span) = &current_span {
+        message = format!("{} {}", format_span_context(span, Type::Event), message);
+    }
+
+    message
+}
+
+impl<S, W> Layer<S> for FlowyFormattingLayer<W>
+where
+    S: Subscriber + for<'a> tracing_subscriber::registry::LookupSpan<'a>,
+    W: MakeWriter + 'static,
+{
+    fn on_event(&self, event: &Event<'_>, ctx: Context<'_, S>) {
+        // Events do not necessarily happen in the context of a span, hence
+        // lookup_current returns an `Option<SpanRef<_>>` instead of a
+        // `SpanRef<_>`.
+        let current_span = ctx.lookup_current();
+
+        let mut event_visitor = JsonStorage::default();
+        event.record(&mut event_visitor);
+
+        // Opting for a closure to use the ? operator and get more linear code.
+        let format = || {
+            let mut buffer = Vec::new();
+
+            let mut serializer = serde_json::Serializer::new(&mut buffer);
+            let mut map_serializer = serializer.serialize_map(None)?;
+
+            let message = format_event_message(&current_span, event, &event_visitor);
+            self.serialize_flowy_core_fields(&mut map_serializer, &message, event.metadata().level())?;
+            // Additional metadata useful for debugging
+            // They should be nested under `src` (see https://github.com/trentm/node-bunyan#src )
+            // but `tracing` does not support nested values yet
+
+            if self.with_target {
+                map_serializer.serialize_entry("target", event.metadata().target())?;
+            }
+
+            map_serializer.serialize_entry("line", &event.metadata().line())?;
+            map_serializer.serialize_entry("file", &event.metadata().file())?;
+
+            // Add all the other fields associated with the event, expect the message we
+            // already used.
+            for (key, value) in event_visitor
+                .values()
+                .iter()
+                .filter(|(&key, _)| key != "message" && !FLOWY_RESERVED_FIELDS.contains(&key))
+            {
+                map_serializer.serialize_entry(key, value)?;
+            }
+
+            // Add all the fields from the current span, if we have one.
+            if let Some(span) = &current_span {
+                let extensions = span.extensions();
+                if let Some(visitor) = extensions.get::<JsonStorage>() {
+                    for (key, value) in visitor.values() {
+                        if !FLOWY_RESERVED_FIELDS.contains(key) {
+                            map_serializer.serialize_entry(key, value)?;
+                        } else {
+                            tracing::debug!("{} is a reserved field in the flowy log format. Skipping it.", key);
+                        }
+                    }
+                }
+            }
+            map_serializer.end()?;
+            Ok(buffer)
+        };
+
+        let result: std::io::Result<Vec<u8>> = format();
+        if let Ok(formatted) = result {
+            let _ = self.emit(formatted);
+        }
+    }
+
+    fn new_span(&self, _attrs: &Attributes, id: &Id, ctx: Context<'_, S>) {
+        let span = ctx.span(id).expect("Span not found, this is a bug");
+        if let Ok(serialized) = self.serialize_span(&span, Type::EnterSpan) {
+            let _ = self.emit(serialized);
+        }
+    }
+
+    fn on_close(&self, id: Id, ctx: Context<'_, S>) {
+        let span = ctx.span(&id).expect("Span not found, this is a bug");
+        if let Ok(serialized) = self.serialize_span(&span, Type::ExitSpan) {
+            let _ = self.emit(serialized);
+        }
+    }
+}

+ 18 - 14
rust-lib/flowy-log/src/lib.rs

@@ -1,10 +1,13 @@
+mod layer;
+
 use log::LevelFilter;
 use std::path::Path;
 use tracing::subscriber::set_global_default;
 
+use crate::layer::*;
 use tracing_bunyan_formatter::{BunyanFormattingLayer, JsonStorageLayer};
 use tracing_log::LogTracer;
-use tracing_subscriber::{layer::SubscriberExt, EnvFilter};
+use tracing_subscriber::{fmt::format::FmtSpan, layer::SubscriberExt, EnvFilter};
 
 pub struct Builder {
     name: String,
@@ -37,23 +40,27 @@ impl Builder {
         let env_filter = EnvFilter::new(self.env_filter);
 
         let subscriber = tracing_subscriber::fmt()
-            .with_target(false)
+            // .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE)
+            .with_target(true)
             .with_max_level(tracing::Level::TRACE)
             .with_writer(std::io::stderr)
             .with_thread_ids(false)
-            .with_target(false)
             // .with_writer(non_blocking)
+            // .json()
             .compact()
             .finish()
             .with(env_filter);
 
-        if cfg!(feature = "use_bunyan") {
-            let formatting_layer = BunyanFormattingLayer::new(self.name.clone(), std::io::stdout);
-            let _ = set_global_default(subscriber.with(JsonStorageLayer).with(formatting_layer))
-                .map_err(|e| format!("{:?}", e))?;
-        } else {
-            let _ = set_global_default(subscriber).map_err(|e| format!("{:?}", e))?;
-        }
+        // if cfg!(feature = "use_bunyan") {
+        //     let formatting_layer = BunyanFormattingLayer::new(self.name.clone(),
+        // std::io::stdout);     let _ =
+        // set_global_default(subscriber.with(JsonStorageLayer).with(formatting_layer)).
+        // map_err(|e| format!("{:?}", e))?; } else {
+        //     let _ = set_global_default(subscriber).map_err(|e| format!("{:?}", e))?;
+        // }
+
+        let formatting_layer = FlowyFormattingLayer::new(std::io::stdout);
+        let _ = set_global_default(subscriber.with(JsonStorageLayer).with(formatting_layer)).map_err(|e| format!("{:?}", e))?;
 
         let _ = LogTracer::builder()
             .with_max_level(LevelFilter::Trace)
@@ -81,10 +88,7 @@ mod tests {
         let _ = Builder::new("flowy").env_filter("debug").build();
         tracing::info!("😁 Tracing info log");
 
-        let pos = Position {
-            x: 3.234,
-            y: -1.223,
-        };
+        let pos = Position { x: 3.234, y: -1.223 };
 
         tracing::debug!(?pos.x, ?pos.y);
         log::debug!("😁 bridge 'log' to 'tracing'");

+ 1 - 9
rust-lib/flowy-user/src/errors.rs

@@ -21,7 +21,7 @@ impl UserError {
     pub(crate) fn new(code: ErrorCode, msg: &str) -> Self { Self { code, msg: msg.to_owned() } }
 }
 
-#[derive(Clone, ProtoBuf_Enum, Display, PartialEq, Eq)]
+#[derive(Debug, Clone, ProtoBuf_Enum, Display, PartialEq, Eq)]
 pub enum ErrorCode {
     #[display(fmt = "Unknown")]
     Unknown              = 0,
@@ -70,14 +70,6 @@ pub enum ErrorCode {
     InternalError        = 100,
 }
 
-impl Debug for ErrorCode {
-    fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result { f.write_str(&format!("{}", self)) }
-}
-
-impl ErrorCode {
-    pub fn to_string(&self) -> String { format!("{}", self) }
-}
-
 impl std::default::Default for ErrorCode {
     fn default() -> Self { ErrorCode::Unknown }
 }

+ 0 - 1
rust-lib/flowy-user/src/services/user/user_session.rs

@@ -149,7 +149,6 @@ impl UserSession {
                     notify(&token, UserObservable::UserProfileUpdated).payload(profile).send();
                 },
                 Err(e) => {
-                    log::error!("{:?}", e);
                     notify(&token, UserObservable::UserProfileUpdated).error(e).send();
                 },
             }

+ 4 - 1
rust-lib/flowy-workspace/src/errors.rs

@@ -102,7 +102,10 @@ impl fmt::Display for WorkspaceError {
 pub type ErrorBuilder = flowy_infra::errors::Builder<ErrorCode, WorkspaceError>;
 
 impl flowy_infra::errors::Build<ErrorCode> for WorkspaceError {
-    fn build(code: ErrorCode, msg: String) -> Self { WorkspaceError::new(code, &msg) }
+    fn build(code: ErrorCode, msg: String) -> Self {
+        let msg = if msg.is_empty() { format!("{}", code) } else { msg };
+        WorkspaceError::new(code, &msg)
+    }
 }
 
 fn server_error_to_workspace_error(code: ServerErrorCode) -> ErrorCode {

+ 6 - 4
rust-lib/flowy-workspace/src/services/app_controller.rs

@@ -146,10 +146,12 @@ impl AppController {
         let server = self.server.clone();
         spawn(async move {
             // Opti: retry?
-            let app = server.read_app(&token, params).await.unwrap();
-            match app {
-                None => {},
-                Some(_) => {},
+            match server.read_app(&token, params).await {
+                Ok(option) => match option {
+                    None => {},
+                    Some(app) => {},
+                },
+                Err(_) => {},
             }
         });
         Ok(())