Add detailed request logging

Currently we don't offer a way to expose the details of the API requests the CLI or other SDK consumers to users, making troubleshooting difficult. With the new `middleware` feature available in Progenitor, we can now inject our own logger using the `reqwest-tracing` crate. This gives us output like: ./target/debug/oxide --debug disk list --project will | jq . { "timestamp": "2025-02-26T17:29:23.354297Z", "level": "DEBUG", "fields": { "message": "close", "time.busy": "16.7ms", "time.idle": "365ms" }, "target": "oxide::tracing", "span": { "host": "oxide.sys.r3.oxide-preview.com", "http.request.method": "GET", "http.response.content_length": 998, "http.response.status_code": 200, "oxide.request_id": "c5e7d65e-bcb2-4ade-a817-6f13b681b19b", "url": "https://oxide.sys.r3.oxide-preview.com/v1/disks?project=will", "name": "Oxide API Request" }, "spans": [] } We will also log the first KiB of the request body, if present. This should be enough to capture the details human-readable requests, e.g. an OxQL query, but avoid too much noise from something like a disk import. The `--debug` flag will enable debug logs for both the CLI and any dependencies, such as `hyper`. To view only CLI logs, set `RUST_LOG=oxide=debug`. Closes #1014.
oxidecomputer · Feb 26, 2025 · c6a1fd2 · c6a1fd2
1 parent 077ec52
commit c6a1fd2
Show file tree

Hide file tree

Showing 12 changed files with 392 additions and 88 deletions.
diff --git a/Cargo.lock b/Cargo.lock
diff --git a/Cargo.toml b/Cargo.toml
@@ -23,15 +23,15 @@ 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"
+http = "1.2.0"
 httpmock = "0.7.0"
 humantime = "2"
+hyper = "1.5.2"
 indicatif = "0.17"
 libc = "0.2.169"
-log = "0.4.25"
 md5 = "0.7.0"
 newline-converter = "0.3.0"
 oauth2 = "5.0.0"
@@ -41,14 +41,16 @@ oxide-httpmock = { path = "sdk-httpmock", version = "0.10.0" }
 oxnet = "0.1.0"
 predicates = "3.1.3"
 pretty_assertions = "1.4.1"
-progenitor = { git = "https://github.com/oxidecomputer/progenitor", default-features = false }
-progenitor-client = "0.9.1"
+progenitor = { git = "https://github.com/oxidecomputer/progenitor", default-features = false, features = ["middleware"] }
+progenitor-client = { version = "0.9.1", features = ["middleware"] }
 rand = "0.8.5"
 ratatui = "0.26.3"
 rcgen = "0.10.0"
 regex = "1.11.1"
 regress = "0.10.3"
 reqwest = "0.12.12"
+reqwest-middleware = { version = "0.4.1", features = ["json"] }
+reqwest-tracing = { version = "0.5.6" }
 rustfmt-wrapper = "0.2.1"
 schemars = { version = "0.8.20", features = ["chrono", "uuid1"] }
 serde = { version = "1.0.217", features = ["derive"] }
@@ -62,6 +64,8 @@ thouart = { git = "https://github.com/oxidecomputer/thouart" }
 tokio = { version = "1.43.0", features = ["full"] }
 toml = "0.8.20"
 toml_edit = "0.22.24"
+tracing = "0.1.41"
+tracing-subscriber = { version = "0.3", features = ["env-filter","json"] }
 url = "2.5.4"
 uuid = { version = "1.13.1", features = ["serde", "v4"] }
 

diff --git a/cli/Cargo.toml b/cli/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 }
 

diff --git a/cli/src/cli_builder.rs b/cli/src/cli_builder.rs
@@ -2,14 +2,17 @@
 // 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 std::{
+    any::TypeId, collections::BTreeMap, io, 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::fmt::format::FmtSpan;
+use tracing_subscriber::EnvFilter;
 
 use crate::{
     context::Context,
@@ -229,11 +232,18 @@ 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_span_events(FmtSpan::CLOSE)
+            .with_writer(io::stderr)
+            .json()
+            .init();
 
         let mut client_config = ClientConfig::default();
 

diff --git a/cli/src/cmd_auth.rs b/cli/src/cmd_auth.rs
@@ -2,7 +2,7 @@
 // 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::error::Error;
 use std::fs::{File, OpenOptions};
@@ -465,11 +465,11 @@ impl CmdAuthStatus {
 
             match result {
                 Ok(user) => {
-                    log::debug!("success response for {} (env): {:?}", host_env, user);
+                    tracing::debug!("success response for {} (env): {:?}", host_env, user);
                     println_nopipe!("Logged in to {} as {}", host_env, user.id)
                 }
                 Err(e) => {
-                    log::debug!("error response for {} (env): {:#}", host_env, e);
+                    tracing::debug!("error response for {} (env): {:#}", host_env, e);
                     println_nopipe!("{}: {}", host_env, Self::error_msg(&e))
                 }
             };
@@ -490,11 +490,11 @@ impl CmdAuthStatus {
 
                 let status = match result {
                     Ok(v) => {
-                        log::debug!("success response for {}: {:?}", profile_info.host, v);
+                        tracing::debug!("success response for {}: {:?}", profile_info.host, v);
                         "Authenticated".to_string()
                     }
                     Err(e) => {
-                        log::debug!("error response for {}: {:#}", profile_info.host, e);
+                        tracing::debug!("error response for {}: {:#}", profile_info.host, e);
                         Self::error_msg(&e)
                     }
                 };
@@ -566,6 +566,9 @@ impl CmdAuthStatus {
                 // didn't supply all required values.
                 format!("Internal error: {}", msg)
             }
+            oxide::Error::MiddlewareError(e) => {
+                format!("Middleware error: {}", e)
+            }
             oxide::Error::InvalidUpgrade(_) => {
                 unreachable!("auth should not be establishing a websocket")
             }

diff --git a/cli/tests/test_auth.rs b/cli/tests/test_auth.rs
@@ -2,7 +2,7 @@
 // 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::{
     fs::{read_to_string, write, File},
@@ -586,3 +586,35 @@ fn test_cmd_auth_debug_logging() {
         .failure()
         .stderr(str::contains("DEBUG"));
 }
+
+#[test]
+fn test_cmd_auth_debug_trace_span() {
+    let server = MockServer::start();
+
+    let oxide_mock = server.current_user_view(|when, then| {
+        when.into_inner()
+            .header("authorization", "Bearer oxide-token-good");
+
+        then.ok(&oxide::types::CurrentUser {
+            display_name: "privileged".to_string(),
+            id: "001de000-05e4-4000-8000-000000004007".parse().unwrap(),
+            silo_id: "d1bb398f-872c-438c-a4c6-2211e2042526".parse().unwrap(),
+            silo_name: "funky-town".parse().unwrap(),
+        });
+    });
+
+    let debug_output = r#".*"target":"oxide::tracing","span":\{"host":"127.0.0.1","http.request.method":"GET","http.response.content_length":\d+,"http.response.status_code":200,"url":"http://127.0.0.1:\d+/v1/me","name":"Oxide API Request"\}.*"#;
+
+    Command::cargo_bin("oxide")
+        .unwrap()
+        .arg("auth")
+        .arg("status")
+        .env("RUST_LOG", "oxide=debug")
+        .env("OXIDE_HOST", server.url(""))
+        .env("OXIDE_TOKEN", "oxide-token-good")
+        .assert()
+        .success()
+        .stderr(str::is_match(debug_output).unwrap());
+
+    oxide_mock.assert();
+}
diff --git a/cli/tests/test_net.rs b/cli/tests/test_net.rs
@@ -2,7 +2,7 @@
 // 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 assert_cmd::Command;
 use chrono::prelude::*;
@@ -295,7 +295,7 @@ fn test_port_config() {
             then.ok(&switch1_qsfp0_view);
         });
 
-    env_logger::init();
+    tracing_subscriber::fmt().init();
 
     Command::cargo_bin("oxide")
         .unwrap()

diff --git a/sdk/Cargo.toml b/sdk/Cargo.toml
@@ -14,17 +14,22 @@ clap = { workspace = true, optional = true }
 dirs = { workspace = true }
 flume = { workspace = true }
 futures = { workspace = true }
+http = { workspace = true }
+hyper = { workspace = true }
 progenitor-client = { workspace = true }
 rand = { workspace = true }
 regress = { workspace = true }
 reqwest = { workspace = true, features = ["native-tls-vendored"] }
+reqwest-middleware = { workspace = true }
+reqwest-tracing = { workspace = true }
 serde = { workspace = true }
 serde_json = { workspace = true }
 schemars = { workspace = true }
 thiserror =  { workspace = true }
 tokio = { workspace = true }
 toml = { workspace = true }
 toml_edit = { workspace = true }
+tracing = { workspace = true }
 uuid = { workspace = true }
 
 [dev-dependencies]

diff --git a/sdk/src/auth.rs b/sdk/src/auth.rs
@@ -2,14 +2,15 @@
 // 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::{
     collections::BTreeMap,
     net::{IpAddr, SocketAddr},
     path::{Path, PathBuf},
 };
 
+use crate::tracing::RequestSpan;
 use crate::{Client, OxideAuthError};
 use reqwest::ClientBuilder;
 use serde::Deserialize;
@@ -173,12 +174,17 @@ impl Client {
                 .collect(),
         );
 
-        Ok(Self::new_with_client(
-            &host,
-            client_builder
+        let client = client_builder
+            .build()
+            .expect("failed to construct underlying client object");
+
+        let client = {
+            reqwest_middleware::ClientBuilder::new(client)
+                .with(reqwest_tracing::TracingMiddleware::<RequestSpan>::new())
                 .build()
-                .expect("failure to construct underlying client object"),
-        ))
+        };
+
+        Ok(Self::new_with_client(&host, client))
     }
 }
 

diff --git a/sdk/src/generated_sdk.rs b/sdk/src/generated_sdk.rs
@@ -51712,14 +51712,14 @@ pub mod types {
 /// Version: 20250212.0.0
 pub struct Client {
     pub(crate) baseurl: String,
-    pub(crate) client: reqwest::Client,
+    pub(crate) client: reqwest_middleware::ClientWithMiddleware,
 }
 
 impl Client {
     /// Create a new client.
     ///
     /// `baseurl` is the base URL provided to the internal
-    /// `reqwest::Client`, and should include a scheme and hostname,
+    /// HTTP client, and should include a scheme and hostname,
     /// as well as port and a path stem if applicable.
     pub fn new(baseurl: &str) -> Self {
         #[cfg(not(target_arch = "wasm32"))]
@@ -51731,16 +51731,21 @@ impl Client {
         };
         #[cfg(target_arch = "wasm32")]
         let client = reqwest::ClientBuilder::new();
-        Self::new_with_client(baseurl, client.build().unwrap())
+        let built_client = client.build().unwrap();
+        let built_client = reqwest_middleware::ClientBuilder::new(built_client).build();
+        Self::new_with_client(baseurl, built_client)
     }
 
-    /// Construct a new client with an existing `reqwest::Client`,
+    /// Construct a new client with an existing HTTP client
     /// allowing more control over its configuration.
     ///
     /// `baseurl` is the base URL provided to the internal
-    /// `reqwest::Client`, and should include a scheme and hostname,
+    /// HTTP client, and should include a scheme and hostname,
     /// as well as port and a path stem if applicable.
-    pub fn new_with_client(baseurl: &str, client: reqwest::Client) -> Self {
+    pub fn new_with_client(
+        baseurl: &str,
+        client: reqwest_middleware::ClientWithMiddleware,
+    ) -> Self {
         Self {
             baseurl: baseurl.to_string(),
             client,
@@ -51752,8 +51757,8 @@ impl Client {
         &self.baseurl
     }
 
-    /// Get the internal `reqwest::Client` used to make requests.
-    pub fn client(&self) -> &reqwest::Client {
+    /// Get the internal HTTP client used to make requests.
+    pub fn client(&self) -> &reqwest_middleware::ClientWithMiddleware {
         &self.client
     }
 

diff --git a/sdk/src/lib.rs b/sdk/src/lib.rs
@@ -2,7 +2,7 @@
 // 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
 
 #![forbid(unsafe_code)]
 #![doc = include_str!("../README.md")]
@@ -16,6 +16,7 @@ mod auth;
 mod clap_feature;
 pub mod extras;
 mod generated_sdk;
+mod tracing;
 
 pub use auth::*;
 pub use generated_sdk::*;