Add debug logging for all Oxide API requests

Currently only the `auth` CLI subcommand will log any request details
when debug logging is enabled. Adding debug logging for all requests
will enable users to troubleshoot issues on any API endpoint.

To do this, we add add pre and post-request hooks via Progenitor.
However, this does not lend itself to tracking the duration of the
request, or creating a single log event with the details from the the
`Request` and `Response`.

We add a `LogCtx` inner type to the client to act as a store while
requests are in flight, but need something to associate the start and
end. We could inject a header into the request, but on failure this will
not be available to us.

Instead, we use the tokio `task::Id` as an identifier, which is unique
within a given runtime. This raises the possibility of a client shared
between runtimes associating the wrong start with a finished request.
We do not have a way to detect which runtime a task is associated with,
`runtime::Id` is an unstable feature, but we will log a warning if we
find a response without a corresponding request, along with the response
details. Should a request be run outside of a task, we fall back to
logging separate events for start and end.

We also create a `Span` that includes the log event. This is ignored by
the CLI, but may be useful for other consumers of the SDK that want to
integrate it with their monitoring infrastructure.

An example event:

  {
    "timestamp": "2025-03-12T15:25:58.487790Z",
    "level": "DEBUG",
    "message": "request succeeded",
    "url": "https://oxide.sys.r3.oxide-preview.com/v1/disks?project=will",
    "path": "/v1/disks",
    "remote_addr": "45.154.216.35:443",
    "http.request.method": "GET",
    "http.response.content_length": 998,
    "http.response.status_code": 200,
    "start_time": "2025-03-12T15:25:58.048984Z",
    "duration_ms": 438,
    "oxide.request_id": "5d738e7a-ad78-4938-b682-c43f7b2a84be",
    "target": "oxide::tracing"
  }

Closes #1014

Author: wfchandler

Cargo.lock

@@ -23,15 +23,13 @@ crossterm = { version = "0.27.0", features = [ "event-stream" ] }
 dialoguer = "0.10.4"
 dirs = "4.0.0"
 dropshot = "0.13.0"
-env_logger = "0.10.2"
 expectorate = { version = "1.1.0", features = ["predicates"] }
 flume = "0.11.1"
 futures = "0.3.31"
 httpmock = "0.7.0"
 humantime = "2"
 indicatif = "0.17"
 libc = "0.2.170"
-log = "0.4.26"
 md5 = "0.7.0"
 newline-converter = "0.3.0"
 oauth2 = "5.0.0"
@@ -43,6 +41,7 @@ predicates = "3.1.3"
 pretty_assertions = "1.4.1"
 progenitor = { git = "https://github.com/oxidecomputer/progenitor", default-features = false }
 progenitor-client = "0.9.1"
+quote = "1.0.39"
 rand = "0.8.5"
 ratatui = "0.26.3"
 rcgen = "0.10.0"
@@ -62,6 +61,8 @@ thouart = { git = "https://github.com/oxidecomputer/thouart" }
 tokio = { version = "1.44.0", features = ["full"] }
 toml = "0.8.20"
 toml_edit = "0.22.24"
+tracing = "0.1.41"
+tracing-subscriber = { version = "0.3.19", features = ["env-filter","json"] }
 url = "2.5.4"
 uuid = { version = "1.15.1", features = ["serde", "v4"] }
 

Cargo.toml

@@ -28,11 +28,9 @@ colored = { workspace = true }
 crossterm = { workspace = true }
 dialoguer = { workspace = true }
 dirs = { workspace = true }
-env_logger = { workspace = true }
 futures = { workspace = true }
 humantime = { workspace = true }
 indicatif = { workspace = true }
-log = { workspace = true }
 md5 = { workspace = true }
 oauth2 = { workspace = true }
 open = { workspace = true }
@@ -49,6 +47,8 @@ thouart = { workspace = true }
 toml = { workspace = true }
 toml_edit = { workspace = true }
 tokio = { workspace = true }
+tracing = { workspace = true }
+tracing-subscriber = { workspace = true }
 url = { workspace = true }
 uuid = { workspace = true }
 

cli/Cargo.toml

@@ -2,14 +2,14 @@
 // License, v. 2.0. If a copy of the MPL was not distributed with this
 // file, You can obtain one at https://mozilla.org/MPL/2.0/.
 
-// Copyright 2024 Oxide Computer Company
+// Copyright 2025 Oxide Computer Company
 
 use std::{any::TypeId, collections::BTreeMap, marker::PhantomData, net::IpAddr, path::PathBuf};
 
 use anyhow::{bail, Result};
 use async_trait::async_trait;
 use clap::{Arg, ArgMatches, Command, CommandFactory, FromArgMatches};
-use log::LevelFilter;
+use tracing_subscriber::EnvFilter;
 
 use crate::{
     context::Context,
@@ -229,11 +229,20 @@ impl<'a> NewCli<'a> {
             timeout,
         } = OxideCli::from_arg_matches(&matches).expect("failed to parse OxideCli from args");
 
-        let mut log_builder = env_logger::builder();
-        if debug {
-            log_builder.filter_level(LevelFilter::Debug);
-        }
-        log_builder.init();
+        let env_filter = if debug {
+            EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("debug"))
+        } else {
+            EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("info"))
+        };
+
+        tracing_subscriber::fmt()
+            .with_env_filter(env_filter)
+            .with_writer(std::io::stderr)
+            .json()
+            .flatten_event(true)
+            .with_current_span(false)
+            .with_span_list(false)
+            .init();
 
         let mut client_config = ClientConfig::default();