WIP logging sql.rs without context

Author: link2xt

Cargo.lock

@@ -52,7 +52,8 @@ once_cell = "1.17.0"
 percent-encoding = "2.2"
 pgp = { version = "0.9", default-features = false }
 tracing = "0.1"
-tracing-subscriber = { version = "0.3", default-features=false, features = ["std", "env-filter", "fmt"] }
+tracing-subscriber = { version = "0.3", default-features=false, features = ["std", "env-filter", "registry"] }
+tracing-futures = "0.2"
 quick-xml = "0.27"
 r2d2 = "0.8"
 r2d2_sqlite = "0.20"
@@ -140,7 +141,7 @@ harness = false
 [features]
 default = ["vendored"]
 internals = []
-repl = ["internals", "rustyline", "ansi_term", "dirs"]
+repl = ["internals", "rustyline", "ansi_term", "dirs", "tracing-subscriber/fmt"]
 vendored = [
   "async-native-tls/vendored",
   "async-smtp/native-tls-vendored",

Cargo.toml

@@ -9,9 +9,12 @@ use std::path::{Path, PathBuf};
 use std::sync::Arc;
 use std::time::{Duration, Instant, SystemTime};
 
+use crate::log::EventLayer;
 use anyhow::{ensure, Result};
 use async_channel::{self as channel, Receiver, Sender};
 use tokio::sync::{Mutex, RwLock};
+use tracing_futures::WithSubscriber;
+use tracing_subscriber::{prelude::*, registry::Registry, EnvFilter};
 
 use crate::chat::{get_chat_cnt, ChatId};
 use crate::config::Config;
@@ -279,11 +282,20 @@ impl Context {
         events: Events,
         stock_strings: StockStrings,
     ) -> Result<Context> {
-        let context = Self::new_closed(dbfile, id, events, stock_strings).await?;
+        let context = Self::new_closed(dbfile, id, events.clone(), stock_strings).await?;
 
         // Open the database if is not encrypted.
         if context.check_passphrase("".to_string()).await? {
-            context.sql.open(&context, "".to_string()).await?;
+            let filter =
+                EnvFilter::try_from_default_env().or_else(|_| EnvFilter::try_new("info"))?;
+            let subscriber = Registry::default()
+                .with(filter)
+                .with(EventLayer::new(id, events));
+            context
+                .sql
+                .open(&context, "".to_string())
+                .with_subscriber(subscriber)
+                .await?;
         }
         Ok(context)
     }

src/context.rs

@@ -2,7 +2,63 @@
 
 #![allow(missing_docs)]
 
+use std::fmt::Write;
+
+use tracing::Level;
+use tracing_subscriber::Layer;
+
 use crate::context::Context;
+use crate::events::{Event, EventType, Events};
+
+#[derive(Debug)]
+struct MessageStorage<'a>(&'a mut String);
+
+impl tracing::field::Visit for MessageStorage<'_> {
+    fn record_debug(&mut self, field: &tracing::field::Field, value: &dyn std::fmt::Debug) {
+        if field.name() == "message" {
+            write!(self.0, "{:?}", value).ok();
+        }
+    }
+}
+
+#[derive(Debug)]
+pub(crate) struct EventLayer {
+    context_id: u32,
+    events: Events,
+}
+
+impl EventLayer {
+    pub(crate) fn new(context_id: u32, events: Events) -> Self {
+        Self { context_id, events }
+    }
+}
+
+impl<S> Layer<S> for EventLayer
+where
+    S: tracing::Subscriber,
+{
+    fn on_event(
+        &self,
+        event: &tracing::Event<'_>,
+        _ctx: tracing_subscriber::layer::Context<'_, S>,
+    ) {
+        let &level = event.metadata().level();
+
+        let mut message = "".to_string();
+        let mut visitor = MessageStorage(&mut message);
+        event.record(&mut visitor);
+
+        if level == Level::INFO {
+            let dbg_message = message.clone();
+            eprintln!("INFO id={}!!! {}", self.context_id, &dbg_message);
+            self.events.emit(Event {
+                id: self.context_id,
+                typ: EventType::Info(message),
+            });
+            eprintln!("EMITTED INFO!!! {}", &dbg_message);
+        }
+    }
+}
 
 #[macro_export]
 macro_rules! info {

src/log.rs

@@ -24,7 +24,8 @@ use crate::param::{Param, Params};
 use crate::peerstate::{deduplicate_peerstates, Peerstate};
 use crate::stock_str;
 use crate::tools::{delete_file, time};
-use crate::{error, info, warn};
+use crate::{error, warn};
+use tracing::info;
 
 #[macro_export]
 macro_rules! paramsv {
@@ -267,7 +268,7 @@ impl Sql {
         // the structure is complete now and all objects are usable
 
         if recalc_fingerprints {
-            info!(context, "[migration] recalc fingerprints");
+            info!("[migration] recalc fingerprints");
             let addrs = self
                 .query_map(
                     "SELECT addr FROM acpeerstates;",
@@ -342,7 +343,7 @@ impl Sql {
             self.close().await;
             Err(err)
         } else {
-            info!(context, "Opened database {:?}.", self.dbfile);
+            info!("Opened database {:?}.", self.dbfile);
             *self.is_encrypted.write().await = Some(passphrase_nonempty);
             Ok(())
         }
@@ -677,15 +678,15 @@ pub async fn housekeeping(context: &Context) -> Result<()> {
         .await
         .ok_or_log_msg(context, "failed to remove old MDNs");
 
-    info!(context, "Housekeeping done.");
+    info!("Housekeeping done.");
     Ok(())
 }
 
 pub async fn remove_unused_files(context: &Context) -> Result<()> {
     let mut files_in_use = HashSet::new();
     let mut unreferenced_count = 0;
 
-    info!(context, "Start housekeeping...");
+    info!("Start housekeeping...");
     maybe_add_from_param(
         &context.sql,
         &mut files_in_use,
@@ -731,7 +732,7 @@ pub async fn remove_unused_files(context: &Context) -> Result<()> {
         .await
         .context("housekeeping: failed to SELECT value FROM config")?;
 
-    info!(context, "{} files in use.", files_in_use.len(),);
+    info!("{} files in use.", files_in_use.len(),);
     /* go through directory and delete unused files */
     let p = context.get_blobdir();
     match tokio::fs::read_dir(p).await {
@@ -768,7 +769,6 @@ pub async fn remove_unused_files(context: &Context) -> Result<()> {
 
                     if recently_created || recently_modified || recently_accessed {
                         info!(
-                            context,
                             "Housekeeping: Keeping new unreferenced file #{}: {:?}",
                             unreferenced_count,
                             entry.file_name(),
@@ -777,7 +777,6 @@ pub async fn remove_unused_files(context: &Context) -> Result<()> {
                     }
                 }
                 info!(
-                    context,
                     "Housekeeping: Deleting unreferenced file #{}: {:?}",
                     unreferenced_count,
                     entry.file_name()
@@ -1050,7 +1049,9 @@ mod tests {
         assert!(!disable_server_delete);
         assert!(!recode_avatar);
 
-        info!(&t, "test_migration_flags: XXX END MARKER");
+        t.emit_event(crate::EventType::Info(
+            "test_migration_flags: XXX END MARKER".to_string(),
+        ));
 
         loop {
             let evt = t