add tracing

Cargo.toml

@@ -38,9 +38,10 @@ path = "src/main.rs"
 cast = "0.3"
 clap = "2.33"
 clap_conf = "0.1.5"
-env_logger = "0.9"
 inflections = "1.1"
-log = { version = "~0.4", features = ["std"] }
+tracing = { version = "0.1", default-features = false, features = ["std", "attributes"] }
+tracing-subscriber = { version = "0.3", default-features = false, features = ["std", "ansi", "fmt", "env-filter", "tracing-log"] }
+
 quote = "1.0"
 proc-macro2 = "1.0"
 anyhow = "1.0"

src/generate/device.rs

@@ -2,9 +2,9 @@ use crate::svd::Device;
 use proc_macro2::{Ident, Span, TokenStream};
 use quote::{quote, ToTokens};
 
-use log::debug;
 use std::fs::File;
 use std::io::Write;
+use tracing::debug;
 
 use crate::util::{self, Config, ToSanitizedUpperCase};
 use crate::Target;
@@ -186,16 +186,15 @@ pub fn render(d: &Device, config: &Config, device_x: &mut String) -> Result<Toke
     }
 
     debug!("Rendering interrupts");
-    out.extend(interrupt::render(config.target, &d.peripherals, device_x)?);
+    out.extend(interrupt::render_interrupts(config.target, &d.peripherals, device_x)?);
 
     for p in &d.peripherals {
         if config.target == Target::CortexM && core_peripherals.contains(&&*p.name.to_uppercase()) {
             // Core peripherals are handled above
             continue;
         }
 
-        debug!("Rendering peripheral {}", p.name);
-        match peripheral::render(p, &d.peripherals, &d.default_register_properties, config) {
+        match peripheral::render_peripheral(p, &d.peripherals, &d.default_register_properties, config) {
             Ok(periph) => out.extend(periph),
             Err(e) => {
                 let descrip = p.description.as_deref().unwrap_or("No description");

src/generate/interrupt.rs

@@ -5,13 +5,15 @@ use crate::svd::Peripheral;
 use cast::u64;
 use proc_macro2::{Ident, Span, TokenStream};
 use quote::quote;
+use tracing::debug;
 
 use crate::util::{self, ToSanitizedUpperCase};
 use crate::Target;
 use anyhow::Result;
 
 /// Generates code for `src/interrupt.rs`
-pub fn render(
+#[tracing::instrument(skip_all)]
+pub fn render_interrupts(
     target: Target,
     peripherals: &[Peripheral],
     device_x: &mut String,
@@ -35,6 +37,7 @@ pub fn render(
     let mut pos = 0;
     let mut mod_items = TokenStream::new();
     for interrupt in &interrupts {
+        debug!("Rendering interrupt {}", interrupt.name);
         while pos < interrupt.value {
             elements.extend(quote!(Vector { _reserved: 0 },));
             pos += 1;

src/generate/peripheral.rs

@@ -6,10 +6,11 @@ use crate::svd::{
     Cluster, ClusterInfo, DeriveFrom, DimElement, Peripheral, Register, RegisterCluster,
     RegisterProperties,
 };
-use log::{debug, trace, warn};
+
 use proc_macro2::{Ident, Punct, Spacing, Span, TokenStream};
 use quote::{quote, ToTokens};
 use syn::{parse_str, Token};
+use tracing::{debug, trace, warn};
 
 use crate::util::{
     self, handle_cluster_error, handle_reg_error, Config, FullName, ToSanitizedSnakeCase,
@@ -19,12 +20,15 @@ use anyhow::{anyhow, bail, Context, Result};
 
 use crate::generate::register;
 
-pub fn render(
+#[tracing::instrument(skip_all,fields(peripheral.name = %p_original.name))]
+pub fn render_peripheral(
     p_original: &Peripheral,
     all_peripherals: &[Peripheral],
     defaults: &RegisterProperties,
     config: &Config,
 ) -> Result<TokenStream> {
+    debug!("Rendering peripheral {}", p_original.name);
+
     let mut out = TokenStream::new();
 
     let p_derivedfrom = p_original
@@ -175,18 +179,25 @@ pub fn render(
     let mut mod_items = TokenStream::new();
     mod_items.extend(register_or_cluster_block(&ercs, &defaults, None, config)?);
 
-    debug!("Pushing cluster information into output");
+    if !clusters.is_empty() {
+        debug!("Pushing cluster information into output");
+    }
     // Push all cluster related information into the peripheral module
     for c in &clusters {
-        trace!("Cluster: {}", c.name);
-        mod_items.extend(cluster_block(c, &defaults, p, all_peripherals, config)?);
+        mod_items.extend(render_cluster_block(
+            c,
+            &defaults,
+            p,
+            all_peripherals,
+            config,
+        )?);
+    }
+    if !registers.is_empty() {
+        debug!("Pushing register information into output");
     }
-
-    debug!("Pushing register information into output");
     // Push all register related information into the peripheral module
     for reg in registers {
-        trace!("Register: {}", reg.name);
-        match register::render(reg, registers, p, all_peripherals, &defaults, config) {
+        match register::render_register(reg, registers, p, all_peripherals, &defaults, config) {
             Ok(rendered_reg) => mod_items.extend(rendered_reg),
             Err(e) => {
                 let res: Result<TokenStream> = Err(e);
@@ -593,7 +604,6 @@ fn expand(
             RegisterCluster::Register(register) => {
                 match expand_register(register, defs, name, config) {
                     Ok(expanded_reg) => {
-                        trace!("Register: {}", register.name);
                         ercs_expanded.extend(expanded_reg);
                     }
                     Err(e) => {
@@ -605,7 +615,6 @@ fn expand(
             RegisterCluster::Cluster(cluster) => {
                 match expand_cluster(cluster, defs, name, config) {
                     Ok(expanded_cluster) => {
-                        trace!("Cluster: {}", cluster.name);
                         ercs_expanded.extend(expanded_cluster);
                     }
                     Err(e) => {
@@ -681,12 +690,15 @@ fn cluster_info_size_in_bits(
 }
 
 /// Render a given cluster (and any children) into `RegisterBlockField`s
+#[tracing::instrument(skip_all, fields(cluster.name = %cluster.name, module = name))]
 fn expand_cluster(
     cluster: &Cluster,
     defs: &RegisterProperties,
     name: Option<&str>,
     config: &Config,
 ) -> Result<Vec<RegisterBlockField>> {
+    trace!("Expanding cluster: {}", cluster.name);
+
     let mut cluster_expanded = vec![];
 
     let defs = cluster.default_register_properties.derive_from(defs);
@@ -743,12 +755,14 @@ fn expand_cluster(
 
 /// If svd register arrays can't be converted to rust arrays (non sequential addresses, non
 /// numeral indexes, or not containing all elements from 0 to size) they will be expanded
+#[tracing::instrument(skip_all, fields(register.name = %register.name))]
 fn expand_register(
     register: &Register,
     defs: &RegisterProperties,
     name: Option<&str>,
     config: &Config,
 ) -> Result<Vec<RegisterBlockField>> {
+    trace!("Expanding register: {}", register.name);
     let mut register_expanded = vec![];
 
     let register_size = register
@@ -805,13 +819,16 @@ fn expand_register(
 }
 
 /// Render a Cluster Block into `TokenStream`
-fn cluster_block(
+#[tracing::instrument(skip_all, fields(peripheral.name = %p.name, cluster.name = %c.name))]
+fn render_cluster_block(
     c: &Cluster,
     defaults: &RegisterProperties,
     p: &Peripheral,
     all_peripherals: &[Peripheral],
     config: &Config,
 ) -> Result<TokenStream> {
+    debug!("Rendering cluster: {}", c.name);
+
     let mut mod_items = TokenStream::new();
 
     // name_sc needs to take into account array type.
@@ -835,7 +852,7 @@ fn cluster_block(
     // Generate definition for each of the registers.
     let registers = util::only_registers(&c.children);
     for reg in &registers {
-        match register::render(reg, &registers, p, all_peripherals, &defaults, config) {
+        match register::render_register(reg, &registers, p, all_peripherals, &defaults, config) {
             Ok(rendered_reg) => mod_items.extend(rendered_reg),
             Err(e) => {
                 let res: Result<TokenStream> = Err(e);
@@ -851,7 +868,13 @@ fn cluster_block(
     // Generate the sub-cluster blocks.
     let clusters = util::only_clusters(&c.children);
     for c in &clusters {
-        mod_items.extend(cluster_block(c, &defaults, p, all_peripherals, config)?);
+        mod_items.extend(render_cluster_block(
+            c,
+            &defaults,
+            p,
+            all_peripherals,
+            config,
+        )?);
     }
 
     Ok(quote! {

src/generate/register.rs

@@ -4,21 +4,23 @@ use crate::svd::{
 };
 use cast::u64;
 use core::u64;
-use log::warn;
 use proc_macro2::{Ident, Punct, Spacing, Span, TokenStream};
 use quote::{quote, ToTokens};
+use tracing::{debug, warn};
 
 use crate::util::{self, Config, ToSanitizedSnakeCase, ToSanitizedUpperCase, U32Ext};
 use anyhow::{anyhow, Result};
 
-pub fn render(
+#[tracing::instrument(skip_all, fields(register.name = %register.name))]
+pub fn render_register(
     register: &Register,
     all_registers: &[&Register],
     peripheral: &Peripheral,
     all_peripherals: &[Peripheral],
     defs: &RegisterProperties,
     config: &Config,
 ) -> Result<TokenStream> {
+    debug!("Rendering register: {}", register.name);
     let access = util::access_of(register);
     let name = util::name_of(register, config.ignore_groups);
     let span = Span::call_site();

src/main.rs

@@ -1,8 +1,8 @@
 #![recursion_limit = "128"]
 
-use log::{error, info};
 use std::path::PathBuf;
 use svd_parser::svd;
+use tracing::{debug, error, info};
 
 mod generate;
 mod util;
@@ -90,10 +90,9 @@ fn run() -> Result<()> {
                     .short("l")
                     .help(&format!(
                         "Choose which messages to log (overrides {})",
-                        env_logger::DEFAULT_FILTER_ENV
+                        tracing_subscriber::EnvFilter::DEFAULT_ENV
                     ))
-                    .takes_value(true)
-                    .possible_values(&["off", "error", "warn", "info", "debug", "trace"]),
+                    .takes_value(true),
             )
             .version(concat!(
                 env!("CARGO_PKG_VERSION"),
@@ -174,6 +173,7 @@ fn run() -> Result<()> {
         .with_context(|| "Error rendering device")?;
 
     let filename = if make_mod { "mod.rs" } else { "lib.rs" };
+    debug!("Writing files");
     let mut file = File::create(path.join(filename)).expect("Couldn't create output file");
 
     let data = items.to_string().replace("] ", "]\n");
@@ -188,34 +188,30 @@ fn run() -> Result<()> {
         writeln!(File::create(path.join("device.x"))?, "{}", device_x)?;
         writeln!(File::create(path.join("build.rs"))?, "{}", build_rs())?;
     }
-
+    info!("Code generation completed. Output written to `{}`", path.display());
     Ok(())
 }
 
 fn setup_logging<'a>(getter: &'a impl clap_conf::Getter<'a, String>) {
-    // * Log at info by default.
+    // * Log at `info` by default.
     // * Allow users the option of setting complex logging filters using
-    //   env_logger's `RUST_LOG` environment variable.
-    // * Override both of those if the logging level is set via the `--log`
-    //   command line argument.
-    let env = env_logger::Env::default().filter_or(env_logger::DEFAULT_FILTER_ENV, "info");
-    let mut builder = env_logger::Builder::from_env(env);
-    builder.format_timestamp(None);
-
-    let log_lvl_from_env = std::env::var_os(env_logger::DEFAULT_FILTER_ENV).is_some();
-
-    if log_lvl_from_env {
-        log::set_max_level(log::LevelFilter::Trace);
-    } else {
-        let level = match getter.grab().arg("log_level").conf("log_level").done() {
-            Some(lvl) => lvl.parse().unwrap(),
-            None => log::LevelFilter::Info,
-        };
-        log::set_max_level(level);
-        builder.filter_level(level);
-    }
+    //   the `RUST_LOG` environment variable.
+    // * Override both of those if the logging level is set via
+    //   the `log_level` config setting.
+
+    let filter = match getter.grab().arg("log_level").conf("log_level").done() {
+        Some(lvl) => tracing_subscriber::EnvFilter::from(lvl),
+        None => tracing_subscriber::EnvFilter::from_default_env()
+            .add_directive(tracing::Level::INFO.into()),
+    };
 
-    builder.init();
+    tracing_subscriber::fmt()
+        .without_time()
+        .with_target(false)
+        .with_env_filter(filter)
+        .compact()
+        .with_ansi(true)
+        .init();
 }
 
 fn main() {