diff --git a/.github/workflows/CI.yml b/.github/workflows/CI.yml index 295e3c8773..36d1c885db 100644 --- a/.github/workflows/CI.yml +++ b/.github/workflows/CI.yml @@ -144,7 +144,7 @@ jobs: uses: taiki-e/install-action@cargo-hack - name: check --feature-powerset - run: cargo hack check --feature-powerset --depth 2 --skip ffi -Z avoid-dev-deps + run: cargo hack check --feature-powerset --depth 2 --skip ffi,tracing -Z avoid-dev-deps ffi: name: Test C API (FFI) diff --git a/Cargo.toml b/Cargo.toml index a753ad81ea..e5820e30de 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -33,7 +33,6 @@ http-body-util = { version = "=0.1.0-rc.3", optional = true } httparse = "1.8" h2_wasi = { version = "0.3.9", optional = true } itoa = "1" -tracing = { version = "0.1", default-features = false, features = ["std"] } pin-project-lite = "0.2.4" tokio_wasi = { version = "1", features = ["sync"] } @@ -42,6 +41,7 @@ tokio_wasi = { version = "1", features = ["sync"] } httpdate = { version = "1.0", optional = true } libc = { version = "0.2", optional = true } wasmedge_wasi_socket = {version = "0.4.2", optional = true } +tracing = { version = "0.1", default-features = false, features = ["std"], optional = true } want = { version = "0.3", optional = true } [dev-dependencies] @@ -88,12 +88,15 @@ server = ["dep:httpdate"] # C-API support (currently unstable (no semver)) ffi = ["dep:libc", "dep:http-body-util"] +# Utilize tracing (currently unstable) +tracing = ["dep:tracing"] + # internal features used in CI nightly = [] [package.metadata.docs.rs] -features = ["ffi", "full"] -rustdoc-args = ["--cfg", "docsrs", "--cfg", "hyper_unstable_ffi"] +features = ["ffi", "full", "tracing"] +rustdoc-args = ["--cfg", "docsrs", "--cfg", "hyper_unstable_ffi", "--cfg", "hyper_unstable_tracing"] [package.metadata.playground] features = ["full"] diff --git a/src/body/length.rs b/src/body/length.rs index e2bbee8039..2e46e4b309 100644 --- a/src/body/length.rs +++ b/src/body/length.rs @@ -50,8 +50,6 @@ impl DecodedLength { /// Checks the `u64` is within the maximum allowed for content-length. #[cfg(any(feature = "http1", feature = "http2"))] pub(crate) fn checked_new(len: u64) -> Result { - use tracing::warn; - if len <= MAX_LEN { Ok(DecodedLength(len)) } else { diff --git a/src/client/conn/http1.rs b/src/client/conn/http1.rs index 2034f0f2a6..4887f86663 100644 --- a/src/client/conn/http1.rs +++ b/src/client/conn/http1.rs @@ -191,8 +191,7 @@ where Err(_canceled) => panic!("dispatch dropped without returning error"), }, Err(_req) => { - tracing::debug!("connection was not ready"); - + debug!("connection was not ready"); Err(crate::Error::new_canceled().with("connection was not ready")) } } @@ -219,7 +218,7 @@ where })) } Err(req) => { - tracing::debug!("connection was not ready"); + debug!("connection was not ready"); let err = crate::Error::new_canceled().with("connection was not ready"); Either::Right(future::err((err, Some(req)))) } @@ -478,7 +477,7 @@ impl Builder { let opts = self.clone(); async move { - tracing::trace!("client handshake HTTP/1"); + trace!("client handshake HTTP/1"); let (tx, rx) = dispatch::channel(); let mut conn = proto::Conn::new(io); diff --git a/src/client/conn/http2.rs b/src/client/conn/http2.rs index e9686347b3..edb99cfeff 100644 --- a/src/client/conn/http2.rs +++ b/src/client/conn/http2.rs @@ -146,7 +146,7 @@ where Err(_canceled) => panic!("dispatch dropped without returning error"), }, Err(_req) => { - tracing::debug!("connection was not ready"); + debug!("connection was not ready"); Err(crate::Error::new_canceled().with("connection was not ready")) } @@ -174,7 +174,7 @@ where })) } Err(req) => { - tracing::debug!("connection was not ready"); + debug!("connection was not ready"); let err = crate::Error::new_canceled().with("connection was not ready"); Either::Right(future::err((err, Some(req)))) } @@ -407,7 +407,7 @@ where let opts = self.clone(); async move { - tracing::trace!("client handshake HTTP/1"); + trace!("client handshake HTTP/1"); let (tx, rx) = dispatch::channel(); let h2 = proto::h2::client::handshake(io, rx, &opts.h2_builder, opts.exec, opts.timer) diff --git a/src/client/dispatch.rs b/src/client/dispatch.rs index 40cb554917..ef9bce181c 100644 --- a/src/client/dispatch.rs +++ b/src/client/dispatch.rs @@ -5,7 +5,6 @@ use http::{Request, Response}; use http_body::Body; use pin_project_lite::pin_project; use tokio::sync::{mpsc, oneshot}; -use tracing::trace; use crate::{ body::Incoming, diff --git a/src/lib.rs b/src/lib.rs index 7de04debc3..0d1db8320a 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -51,7 +51,20 @@ //! - `server`: Enables the HTTP `server`. //! //! [feature flags]: https://doc.rust-lang.org/cargo/reference/manifest.html#the-features-section - +//! +//! # Unstable Features +//! hyper includes a set of unstable optional features that can be enabled through the use of a +//! feature flag and a [configuration flag]. +//! +//! The following is a list of feature flags and their corresponding `RUSTFLAG`: +//! - `ffi`: Enables C API for hyper `hyper_unstable_ffi`. +//! - `tracing`: Enables debug logging with `hyper_unstable_tracing`. +//! +//! Enabling an unstable feature is possible with the following `cargo` command, as of version `1.64.0`: +//! ```notrust +//! RUSTFLAGS="--cfg hyper_unstable_tracing" cargo rustc --features client,http1,http2,tracing --crate-type cdylib +//!``` +//! [configuration flag]: https://doc.rust-lang.org/reference/conditional-compilation.html #[doc(hidden)] pub use http; @@ -67,6 +80,10 @@ pub use crate::error::{Error, Result}; #[macro_use] mod cfg; + +#[macro_use] +mod trace; + #[macro_use] mod common; pub mod body; diff --git a/src/proto/h1/conn.rs b/src/proto/h1/conn.rs index 04f25ef085..ce7c41a366 100644 --- a/src/proto/h1/conn.rs +++ b/src/proto/h1/conn.rs @@ -9,7 +9,6 @@ use bytes::{Buf, Bytes}; use http::header::{HeaderValue, CONNECTION}; use http::{HeaderMap, Method, Version}; use httparse::ParserConfig; -use tracing::{debug, error, trace}; use super::io::Buffered; use super::{Decoder, Encode, EncodedBuf, Encoder, Http1Transaction, ParseContext, Wants}; @@ -439,7 +438,7 @@ where let result = ready!(self.io.poll_read_from_io(cx)); Poll::Ready(result.map_err(|e| { - trace!("force_io_read; io error = {:?}", e); + trace!(error = %e, "force_io_read; io error"); self.state.close(); e })) @@ -749,7 +748,9 @@ where // If still in Reading::Body, just give up match self.state.reading { - Reading::Init | Reading::KeepAlive => trace!("body drained"), + Reading::Init | Reading::KeepAlive => { + trace!("body drained") + } _ => self.close_read(), } } diff --git a/src/proto/h1/decode.rs b/src/proto/h1/decode.rs index 47d9bbd081..81ac3a95c3 100644 --- a/src/proto/h1/decode.rs +++ b/src/proto/h1/decode.rs @@ -4,7 +4,6 @@ use std::io; use std::usize; use bytes::Bytes; -use tracing::{debug, trace}; use crate::common::{task, Poll}; diff --git a/src/proto/h1/dispatch.rs b/src/proto/h1/dispatch.rs index eea31a1105..c1d068a487 100644 --- a/src/proto/h1/dispatch.rs +++ b/src/proto/h1/dispatch.rs @@ -3,7 +3,6 @@ use std::error::Error as StdError; use crate::rt::{Read, Write}; use bytes::{Buf, Bytes}; use http::Request; -use tracing::{debug, trace}; use super::{Http1Transaction, Wants}; use crate::body::{Body, DecodedLength, Incoming as IncomingBody}; diff --git a/src/proto/h1/encode.rs b/src/proto/h1/encode.rs index cb4a7841fe..c98c55d664 100644 --- a/src/proto/h1/encode.rs +++ b/src/proto/h1/encode.rs @@ -3,7 +3,6 @@ use std::io::IoSlice; use bytes::buf::{Chain, Take}; use bytes::Buf; -use tracing::trace; use super::io::WriteBuf; diff --git a/src/proto/h1/io.rs b/src/proto/h1/io.rs index b49cda3dd3..785f6c0221 100644 --- a/src/proto/h1/io.rs +++ b/src/proto/h1/io.rs @@ -8,7 +8,6 @@ use std::mem::MaybeUninit; use crate::rt::{Read, ReadBuf, Write}; use bytes::{Buf, BufMut, Bytes, BytesMut}; -use tracing::{debug, trace}; use super::{Http1Transaction, ParseContext, ParsedMessage}; use crate::common::buf::BufList; @@ -224,7 +223,7 @@ where if Pin::new(h1_header_read_timeout_fut).poll(cx).is_ready() { *parse_ctx.h1_header_read_timeout_running = false; - tracing::warn!("read header from client timeout"); + warn!("read header from client timeout"); return Poll::Ready(Err(crate::Error::new_header_timeout())); } } diff --git a/src/proto/h1/role.rs b/src/proto/h1/role.rs index daf41c719c..f964d2138f 100644 --- a/src/proto/h1/role.rs +++ b/src/proto/h1/role.rs @@ -9,7 +9,6 @@ use bytes::BytesMut; use http::header::ValueIter; use http::header::{self, Entry, HeaderName, HeaderValue}; use http::{HeaderMap, Method, StatusCode, Version}; -use tracing::{debug, error, trace, trace_span, warn}; use crate::body::DecodedLength; #[cfg(feature = "server")] @@ -72,8 +71,7 @@ where return Ok(None); } - let span = trace_span!("parse_headers"); - let _s = span.enter(); + let _entered = trace_span!("parse_headers"); #[cfg(feature = "server")] if !*ctx.h1_header_read_timeout_running { @@ -103,8 +101,7 @@ pub(super) fn encode_headers( where T: Http1Transaction, { - let span = trace_span!("encode_headers"); - let _s = span.enter(); + let _entered = trace_span!("encode_headers"); T::encode(enc, dst) } diff --git a/src/proto/h2/client.rs b/src/proto/h2/client.rs index 7226c98bf5..ebd8822a5d 100644 --- a/src/proto/h2/client.rs +++ b/src/proto/h2/client.rs @@ -12,7 +12,6 @@ use h2::client::{Builder, Connection, SendRequest}; use h2::SendStream; use http::{Method, StatusCode}; use pin_project_lite::pin_project; -use tracing::{debug, trace, warn}; use super::ping::{Ponger, Recorder}; use super::{ping, H2Upgraded, PipeToSendStream, SendBuf}; @@ -243,7 +242,9 @@ where if polled.is_ready() { *this.is_terminated = true; } - polled.map_err(|e| debug!("connection error: {}", e)) + polled.map_err(|_e| { + debug!(error = %_e, "connection error"); + }) } } @@ -441,8 +442,8 @@ where match this.pipe.poll_unpin(cx) { Poll::Ready(result) => { - if let Err(e) = result { - debug!("client request body error: {}", e); + if let Err(_e) = result { + debug!("client request body error: {}", _e); } drop(this.conn_drop_ref.take().expect("Future polled twice")); drop(this.ping.take().expect("Future polled twice")); diff --git a/src/proto/h2/mod.rs b/src/proto/h2/mod.rs index 2002edeb13..defc2512d6 100644 --- a/src/proto/h2/mod.rs +++ b/src/proto/h2/mod.rs @@ -8,7 +8,6 @@ use std::error::Error as StdError; use std::io::{Cursor, IoSlice}; use std::mem; use std::task::Context; -use tracing::{debug, trace, warn}; use crate::body::Body; use crate::common::{task, Future, Pin, Poll}; diff --git a/src/proto/h2/ping.rs b/src/proto/h2/ping.rs index 297e0c7876..61d24112f6 100644 --- a/src/proto/h2/ping.rs +++ b/src/proto/h2/ping.rs @@ -26,7 +26,6 @@ use std::task::{self, Poll}; use std::time::{Duration, Instant}; use h2::{Ping, PingPong}; -use tracing::{debug, trace}; use crate::common::time::Time; use crate::rt::Sleep; @@ -300,8 +299,8 @@ impl Ponger { } } } - Poll::Ready(Err(e)) => { - debug!("pong error: {}", e); + Poll::Ready(Err(_e)) => { + debug!("pong error: {}", _e); } Poll::Pending => { if let Some(ref mut ka) = self.keep_alive { @@ -332,8 +331,8 @@ impl Shared { self.ping_sent_at = Some(Instant::now()); trace!("sent ping"); } - Err(err) => { - debug!("error sending ping: {}", err); + Err(_err) => { + debug!("error sending ping: {}", _err); } } } diff --git a/src/proto/h2/server.rs b/src/proto/h2/server.rs index 0913f314c9..0d830ad017 100644 --- a/src/proto/h2/server.rs +++ b/src/proto/h2/server.rs @@ -9,7 +9,6 @@ use h2::server::{Connection, Handshake, SendResponse}; use h2::{Reason, RecvStream}; use http::{Method, Request}; use pin_project_lite::pin_project; -use tracing::{debug, trace, warn}; use super::{ping, PipeToSendStream, SendBuf}; use crate::body::{Body, Incoming as IncomingBody}; @@ -508,8 +507,8 @@ where fn poll(self: Pin<&mut Self>, cx: &mut task::Context<'_>) -> Poll { self.poll2(cx).map(|res| { - if let Err(e) = res { - debug!("stream error: {}", e); + if let Err(_e) = res { + debug!("stream error: {}", _e); } }) } diff --git a/src/trace.rs b/src/trace.rs new file mode 100644 index 0000000000..88f9a243a0 --- /dev/null +++ b/src/trace.rs @@ -0,0 +1,128 @@ +// For completeness, wrappers around all of tracing's public logging and span macros are provided, +// even if they are not used at the present time. +#![allow(unused_macros)] + +#[cfg(all(not(hyper_unstable_tracing), feature = "tracing"))] +compile_error!( + "\ + The `tracing` feature is unstable, and requires the \ + `RUSTFLAGS='--cfg hyper_unstable_tracing'` environment variable to be set.\ +" +); + +macro_rules! debug { + ($($arg:tt)+) => { + #[cfg(feature = "tracing")] + { + tracing::debug!($($arg)+); + } + } +} + +macro_rules! debug_span { + ($($arg:tt)*) => { + { + #[cfg(feature = "tracing")] + { + let _span = tracing::debug_span!($($arg)+); + _span.entered() + } + } + } +} + +macro_rules! error { + ($($arg:tt)*) => { + #[cfg(feature = "tracing")] + { + tracing::error!($($arg)+); + } + } +} + +macro_rules! error_span { + ($($arg:tt)*) => { + { + #[cfg(feature = "tracing")] + { + let _span = tracing::error_span!($($arg)+); + _span.entered() + } + } + } +} + +macro_rules! info { + ($($arg:tt)*) => { + #[cfg(feature = "tracing")] + { + tracing::info!($($arg)+); + } + } +} + +macro_rules! info_span { + ($($arg:tt)*) => { + { + #[cfg(feature = "tracing")] + { + let _span = tracing::info_span!($($arg)+); + _span.entered() + } + } + } +} + +macro_rules! trace { + ($($arg:tt)*) => { + #[cfg(feature = "tracing")] + { + tracing::trace!($($arg)+); + } + } +} + +macro_rules! trace_span { + ($($arg:tt)*) => { + { + #[cfg(feature = "tracing")] + { + let _span = tracing::trace_span!($($arg)+); + _span.entered() + } + } + } +} + +macro_rules! span { + ($($arg:tt)*) => { + { + #[cfg(feature = "tracing")] + { + let _span = tracing::span!($($arg)+); + _span.entered() + } + } + } +} + +macro_rules! warn { + ($($arg:tt)*) => { + #[cfg(feature = "tracing")] + { + tracing::warn!($($arg)+); + } + } +} + +macro_rules! warn_span { + ($($arg:tt)*) => { + { + #[cfg(feature = "tracing")] + { + let _span = tracing::warn_span!($($arg)+); + _span.entered() + } + } + } +} diff --git a/src/upgrade.rs b/src/upgrade.rs index 231578f913..03a56af6c5 100644 --- a/src/upgrade.rs +++ b/src/upgrade.rs @@ -48,8 +48,6 @@ use std::marker::Unpin; use crate::rt::{Read, ReadBufCursor, Write}; use bytes::Bytes; use tokio::sync::oneshot; -#[cfg(any(feature = "http1", feature = "http2"))] -use tracing::trace; use crate::common::io::Rewind; use crate::common::{task, Future, Pin, Poll}; @@ -241,6 +239,7 @@ impl Pending { /// Don't fulfill the pending Upgrade, but instead signal that /// upgrades are handled manually. pub(super) fn manual(self) { + #[cfg(any(feature = "http1", feature = "http2"))] trace!("pending upgrade handled manually"); let _ = self.tx.send(Err(crate::Error::new_user_manual_upgrade())); }