Enable tracing formats

dsc/Cargo.toml

@@ -25,5 +25,5 @@ serde_yaml = { version = "0.9.3" }
 syntect = { version = "5.0", features = ["default-fancy"], default-features = false }
 sysinfo = { version = "0.29.10" }
 thiserror = "1.0"
-tracing = "0.1.37"
-tracing-subscriber = "0.3.17"
+tracing = { version = "0.1.37" }
+tracing-subscriber = { version = "0.3.17", features = ["ansi", "env-filter", "json"] }

dsc/src/args.rs

@@ -3,7 +3,6 @@
 
 use clap::{Parser, Subcommand, ValueEnum};
 use clap_complete::Shell;
-use crate::util::LogLevel;
 
 #[derive(Debug, Clone, PartialEq, Eq, ValueEnum)]
 pub enum OutputFormat {
@@ -12,21 +11,39 @@ pub enum OutputFormat {
     Yaml,
 }
 
+#[derive(Debug, Clone, PartialEq, Eq, ValueEnum)]
+pub enum TraceFormat {
+    Default,
+    Plaintext,
+    Json,
+}
+
+#[derive(Debug, Clone, PartialEq, Eq, ValueEnum)]
+pub enum TraceLevel {
+    Error,
+    Warning,
+    Info,
+    Debug,
+    Trace
+}
+
 #[derive(Debug, Parser)]
 #[clap(name = "dsc", version = env!("CARGO_PKG_VERSION"), about = "Apply configuration or invoke specific DSC resources", long_about = None)]
 pub struct Args {
     /// The subcommand to run
     #[clap(subcommand)]
     pub subcommand: SubCommand,
     /// The output format to use
-    #[clap(short = 'f', long)]
+    #[clap(short = 'o', long)]
     pub format: Option<OutputFormat>,
     #[clap(short = 'i', long, help = "The input to pass to the configuration or resource", conflicts_with = "input_file")]
     pub input: Option<String>,
     #[clap(short = 'p', long, help = "The path to a file used as input to the configuration or resource")]
     pub input_file: Option<String>,
-    #[clap(short = 'l', long = "logging-level", help = "Log level to display", value_enum, default_value = "info")]
-    pub logging_level: LogLevel,
+    #[clap(short = 'l', long, help = "Trace level to use", value_enum, default_value = "warning")]
+    pub trace_level: TraceLevel,
+    #[clap(short = 'f', long, help = "Trace format to use", value_enum, default_value = "default")]
+    pub trace_format: TraceFormat,
 }
 
 #[derive(Debug, PartialEq, Eq, Subcommand)]

dsc/src/main.rs

@@ -8,7 +8,7 @@ use clap_complete::generate;
 use std::io::{self, Read};
 use std::process::exit;
 use sysinfo::{Process, ProcessExt, RefreshKind, System, SystemExt, get_current_pid, ProcessRefreshKind};
-use tracing::{Level, error, info, warn, debug};
+use tracing::{error, info, warn, debug};
 
 #[cfg(debug_assertions)]
 use crossterm::event;
@@ -31,19 +31,7 @@ fn main() {
 
     let args = Args::parse();
 
-    let tracing_level = match args.logging_level {
-        util::LogLevel::Error => Level::ERROR,
-        util::LogLevel::Warning => Level::WARN,
-        util::LogLevel::Info => Level::INFO,
-        util::LogLevel::Debug => Level::DEBUG,
-        util::LogLevel::Trace => Level::TRACE,
-    };
-
-    // create subscriber that writes all events to stderr
-    let subscriber = tracing_subscriber::fmt().pretty().with_max_level(tracing_level).with_writer(std::io::stderr).finish();
-    if tracing::subscriber::set_global_default(subscriber).is_err() {
-        eprintln!("Unable to set global default subscriber");
-    }
+    util::enable_tracing(&args.trace_level, &args.trace_format);
 
     debug!("Running dsc {}", env!("CARGO_PKG_VERSION"));
 

dsc/src/util.rs

@@ -1,7 +1,7 @@
 // Copyright (c) Microsoft Corporation.
 // Licensed under the MIT License.
 
-use crate::args::{DscType, OutputFormat};
+use crate::args::{DscType, OutputFormat, TraceFormat, TraceLevel};
 
 use atty::Stream;
 use dsc_lib::{
@@ -25,7 +25,8 @@ use syntect::{
     parsing::SyntaxSet,
     util::{as_24_bit_terminal_escaped, LinesWithEndings}
 };
-use tracing::error;
+use tracing::{Level, error};
+use tracing_subscriber::{filter::EnvFilter, layer::SubscriberExt, Layer};
 
 pub const EXIT_SUCCESS: i32 = 0;
 pub const EXIT_INVALID_ARGS: i32 = 1;
@@ -35,16 +36,6 @@ pub const EXIT_INVALID_INPUT: i32 = 4;
 pub const EXIT_VALIDATION_FAILED: i32 = 5;
 pub const EXIT_CTRL_C: i32 = 6;
 
-#[derive(Debug)]
-#[derive(clap::ValueEnum, Clone)]
-pub enum LogLevel {
-   Error,
-   Warning,
-   Info,
-   Debug,
-   Trace
-}
-
 /// Get string representation of JSON value.
 ///
 /// # Arguments
@@ -251,3 +242,49 @@ pub fn write_output(json: &str, format: &Option<OutputFormat>) {
         println!("{output}");
     }
 }
+
+pub fn enable_tracing(trace_level: &TraceLevel, trace_format: &TraceFormat) {
+    let tracing_level = match trace_level {
+        TraceLevel::Error => Level::ERROR,
+        TraceLevel::Warning => Level::WARN,
+        TraceLevel::Info => Level::INFO,
+        TraceLevel::Debug => Level::DEBUG,
+        TraceLevel::Trace => Level::TRACE,
+    };
+
+    let filter = EnvFilter::try_from_default_env()
+        .or_else(|_| EnvFilter::try_new("warning"))
+        .unwrap_or_default()
+        .add_directive(tracing_level.into());
+    let layer = tracing_subscriber::fmt::Layer::default().with_writer(std::io::stderr);
+    let fmt = match trace_format {
+        TraceFormat::Default => {
+            layer
+                .with_ansi(true)
+                .with_level(true)
+                .with_line_number(true)
+                .boxed()
+        },
+        TraceFormat::Plaintext => {
+            layer
+                .with_ansi(false)
+                .with_level(true)
+                .with_line_number(false)
+                .boxed()
+        },
+        TraceFormat::Json => {
+            layer
+                .with_ansi(false)
+                .with_level(true)
+                .with_line_number(true)
+                .json()
+                .boxed()
+        }
+    };
+
+    let subscriber = tracing_subscriber::Registry::default().with(fmt).with(filter);
+
+    if tracing::subscriber::set_global_default(subscriber).is_err() {
+        eprintln!("Unable to set global default tracing subscriber.  Tracing is diabled.");
+    }
+}

dsc/tests/dsc_tracing.tests.ps1

@@ -0,0 +1,47 @@
+# Copyright (c) Microsoft Corporation.
+# Licensed under the MIT License.
+
+Describe 'tracing tests' {
+    It 'trace level <level> works' -TestCases @(
+        @{ level = 'error' }
+        # @{ level = 'WARNING' } TODO: currently no warnings are emitted
+        @{ level = 'info' }
+        @{ level = 'debug' }
+        # @{ level = 'trace' } TODO: currently no trace is emitted
+    ) {
+        param($level)
+
+        $logPath = "$TestDrive/dsc_trace.log"
+        $null = '{}' | dsc -l $level resource get -r 'DoesNotExist' 2> $logPath
+        $log = Get-Content $logPath -Raw
+        $log | Should -BeLikeExactly "* $($level.ToUpper()) *"
+    }
+
+    It 'trace level error does not emit other levels' {
+        $logPath = "$TestDrive/dsc_trace.log"
+        $null = '{}' | dsc --trace-level error resource get -r 'DoesNotExist' 2> $logPath
+        $log = Get-Content $logPath -Raw
+        $log | Should -Not -BeLikeExactly "* WARNING *"
+        $log | Should -Not -BeLikeExactly "* INFO *"
+        $log | Should -Not -BeLikeExactly "* DEBUG *"
+        $log | Should -Not -BeLikeExactly "* TRACE *"
+    }
+
+    It 'trace format plaintext does not emit ANSI' {
+        $logPath = "$TestDrive/dsc_trace.log"
+        $null = '{}' | dsc --trace-format plaintext resource get -r 'DoesNotExist' 2> $logPath
+        $log = Get-Content $logPath -Raw
+        $log | Should -Not -BeLikeExactly "*``[0m*"
+    }
+
+    It 'trace format json emits json' {
+        $logPath = "$TestDrive/dsc_trace.log"
+        $null = '{}' | dsc --trace-format json resource get -r 'DoesNotExist' 2> $logPath
+        foreach ($line in (Get-Content $logPath)) {
+            $trace = $line | ConvertFrom-Json -Depth 10
+            $trace.timestamp | Should -Not -BeNullOrEmpty
+            $trace.level | Should -BeIn 'ERROR', 'WARNING', 'INFO', 'DEBUG', 'TRACE'
+            $trace.fields.message | Should -Not -BeNullOrEmpty
+        }
+    }
+}