From 3a3d635adddf5cb16a93827e688e061613a083d7 Mon Sep 17 00:00:00 2001 From: diogo464 Date: Fri, 5 Dec 2025 19:29:52 +0000 Subject: reworked logging --- Cargo.lock | 125 +++++++++++++++++++++++++++++++++++++++ Cargo.toml | 13 +++- examples/binary_sensor.rs | 2 +- examples/button.rs | 2 +- examples/common/mod.rs | 8 +++ examples/common/std_async_tcp.rs | 10 +++- examples/switch.rs | 3 +- src/lib.rs | 62 +++++++++++-------- src/log.rs | 115 +++++++++++++++++++++++++++++++++++ 9 files changed, 307 insertions(+), 33 deletions(-) create mode 100644 src/log.rs diff --git a/Cargo.lock b/Cargo.lock index 5bc99f3..d38b2c7 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -165,6 +165,8 @@ dependencies = [ "serde", "serde-json-core", "static_cell", + "tracing", + "tracing-subscriber", ] [[package]] @@ -380,6 +382,12 @@ version = "1.0.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "b9e0384b61958566e926dc50660321d12159025e767c18e043daf26b70104c39" +[[package]] +name = "lazy_static" +version = "1.5.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bbd2bcb4c963f2ddae06a2efc7e9f3591312473c50c6685e1f298068316e66fe" + [[package]] name = "libc" version = "0.2.178" @@ -392,6 +400,12 @@ version = "1.0.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "11d3d7f243d5c5a8b9bb5d6dd2b1602c0cb0b9db1621bafc7ed66e35ff9fe092" +[[package]] +name = "log" +version = "0.4.29" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5e5032e24019045c762d3c0f28f5b6b8bbf38563a65908389bf7978758920897" + [[package]] name = "managed" version = "0.8.0" @@ -413,6 +427,27 @@ version = "1.1.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "8d5439c4ad607c3c23abf66de8c8bf57ba8adcd1f129e699851a6e43935d339d" +[[package]] +name = "nu-ansi-term" +version = "0.50.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7957b9740744892f114936ab4a57b3f487491bbeafaf8083688b16841a4240e5" +dependencies = [ + "windows-sys", +] + +[[package]] +name = "once_cell" +version = "1.21.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "42f5e15c9953c5e4ccceeb2e7382a716482c34515315f7b03532b8b4e8393d2d" + +[[package]] +name = "pin-project-lite" +version = "0.2.16" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3b3cff922bd51709b605d9ead9aa71031d81447142d828eb4a6eba76fe619f9b" + [[package]] name = "portable-atomic" version = "1.11.1" @@ -550,6 +585,21 @@ dependencies = [ "syn", ] +[[package]] +name = "sharded-slab" +version = "0.1.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f40ca3c46823713e0d4209592e8d6e826aa57e928f09752619fc696c499637f6" +dependencies = [ + "lazy_static", +] + +[[package]] +name = "smallvec" +version = "1.15.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "67b1b7a3b5fe4f1376887184045fcf45c69e92af734b7aaddc05fb777b6fbd03" + [[package]] name = "smoltcp" version = "0.12.0" @@ -616,12 +666,72 @@ dependencies = [ "syn", ] +[[package]] +name = "thread_local" +version = "1.1.9" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f60246a4944f24f6e018aa17cdeffb7818b76356965d03b07d6a9886e8962185" +dependencies = [ + "cfg-if", +] + +[[package]] +name = "tracing" +version = "0.1.43" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2d15d90a0b5c19378952d479dc858407149d7bb45a14de0142f6c534b16fc647" +dependencies = [ + "pin-project-lite", + "tracing-core", +] + +[[package]] +name = "tracing-core" +version = "0.1.35" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7a04e24fab5c89c6a36eb8558c9656f30d81de51dfa4d3b45f26b21d61fa0a6c" +dependencies = [ + "once_cell", + "valuable", +] + +[[package]] +name = "tracing-log" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ee855f1f400bd0e5c02d150ae5de3840039a3f54b025156404e34c23c03f47c3" +dependencies = [ + "log", + "once_cell", + "tracing-core", +] + +[[package]] +name = "tracing-subscriber" +version = "0.3.22" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2f30143827ddab0d256fd843b7a66d164e9f271cfa0dde49142c5ca0ca291f1e" +dependencies = [ + "nu-ansi-term", + "sharded-slab", + "smallvec", + "thread_local", + "tracing-core", + "tracing-log", +] + [[package]] name = "unicode-ident" version = "1.0.22" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "9312f7c4f6ff9069b165498234ce8be658059c6728633667c526e27dc2cf1df5" +[[package]] +name = "valuable" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ba73ea9cf16a25df0c8caa16c51acb937d5712a8429db78a3ee29d5dcacd3a65" + [[package]] name = "void" version = "1.0.2" @@ -637,6 +747,21 @@ dependencies = [ "wit-bindgen", ] +[[package]] +name = "windows-link" +version = "0.2.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f0805222e57f7521d6a62e36fa9163bc891acd422f971defe97d64e70d0a4fe5" + +[[package]] +name = "windows-sys" +version = "0.61.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ae137229bcbd6cdf0f7b80a31df61766145077ddf49416a728b02cb3921ff3fc" +dependencies = [ + "windows-link", +] + [[package]] name = "wit-bindgen" version = "0.46.0" diff --git a/Cargo.toml b/Cargo.toml index 6a9ea4f..38ada69 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -3,15 +3,21 @@ name = "embassy-ha" version = "0.1.0" edition = "2024" +[features] +default = [] +defmt = ["dep:defmt", "embassy-net/defmt", "embassy-sync/defmt"] +tracing = ["dep:tracing"] + [dependencies] embedded-mqtt = { path = "./embedded-mqtt" , features = ["embassy-net"] } -embassy-net = { version = "0.7.1", features = ["defmt", "medium-ip", "proto-ipv4", "tcp"] } +embassy-net = { version = "0.7.1", features = ["medium-ip", "proto-ipv4", "tcp"] } heapless = "0.9.2" embassy-time = { version = "0.5.0" } serde-json-core = "0.6.0" serde = { version = "1.0.228", default-features = false, features = ["derive"] } -defmt = "1.0.1" -embassy-sync = { version = "0.7.2", features = ["defmt"] } +defmt = { version = "1.0.1", optional = true } +tracing = { version = "0.1", optional = true, default-features = false } +embassy-sync = { version = "0.7.2" } embassy-futures = "0.1.2" embedded-io-async = "0.6" @@ -23,3 +29,4 @@ static_cell = "2.1.1" embedded-io-async = { version = "0.6", features = ["std"] } critical-section = { version = "1", features = ["std"] } rand = "0.9.2" +tracing-subscriber = "0.3" diff --git a/examples/binary_sensor.rs b/examples/binary_sensor.rs index 7363a6c..27cfdb5 100644 --- a/examples/binary_sensor.rs +++ b/examples/binary_sensor.rs @@ -41,7 +41,7 @@ async fn main_task(spawner: Spawner) { async fn binary_sensor_class(mut switch: embassy_ha::BinarySensor<'static>) { loop { let state = switch.toggle(); - println!("state = {}", state); + tracing::info!("state = {}", state); Timer::after_secs(2).await; } } diff --git a/examples/button.rs b/examples/button.rs index d1d2159..e3d7086 100644 --- a/examples/button.rs +++ b/examples/button.rs @@ -31,7 +31,7 @@ async fn main_task(spawner: Spawner) { async fn button_task(mut button: embassy_ha::Button<'static>) { loop { button.pressed().await; - println!("The button has been pressed"); + tracing::info!("The button has been pressed"); } } diff --git a/examples/common/mod.rs b/examples/common/mod.rs index fd61e9d..db97463 100644 --- a/examples/common/mod.rs +++ b/examples/common/mod.rs @@ -9,6 +9,14 @@ pub static EXECUTOR: StaticCell = StaticCell::new(); macro_rules! example_main { () => { fn main() { + // Initialize tracing if tracing feature is enabled + #[cfg(feature = "tracing")] + { + tracing_subscriber::fmt() + .with_max_level(tracing::Level::DEBUG) + .init(); + } + let executor = common::EXECUTOR.init(Executor::new()); executor.run(|spawner| { spawner.must_spawn(main_task(spawner)); diff --git a/examples/common/std_async_tcp.rs b/examples/common/std_async_tcp.rs index bd97fa9..10a9fd8 100644 --- a/examples/common/std_async_tcp.rs +++ b/examples/common/std_async_tcp.rs @@ -1,4 +1,5 @@ use std::{ + future::Future, io::{Read, Write}, net::{TcpStream, ToSocketAddrs}, sync::{Arc, Mutex}, @@ -16,7 +17,9 @@ pub struct AsyncTcp { impl AsyncTcp { pub fn connect(addr: impl ToSocketAddrs) -> Self { + tracing::info!("Connecting to TCP server"); let stream = TcpStream::connect(addr).expect("failed to connect to remote"); + tracing::info!("TCP connection established"); let mut read_stream = stream.try_clone().unwrap(); let mut write_stream = stream; @@ -34,9 +37,10 @@ impl AsyncTcp { std::mem::take(&mut *buffer) }; if !buffer.is_empty() { - println!("writing {} bytes", buffer.len()); + let len = buffer.len(); write_stream.write_all(&buffer).unwrap(); write_stream.flush().unwrap(); + tracing::debug!("Wrote {} bytes to TCP stream", len); } else { std::thread::park(); } @@ -52,9 +56,11 @@ impl AsyncTcp { loop { let n = read_stream.read(&mut scratch).unwrap(); if n == 0 { + tracing::warn!("TCP stream closed (EOF)"); panic!("EOF"); } + tracing::debug!("Read {} bytes from TCP stream", n); { let mut buffer = read_buffer.lock().unwrap(); buffer.extend_from_slice(&scratch[..n]); @@ -79,6 +85,7 @@ impl embedded_io_async::ErrorType for AsyncTcp { impl embedded_io_async::Write for AsyncTcp { async fn write(&mut self, buf: &[u8]) -> Result { + tracing::trace!("Queueing {} bytes for write", buf.len()); { let mut buffer = self.write_buffer.lock().unwrap(); buffer.extend_from_slice(buf); @@ -116,6 +123,7 @@ impl embedded_io_async::Read for AsyncTcp { let copy_n = buf.len().min(buffer.len()); buf[..copy_n].copy_from_slice(&buffer[..copy_n]); buffer.drain(..copy_n); + tracing::trace!("Async read returned {} bytes", copy_n); return Ok(copy_n); } } diff --git a/examples/switch.rs b/examples/switch.rs index 0571758..67767d7 100644 --- a/examples/switch.rs +++ b/examples/switch.rs @@ -41,8 +41,7 @@ async fn main_task(spawner: Spawner) { async fn switch_task(mut switch: embassy_ha::Switch<'static>) { loop { let state = switch.wait().await; - - println!("state = {}", state); + tracing::info!("state = {}", state); Timer::after_secs(1).await; } } diff --git a/src/lib.rs b/src/lib.rs index 036ae12..3ebb190 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -2,7 +2,6 @@ use core::{cell::RefCell, task::Waker}; -use defmt::Format; use embassy_sync::waitqueue::AtomicWaker; use heapless::{ Vec, VecView, @@ -10,6 +9,9 @@ use heapless::{ }; use serde::Serialize; +pub mod log; +pub use log::Format; + pub mod constants; mod binary_state; @@ -59,7 +61,8 @@ impl Error { } } -#[derive(Debug, Format, Clone, Copy, Serialize)] +#[derive(Debug, Clone, Copy, Serialize)] +#[cfg_attr(feature = "defmt", derive(Format))] struct DeviceDiscovery<'a> { identifiers: &'a [&'a str], name: &'a str, @@ -67,7 +70,8 @@ struct DeviceDiscovery<'a> { model: &'a str, } -#[derive(Debug, Format, Serialize)] +#[derive(Debug, Serialize)] +#[cfg_attr(feature = "defmt", derive(Format))] struct EntityDiscovery<'a> { #[serde(rename = "unique_id")] id: &'a str, @@ -490,11 +494,11 @@ impl<'a> Device<'a> { pub async fn run(&mut self, transport: &mut T) -> Result<(), Error> { let mut client = embedded_mqtt::Client::new(self.mqtt_resources, transport); if let Err(err) = client.connect(self.config.device_id).await { - defmt::error!("mqtt connect failed with: {:?}", defmt::Debug2Format(&err)); + crate::log::error!("mqtt connect failed with: {:?}", crate::log::Debug2Format(&err)); return Err(Error::new("mqtt connection failed")); } - defmt::debug!("sending discover messages"); + crate::log::debug!("sending discover messages"); let device_discovery = DeviceDiscovery { identifiers: &[self.config.device_id], name: self.config.device_name, @@ -561,7 +565,7 @@ impl<'a> Device<'a> { mode: entity_config.mode, device: &device_discovery, }; - defmt::debug!("discovery for entity '{}': {}", entity_config.id, discovery); + crate::log::debug!("discovery for entity '{}': {:?}", entity_config.id, discovery); self.discovery_buffer .resize(self.discovery_buffer.capacity(), 0) @@ -572,25 +576,25 @@ impl<'a> Device<'a> { } let discovery_topic = self.discovery_topic_buffer.as_str(); - defmt::debug!("sending discovery to topic '{}'", discovery_topic); + crate::log::debug!("sending discovery to topic '{}'", discovery_topic); if let Err(err) = client .publish(discovery_topic, &self.discovery_buffer) .await { - defmt::error!( + crate::log::error!( "mqtt discovery publish failed with: {:?}", - defmt::Debug2Format(&err) + crate::log::Debug2Format(&err) ); return Err(Error::new("mqtt discovery publish failed")); } let command_topic = self.command_topic_buffer.as_str(); - defmt::debug!("subscribing to command topic '{}'", command_topic); + crate::log::debug!("subscribing to command topic '{}'", command_topic); if let Err(err) = client.subscribe(command_topic).await { - defmt::error!( + crate::log::error!( "mqtt subscribe to '{}' failed with: {:?}", command_topic, - defmt::Debug2Format(&err) + crate::log::Debug2Format(&err) ); return Err(Error::new( "mqtt subscription to entity command topic failed", @@ -641,7 +645,7 @@ impl<'a> Device<'a> { }) => write!(self.publish_buffer, "{}", value) .expect("publish buffer too small for number state payload"), _ => { - defmt::warn!( + crate::log::warn!( "entity '{}' requested state publish but its storage does not support it", entity.config.id ); @@ -660,10 +664,10 @@ impl<'a> Device<'a> { let state_topic = self.state_topic_buffer.as_str(); if let Err(err) = client.publish(state_topic, self.publish_buffer).await { - defmt::error!( + crate::log::error!( "mqtt state publish on topic '{}' failed with: {:?}", state_topic, - defmt::Debug2Format(&err) + crate::log::Debug2Format(&err) ); return Err(Error::new("mqtt publish failed")); } @@ -675,7 +679,7 @@ impl<'a> Device<'a> { embassy_futures::select::Either::First(packet) => match packet { Ok(embedded_mqtt::Packet::Publish(publish)) => publish, Err(err) => { - defmt::error!("mqtt receive failed with: {:?}", defmt::Debug2Format(&err)); + crate::log::error!("mqtt receive failed with: {:?}", crate::log::Debug2Format(&err)); return Err(Error::new("mqtt receive failed")); } _ => continue, @@ -708,7 +712,7 @@ impl<'a> Device<'a> { let mut read_buffer = [0u8; 128]; if publish.data_len > read_buffer.len() { - defmt::warn!( + crate::log::warn!( "mqtt publish payload on topic {} is too large ({} bytes), ignoring it", publish.topic, publish.data_len @@ -716,7 +720,7 @@ impl<'a> Device<'a> { continue; } - defmt::debug!( + crate::log::debug!( "mqtt receiving {} bytes of data on topic {}", publish.data_len, publish.topic @@ -724,9 +728,9 @@ impl<'a> Device<'a> { let data_len = publish.data_len; if let Err(err) = client.receive_data(&mut read_buffer[..data_len]).await { - defmt::error!( + crate::log::error!( "mqtt receive data failed with: {:?}", - defmt::Debug2Format(&err) + crate::log::Debug2Format(&err) ); return Err(Error::new("mqtt receive data failed")); } @@ -734,7 +738,7 @@ impl<'a> Device<'a> { let command = match str::from_utf8(&read_buffer[..data_len]) { Ok(command) => command, Err(_) => { - defmt::warn!("mqtt message contained invalid utf-8, ignoring it"); + crate::log::warn!("mqtt message contained invalid utf-8, ignoring it"); continue; } }; @@ -745,7 +749,7 @@ impl<'a> Device<'a> { match &mut data.storage { EntityStorage::Button(button_storage) => { if command != constants::HA_BUTTON_PAYLOAD_PRESS { - defmt::warn!( + crate::log::warn!( "button '{}' received unexpected command '{}', expected '{}', ignoring it", data.config.id, command, @@ -760,7 +764,7 @@ impl<'a> Device<'a> { let command = match command.parse::() { Ok(command) => command, Err(_) => { - defmt::warn!( + crate::log::warn!( "switch '{}' received invalid command '{}', expected 'ON' or 'OFF', ignoring it", data.config.id, command @@ -768,16 +772,24 @@ impl<'a> Device<'a> { continue; } }; + let timestamp = embassy_time::Instant::now(); + if switch_storage.publish_on_command { + data.publish = true; + switch_storage.state = Some(SwitchState { + value: command, + timestamp, + }); + } switch_storage.command = Some(SwitchCommand { value: command, - timestamp: embassy_time::Instant::now(), + timestamp, }); } EntityStorage::Number(number_storage) => { let command = match command.parse::() { Ok(command) => command, Err(_) => { - defmt::warn!( + crate::log::warn!( "number '{}' received invalid command '{}', expected a valid number, ignoring it", data.config.id, command diff --git a/src/log.rs b/src/log.rs new file mode 100644 index 0000000..1f7bebd --- /dev/null +++ b/src/log.rs @@ -0,0 +1,115 @@ +//! Logging abstraction that works with both defmt and tracing. +//! +//! This module provides logging macros that can use either `defmt` (for embedded targets) +//! or `tracing` (for desktop/testing) depending on the enabled cargo features. +//! +//! ## Features +//! +//! - `defmt`: Use defmt for logging +//! - `tracing`: Use tracing for logging +//! - Neither: Logging is compiled out (no-op) +//! +//! ## Usage +//! +//! ```rust,ignore +//! use crate::log::{trace, debug, info, warn, error}; +//! +//! info!("Application started"); +//! debug!("Value: {}", 42); +//! warn!("Something unexpected: {:?}", some_value); +//! ``` + +// Re-export Format trait when using defmt +#[cfg(feature = "defmt")] +pub use defmt::Format; + +// For tracing or no logging, we provide a stub Format trait +#[cfg(not(feature = "defmt"))] +pub trait Format {} + +// When using defmt, also provide Debug2Format for std types +#[cfg(feature = "defmt")] +pub use defmt::Debug2Format; + +// For tracing or no logging, Debug2Format is a passthrough +#[cfg(not(feature = "defmt"))] +#[inline] +pub fn Debug2Format(value: &T) -> &T { + value +} + +// Logging macros that dispatch to the appropriate backend or no-op +// If both features are enabled, defmt takes precedence + +#[macro_export] +macro_rules! trace { + ($($arg:tt)*) => { + #[cfg(feature = "defmt")] + defmt::trace!($($arg)*); + + #[cfg(all(feature = "tracing", not(feature = "defmt")))] + tracing::trace!($($arg)*); + + #[cfg(not(any(feature = "defmt", feature = "tracing")))] + { let _ = (); } // no-op + }; +} + +#[macro_export] +macro_rules! debug { + ($($arg:tt)*) => { + #[cfg(feature = "defmt")] + defmt::debug!($($arg)*); + + #[cfg(all(feature = "tracing", not(feature = "defmt")))] + tracing::debug!($($arg)*); + + #[cfg(not(any(feature = "defmt", feature = "tracing")))] + { let _ = (); } // no-op + }; +} + +#[macro_export] +macro_rules! info { + ($($arg:tt)*) => { + #[cfg(feature = "defmt")] + defmt::info!($($arg)*); + + #[cfg(all(feature = "tracing", not(feature = "defmt")))] + tracing::info!($($arg)*); + + #[cfg(not(any(feature = "defmt", feature = "tracing")))] + { let _ = (); } // no-op + }; +} + +#[macro_export] +macro_rules! warn { + ($($arg:tt)*) => { + #[cfg(feature = "defmt")] + defmt::warn!($($arg)*); + + #[cfg(all(feature = "tracing", not(feature = "defmt")))] + tracing::warn!($($arg)*); + + #[cfg(not(any(feature = "defmt", feature = "tracing")))] + { let _ = (); } // no-op + }; +} + +#[macro_export] +macro_rules! error { + ($($arg:tt)*) => { + #[cfg(feature = "defmt")] + defmt::error!($($arg)*); + + #[cfg(all(feature = "tracing", not(feature = "defmt")))] + tracing::error!($($arg)*); + + #[cfg(not(any(feature = "defmt", feature = "tracing")))] + { let _ = (); } // no-op + }; +} + +// Re-export the macros at the module level for easier use +pub use crate::{trace, debug, info, warn, error}; -- cgit