feat(client): optional tracing spans (feature tracing, off by default)

Cargo.toml

@@ -29,6 +29,7 @@ rustls-platform-verifier = { version = "0.7", optional = true }
 url = { version = "2", optional = true }
 serde = { version = "1", optional = true }
 serde_json = { version = "1", optional = true }
+tracing = { version = "0.1", default-features = false, features = ["std"], optional = true }
 
 [dev-dependencies]
 atoi = "2"
@@ -51,6 +52,8 @@ testcontainers = "0.15"
 tokio = { version = "1", features = ["full"] }
 rcgen = "0.14"
 flate2 = "1.1"
+tracing = "0.1"
+tracing-subscriber = { version = "0.3", default-features = false, features = ["registry", "std"] }
 
 [target.'cfg(unix)'.dev-dependencies]
 may_postgres = { git = "https://github.com/Xudong-Huang/may_postgres.git", default-features = false }
@@ -61,6 +64,8 @@ default = ["may/default"]
 client = ["http", "may/io_timeout", "dep:generator", "dep:rustls", "dep:rustls-platform-verifier", "dep:url"]
 # Typed JSON request/response helpers. Kept optional so the core HTTP transport stays lean.
 json = ["client", "dep:serde", "dep:serde_json"]
+# `tracing` spans and events in the client (see `client::trace`). Off: nothing is compiled in.
+tracing = ["client", "dep:tracing"]
 
 # Examples that use the client module — automatically enable the `client` feature.
 [[example]]
@@ -153,6 +158,10 @@ required-features = ["client"]
 name = "tcp_nodelay_stall"
 required-features = ["client"]
 
+[[test]]
+name = "client_tracing"
+required-features = ["tracing"]
+
 [profile.release]
 opt-level = 3
 codegen-units = 1

README.md

@@ -128,6 +128,25 @@ let client = Client::builder().build_with_interceptor(AttemptId)?;
 # Ok::<(), Box<dyn std::error::Error>>(())
 ```
 
+#### Tracing (feature `tracing`)
+
+With the `tracing` feature, each request through `Client` is a span tree under target
+`may_minihttp::client`:
+
+- `http_client_request` (INFO) has method, server address and port, status, `error.type`, resend
+  count and connection reuse.
+- `http_client_connect` (INFO) covers a new connection.
+- `http_client_write`, `http_client_wait` (time to first byte) and `http_client_body` are at
+  DEBUG level.
+- `pool_checkout` and `pool_evict` are DEBUG events.
+
+Paths, query strings and headers are not recorded.
+
+Spans are never entered, because a coroutine can resume on another thread. Give the parent
+explicitly with `RequestBuilder::parent_span`, or hand the client your own per-request span with
+`RequestBuilder::request_span`. Without the feature, nothing is compiled in, and `tracing` is not a
+dependency.
+
 Multipart filesystem helpers are deliberately named `blocking_*` and must be called outside
 latency-sensitive may coroutines. Automatic stale-socket retry is limited to one attempt for
 idempotent requests with replayable bodies.

examples/bench_client.rs

@@ -18,6 +18,10 @@
 //! `header-bytes` adds an `X-Pad` header of that size (a bearer token with claims is 1-6 KiB);
 //! `body-bytes > 0` makes the request a POST with a body of that size (`/echo` on bench_server).
 //! Workers are may coroutines. Pair with `examples/bench_server.rs`.
+//!
+//! Built with `--features tracing`, `BENCH_TRACING=info` (or `debug`) installs a
+//! `tracing-subscriber` registry at that level, so the client's spans are created and closed;
+//! unset, the feature is compiled in with no subscriber.
 
 use std::alloc::{GlobalAlloc, Layout, System};
 use std::io::{self, Read};
@@ -143,6 +147,20 @@ fn main() -> io::Result<()> {
     let body_bytes: usize = arg(args.next(), 0);
 
     may::config().set_stack_size(0x8000);
+    #[cfg(feature = "tracing")]
+    {
+        use tracing_subscriber::filter::LevelFilter;
+        use tracing_subscriber::layer::SubscriberExt;
+        let level = match std::env::var("BENCH_TRACING").as_deref() {
+            Ok("info") => Some(LevelFilter::INFO),
+            Ok("debug") => Some(LevelFilter::DEBUG),
+            _ => None,
+        };
+        if let Some(level) = level {
+            tracing::subscriber::set_global_default(tracing_subscriber::registry().with(level))
+                .expect("install the tracing subscriber");
+        }
+    }
     let parsed: Uri = url.parse().map_err(io::Error::other)?;
     let path: Uri = parsed
         .path_and_query()

src/client/client_impl.rs

@@ -356,14 +356,25 @@ impl HttpClient {
 
     /// Send a request built from this client and read the response.
     #[inline]
-    pub fn send_request(&mut self, mut req: Request) -> io::Result<Response> {
+    pub fn send_request(&mut self, req: Request) -> io::Result<Response> {
+        self.write_request(req)?;
+        self.get_rsp()
+    }
+
+    /// The first half of [`send_request`](Self::send_request): finish writing the request.
+    pub(crate) fn write_request(&mut self, mut req: Request) -> io::Result<()> {
         debug_assert!(
             self.conn.ptr_eq(req.conn()),
             "client and request must share the same connection"
         );
         self.expect_body = req.expect_body_request();
         req.finish()?;
         drop(req);
+        Ok(())
+    }
+
+    /// The second half of [`send_request`](Self::send_request): read the response head.
+    pub(crate) fn read_response(&mut self) -> io::Result<Response> {
         self.get_rsp()
     }
 

src/client/mod.rs

@@ -17,6 +17,7 @@ mod response;
 mod rich;
 mod shared;
 mod tls;
+mod trace;
 
 pub use cancellation::CancellationToken;
 pub use client_impl::HttpClient;