Add tracing crates

Cargo.lock

@@ -32,6 +32,15 @@ dependencies = [
  "memchr",
 ]
 
+[[package]]
+name = "ansi_term"
+version = "0.12.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "d52a9bb7ec0cf484c551830a7ce27bd20d67eac647e1befb56b0be4ee39a55d2"
+dependencies = [
+ "winapi",
+]
+
 [[package]]
 name = "async-trait"
 version = "0.1.56"
@@ -501,6 +510,8 @@ dependencies = [
  "tokio",
  "tokio-modbus",
  "tokio-serial",
+ "tracing",
+ "tracing-subscriber",
 ]
 
 [[package]]
@@ -791,6 +802,15 @@ dependencies = [
  "winapi",
 ]
 
+[[package]]
+name = "sharded-slab"
+version = "0.1.4"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "900fba806f70c630b0a382d0d825e17a0f19fcd059a2ade1ff237bcddf446b31"
+dependencies = [
+ "lazy_static",
+]
+
 [[package]]
 name = "slab"
 version = "0.4.6"
@@ -880,6 +900,15 @@ dependencies = [
  "syn",
 ]
 
+[[package]]
+name = "thread_local"
+version = "1.1.4"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "5516c27b78311c50bf42c071425c560ac799b11c30b31f87e3081965fe5e0180"
+dependencies = [
+ "once_cell",
+]
+
 [[package]]
 name = "tinyvec"
 version = "1.6.0"
@@ -982,22 +1011,60 @@ dependencies = [
 
 [[package]]
 name = "tracing"
-version = "0.1.35"
+version = "0.1.36"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "a400e31aa60b9d44a52a8ee0343b5b18566b03a8321e0d321f695cf56e940160"
+checksum = "2fce9567bd60a67d08a16488756721ba392f24f29006402881e43b19aac64307"
 dependencies = [
  "cfg-if",
  "pin-project-lite",
+ "tracing-attributes",
  "tracing-core",
 ]
 
 [[package]]
-name = "tracing-core"
+name = "tracing-attributes"
-version = "0.1.28"
+version = "0.1.22"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "7b7358be39f2f274f322d2aaed611acc57f382e8eb1e5b48cb9ae30933495ce7"
+checksum = "11c75893af559bc8e10716548bdef5cb2b983f8e637db9d0e15126b61b484ee2"
+dependencies = [
+ "proc-macro2",
+ "quote",
+ "syn",
+]
+
+[[package]]
+name = "tracing-core"
+version = "0.1.29"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "5aeea4303076558a00714b823f9ad67d58a3bbda1df83d8827d21193156e22f7"
 dependencies = [
  "once_cell",
+ "valuable",
+]
+
+[[package]]
+name = "tracing-log"
+version = "0.1.3"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "78ddad33d2d10b1ed7eb9d1f518a5674713876e97e5bb9b7345a7984fbb4f922"
+dependencies = [
+ "lazy_static",
+ "log",
+ "tracing-core",
+]
+
+[[package]]
+name = "tracing-subscriber"
+version = "0.3.15"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "60db860322da191b40952ad9affe65ea23e7dd6a5c442c2c42865810c6ab8e6b"
+dependencies = [
+ "ansi_term",
+ "sharded-slab",
+ "smallvec",
+ "thread_local",
+ "tracing-core",
+ "tracing-log",
 ]
 
 [[package]]
@@ -1039,6 +1106,12 @@ dependencies = [
  "percent-encoding",
 ]
 
+[[package]]
+name = "valuable"
+version = "0.1.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "830b7e5d4d90034032940e4ace0d9a9a057e7a45cd94e6c007832e39edb82f6d"
+
 [[package]]
 name = "version_check"
 version = "0.9.4"

Cargo.toml

@@ -17,3 +17,5 @@ serialport = { version = "4.2.0", features = ["serde"] }
 tokio = { version = "1.20.0", features = ["rt", "rt-multi-thread", "time"] }
 tokio-modbus = "0.5.3"
 tokio-serial = "5.4.3"
+tracing = "0.1.36"
+tracing-subscriber = "0.3.15"

src/main.rs

@@ -4,6 +4,7 @@ use serde_json::json;
 use std::{collections::HashMap, time::Duration};
 use tokio::{sync::mpsc, sync::oneshot, time::MissedTickBehavior};
 use tokio_modbus::prelude::*;
+use tracing::{debug, error, info, span, warn, Level};
 
 use clap::Parser;
 
@@ -39,6 +40,8 @@ enum MainStatus {
 
 #[tokio::main(worker_threads = 1)]
 async fn main() {
+    tracing_subscriber::fmt::init();
+
     let args = Cli::parse();
 
     let (registry_tx, mut registry_rx) = mpsc::channel::<RegistryCommand>(32);
@@ -80,7 +83,7 @@ async fn mqtt_dispatcher(
     registry: mpsc::Sender<RegistryCommand>,
     mut rx: mpsc::Receiver<DispatchCommand>,
 ) {
-    println!("Connecting to MQTT broker...");
+    info!("Connecting to MQTT broker...");
 
     options.set_last_will(LastWill {
         topic: format!("{}/status", prefix).to_string(),
@@ -116,7 +119,7 @@ async fn mqtt_dispatcher(
     let rx_loop_handler = {
         let client = client.clone();
         tokio::spawn(async move {
-            println!("Start dispatcher rx loop");
+            info!("Start dispatcher rx loop");
             while let Some(command) = rx.recv().await {
                 match command {
                     DispatchCommand::Publish { topic, payload } => {
@@ -135,11 +138,11 @@ async fn mqtt_dispatcher(
 
         match event {
             Out(_) => (),
-            In(Incoming::ConnAck(_)) => println!("Connected to MQTT!"),
+            In(Incoming::ConnAck(_)) => info!("Connected to MQTT!"),
             In(Incoming::PingResp | Incoming::SubAck(_)) => (),
 
             In(Incoming::Publish(Publish { topic, payload, .. })) => {
-                println!("{} -> {:?}", &topic, &payload);
+                debug!("{} -> {:?}", &topic, &payload);
 
                 match topic.split('/').collect::<Vec<&str>>()[..] {
                     [p, "connect", conn_name] if p == prefix.as_str() => {
@@ -155,7 +158,7 @@ async fn mqtt_dispatcher(
                 };
             }
             _ => {
-                println!("{:?}", event);
+                debug!("{:?}", event);
             }
         }
     }
@@ -181,7 +184,7 @@ async fn connection_registry(
     dispatcher: mpsc::Sender<DispatchCommand>,
     mut rx: mpsc::Receiver<RegistryCommand>,
 ) {
-    println!("Starting connection registry...");
+    info!("Starting connection registry...");
     let mut db: RegistryDb = HashMap::new();
 
     while let Some(command) = rx.recv().await {
@@ -193,7 +196,7 @@ async fn connection_registry(
                 }
             }
             Connect { id, details } => {
-                println!("Connection {}: {:?}", id, &details);
+                info!(id, payload = ?details, "Establishing connection");
                 let prefix = prefix.clone();
                 let dispatcher = dispatcher.clone();
 
@@ -206,7 +209,7 @@ async fn connection_registry(
                     tokio::spawn(handle_connect(dispatcher, id, prefix, details)),
                 );
             }
-            _ => println!("unimplemented"),
+            _ => error!("unimplemented"),
         }
     }
 }
@@ -225,6 +228,7 @@ enum ModbusCommand {
 
 type ModbusResponse = oneshot::Sender<Result<Vec<u16>, std::io::Error>>;
 
+#[tracing::instrument(level = "debug")]
 async fn handle_connect(
     dispatcher: mpsc::Sender<DispatchCommand>,
     id: ConnectionId,
@@ -233,7 +237,7 @@ async fn handle_connect(
 ) {
     use modbus::config::*;
     use modbus::ConnectState;
-    println!("Starting connection handler for {}", id);
+    info!("Starting connection handler for {}", id);
     match serde_json::from_slice::<Connect>(&payload) {
         Ok(connect) => {
             let unit = connect.unit;
@@ -371,7 +375,7 @@ async fn watch_registers(
                 r.address.checked_sub(address_offset.unsigned_abs() as u16)
             };
             if let Some(address) = address {
-                println!(
+                debug!(
                     "Polling {:?} {} {}",
                     read_type,
                     address,