feat: allow user to specify the time stamp format for printed/logged …

…messages

* Supported time formats: local, utc, rfc3339
* On the CLI: --time-format rfc3339
* In the configuration: time_format="rfc3339"

src/cli/cli_main.rs

@@ -50,12 +50,6 @@ pub async fn cli() -> anyhow::Result<ExitCode> {
     let progress = (!args.server).then(|| {
         MultiProgress::with_draw_target(ProgressDrawTarget::stderr_with_hz(MAX_UPDATE_FPS))
     });
-    setup_tracing(
-        trace_level(&args.client_params),
-        progress.as_ref(),
-        &args.client_params.log_file,
-    )
-    .inspect_err(|e| eprintln!("{e:?}"))?;
 
     if args.config_files {
         // do this before attempting to read config, in case it fails
@@ -81,6 +75,14 @@ pub async fn cli() -> anyhow::Result<ExitCode> {
         }
     };
 
+    setup_tracing(
+        trace_level(&args.client_params),
+        progress.as_ref(),
+        &args.client_params.log_file,
+        config.time_format,
+    )
+    .inspect_err(|e| eprintln!("{e:?}"))?;
+
     if args.show_config {
         println!(
             "{}",

src/client/options.rs

@@ -19,26 +19,33 @@ pub struct Parameters {
     ///
     /// By default the log receives everything printed to stderr.
     /// To override this behaviour, set the environment variable `RUST_LOG_FILE_DETAIL` (same semantics as `RUST_LOG`).
-    #[arg(short('l'), long, action, help_heading("Debug"), value_name("FILE"))]
+    #[arg(short('l'), long, action, value_name("FILE"), help_heading("Output"))]
     pub log_file: Option<String>,
 
     /// Quiet mode
     ///
     /// Switches off progress display and statistics; reports only errors
-    #[arg(short, long, action, conflicts_with("debug"))]
+    #[arg(short, long, action, conflicts_with("debug"), help_heading("Output"))]
     pub quiet: bool,
 
-    /// Outputs additional transfer statistics
-    #[arg(short = 's', long, alias("stats"), action, conflicts_with("quiet"))]
+    /// Show additional transfer statistics
+    #[arg(
+        short = 's',
+        long,
+        alias("stats"),
+        action,
+        conflicts_with("quiet"),
+        help_heading("Output")
+    )]
     pub statistics: bool,
 
     /// Enables detailed debug output from the remote endpoint
     /// (this may interfere with transfer speeds)
     #[arg(long, action, help_heading("Debug"))]
     pub remote_debug: bool,
 
-    /// Prints timing profile data after completion
-    #[arg(long, action, help_heading("Debug"))]
+    /// Output timing profile data after completion
+    #[arg(long, action, help_heading("Output"))]
     pub profile: bool,
 
     // JOB SPECIFICAION ====================================================================

src/config/structure.rs

@@ -10,8 +10,12 @@ use struct_field_names_as_array::FieldNamesAsSlice;
 
 use crate::{
     transport::CongestionControllerType,
-    util::{derive_deftly_template_Optionalify, humanu64::HumanU64, AddressFamily, PortRange},
+    util::{
+        derive_deftly_template_Optionalify, humanu64::HumanU64, AddressFamily, PortRange,
+        TimeFormat,
+    },
 };
+
 use derive_deftly::Deftly;
 
 /// The set of configurable options supported by qcp.
@@ -126,6 +130,10 @@ pub struct Configuration {
     /// If unspecified, uses any available UDP port.
     #[arg(short = 'P', long, value_name("M-N"), help_heading("Connection"))]
     pub remote_port: Option<PortRange>,
+
+    /// Specifies the time format to use when printing messages to the console or to file
+    #[arg(short = 'T', long, value_name("FORMAT"), help_heading("Output"))]
+    pub time_format: TimeFormat,
 }
 
 impl Configuration {
@@ -233,6 +241,7 @@ impl Default for Configuration {
             ssh: "ssh".into(),
             ssh_opt: vec![],
             remote_port: None,
+            time_format: TimeFormat::Local,
         }
     }
 }

src/util/mod.rs

@@ -19,7 +19,7 @@ pub mod stats;
 pub mod time;
 
 mod tracing;
-pub use tracing::setup as setup_tracing;
+pub use tracing::{setup as setup_tracing, TimeFormat};
 
 mod port_range;
 pub use port_range::PortRange;

src/util/tracing.rs

@@ -10,15 +10,52 @@ use std::{
 use anstream::eprintln;
 use anyhow::Context;
 use indicatif::MultiProgress;
+use serde::{Deserialize, Serialize};
 use tracing_subscriber::{
-    fmt::{time::ChronoLocal, MakeWriter},
+    fmt::{
+        time::{ChronoLocal, ChronoUtc},
+        MakeWriter,
+    },
     prelude::*,
     EnvFilter,
 };
 
+const FRIENDLY_FORMAT_LOCAL: &str = "%Y-%m-%d %H:%M:%SL";
+const FRIENDLY_FORMAT_UTC: &str = "%Y-%m-%d %H:%M:%SZ";
+
+/// Environment variable that controls what gets logged to stderr
 const STANDARD_ENV_VAR: &str = "RUST_LOG";
+/// Environment variable that controls what gets logged to file
 const LOG_FILE_DETAIL_ENV_VAR: &str = "RUST_LOG_FILE_DETAIL";
 
+/// Selects the format of time stamps in output messages
+#[derive(
+    Copy,
+    Clone,
+    Debug,
+    Default,
+    Eq,
+    PartialEq,
+    strum_macros::Display,
+    clap::ValueEnum,
+    Serialize,
+    Deserialize,
+)]
+#[serde(rename_all = "kebab-case")]
+pub enum TimeFormat {
+    /// Local time (as best as we can figure it out), as "year-month-day HH:MM:SS"
+    #[default]
+    Local,
+    /// UTC time, as "year-month-day HH:MM:SS"
+    Utc,
+    /// UTC time, in the format described in [RFC 3339](https://datatracker.ietf.org/doc/html/rfc3339).
+    ///
+    /// Examples:
+    /// `1997-11-12T09:55:06-06:00`
+    /// `2010-03-14T18:32:03Z`
+    Rfc3339,
+}
+
 /// Result type for `filter_for()`
 struct FilterResult {
     filter: EnvFilter,
@@ -46,9 +83,10 @@ fn filter_for(trace_level: &str, key: &str) -> anyhow::Result<FilterResult> {
         })
 }
 
-fn layer_factory<S, W, F>(
+fn make_tracing_layer<S, W, F>(
     writer: W,
     filter: F,
+    time_format: TimeFormat,
     show_target: bool,
     ansi: bool,
 ) -> Box<dyn tracing_subscriber::Layer<S> + Send + Sync>
@@ -57,14 +95,32 @@ where
     W: for<'writer> MakeWriter<'writer> + 'static + Sync + Send,
     F: tracing_subscriber::layer::Filter<S> + 'static + Sync + Send,
 {
-    tracing_subscriber::fmt::layer::<S>()
-        .with_timer(ChronoLocal::rfc_3339())
+    // The common bit
+    let layer = tracing_subscriber::fmt::layer::<S>()
         .compact()
         .with_target(show_target)
-        .with_ansi(ansi)
-        .with_writer(writer)
-        .with_filter(filter)
-        .boxed()
+        .with_ansi(ansi);
+
+    // Unfortunately, you have to add the timer before you can add the writer and filter, so
+    // there's a bit of duplication here:
+    match time_format {
+        TimeFormat::Local => layer
+            .with_timer(ChronoLocal::new(FRIENDLY_FORMAT_LOCAL.into()))
+            .with_writer(writer)
+            .with_filter(filter)
+            .boxed(),
+        TimeFormat::Utc => layer
+            .with_timer(ChronoUtc::new(FRIENDLY_FORMAT_UTC.into()))
+            .with_writer(writer)
+            .with_filter(filter)
+            .boxed(),
+
+        TimeFormat::Rfc3339 => layer
+            .with_timer(ChronoLocal::rfc_3339())
+            .with_writer(writer)
+            .with_filter(filter)
+            .boxed(),
+    }
 }
 
 /// Set up rust tracing, to console (via an optional `MultiProgress`) and optionally to file.
@@ -79,6 +135,7 @@ pub fn setup(
     trace_level: &str,
     display: Option<&MultiProgress>,
     filename: &Option<String>,
+    time_format: TimeFormat,
 ) -> anyhow::Result<()> {
     let mut layers = Vec::new();
 
@@ -89,17 +146,19 @@ pub fn setup(
 
     match display {
         None => {
-            layers.push(layer_factory(
+            layers.push(make_tracing_layer(
                 std::io::stderr,
                 filter.filter,
+                time_format,
                 filter.used_env,
                 true,
             ));
         }
         Some(mp) => {
-            layers.push(layer_factory(
+            layers.push(make_tracing_layer(
                 ProgressWriter::wrap(mp),
                 filter.filter,
+                time_format,
                 filter.used_env,
                 true,
             ));
@@ -119,9 +178,10 @@ pub fn setup(
             filter_for(trace_level, STANDARD_ENV_VAR)?
         };
         // Same logic for whether we used the environment variable.
-        layers.push(layer_factory(
+        layers.push(make_tracing_layer(
             out_file,
             filter.filter,
+            time_format,
             filter.used_env,
             false,
         ));