Improve logging and trace listeners

src/main.rs

@@ -36,7 +36,7 @@ fn main() -> Result<()> {
 
     let sections = query_sections(&conn)?;
     for sec in sections {
-        info!("section: {:?}", sec);
+        info!(section = debug(&sec), "read section");
     }
 
     Ok(())

src/migrations.rs

@@ -3,7 +3,7 @@ use rusqlite::{params, Connection};
 use std::collections::BTreeMap;
 use std::ops::Bound::{Excluded, Unbounded};
 use thiserror::Error;
-use tracing::{debug, trace};
+use tracing::{debug, trace, info};
 
 #[derive(Debug, Error)]
 pub enum MigrationError {
@@ -144,6 +144,7 @@ impl Migrations {
             last_ver = *ver;
         }
         if last_ver != NO_MIGRATIONS {
+            info!(old_version = db_version, new_version = last_ver, "applied database migrations");
             set_db_version(&trans, last_ver)?;
         }
         trans.commit()?;

src/section_runner.rs

@@ -117,17 +117,22 @@ impl SectionRunner {
 mod test {
     use super::*;
     use crate::section_interface::MockSectionInterface;
-    use tracing_subscriber::prelude::*;
     use crate::trace_listeners::{EventListener, Filters, SpanFilters, SpanListener};
+    use tracing_subscriber::prelude::*;
 
     #[tokio::test]
     async fn test_quit() {
         let quit_msg = EventListener::new(
             Filters::new()
-                .filter_message("runner_task recv")
+                .target("sprinklers_rs::section_runner")
-                .filter_field_value("msg", "Quit"),
+                .message("runner_task recv")
+                .field_value("msg", "Quit"),
+        );
+        let task_span = SpanListener::new(
+            SpanFilters::new()
+                .target("sprinklers_rs::section_runner")
+                .name("runner_task"),
         );
-        let task_span = SpanListener::new(SpanFilters::new().filter_name("runner_task"));
         let subscriber = tracing_subscriber::registry()
             .with(quit_msg.clone())
             .with(task_span.clone());

src/trace_listeners.rs

@@ -11,6 +11,8 @@ use tracing_subscriber::{
 
 #[derive(Clone, Debug)]
 pub struct Filters {
+    filter_target: Option<String>,
+    filter_name: Option<String>,
     filter_message: Option<String>,
     filter_field: Option<String>,
     filter_field_value: Option<String>,
@@ -19,27 +21,53 @@ pub struct Filters {
 impl Filters {
     pub fn new() -> Self {
         Self {
+            filter_target: None,
+            filter_name: None,
             filter_message: None,
             filter_field: None,
             filter_field_value: None,
         }
     }
 
-    pub fn filter_message(mut self, message: impl ToString) -> Self {
+    pub fn target(mut self, target: impl ToString) -> Self {
+        self.filter_target = Some(target.to_string());
+        self
+    }
+
+    pub fn name(mut self, name: impl ToString) -> Self {
+        self.filter_name = Some(name.to_string());
+        self
+    }
+
+    pub fn message(mut self, message: impl ToString) -> Self {
         self.filter_message = Some(message.to_string());
         self
     }
 
-    pub fn filter_field(mut self, field: impl ToString) -> Self {
+    pub fn field(mut self, field: impl ToString) -> Self {
         self.filter_field = Some(field.to_string());
         self
     }
 
-    pub fn filter_field_value(mut self, field: impl ToString, value: impl ToString) -> Self {
+    pub fn field_value(mut self, field: impl ToString, value: impl ToString) -> Self {
         self.filter_field = Some(field.to_string());
         self.filter_field_value = Some(value.to_string());
         self
     }
+
+    fn matches_metadata(&self, metadata: &tracing::Metadata) -> bool {
+        if let Some(target) = &self.filter_target {
+            if metadata.target() != target {
+                return false;
+            }
+        }
+        if let Some(name) = &self.filter_name {
+            if metadata.name() != name {
+                return false;
+            }
+        }
+        true
+    }
 }
 
 struct TraceListenerVisitor<'a> {
@@ -104,6 +132,10 @@ impl EventListener {
 }
 impl<S: Subscriber> Layer<S> for EventListener {
     fn on_event(&self, ev: &tracing::Event, _: Context<S>) {
+        println!("event name: {}", ev.metadata().name());
+        if !self.filters.matches_metadata(ev.metadata()) {
+            return;
+        }
         let mut visit = TraceListenerVisitor::new(&self.filters);
         ev.record(&mut visit);
         if visit.did_match() {
@@ -115,19 +147,36 @@ impl<S: Subscriber> Layer<S> for EventListener {
 #[derive(Clone, Debug)]
 pub struct SpanFilters {
     filters: Filters,
-    filter_name: Option<String>,
 }
 
 impl SpanFilters {
     pub fn new() -> Self {
         Self {
             filters: Filters::new(),
-            filter_name: None,
         }
     }
+    pub fn target(mut self, target: impl ToString) -> Self {
+        self.filters = self.filters.target(target);
+        self
+    }
 
-    pub fn filter_name(mut self, name: impl ToString) -> Self {
+    pub fn name(mut self, name: impl ToString) -> Self {
-        self.filter_name = Some(name.to_string());
+        self.filters = self.filters.name(name);
+        self
+    }
+
+    pub fn message(mut self, message: impl ToString) -> Self {
+        self.filters = self.filters.message(message);
+        self
+    }
+
+    pub fn field(mut self, field: impl ToString) -> Self {
+        self.filters = self.filters.field(field);
+        self
+    }
+
+    pub fn field_value(mut self, field: impl ToString, value: impl ToString) -> Self {
+        self.filters = self.filters.field_value(field, value);
         self
     }
 }
@@ -137,10 +186,8 @@ impl SpanFilters {
     where
         S: Subscriber + for<'lookup> LookupSpan<'lookup>,
     {
-        if let Some(name) = &self.filter_name {
+        if !self.filters.matches_metadata(span.metadata()) {
-            if span.name() != name {
+            return false;
-                return false;
-            }
         }
         true
     }
@@ -212,15 +259,16 @@ mod test {
 
     #[test]
     fn test_event_listener() {
-        let all_listener = EventListener::new(Filters::new());
+        let none_listener = EventListener::new(Filters::new().target("not my module path"));
-        let msg_listener = EventListener::new(Filters::new().filter_message("filter message"));
+        let all_listener = EventListener::new(Filters::new().target(std::module_path!()));
-        let field_listener = EventListener::new(Filters::new().filter_field("field"));
+        let msg_listener = EventListener::new(Filters::new().message("filter message"));
+        let field_listener = EventListener::new(Filters::new().field("field"));
         let field_value_listener =
-            EventListener::new(Filters::new().filter_field_value("field", 1234));
+            EventListener::new(Filters::new().field_value("field", 1234));
         let msg_field_value_listener = EventListener::new(
             Filters::new()
-                .filter_message("filter message")
+                .message("filter message")
-                .filter_field_value("field", 1234),
+                .field_value("field", 1234),
         );
         let subscriber = tracing_subscriber::registry()
             .with(all_listener.clone())
@@ -230,6 +278,7 @@ mod test {
             .with(msg_field_value_listener.clone());
         let _sub = tracing::subscriber::set_default(subscriber);
 
+        assert_eq!(none_listener.get_count(), 0);
         assert_eq!(all_listener.get_count(), 0);
         assert_eq!(msg_listener.get_count(), 0);
         assert_eq!(field_listener.get_count(), 0);
@@ -270,6 +319,7 @@ mod test {
 
         info!(field = 1234, "filter message");
 
+        assert_eq!(none_listener.get_count(), 0);
         assert_eq!(all_listener.get_count(), 5);
         assert_eq!(msg_listener.get_count(), 2);
         assert_eq!(field_listener.get_count(), 3);