Skip to content

Commit

Permalink
Add defmt logging support
Browse files Browse the repository at this point in the history
Also modify the embassy-net example to use defmt via a small tcp logging backend
  • Loading branch information
dpeckett committed Dec 29, 2024
1 parent 1525bee commit 8cd156e
Show file tree
Hide file tree
Showing 9 changed files with 102 additions and 40 deletions.
4 changes: 2 additions & 2 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -33,7 +33,7 @@ sntpc = { version = "0.5", features = ["sync"] }
```rust
use sntpc::{sync::get_time, NtpContext, StdTimestampGen};

use std::net::{ToSocketAddrs, UdpSocket};
use std::net::{SocketAddr, ToSocketAddrs, UdpSocket};
use std::thread;
use std::time::Duration;

Expand All @@ -56,7 +56,7 @@ fn main() {
.set_read_timeout(Some(Duration::from_secs(2)))
.expect("Unable to set UDP socket read timeout");

for addr in POOL_NTP_ADDR.to_socket_addrs().unwrap() {
for addr in POOL_NTP_ADDR.to_socket_addrs().filter(SocketAddr::is_ipv4).unwrap() {
let ntp_context = NtpContext::new(StdTimestampGen::default());
let result = get_time(addr, &socket, ntp_context);

Expand Down
15 changes: 6 additions & 9 deletions examples/embassy-net/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -4,18 +4,15 @@ version = "0.1.0"
edition = "2021"
publish = false

[features]
log = ["dep:simple_logger", "dep:log", "sntpc/log", "embassy-executor/log", "embassy-time/log", "embassy-net/log"]

[dependencies]
sntpc = { path = "../../sntpc", default-features = false, features = ["embassy-socket"] }
log = { version = "~0.4", optional = true }
simple_logger = { version = "5", optional = true }
embassy-executor = { version = "0.6.3", features = ["task-arena-size-32768", "arch-std", "executor-thread"] }
embassy-time = { version = "0.3.2", features = ["std", "generic-queue"] }
embassy-net = { version = "0.5.0", features = ["std", "medium-ethernet", "udp", "dns"] }
sntpc = { path = "../../sntpc", default-features = false, features = ["defmt", "embassy-socket"] }
embassy-executor = { version = "0.6.3", features = ["arch-std", "defmt", "task-arena-size-32768", "executor-thread"] }
embassy-time = { version = "0.3.2", features = ["std", "defmt", "generic-queue"] }
embassy-net = { version = "0.5.0", features = ["std", "defmt", "medium-ethernet", "udp", "dns"] }
static_cell = "2"
heapless = { version = "0.8", default-features = false }
defmt = "0.3"
defmt-logger-tcp = "0.2"

[target.'cfg(unix)'.dependencies]
embassy-net-tuntap = "0.1.0"
17 changes: 17 additions & 0 deletions examples/embassy-net/build.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,17 @@
fn main() {
if cfg!(target_os = "linux") {
let target_arch = std::env::var("CARGO_CFG_TARGET_ARCH").unwrap();

// Add back the default linker script.
println!("cargo:rustc-link-search=/usr/lib/{target_arch}-linux-gnu/ldscripts");
println!("cargo:rustc-link-arg=-Telf_{target_arch}.x");

// Add the defmt strings section to the elf file.
println!("cargo:rustc-link-arg=-Tdefmt.x");

// Enable info level logging for the current crate (if not already set).
if std::env::var("DEFMT_LOG").is_err() {
println!("cargo:rustc-env=DEFMT_LOG=info");
}
}
}
26 changes: 15 additions & 11 deletions examples/embassy-net/src/main.rs
Original file line number Diff line number Diff line change
Expand Up @@ -23,10 +23,21 @@
//! ## Run the example
//!
//! ```sh
//! cargo build --features "log"
//! cargo build
//! sudo ../../target/debug/example-embassy-net
//! ```
//!
//! To view logs, run:
//!
//! ```sh
//! defmt-print -e ../../target/debug/example-embassy-net tcp
//! ```
//! You will need the defmt-print tool installed. You can install it by running:
//!
//! ```sh
//! cargo install defmt-print
//! ```
//!
//! ## Cleanup
//!
//! To remove the TUN/TAP interface, run:
Expand Down Expand Up @@ -65,6 +76,7 @@ cfg_unix! {

use core::net::{IpAddr, SocketAddr};
use std::time::SystemTime;
use std::thread;

const NTP_SERVER: &str = "pool.ntp.org";

Expand All @@ -89,8 +101,7 @@ cfg_unix! {
}
}

#[cfg(feature = "log")]
use log::{error, info};
use defmt::{error, info};

#[embassy_executor::task]
async fn net_task(
Expand Down Expand Up @@ -150,7 +161,6 @@ cfg_unix! {
.await
.expect("Failed to resolve DNS");
if ntp_addrs.is_empty() {
#[cfg(feature = "log")]
error!("Failed to resolve DNS");
return;
}
Expand All @@ -162,7 +172,6 @@ cfg_unix! {
.await
.unwrap();

#[cfg(feature = "log")]
info!("Time: {:?}", result);

Timer::after(Duration::from_secs(15)).await;
Expand All @@ -172,12 +181,7 @@ cfg_unix! {
static EXECUTOR: StaticCell<Executor> = StaticCell::new();

fn main() {
#[cfg(feature = "log")]
if cfg!(debug_assertions) {
simple_logger::init_with_level(log::Level::Trace).unwrap();
} else {
simple_logger::init_with_level(log::Level::Info).unwrap();
}
thread::spawn(defmt_logger_tcp::run);

let executor = EXECUTOR.init(Executor::new());
executor.run(|spawner| {
Expand Down
2 changes: 2 additions & 0 deletions sntpc/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -28,13 +28,15 @@ log = ["dep:log"]
std-socket = []
embassy-socket = ["dep:embassy-net"]
tokio-socket = ["dep:tokio"]
defmt = ["dep:defmt"]

[dependencies]
log = { version = "~0.4", optional = true }
chrono = { version = "~0.4", default-features = false, optional = true }
miniloop = { version = "~0.3", optional = true }
embassy-net = { version = "0.5.0", features = ["udp", "proto-ipv4", "proto-ipv6", "medium-ip"], optional = true }
tokio = { version = "1", features = ["net"], optional = true }
defmt = { version = "0.3", optional = true }

[dev-dependencies]
miniloop = "~0.3"
Expand Down
51 changes: 41 additions & 10 deletions sntpc/src/lib.rs
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,7 @@
//! - `std-socket`: add `NtpUdpSocket` trait implementation for `std::net::UdpSocket`
//! - `embassy-socket`: add `NtpUdpSocket` trait implementation for `embassy_net::udp::UdpSocket`
//! - `tokio-socket`: add `NtpUdpSocket` trait implementation for `tokio::net::UdpSocket`
//! - `defmt`: enables library debug output using defmt
//!
//! <div class="warning">
//!
Expand All @@ -50,8 +51,8 @@
//!
//! ## Logging support
//!
//! Library debug logs can be enabled in executables by enabling `log` feature. Server
//! addresses, response payload will be printed.
//! Library debug logs can be enabled in executables by enabling `log` or `defmt`
//! feature. Server addresses, response payload will be printed.
//!
//! # Example
//!
Expand Down Expand Up @@ -155,7 +156,7 @@ mod types;

pub use crate::types::*;

#[cfg(feature = "log")]
#[cfg(any(feature = "log", feature = "defmt"))]
use core::str;

/// Network types used by the `sntpc` crate
Expand All @@ -166,6 +167,8 @@ pub mod net {
pub use std::net::UdpSocket;
}

#[cfg(all(feature = "defmt", not(feature = "log")))]
use defmt::debug;
#[cfg(feature = "log")]
use log::debug;

Expand Down Expand Up @@ -411,7 +414,7 @@ where
U: NtpUdpSocket,
T: NtpTimestampGenerator,
{
#[cfg(feature = "log")]
#[cfg(any(feature = "log", feature = "defmt"))]
debug!("send request - Address: {:?}", dest);
let request = NtpPacket::new(context.timestamp_gen);

Expand Down Expand Up @@ -518,7 +521,7 @@ where
/// fn main() {
/// let socket = UdpSocket::bind("0.0.0.0:0").expect("Unable to crate UDP socket");
/// let context = NtpContext::new(Timestamp::default());
/// let server_addr: SocketAddr = "time.google.com:123".to_socket_addrs().expect("Unable to resolve host").next().unwrap();
/// let server_addr: SocketAddr = "time.google.com:123".to_socket_addrs().expect("Unable to resolve host").filter(SocketAddr::is_ipv4).next().unwrap();
/// # let mut executor = Executor::new();
///
/// let request_result = executor.block_on(async {
Expand Down Expand Up @@ -555,7 +558,7 @@ where
let (response, src) = socket.recv_from(response_buf.0.as_mut()).await?;
context.timestamp_gen.init();
let recv_timestamp = get_ntp_timestamp(&context.timestamp_gen);
#[cfg(feature = "log")]
#[cfg(any(feature = "log", feature = "defmt"))]
debug!("Response: {}", response);

if dest != src {
Expand All @@ -569,7 +572,7 @@ where
let result =
process_response(send_req_result, response_buf, recv_timestamp);

#[cfg(feature = "log")]
#[cfg(any(feature = "log", feature = "defmt"))]
if let Ok(r) = &result {
debug!("{:?}", r);
}
Expand Down Expand Up @@ -610,6 +613,8 @@ pub mod sync {

use miniloop::executor::Executor;

#[cfg(all(feature = "defmt", not(feature = "log")))]
use defmt::debug;
#[cfg(feature = "log")]
use log::debug;

Expand Down Expand Up @@ -640,7 +645,7 @@ pub mod sync {
T: NtpTimestampGenerator + Copy,
{
let result = sntp_send_request(addr, socket, context)?;
#[cfg(feature = "log")]
#[cfg(any(feature = "log", feature = "defmt"))]
debug!("{:?}", result);

sntp_process_response(addr, socket, context, result)
Expand Down Expand Up @@ -853,7 +858,7 @@ fn process_response(
let mut packet = NtpPacket::from(resp);

convert_from_network(&mut packet);
#[cfg(feature = "log")]
#[cfg(any(feature = "log", feature = "defmt"))]
debug_ntp_packet(&packet, recv_timestamp);

if send_req_result.originate_timestamp != packet.origin_timestamp {
Expand Down Expand Up @@ -899,7 +904,7 @@ fn process_response(
let offset = offset_calculate(t1, t2, t3, t4, units);
let timestamp = NtpTimestamp::from(packet.tx_timestamp);

#[cfg(feature = "log")]
#[cfg(any(feature = "log", feature = "defmt"))]
debug!(
"Roundtrip delay: {} {}. Offset: {} {}",
roundtrip, units, offset, units
Expand Down Expand Up @@ -1029,6 +1034,32 @@ fn debug_ntp_packet(packet: &NtpPacket, recv_timestamp: u64) {
debug!("{}", delimiter_gen());
}

#[cfg(all(feature = "defmt", not(feature = "log")))]
fn debug_ntp_packet(packet: &NtpPacket, recv_timestamp: u64) {
let mode = shifter(packet.li_vn_mode, MODE_MASK, MODE_SHIFT);
let version = shifter(packet.li_vn_mode, VERSION_MASK, VERSION_SHIFT);
let li = shifter(packet.li_vn_mode, LI_MASK, LI_SHIFT);

debug!("NTP Packet:");
debug!("Mode: {}", mode);
debug!("Version: {}", version);
debug!("Leap: {}", li);
debug!("Stratum: {}", packet.stratum);
debug!("Poll: {}", packet.poll);
debug!("Precision: {}", packet.precision);
debug!("Root delay: {}", packet.root_delay);
debug!("Root dispersion: {}", packet.root_dispersion);
debug!(
"Reference ID: {}",
str::from_utf8(&packet.ref_id.to_be_bytes()).unwrap_or("")
);
debug!("Origin timestamp (client): {}", packet.origin_timestamp);
debug!("Receive timestamp (server): {}", packet.recv_timestamp);
debug!("Transmit timestamp (server): {}", packet.tx_timestamp);
debug!("Receive timestamp (client): {}", recv_timestamp);
debug!("Reference timestamp (server): {}", packet.ref_timestamp);
}

fn get_ntp_timestamp<T: NtpTimestampGenerator>(timestamp_gen: &T) -> u64 {
((timestamp_gen.timestamp_sec()
+ (u64::from(NtpPacket::NTP_TIMESTAMP_DELTA)))
Expand Down
13 changes: 9 additions & 4 deletions sntpc/src/socket/embassy.rs
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,11 @@ use embassy_net::{udp::UdpSocket, IpAddress, IpEndpoint};

use core::net::IpAddr;

#[cfg(feature = "log")]
use log::error;
#[cfg(all(feature = "defmt", not(feature = "log")))]
use defmt::error;

impl NtpUdpSocket for UdpSocket<'_> {
async fn send_to(&self, buf: &[u8], addr: SocketAddr) -> Result<usize> {
// Currently smoltcp still has its own address enum
Expand All @@ -17,8 +22,8 @@ impl NtpUdpSocket for UdpSocket<'_> {
match UdpSocket::send_to(self, buf, endpoint).await {
Ok(()) => Ok(buf.len()),
Err(e) => {
#[cfg(feature = "log")]
log::error!("Error while sending to {endpoint}: {e:?}");
#[cfg(any(feature = "log", feature = "defmt"))]
error!("Error while sending to {}: {:?}", endpoint, e);
Err(Error::Network)
}
}
Expand All @@ -38,8 +43,8 @@ impl NtpUdpSocket for UdpSocket<'_> {
match UdpSocket::recv_from(self, buf).await {
Ok((len, ep)) => Ok((len, to_addr(ep.endpoint))),
Err(e) => {
#[cfg(feature = "log")]
log::error!("Error receiving {e:?}");
#[cfg(any(feature = "log", feature = "defmt"))]
error!("Error receiving {:?}", e);
Err(Error::Network)
}
}
Expand Down
8 changes: 6 additions & 2 deletions sntpc/src/types.rs
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,8 @@ use core::fmt::{Debug, Display};
use core::mem;

use core::future::Future;
#[cfg(all(feature = "defmt", not(feature = "log")))]
use defmt::debug;
#[cfg(feature = "log")]
use log::debug;

Expand Down Expand Up @@ -75,6 +77,7 @@ impl From<u64> for NtpTimestamp {

/// Helper enum for specification delay units
#[derive(Copy, Clone, Debug)]
#[cfg_attr(feature = "defmt", derive(defmt::Format))]
pub(crate) enum Units {
#[allow(dead_code)]
Milliseconds,
Expand Down Expand Up @@ -121,6 +124,7 @@ pub enum Error {

/// SNTP request result representation
#[derive(Debug, Copy, Clone)]
#[cfg_attr(feature = "defmt", derive(defmt::Format))]
pub struct NtpResult {
/// NTP server seconds value
pub seconds: u32,
Expand Down Expand Up @@ -213,8 +217,8 @@ impl NtpPacket {
timestamp_gen.init();
let tx_timestamp = get_ntp_timestamp(&timestamp_gen);

#[cfg(feature = "log")]
debug!(target: "NtpPacket::new", "{}", tx_timestamp);
#[cfg(any(feature = "log", feature = "defmt"))]
debug!("NtpPacket::new({})", tx_timestamp);

NtpPacket {
li_vn_mode: NtpPacket::SNTP_CLIENT_MODE | NtpPacket::SNTP_VERSION,
Expand Down
6 changes: 4 additions & 2 deletions sntpc/src/utils.rs
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,8 @@
#[cfg(feature = "log")]
use chrono::Timelike;
use chrono::{Local, TimeZone, Utc};
#[cfg(all(feature = "defmt", not(feature = "log")))]
use defmt::debug;
#[cfg(feature = "log")]
use log::debug;

Expand All @@ -26,14 +28,14 @@ pub fn update_system_time(sec: u32, nsec: u32) {

if let Some(time) = time.single() {
let local_time = time.with_timezone(&Local);
#[cfg(feature = "log")]
#[cfg(any(feature = "log", feature = "defmt"))]
debug!(
"UTC time: {:02}:{:02}:{:02}",
time.hour(),
time.minute(),
time.second()
);
#[cfg(feature = "log")]
#[cfg(any(feature = "log", feature = "defmt"))]
debug!(
"{} time: {:02}:{:02}:{:02}",
local_time.offset(),
Expand Down

0 comments on commit 8cd156e

Please sign in to comment.