From 3b141de434795801babf0a90668d9bd2b38bd2eb Mon Sep 17 00:00:00 2001
From: Eliza Weisman <eliza@buoyant.io>
Date: Thu, 16 Jul 2020 10:10:46 -0700
Subject: [PATCH 01/26] migrate internal diagnostics to `tracing`

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
---
 Cargo.toml            |  1 +
 src/filter/service.rs |  2 +-
 src/filters/body.rs   | 24 ++++++++++++------------
 src/filters/cors.rs   |  6 ++++--
 src/filters/fs.rs     | 34 +++++++++++++++++-----------------
 src/filters/header.rs | 14 +++++++-------
 src/filters/method.rs |  2 +-
 src/filters/path.rs   |  6 +++---
 src/filters/query.rs  |  4 ++--
 src/filters/sse.rs    |  6 +++---
 src/filters/ws.rs     | 12 ++++++------
 src/reject.rs         |  2 +-
 src/reply.rs          | 14 ++++++++------
 src/server.rs         | 26 +++++++++++++-------------
 src/test.rs           |  2 +-
 15 files changed, 80 insertions(+), 75 deletions(-)

diff --git a/Cargo.toml b/Cargo.toml
index 02409fce6..960facb65 100644
--- a/Cargo.toml
+++ b/Cargo.toml
@@ -32,6 +32,7 @@ serde = "1.0"
 serde_json = "1.0"
 serde_urlencoded = "0.6"
 tokio = { version = "0.2", features = ["fs", "stream", "sync", "time"] }
+tracing = { version = "0.1", default-features = false, features = ["log", "std"] }
 tower-service = "0.3"
 # tls is enabled by default, we don't want that yet
 tokio-tungstenite = { version = "0.10", default-features = false, optional = true }
diff --git a/src/filter/service.rs b/src/filter/service.rs
index c2dea4ee1..2c222e6c0 100644
--- a/src/filter/service.rs
+++ b/src/filter/service.rs
@@ -129,7 +129,7 @@ where
             Poll::Ready(Ok(ok)) => Poll::Ready(Ok(ok.into_response())),
             Poll::Pending => Poll::Pending,
             Poll::Ready(Err(err)) => {
-                log::debug!("rejected: {:?}", err);
+                tracing::debug!("rejected: {:?}", err);
                 Poll::Ready(Ok(err.into_response()))
             }
         }
diff --git a/src/filters/body.rs b/src/filters/body.rs
index 0828d59b7..0def35a4e 100644
--- a/src/filters/body.rs
+++ b/src/filters/body.rs
@@ -28,7 +28,7 @@ type BoxError = Box<dyn StdError + Send + Sync>;
 pub(crate) fn body() -> impl Filter<Extract = (Body,), Error = Rejection> + Copy {
     filter_fn_one(|route| {
         future::ready(route.take_body().ok_or_else(|| {
-            log::error!("request body already taken in previous filter");
+            tracing::error!("request body already taken in previous filter");
             reject::known(BodyConsumedMultipleTimes { _p: () })
         }))
     })
@@ -51,14 +51,14 @@ pub(crate) fn body() -> impl Filter<Extract = (Body,), Error = Rejection> + Copy
 pub fn content_length_limit(limit: u64) -> impl Filter<Extract = (), Error = Rejection> + Copy {
     crate::filters::header::header2()
         .map_err(crate::filter::Internal, |_| {
-            log::debug!("content-length missing");
+            tracing::debug!("content-length missing");
             reject::length_required()
         })
         .and_then(move |ContentLength(length)| {
             if length <= limit {
                 future::ok(())
             } else {
-                log::debug!("content-length: {} is over limit {}", length, limit);
+                tracing::debug!("content-length: {} is over limit {}", length, limit);
                 future::err(reject::payload_too_large())
             }
         })
@@ -106,7 +106,7 @@ pub fn stream(
 pub fn bytes() -> impl Filter<Extract = (Bytes,), Error = Rejection> + Copy {
     body().and_then(|body: hyper::Body| {
         hyper::body::to_bytes(body).map_err(|err| {
-            log::debug!("to_bytes error: {}", err);
+            tracing::debug!("to_bytes error: {}", err);
             reject::known(BodyReadError(err))
         })
     })
@@ -144,7 +144,7 @@ pub fn bytes() -> impl Filter<Extract = (Bytes,), Error = Rejection> + Copy {
 pub fn aggregate() -> impl Filter<Extract = (impl Buf,), Error = Rejection> + Copy {
     body().and_then(|body: ::hyper::Body| {
         hyper::body::aggregate(body).map_err(|err| {
-            log::debug!("aggregate error: {}", err);
+            tracing::debug!("aggregate error: {}", err);
             reject::known(BodyReadError(err))
         })
     })
@@ -175,7 +175,7 @@ pub fn json<T: DeserializeOwned + Send>() -> impl Filter<Extract = (T,), Error =
         .and(aggregate())
         .and_then(|buf| async move {
             Json::decode(buf).map_err(|err| {
-                log::debug!("request json body error: {}", err);
+                tracing::debug!("request json body error: {}", err);
                 reject::known(BodyDeserializeError { cause: err })
             })
         })
@@ -210,7 +210,7 @@ pub fn form<T: DeserializeOwned + Send>() -> impl Filter<Extract = (T,), Error =
         .and(aggregate())
         .and_then(|buf| async move {
             Form::decode(buf).map_err(|err| {
-                log::debug!("request form body error: {}", err);
+                tracing::debug!("request form body error: {}", err);
                 reject::known(BodyDeserializeError { cause: err })
             })
         })
@@ -254,7 +254,7 @@ fn is_content_type<D: Decode>() -> impl Filter<Extract = (), Error = Rejection>
     filter_fn(move |route| {
         let (type_, subtype) = D::MIME;
         if let Some(value) = route.headers().get(CONTENT_TYPE) {
-            log::trace!("is_content_type {}/{}? {:?}", type_, subtype, value);
+            tracing::trace!("is_content_type {}/{}? {:?}", type_, subtype, value);
             let ct = value
                 .to_str()
                 .ok()
@@ -263,7 +263,7 @@ fn is_content_type<D: Decode>() -> impl Filter<Extract = (), Error = Rejection>
                 if ct.type_() == type_ && ct.subtype() == subtype {
                     future::ok(())
                 } else {
-                    log::debug!(
+                    tracing::debug!(
                         "content-type {:?} doesn't match {}/{}",
                         value,
                         type_,
@@ -272,15 +272,15 @@ fn is_content_type<D: Decode>() -> impl Filter<Extract = (), Error = Rejection>
                     future::err(reject::unsupported_media_type())
                 }
             } else {
-                log::debug!("content-type {:?} couldn't be parsed", value);
+                tracing::debug!("content-type {:?} couldn't be parsed", value);
                 future::err(reject::unsupported_media_type())
             }
         } else if D::WITH_NO_CONTENT_TYPE {
             // Optimistically assume its correct!
-            log::trace!("no content-type header, assuming {}/{}", type_, subtype);
+            tracing::trace!("no content-type header, assuming {}/{}", type_, subtype);
             future::ok(())
         } else {
-            log::debug!("no content-type found");
+            tracing::debug!("no content-type found");
             future::err(reject::unsupported_media_type())
         }
     })
diff --git a/src/filters/cors.rs b/src/filters/cors.rs
index d6e2a7d64..1cb5a5e78 100644
--- a/src/filters/cors.rs
+++ b/src/filters/cors.rs
@@ -368,7 +368,9 @@ impl Configured {
                         return Err(Forbidden::MethodNotAllowed);
                     }
                 } else {
-                    log::trace!("preflight request missing access-control-request-method header");
+                    tracing::trace!(
+                        "preflight request missing access-control-request-method header"
+                    );
                     return Err(Forbidden::MethodNotAllowed);
                 }
 
@@ -388,7 +390,7 @@ impl Configured {
             (Some(origin), _) => {
                 // Any other method, simply check for a valid origin...
 
-                log::trace!("origin header: {:?}", origin);
+                tracing::trace!("origin header: {:?}", origin);
                 if self.is_origin_allowed(origin) {
                     Ok(Validated::Simple(origin.clone()))
                 } else {
diff --git a/src/filters/fs.rs b/src/filters/fs.rs
index 4ed115287..bdef206aa 100644
--- a/src/filters/fs.rs
+++ b/src/filters/fs.rs
@@ -48,7 +48,7 @@ pub fn file(path: impl Into<PathBuf>) -> impl FilterClone<Extract = One<File>, E
     let path = Arc::new(path.into());
     crate::any()
         .map(move || {
-            log::trace!("file: {:?}", path);
+            tracing::trace!("file: {:?}", path);
             ArcPath(path.clone())
         })
         .and(conditionals())
@@ -96,10 +96,10 @@ fn path_from_tail(
                 .unwrap_or(false);
 
             if is_dir {
-                log::debug!("dir: appending index.html to directory path");
+                tracing::debug!("dir: appending index.html to directory path");
                 buf.push("index.html");
             }
-            log::trace!("dir: {:?}", buf);
+            tracing::trace!("dir: {:?}", buf);
             Ok(ArcPath(Arc::new(buf)))
         })
     })
@@ -110,18 +110,18 @@ fn sanitize_path(base: impl AsRef<Path>, tail: &str) -> Result<PathBuf, Rejectio
     let p = match decode(tail) {
         Ok(p) => p,
         Err(err) => {
-            log::debug!("dir: failed to decode route={:?}: {:?}", tail, err);
+            tracing::debug!("dir: failed to decode route={:?}: {:?}", tail, err);
             // FromUrlEncodingError doesn't implement StdError
             return Err(reject::not_found());
         }
     };
-    log::trace!("dir? base={:?}, route={:?}", base.as_ref(), p);
+    tracing::trace!("dir? base={:?}, route={:?}", base.as_ref(), p);
     for seg in p.split('/') {
         if seg.starts_with("..") {
-            log::warn!("dir: rejecting segment starting with '..'");
+            tracing::warn!("dir: rejecting segment starting with '..'");
             return Err(reject::not_found());
         } else if seg.contains('\\') {
-            log::warn!("dir: rejecting segment containing with backslash (\\)");
+            tracing::warn!("dir: rejecting segment containing with backslash (\\)");
             return Err(reject::not_found());
         } else {
             buf.push(seg);
@@ -150,7 +150,7 @@ impl Conditionals {
                 .map(|time| since.precondition_passes(time.into()))
                 .unwrap_or(false);
 
-            log::trace!(
+            tracing::trace!(
                 "if-unmodified-since? {:?} vs {:?} = {}",
                 since,
                 last_modified,
@@ -164,7 +164,7 @@ impl Conditionals {
         }
 
         if let Some(since) = self.if_modified_since {
-            log::trace!(
+            tracing::trace!(
                 "if-modified-since? header = {:?}, file = {:?}",
                 since,
                 last_modified
@@ -181,7 +181,7 @@ impl Conditionals {
         }
 
         if let Some(if_range) = self.if_range {
-            log::trace!("if-range? {:?} vs {:?}", if_range, last_modified);
+            tracing::trace!("if-range? {:?} vs {:?}", if_range, last_modified);
             let can_range = !if_range.is_modified(None, last_modified.as_ref());
 
             if !can_range {
@@ -265,15 +265,15 @@ fn file_reply(
         Err(err) => {
             let rej = match err.kind() {
                 io::ErrorKind::NotFound => {
-                    log::debug!("file not found: {:?}", path.as_ref().display());
+                    tracing::debug!("file not found: {:?}", path.as_ref().display());
                     reject::not_found()
                 }
                 io::ErrorKind::PermissionDenied => {
-                    log::warn!("file permission denied: {:?}", path.as_ref().display());
+                    tracing::warn!("file permission denied: {:?}", path.as_ref().display());
                     reject::known(FilePermissionError { _p: () })
                 }
                 _ => {
-                    log::error!(
+                    tracing::error!(
                         "file open error (path={:?}): {} ",
                         path.as_ref().display(),
                         err
@@ -290,7 +290,7 @@ async fn file_metadata(f: TkFile) -> Result<(TkFile, Metadata), Rejection> {
     match f.metadata().await {
         Ok(meta) => Ok((f, meta)),
         Err(err) => {
-            log::debug!("file metadata error: {}", err);
+            tracing::debug!("file metadata error: {}", err);
             Err(reject::not_found())
         }
     }
@@ -382,7 +382,7 @@ fn bytes_range(range: Option<Range>, max_len: u64) -> Result<(u64, u64), BadRang
             if start < end && end <= max_len {
                 Ok((start, end))
             } else {
-                log::trace!("unsatisfiable byte range: {}-{}/{}", start, end, max_len);
+                tracing::trace!("unsatisfiable byte range: {}-{}/{}", start, end, max_len);
                 Err(BadRange)
             }
         })
@@ -423,13 +423,13 @@ fn file_stream(
                 let n = match ready!(Pin::new(&mut f).poll_read_buf(cx, &mut buf)) {
                     Ok(n) => n as u64,
                     Err(err) => {
-                        log::debug!("file read error: {}", err);
+                        tracing::debug!("file read error: {}", err);
                         return Poll::Ready(Some(Err(err)));
                     }
                 };
 
                 if n == 0 {
-                    log::debug!("file read found EOF before expected length");
+                    tracing::debug!("file read found EOF before expected length");
                     return Poll::Ready(None);
                 }
 
diff --git a/src/filters/header.rs b/src/filters/header.rs
index dd3ed928f..ebd9c39a8 100644
--- a/src/filters/header.rs
+++ b/src/filters/header.rs
@@ -38,7 +38,7 @@ pub fn header<T: FromStr + Send + 'static>(
     name: &'static str,
 ) -> impl Filter<Extract = One<T>, Error = Rejection> + Copy {
     filter_fn_one(move |route| {
-        log::trace!("header({:?})", name);
+        tracing::trace!("header({:?})", name);
         let route = route
             .headers()
             .get(name)
@@ -52,7 +52,7 @@ pub fn header<T: FromStr + Send + 'static>(
 pub(crate) fn header2<T: Header + Send + 'static>(
 ) -> impl Filter<Extract = One<T>, Error = Rejection> + Copy {
     filter_fn_one(move |route| {
-        log::trace!("header2({:?})", T::name());
+        tracing::trace!("header2({:?})", T::name());
         let route = route
             .headers()
             .typed_get()
@@ -80,7 +80,7 @@ where
     T: FromStr + Send + 'static,
 {
     filter_fn_one(move |route| {
-        log::trace!("optional({:?})", name);
+        tracing::trace!("optional({:?})", name);
         let result = route.headers().get(name).map(|value| {
             value
                 .to_str()
@@ -110,7 +110,7 @@ where
     T: Header + PartialEq + Clone + Send,
 {
     filter_fn(move |route| {
-        log::trace!("exact2({:?})", T::NAME);
+        tracing::trace!("exact2({:?})", T::NAME);
         route.headers()
             .typed_get::<T>()
             .and_then(|val| if val == header {
@@ -139,7 +139,7 @@ pub fn exact(
     value: &'static str,
 ) -> impl Filter<Extract = (), Error = Rejection> + Copy {
     filter_fn(move |route| {
-        log::trace!("exact?({:?}, {:?})", name, value);
+        tracing::trace!("exact?({:?}, {:?})", name, value);
         let route = route
             .headers()
             .get(name)
@@ -171,7 +171,7 @@ pub fn exact_ignore_case(
     value: &'static str,
 ) -> impl Filter<Extract = (), Error = Rejection> + Copy {
     filter_fn(move |route| {
-        log::trace!("exact_ignore_case({:?}, {:?})", name, value);
+        tracing::trace!("exact_ignore_case({:?}, {:?})", name, value);
         let route = route
             .headers()
             .get(name)
@@ -203,7 +203,7 @@ pub fn value(
     name: &'static str,
 ) -> impl Filter<Extract = One<HeaderValue>, Error = Rejection> + Copy {
     filter_fn_one(move |route| {
-        log::trace!("value({:?})", name);
+        tracing::trace!("value({:?})", name);
         let route = route
             .headers()
             .get(name)
diff --git a/src/filters/method.rs b/src/filters/method.rs
index ce5b76711..a0bf2aac2 100644
--- a/src/filters/method.rs
+++ b/src/filters/method.rs
@@ -131,7 +131,7 @@ where
 {
     filter_fn(move |route| {
         let method = func();
-        log::trace!("method::{:?}?: {:?}", method, route.method());
+        tracing::trace!("method::{:?}?: {:?}", method, route.method());
         if route.method() == method {
             future::ok(())
         } else {
diff --git a/src/filters/path.rs b/src/filters/path.rs
index a09526d65..3269242d5 100644
--- a/src/filters/path.rs
+++ b/src/filters/path.rs
@@ -179,7 +179,7 @@ where
     Exact(Opaque(p))
     /*
     segment(move |seg| {
-        log::trace!("{:?}?: {:?}", p, seg);
+        tracing::trace!("{:?}?: {:?}", p, seg);
         if seg == p {
             Ok(())
         } else {
@@ -209,7 +209,7 @@ where
         route::with(|route| {
             let p = self.0.as_ref();
             future::ready(with_segment(route, |seg| {
-                log::trace!("{:?}?: {:?}", p, seg);
+                tracing::trace!("{:?}?: {:?}", p, seg);
 
                 if seg == p {
                     Ok(())
@@ -266,7 +266,7 @@ pub fn end() -> impl Filter<Extract = (), Error = Rejection> + Copy {
 pub fn param<T: FromStr + Send + 'static>(
 ) -> impl Filter<Extract = One<T>, Error = Rejection> + Copy {
     filter_segment(|seg| {
-        log::trace!("param?: {:?}", seg);
+        tracing::trace!("param?: {:?}", seg);
         if seg.is_empty() {
             return Err(reject::not_found());
         }
diff --git a/src/filters/query.rs b/src/filters/query.rs
index be7224326..b31f096f3 100644
--- a/src/filters/query.rs
+++ b/src/filters/query.rs
@@ -14,12 +14,12 @@ pub fn query<T: DeserializeOwned + Send + 'static>(
 ) -> impl Filter<Extract = One<T>, Error = Rejection> + Copy {
     filter_fn_one(|route| {
         let query_string = route.query().unwrap_or_else(|| {
-            log::debug!("route was called without a query string, defaulting to empty");
+            tracing::debug!("route was called without a query string, defaulting to empty");
             ""
         });
 
         let query_encoded = serde_urlencoded::from_str(query_string).map_err(|e| {
-            log::debug!("failed to decode query string '{}': {:?}", query_string, e);
+            tracing::debug!("failed to decode query string '{}': {:?}", query_string, e);
             reject::invalid_query()
         });
         future::ready(query_encoded)
diff --git a/src/filters/sse.rs b/src/filters/sse.rs
index 6235339fb..b22b80c21 100644
--- a/src/filters/sse.rs
+++ b/src/filters/sse.rs
@@ -231,7 +231,7 @@ impl<T: Serialize> SseFormat for SseJson<T> {
             k.fmt(f)?;
             serde_json::to_string(&self.0)
                 .map_err(|error| {
-                    log::error!("sse::json error {}", error);
+                    tracing::error!("sse::json error {}", error);
                     fmt::Error
                 })
                 .and_then(|data| data.fmt(f))?;
@@ -409,7 +409,7 @@ where
             .event_stream
             .map_err(|error| {
                 // FIXME: error logging
-                log::error!("sse stream error: {}", error);
+                tracing::error!("sse stream error: {}", error);
                 SseError
             })
             .into_stream()
@@ -592,7 +592,7 @@ where
             }
             Poll::Ready(None) => Poll::Ready(None),
             Poll::Ready(Some(Err(error))) => {
-                log::error!("sse::keep error: {}", error);
+                tracing::error!("sse::keep error: {}", error);
                 Poll::Ready(Some(Err(SseError)))
             }
         }
diff --git a/src/filters/ws.rs b/src/filters/ws.rs
index ec1389d16..20f37af83 100644
--- a/src/filters/ws.rs
+++ b/src/filters/ws.rs
@@ -139,13 +139,13 @@ where
             .body
             .on_upgrade()
             .and_then(move |upgraded| {
-                log::trace!("websocket upgrade complete");
+                tracing::trace!("websocket upgrade complete");
                 WebSocket::from_raw_socket(upgraded, protocol::Role::Server, config).map(Ok)
             })
             .and_then(move |socket| on_upgrade(socket).map(Ok))
             .map(|result| {
                 if let Err(err) = result {
-                    log::debug!("ws upgrade error: {}", err);
+                    tracing::debug!("ws upgrade error: {}", err);
                 }
             });
         ::tokio::task::spawn(fut);
@@ -196,11 +196,11 @@ impl Stream for WebSocket {
         match ready!(Pin::new(&mut self.inner).poll_next(cx)) {
             Some(Ok(item)) => Poll::Ready(Some(Ok(Message { inner: item }))),
             Some(Err(e)) => {
-                log::debug!("websocket poll error: {}", e);
+                tracing::debug!("websocket poll error: {}", e);
                 Poll::Ready(Some(Err(crate::Error::new(e))))
             }
             None => {
-                log::trace!("websocket closed");
+                tracing::trace!("websocket closed");
                 Poll::Ready(None)
             }
         }
@@ -221,7 +221,7 @@ impl Sink<Message> for WebSocket {
         match Pin::new(&mut self.inner).start_send(item.inner) {
             Ok(()) => Ok(()),
             Err(e) => {
-                log::debug!("websocket start_send error: {}", e);
+                tracing::debug!("websocket start_send error: {}", e);
                 Err(crate::Error::new(e))
             }
         }
@@ -238,7 +238,7 @@ impl Sink<Message> for WebSocket {
         match ready!(Pin::new(&mut self.inner).poll_close(cx)) {
             Ok(()) => Poll::Ready(Ok(())),
             Err(err) => {
-                log::debug!("websocket close error: {}", err);
+                tracing::debug!("websocket close error: {}", err);
                 Poll::Ready(Err(crate::Error::new(err)))
             }
         }
diff --git a/src/reject.rs b/src/reject.rs
index 8fd28badd..fc15380ea 100644
--- a/src/reject.rs
+++ b/src/reject.rs
@@ -418,7 +418,7 @@ impl Rejections {
                 res
             }
             Rejections::Custom(ref e) => {
-                log::error!(
+                tracing::error!(
                     "unhandled custom rejection, returning 500 response: {:?}",
                     e
                 );
diff --git a/src/reply.rs b/src/reply.rs
index 7a60141c4..0c7e736c4 100644
--- a/src/reply.rs
+++ b/src/reply.rs
@@ -105,7 +105,7 @@ where
 {
     Json {
         inner: serde_json::to_vec(val).map_err(|err| {
-            log::error!("reply::json error: {}", err);
+            tracing::error!("reply::json error: {}", err);
         }),
     }
 }
@@ -275,13 +275,13 @@ pub trait Reply: BoxedReply + Send {
                     Reply_(res)
                 },
                 Err(err) => {
-                    log::error!("with_header value error: {}", err.into());
+                    tracing::error!("with_header value error: {}", err.into());
                     Reply_(::reject::server_error()
                         .into_response())
                 }
             },
             Err(err) => {
-                log::error!("with_header name error: {}", err.into());
+                tracing::error!("with_header name error: {}", err.into());
                 Reply_(::reject::server_error()
                     .into_response())
             }
@@ -358,12 +358,14 @@ where
         Ok(name) => match <HeaderValue as TryFrom<V>>::try_from(value) {
             Ok(value) => Some((name, value)),
             Err(err) => {
-                log::error!("with_header value error: {}", err.into());
+                let err = err.into();
+                tracing::error!("with_header value error: {}", err);
                 None
             }
         },
         Err(err) => {
-            log::error!("with_header name error: {}", err.into());
+            let err = err.into();
+            tracing::error!("with_header name error: {}", err);
             None
         }
     };
@@ -418,7 +420,7 @@ where
         match self {
             Ok(t) => t.into_response(),
             Err(e) => {
-                log::error!("reply error: {:?}", e);
+                tracing::error!("reply error: {:?}", e);
                 StatusCode::INTERNAL_SERVER_ERROR.into_response()
             }
         }
diff --git a/src/server.rs b/src/server.rs
index a83faae85..f99c043e3 100644
--- a/src/server.rs
+++ b/src/server.rs
@@ -130,7 +130,7 @@ where
     pub async fn run(self, addr: impl Into<SocketAddr> + 'static) {
         let (addr, fut) = self.bind_ephemeral(addr);
 
-        log::info!("listening on http://{}", addr);
+        tracing::info!("listening on http://{}", addr);
 
         fut.await;
     }
@@ -157,7 +157,7 @@ where
     {
         let fut = self.serve_incoming2(incoming);
 
-        log::info!("listening with custom incoming");
+        tracing::info!("listening with custom incoming");
 
         fut.await;
     }
@@ -183,14 +183,14 @@ where
         let srv = match try_bind!(self, &addr) {
             Ok((_, srv)) => srv,
             Err(err) => {
-                log::error!("error binding to {}: {}", addr, err);
+                tracing::error!("error binding to {}: {}", addr, err);
                 return;
             }
         };
 
         srv.map(|result| {
             if let Err(err) = result {
-                log::error!("server error: {}", err)
+                tracing::error!("server error: {}", err)
             }
         })
         .await;
@@ -211,7 +211,7 @@ where
         let (addr, srv) = bind!(self, addr);
         let srv = srv.map(|result| {
             if let Err(err) = result {
-                log::error!("server error: {}", err)
+                tracing::error!("server error: {}", err)
             }
         });
 
@@ -233,7 +233,7 @@ where
         let (addr, srv) = try_bind!(self, &addr).map_err(crate::Error::new)?;
         let srv = srv.map(|result| {
             if let Err(err) = result {
-                log::error!("server error: {}", err)
+                tracing::error!("server error: {}", err)
             }
         });
 
@@ -281,7 +281,7 @@ where
         let (addr, srv) = bind!(self, addr);
         let fut = srv.with_graceful_shutdown(signal).map(|result| {
             if let Err(err) = result {
-                log::error!("server error: {}", err)
+                tracing::error!("server error: {}", err)
             }
         });
         (addr, fut)
@@ -300,7 +300,7 @@ where
         let (addr, srv) = try_bind!(self, &addr).map_err(crate::Error::new)?;
         let srv = srv.with_graceful_shutdown(signal).map(|result| {
             if let Err(err) = result {
-                log::error!("server error: {}", err)
+                tracing::error!("server error: {}", err)
             }
         });
 
@@ -354,7 +354,7 @@ where
                     .await;
 
             if let Err(err) = srv {
-                log::error!("server error: {}", err);
+                tracing::error!("server error: {}", err);
             }
         }
     }
@@ -373,7 +373,7 @@ where
             .await;
 
         if let Err(err) = srv {
-            log::error!("server error: {}", err);
+            tracing::error!("server error: {}", err);
         }
     }
 
@@ -446,7 +446,7 @@ where
     pub async fn run(self, addr: impl Into<SocketAddr> + 'static) {
         let (addr, fut) = self.bind_ephemeral(addr);
 
-        log::info!("listening on https://{}", addr);
+        tracing::info!("listening on https://{}", addr);
 
         fut.await;
     }
@@ -473,7 +473,7 @@ where
         let (addr, srv) = bind!(tls: self, addr);
         let srv = srv.map(|result| {
             if let Err(err) = result {
-                log::error!("server error: {}", err)
+                tracing::error!("server error: {}", err)
             }
         });
 
@@ -495,7 +495,7 @@ where
 
         let fut = srv.with_graceful_shutdown(signal).map(|result| {
             if let Err(err) = result {
-                log::error!("server error: {}", err)
+                tracing::error!("server error: {}", err)
             }
         });
         (addr, fut)
diff --git a/src/test.rs b/src/test.rs
index a3fe7b467..257d50234 100644
--- a/src/test.rs
+++ b/src/test.rs
@@ -372,7 +372,7 @@ impl RequestBuilder {
                 let res = match result {
                     Ok(rep) => rep.into_response(),
                     Err(rej) => {
-                        log::debug!("rejected: {:?}", rej);
+                        tracing::debug!("rejected: {:?}", rej);
                         rej.into_response()
                     }
                 };

From be5d80a7ded86f3c588d3534ec38bf6e3e37e2cf Mon Sep 17 00:00:00 2001
From: Eliza Weisman <eliza@buoyant.io>
Date: Thu, 16 Jul 2020 11:15:32 -0700
Subject: [PATCH 02/26] add tracing spans to servers

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
---
 src/server.rs | 18 ++++++++++++------
 1 file changed, 12 insertions(+), 6 deletions(-)

diff --git a/src/server.rs b/src/server.rs
index f99c043e3..c4ce79ac9 100644
--- a/src/server.rs
+++ b/src/server.rs
@@ -12,6 +12,7 @@ use hyper::server::conn::AddrIncoming;
 use hyper::service::{make_service_fn, service_fn};
 use hyper::Server as HyperServer;
 use tokio::io::{AsyncRead, AsyncWrite};
+use tracing_futures::Instrument;
 
 use crate::filter::Filter;
 use crate::reject::IsReject;
@@ -129,10 +130,10 @@ where
     /// Run this `Server` forever on the current thread.
     pub async fn run(self, addr: impl Into<SocketAddr> + 'static) {
         let (addr, fut) = self.bind_ephemeral(addr);
+        let span = tracing::info_span!("Server::run", ?addr);
+        tracing::info!(parent: &span, "listening on http://{}", addr);
 
-        tracing::info!("listening on http://{}", addr);
-
-        fut.await;
+        fut.instrument(span).await;
     }
 
     /// Run this `Server` forever on the current thread with a specific stream
@@ -146,6 +147,7 @@ where
         I::Error: Into<Box<dyn StdError + Send + Sync>>,
     {
         self.run_incoming2(incoming.map_ok(crate::transport::LiftIo).into_stream())
+            .instrument(tracing::info_span!("Server::run_incoming"))
             .await;
     }
 
@@ -320,6 +322,7 @@ where
     {
         let incoming = incoming.map_ok(crate::transport::LiftIo);
         self.serve_incoming2(incoming)
+            .instrument(tracing::info_span!("Server::serve_incoming"))
     }
 
     /// Setup this `Server` with a specific stream of incoming connections and a
@@ -357,6 +360,9 @@ where
                 tracing::error!("server error: {}", err);
             }
         }
+        .instrument(tracing::info_span!(
+            "Server::serve_incoming_with_graceful_shutdown"
+        ))
     }
 
     async fn serve_incoming2<I>(self, incoming: I)
@@ -445,10 +451,10 @@ where
     /// *This function requires the `"tls"` feature.*
     pub async fn run(self, addr: impl Into<SocketAddr> + 'static) {
         let (addr, fut) = self.bind_ephemeral(addr);
+        let span = tracing::info_span!("TlsServer::run", %addr);
+        tracing::info!(parent: &span, "listening on https://{}", addr);
 
-        tracing::info!("listening on https://{}", addr);
-
-        fut.await;
+        fut.instrument(span).await;
     }
 
     /// Bind to a socket address, returning a `Future` that can be

From 2207ca6648aa2e26fee186e06c885c66f584fbe0 Mon Sep 17 00:00:00 2001
From: Eliza Weisman <eliza@buoyant.io>
Date: Thu, 16 Jul 2020 11:22:12 -0700
Subject: [PATCH 03/26] whoops, forgot the `tracing-futures` dep

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
---
 Cargo.toml | 1 +
 1 file changed, 1 insertion(+)

diff --git a/Cargo.toml b/Cargo.toml
index 960facb65..d52eb83bb 100644
--- a/Cargo.toml
+++ b/Cargo.toml
@@ -33,6 +33,7 @@ serde_json = "1.0"
 serde_urlencoded = "0.6"
 tokio = { version = "0.2", features = ["fs", "stream", "sync", "time"] }
 tracing = { version = "0.1", default-features = false, features = ["log", "std"] }
+tracing-futures = { version = "0.2", default-features = false, features = ["std-future"] }
 tower-service = "0.3"
 # tls is enabled by default, we don't want that yet
 tokio-tungstenite = { version = "0.10", default-features = false, optional = true }

From 60558aadaba3ca33f42600416f36614ea4e4f4cb Mon Sep 17 00:00:00 2001
From: Ole Martin Ruud <barskern@outlook.com>
Date: Thu, 23 Jan 2020 22:11:59 +0100
Subject: [PATCH 04/26] Add tracing filter

---
 src/filters/mod.rs     |   1 +
 src/filters/tracing.rs | 208 +++++++++++++++++++++++++++++++++++++++++
 src/lib.rs             |   3 +
 tests/tracing.rs       |  44 +++++++++
 4 files changed, 256 insertions(+)
 create mode 100644 src/filters/tracing.rs
 create mode 100644 tests/tracing.rs

diff --git a/src/filters/mod.rs b/src/filters/mod.rs
index 9aee786cf..1be00a070 100644
--- a/src/filters/mod.rs
+++ b/src/filters/mod.rs
@@ -21,6 +21,7 @@ pub mod path;
 pub mod query;
 pub mod reply;
 pub mod sse;
+pub mod tracing;
 #[cfg(feature = "websocket")]
 pub mod ws;
 
diff --git a/src/filters/tracing.rs b/src/filters/tracing.rs
new file mode 100644
index 000000000..0224f113a
--- /dev/null
+++ b/src/filters/tracing.rs
@@ -0,0 +1,208 @@
+//! Tracing Filters
+
+use tracing::Span;
+
+use std::fmt;
+use std::net::SocketAddr;
+
+use http::{self, header};
+
+use crate::filter::{Filter, WrapSealed};
+use crate::reject::IsReject;
+use crate::reply::Reply;
+use crate::route::Route;
+
+use self::internal::WithTrace;
+
+/// Create a wrapping filter which adds a span with request info
+///
+/// # Example
+///
+/// ```
+/// use warp::Filter;
+///
+/// let route = warp::any()
+///     .map(warp::reply)
+///     .with(warp::tracing());
+/// ```
+pub fn tracing() -> Trace<impl Fn(Info) -> Span + Clone> {
+    let func = move |info: Info| {
+        tracing::info_span!(
+            "request",
+            remote_addr = %OptFmt(info.route.remote_addr()),
+            method = %info.method(),
+            path = %info.path(),
+            version = ?info.route.version(),
+            // status = %info.status().as_u16(),
+            referer = %OptFmt(info.referer()),
+            user_agent = %OptFmt(info.user_agent()),
+        )
+    };
+    Trace { func }
+}
+
+/// Create a wrapping filter which adds a custom span with request info
+///
+/// # Example
+///
+/// ```
+/// use warp::Filter;
+///
+/// let tracing = warp::tracing::custom(|info| {
+///     // Create a span using tracing macros
+///     tracing::info_span!(
+///         "request",
+///         method = %info.method(),
+///         path = %info.path(),
+///     );
+/// });
+/// let route = warp::any()
+///     .map(warp::reply)
+///     .with(tracing);
+/// ```
+pub fn custom<F>(func: F) -> Trace<F>
+where
+    F: Fn(Info) -> Span + Clone,
+{
+    Trace { func }
+}
+
+/// Decorates a [`Filter`](::Filter) to log requests and responses.
+#[derive(Clone, Copy, Debug)]
+pub struct Trace<F> {
+    func: F,
+}
+
+/// Information about the request/response that can be used to prepare log lines.
+#[allow(missing_debug_implementations)]
+pub struct Info<'a> {
+    route: &'a Route,
+}
+
+impl<FN, F> WrapSealed<F> for Trace<FN>
+where
+    FN: Fn(Info) -> Span + Clone + Send,
+    F: Filter + Clone + Send,
+    F::Extract: Reply,
+    F::Error: IsReject,
+{
+    type Wrapped = WithTrace<FN, F>;
+
+    fn wrap(&self, filter: F) -> Self::Wrapped {
+        WithTrace {
+            filter,
+            trace: self.clone(),
+        }
+    }
+}
+
+impl<'a> Info<'a> {
+    /// View the remote `SocketAddr` of the request.
+    pub fn remote_addr(&self) -> Option<SocketAddr> {
+        self.route.remote_addr()
+    }
+
+    /// View the `http::Method` of the request.
+    pub fn method(&self) -> &http::Method {
+        self.route.method()
+    }
+
+    /// View the URI path of the request.
+    pub fn path(&self) -> &str {
+        self.route.full_path()
+    }
+
+    /// View the `http::Version` of the request.
+    pub fn version(&self) -> http::Version {
+        self.route.version()
+    }
+
+    /// View the referer of the request.
+    pub fn referer(&self) -> Option<&str> {
+        self.route
+            .headers()
+            .get(header::REFERER)
+            .and_then(|v| v.to_str().ok())
+    }
+
+    /// View the user agent of the request.
+    pub fn user_agent(&self) -> Option<&str> {
+        self.route
+            .headers()
+            .get(header::USER_AGENT)
+            .and_then(|v| v.to_str().ok())
+    }
+
+    /// View the host of the request
+    pub fn host(&self) -> Option<&str> {
+        self.route
+            .headers()
+            .get(header::HOST)
+            .and_then(|v| v.to_str().ok())
+    }
+}
+
+struct OptFmt<T>(Option<T>);
+
+impl<T: fmt::Display> fmt::Display for OptFmt<T> {
+    fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
+        if let Some(ref t) = self.0 {
+            fmt::Display::fmt(t, f)
+        } else {
+            f.write_str("-")
+        }
+    }
+}
+
+mod internal {
+    use futures::{future::Inspect, FutureExt};
+
+    use std::future::Future;
+
+    use super::{Info, Trace};
+    use crate::filter::{Filter, FilterBase, Internal};
+    use crate::reject::IsReject;
+    use crate::reply::Reply;
+    use crate::route;
+
+    #[allow(missing_debug_implementations)]
+    #[derive(Clone, Copy)]
+    pub struct WithTrace<FN, F> {
+        pub(super) filter: F,
+        pub(super) trace: Trace<FN>,
+    }
+
+    use tracing::Span;
+    use tracing_futures::{Instrument, Instrumented};
+
+    impl<FN, F> FilterBase for WithTrace<FN, F>
+    where
+        FN: Fn(Info) -> Span + Clone + Send,
+        F: Filter + Clone + Send,
+        F::Extract: Reply,
+        F::Error: IsReject,
+    {
+        type Extract = F::Extract;
+        type Error = F::Error;
+        type Future = Inspect<Instrumented<F::Future>, fn(&<F::Future as Future>::Output)>;
+
+        fn filter(&self, _: Internal) -> Self::Future {
+            let span = route::with(|route| (self.trace.func)(Info { route }));
+            let _guard = span.enter();
+
+            fn finished_logger<R: Reply, E: IsReject>(reply: &Result<R, E>) {
+                if let Err(e) = reply {
+                    tracing::warn!(target: "warp::filters::tracing", msg = ?e, "error during processing");
+                } else {
+                    tracing::info!(target: "warp::filters::tracing", "successfully finished processing");
+                }
+            }
+
+            tracing::info!(target: "warp::filters::tracing", "processing request");
+            self.filter
+                .filter(Internal)
+                .in_current_span()
+                .inspect(finished_logger)
+        }
+    }
+}
diff --git a/src/lib.rs b/src/lib.rs
index d19343aec..518fab389 100644
--- a/src/lib.rs
+++ b/src/lib.rs
@@ -143,6 +143,9 @@ pub use self::filters::{
     // query() function
     query::query,
     sse,
+    tracing,
+    // tracing() function
+    tracing::tracing,
 };
 // ws() function
 #[cfg(feature = "websocket")]
diff --git a/tests/tracing.rs b/tests/tracing.rs
new file mode 100644
index 000000000..e02be4386
--- /dev/null
+++ b/tests/tracing.rs
@@ -0,0 +1,44 @@
+use warp::Filter;
+
+#[tokio::test]
+async fn uses_tracing() {
+    // Setup a log subscriber (responsible to print to output)
+    let subscriber = tracing_subscriber::fmt::Subscriber::builder()
+        .with_env_filter("trace")
+        .without_time()
+        .finish();
+
+    // Set the previously created subscriber as the global subscriber
+    tracing::subscriber::set_global_default(subscriber).unwrap();
+    // Redirect normal log messages to the tracing subscriber
+    tracing_log::LogTracer::init().unwrap();
+
+    // Start a span with some metadata (fields)
+    let span = tracing::debug_span!("app", domain = "www.example.org");
+    let _guard = span.enter();
+
+    log::error!("logged using log macro");
+
+    let ok = warp::any()
+        .map(|| {
+            tracing::error!("pre failure: this is printed");
+        })
+        .untuple_one()
+        .and(warp::path("aa"))
+        .map(|| {
+            tracing::error!("post failure: this is not printed");
+        })
+        .untuple_one()
+        .map(warp::reply)
+        // Here we add the tracing logger which will ensure that all requests has a span with
+        // useful information about the request (method, url, version, remote_addr, etc.)
+        .with(warp::tracing());
+
+    tracing::info!("logged using tracing macro");
+
+    // Send a request for /
+    let req = warp::test::request();
+    let resp = req.reply(&ok);
+
+    assert_eq!(resp.await.status(), 404);
+}

From a690902fd17d903ddfa11089d04a89a14fc62708 Mon Sep 17 00:00:00 2001
From: Ole Martin Ruud <barskern@outlook.com>
Date: Thu, 23 Jan 2020 22:42:03 +0100
Subject: [PATCH 05/26] Add more extensive tracing for responses

---
 src/filters/tracing.rs | 57 +++++++++++++++++++++++++++++++-----------
 tests/tracing.rs       | 14 +++++++----
 2 files changed, 52 insertions(+), 19 deletions(-)

diff --git a/src/filters/tracing.rs b/src/filters/tracing.rs
index 0224f113a..1269a435f 100644
--- a/src/filters/tracing.rs
+++ b/src/filters/tracing.rs
@@ -155,16 +155,25 @@ impl<T: fmt::Display> fmt::Display for OptFmt<T> {
 }
 
 mod internal {
-    use futures::{future::Inspect, FutureExt};
-
-    use std::future::Future;
+    use futures::{future::Inspect, future::MapOk, FutureExt, TryFutureExt};
 
     use super::{Info, Trace};
     use crate::filter::{Filter, FilterBase, Internal};
     use crate::reject::IsReject;
     use crate::reply::Reply;
+    use crate::reply::Response;
     use crate::route;
 
+    #[allow(missing_debug_implementations)]
+    pub struct Traced(pub(super) Response);
+
+    impl Reply for Traced {
+        #[inline]
+        fn into_response(self) -> Response {
+            self.0
+        }
+    }
+
     #[allow(missing_debug_implementations)]
     #[derive(Clone, Copy)]
     pub struct WithTrace<FN, F> {
@@ -175,6 +184,28 @@ mod internal {
     use tracing::Span;
     use tracing_futures::{Instrument, Instrumented};
 
+    fn finished_logger<E: IsReject>(reply: &Result<(Traced,), E>) {
+        match reply {
+            Ok((Traced(resp),)) => {
+                tracing::info!(target: "warp::filters::tracing", status = %resp.status().as_u16(), "finished processing with success");
+            }
+            Err(e) if e.status().is_server_error() => {
+                tracing::error!(target: "warp::filters::tracing", status = %e.status().as_u16(), msg = ?e, "unable to process request (internal error)");
+            }
+            Err(e) if e.status().is_client_error() => {
+                tracing::warn!(target: "warp::filters::tracing", status = %e.status().as_u16(), msg = ?e, "unable to serve request (client error)");
+            }
+            Err(e) => {
+                // Either informational or redirect
+                tracing::info!(target: "warp::filters::tracing", status = %e.status().as_u16(), msg = ?e, "finished processing with status");
+            }
+        }
+    }
+
+    fn convert_reply<R: Reply>(reply: R) -> (Traced,) {
+        (Traced(reply.into_response()),)
+    }
+
     impl<FN, F> FilterBase for WithTrace<FN, F>
     where
         FN: Fn(Info) -> Span + Clone + Send,
@@ -182,27 +213,25 @@ mod internal {
         F::Extract: Reply,
         F::Error: IsReject,
     {
-        type Extract = F::Extract;
+        type Extract = (Traced,);
         type Error = F::Error;
-        type Future = Inspect<Instrumented<F::Future>, fn(&<F::Future as Future>::Output)>;
+        type Future = Instrumented<
+            Inspect<
+                MapOk<F::Future, fn(F::Extract) -> Self::Extract>,
+                fn(&Result<Self::Extract, F::Error>),
+            >,
+        >;
 
         fn filter(&self, _: Internal) -> Self::Future {
             let span = route::with(|route| (self.trace.func)(Info { route }));
             let _guard = span.enter();
 
-            fn finished_logger<R: Reply, E: IsReject>(reply: &Result<R, E>) {
-                if let Err(e) = reply {
-                    tracing::warn!(target: "warp::filters::tracing", msg = ?e, "error during processing");
-                } else {
-                    tracing::info!(target: "warp::filters::tracing", "successfully finished processing");
-                }
-            }
-
             tracing::info!(target: "warp::filters::tracing", "processing request");
             self.filter
                 .filter(Internal)
+                .map_ok(convert_reply as fn(F::Extract) -> Self::Extract)
+                .inspect(finished_logger as fn(&Result<Self::Extract, F::Error>))
                 .in_current_span()
-                .inspect(finished_logger)
         }
     }
 }
diff --git a/tests/tracing.rs b/tests/tracing.rs
index e02be4386..6cd77cdfd 100644
--- a/tests/tracing.rs
+++ b/tests/tracing.rs
@@ -14,19 +14,19 @@ async fn uses_tracing() {
     tracing_log::LogTracer::init().unwrap();
 
     // Start a span with some metadata (fields)
-    let span = tracing::debug_span!("app", domain = "www.example.org");
+    let span = tracing::info_span!("app", domain = "www.example.org");
     let _guard = span.enter();
 
-    log::error!("logged using log macro");
+    log::info!("logged using log macro");
 
     let ok = warp::any()
         .map(|| {
-            tracing::error!("pre failure: this is printed");
+            tracing::info!("printed for every request");
         })
         .untuple_one()
         .and(warp::path("aa"))
         .map(|| {
-            tracing::error!("post failure: this is not printed");
+            tracing::info!("only printed when path '/aa' matches");
         })
         .untuple_one()
         .map(warp::reply)
@@ -39,6 +39,10 @@ async fn uses_tracing() {
     // Send a request for /
     let req = warp::test::request();
     let resp = req.reply(&ok);
-
     assert_eq!(resp.await.status(), 404);
+
+    // Send a request for /aa
+    let req = warp::test::request().path("/aa");
+    let resp = req.reply(&ok);
+    assert_eq!(resp.await.status(), 200);
 }

From 0dff2579286c32a6d852882fbed0251ace0b4697 Mon Sep 17 00:00:00 2001
From: Ole Martin Ruud <barskern@outlook.com>
Date: Thu, 23 Jan 2020 22:51:43 +0100
Subject: [PATCH 06/26] fixup! Add tracing filter

---
 src/filters/tracing.rs | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/src/filters/tracing.rs b/src/filters/tracing.rs
index 1269a435f..f9ad82dcd 100644
--- a/src/filters/tracing.rs
+++ b/src/filters/tracing.rs
@@ -54,7 +54,7 @@ pub fn tracing() -> Trace<impl Fn(Info) -> Span + Clone> {
 ///         "request",
 ///         method = %info.method(),
 ///         path = %info.path(),
-///     );
+///     )
 /// });
 /// let route = warp::any()
 ///     .map(warp::reply)

From 93d35b888476f0e21364bb4d5b59fb34ff977624 Mon Sep 17 00:00:00 2001
From: Eliza Weisman <eliza@buoyant.io>
Date: Thu, 16 Jul 2020 11:26:17 -0700
Subject: [PATCH 07/26] more idiomatic fields for completion logs

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
---
 src/filters/tracing.rs | 23 +++++++++++++++++++----
 1 file changed, 19 insertions(+), 4 deletions(-)

diff --git a/src/filters/tracing.rs b/src/filters/tracing.rs
index f9ad82dcd..03e3264a8 100644
--- a/src/filters/tracing.rs
+++ b/src/filters/tracing.rs
@@ -187,17 +187,32 @@ mod internal {
     fn finished_logger<E: IsReject>(reply: &Result<(Traced,), E>) {
         match reply {
             Ok((Traced(resp),)) => {
-                tracing::info!(target: "warp::filters::tracing", status = %resp.status().as_u16(), "finished processing with success");
+                tracing::info!(target: "warp::filters::tracing", status = resp.status().as_u16(), "finished processing with success");
             }
             Err(e) if e.status().is_server_error() => {
-                tracing::error!(target: "warp::filters::tracing", status = %e.status().as_u16(), msg = ?e, "unable to process request (internal error)");
+                tracing::error!(
+                    target: "warp::filters::tracing",
+                    status = e.status().as_u16(),
+                    error = ?e,
+                    "unable to process request (internal error)"
+                );
             }
             Err(e) if e.status().is_client_error() => {
-                tracing::warn!(target: "warp::filters::tracing", status = %e.status().as_u16(), msg = ?e, "unable to serve request (client error)");
+                tracing::warn!(
+                    target: "warp::filters::tracing",
+                    status = e.status().as_u16(),
+                    error = ?e,
+                    "unable to serve request (client error)"
+                );
             }
             Err(e) => {
                 // Either informational or redirect
-                tracing::info!(target: "warp::filters::tracing", status = %e.status().as_u16(), msg = ?e, "finished processing with status");
+                tracing::info!(
+                    target: "warp::filters::tracing",
+                    status = e.status().as_u16(),
+                    result = ?e,
+                    "finished processing with status"
+                );
             }
         }
     }

From 4473fba049dcc375db373c2ab9f5edbfbfd314cc Mon Sep 17 00:00:00 2001
From: Eliza Weisman <eliza@buoyant.io>
Date: Thu, 16 Jul 2020 11:31:15 -0700
Subject: [PATCH 08/26] add `context`

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
---
 src/filters/tracing.rs | 33 +++++++++++++++++++++++++++++++++
 1 file changed, 33 insertions(+)

diff --git a/src/filters/tracing.rs b/src/filters/tracing.rs
index 03e3264a8..2d971513e 100644
--- a/src/filters/tracing.rs
+++ b/src/filters/tracing.rs
@@ -67,6 +67,39 @@ where
     Trace { func }
 }
 
+/// Create a wrapping filter that instruments every request with a `tracing`
+/// [`Span`] at the `DEBUG` level representing a named context.
+///
+/// This can be used to instrument multiple routes with their own sub-spans in a
+/// per-request trace.
+///
+/// # Example
+///
+/// ```
+/// use warp::Filter;
+///
+/// let hello = warp::path("hello")
+///     .map(warp::reply)
+///     .with(warp::tracing::context("hello"));
+///
+/// let goodbye = warp::path("goodbye")
+///     .map(warp::reply)
+///     .with(warp::tracing::context("goodbye"));
+///
+/// let routes = hello.or(goodbye);
+/// ```
+///
+/// [`Span`]: https://docs.rs/tracing/latest/tracing/#spans
+pub fn context(name: &'static str) -> Trace<impl Fn(Info<'_>) -> tracing::Span + Copy> {
+    custom(move |_| {
+        tracing::debug_span!(
+            target: "warp",
+            "context",
+            "{}", name,
+        )
+    })
+}
+
 /// Decorates a [`Filter`](::Filter) to log requests and responses.
 #[derive(Clone, Copy, Debug)]
 pub struct Trace<F> {

From fe9613c036c0bcf932e866944a08c977e7298b72 Mon Sep 17 00:00:00 2001
From: Eliza Weisman <eliza@buoyant.io>
Date: Thu, 16 Jul 2020 11:37:24 -0700
Subject: [PATCH 09/26] docs improvements

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
---
 src/filters/tracing.rs | 33 +++++++++++++++++++++++++++------
 1 file changed, 27 insertions(+), 6 deletions(-)

diff --git a/src/filters/tracing.rs b/src/filters/tracing.rs
index 2d971513e..c366fae25 100644
--- a/src/filters/tracing.rs
+++ b/src/filters/tracing.rs
@@ -1,5 +1,13 @@
-//! Tracing Filters
-
+//! [`tracing`] filters.
+//!
+//! [`tracing`] tracing is a framework for instrumenting Rust programs to
+//! collect scoped, structured, and async-aware diagnostics. This module
+//! provides a set of filters for instrumenting Warp applications with `tracing`
+//! spans. [Spans] can be used to associate individual events  with a request,
+//! and track contexts through the application.
+//!
+//! [`tracing`]: https://crates.io/tracing
+/// [Spans]: https://docs.rs/tracing/latest/tracing/#spans
 use tracing::Span;
 
 use std::fmt;
@@ -14,7 +22,8 @@ use crate::route::Route;
 
 use self::internal::WithTrace;
 
-/// Create a wrapping filter which adds a span with request info
+/// Create a wrapping filter that instruments every request with a `tracing`
+/// [`Span`] at the [`INFO`] level, containing a summary of the request.
 ///
 /// # Example
 ///
@@ -25,6 +34,9 @@ use self::internal::WithTrace;
 ///     .map(warp::reply)
 ///     .with(warp::tracing());
 /// ```
+///
+/// [`Span`]: https://docs.rs/tracing/latest/tracing/#spans
+/// [`INFO`]: https://docs.rs/tracing/0.1.16/tracing/struct.Level.html#associatedconstant.INFO
 pub fn tracing() -> Trace<impl Fn(Info) -> Span + Clone> {
     let func = move |info: Info| {
         tracing::info_span!(
@@ -41,7 +53,9 @@ pub fn tracing() -> Trace<impl Fn(Info) -> Span + Clone> {
     Trace { func }
 }
 
-/// Create a wrapping filter which adds a custom span with request info
+/// Create a wrapping filter that instruments every request with a custom
+/// `tracing` [`Span`] provided by a function.
+///
 ///
 /// # Example
 ///
@@ -60,6 +74,8 @@ pub fn tracing() -> Trace<impl Fn(Info) -> Span + Clone> {
 ///     .map(warp::reply)
 ///     .with(tracing);
 /// ```
+///
+/// [`Span`]: https://docs.rs/tracing/latest/tracing/#spans
 pub fn custom<F>(func: F) -> Trace<F>
 where
     F: Fn(Info) -> Span + Clone,
@@ -68,7 +84,7 @@ where
 }
 
 /// Create a wrapping filter that instruments every request with a `tracing`
-/// [`Span`] at the `DEBUG` level representing a named context.
+/// [`Span`] at the [`DEBUG`] level representing a named context.
 ///
 /// This can be used to instrument multiple routes with their own sub-spans in a
 /// per-request trace.
@@ -90,6 +106,7 @@ where
 /// ```
 ///
 /// [`Span`]: https://docs.rs/tracing/latest/tracing/#spans
+/// [`DEBUG`]: https://docs.rs/tracing/0.1.16/tracing/struct.Level.html#associatedconstant.DEBUG
 pub fn context(name: &'static str) -> Trace<impl Fn(Info<'_>) -> tracing::Span + Copy> {
     custom(move |_| {
         tracing::debug_span!(
@@ -100,7 +117,11 @@ pub fn context(name: &'static str) -> Trace<impl Fn(Info<'_>) -> tracing::Span +
     })
 }
 
-/// Decorates a [`Filter`](::Filter) to log requests and responses.
+/// Decorates a [`Filter`](crate::Filter) to create a [`tracing`] [span] for
+/// requests and responses.
+///
+/// [`tracing`]: https://crates.io/tracing
+/// [span]: https://docs.rs/tracing/latest/tracing/#spans
 #[derive(Clone, Copy, Debug)]
 pub struct Trace<F> {
     func: F,

From 9f93422ccbd9a0ccbefe282b01da115e0c029cc7 Mon Sep 17 00:00:00 2001
From: Eliza Weisman <eliza@buoyant.io>
Date: Thu, 16 Jul 2020 11:38:34 -0700
Subject: [PATCH 10/26] avoid enter/exit/span clone in WithTrace

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
---
 src/filters/tracing.rs | 5 ++---
 1 file changed, 2 insertions(+), 3 deletions(-)

diff --git a/src/filters/tracing.rs b/src/filters/tracing.rs
index c366fae25..58dfb8fc0 100644
--- a/src/filters/tracing.rs
+++ b/src/filters/tracing.rs
@@ -293,14 +293,13 @@ mod internal {
 
         fn filter(&self, _: Internal) -> Self::Future {
             let span = route::with(|route| (self.trace.func)(Info { route }));
-            let _guard = span.enter();
 
-            tracing::info!(target: "warp::filters::tracing", "processing request");
+            tracing::info!(target: "warp::filters::tracing", parent: &span, "processing request");
             self.filter
                 .filter(Internal)
                 .map_ok(convert_reply as fn(F::Extract) -> Self::Extract)
                 .inspect(finished_logger as fn(&Result<Self::Extract, F::Error>))
-                .in_current_span()
+                .instrument(span)
         }
     }
 }

From e8fde2de68a2d0e0f941ccf40a5cec864f0b0d67 Mon Sep 17 00:00:00 2001
From: Eliza Weisman <eliza@buoyant.io>
Date: Thu, 16 Jul 2020 11:50:22 -0700
Subject: [PATCH 11/26] oh, never mind, that doesn't work

...we can still avoid round-tripping through the subscriber to clone the
span, though.

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
---
 src/filters/tracing.rs | 5 +++--
 1 file changed, 3 insertions(+), 2 deletions(-)

diff --git a/src/filters/tracing.rs b/src/filters/tracing.rs
index 58dfb8fc0..a92bb414c 100644
--- a/src/filters/tracing.rs
+++ b/src/filters/tracing.rs
@@ -293,13 +293,14 @@ mod internal {
 
         fn filter(&self, _: Internal) -> Self::Future {
             let span = route::with(|route| (self.trace.func)(Info { route }));
+            let _entered = span.enter();
 
-            tracing::info!(target: "warp::filters::tracing", parent: &span, "processing request");
+            tracing::info!(target: "warp::filters::tracing", "processing request");
             self.filter
                 .filter(Internal)
                 .map_ok(convert_reply as fn(F::Extract) -> Self::Extract)
                 .inspect(finished_logger as fn(&Result<Self::Extract, F::Error>))
-                .instrument(span)
+                .instrument(span.clone())
         }
     }
 }

From 89aabce514a95d8e473bfe7117681f6f7556c731 Mon Sep 17 00:00:00 2001
From: Eliza Weisman <eliza@buoyant.io>
Date: Thu, 16 Jul 2020 11:54:38 -0700
Subject: [PATCH 12/26] nicer handling of optional fields

we are not building an access log with our structured fields

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
---
 src/filters/tracing.rs | 27 +++++++++++++++++++++------
 1 file changed, 21 insertions(+), 6 deletions(-)

diff --git a/src/filters/tracing.rs b/src/filters/tracing.rs
index a92bb414c..32a10ecf9 100644
--- a/src/filters/tracing.rs
+++ b/src/filters/tracing.rs
@@ -38,17 +38,32 @@ use self::internal::WithTrace;
 /// [`Span`]: https://docs.rs/tracing/latest/tracing/#spans
 /// [`INFO`]: https://docs.rs/tracing/0.1.16/tracing/struct.Level.html#associatedconstant.INFO
 pub fn tracing() -> Trace<impl Fn(Info) -> Span + Clone> {
+    use tracing::field::{display, Empty};
     let func = move |info: Info| {
-        tracing::info_span!(
+        let span = tracing::info_span!(
             "request",
-            remote_addr = %OptFmt(info.route.remote_addr()),
+            remote_addr = Empty,
             method = %info.method(),
             path = %info.path(),
             version = ?info.route.version(),
-            // status = %info.status().as_u16(),
-            referer = %OptFmt(info.referer()),
-            user_agent = %OptFmt(info.user_agent()),
-        )
+            referer = Empty,
+            user_agent = Empty,
+        );
+
+        // Record optional fields.
+        if let Some(remote_addr) = info.remote_addr() {
+            span.record("remote_addr", &display(remote_addr));
+        }
+
+        if let Some(referer) = info.referer() {
+            span.record("referer", &display(referer));
+        }
+
+        if let Some(user_agent) = info.user_agent() {
+            span.record("user_agent", &display(user_agent));
+        }
+
+        span
     };
     Trace { func }
 }

From 00768b6255ba8da637b6c677c6608c9e87d99e86 Mon Sep 17 00:00:00 2001
From: Eliza Weisman <eliza@buoyant.io>
Date: Thu, 16 Jul 2020 12:00:37 -0700
Subject: [PATCH 13/26] docs fixup

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
---
 src/filters/tracing.rs | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/src/filters/tracing.rs b/src/filters/tracing.rs
index 32a10ecf9..7c05eebac 100644
--- a/src/filters/tracing.rs
+++ b/src/filters/tracing.rs
@@ -1,6 +1,6 @@
 //! [`tracing`] filters.
 //!
-//! [`tracing`] tracing is a framework for instrumenting Rust programs to
+//! [`tracing`] is a framework for instrumenting Rust programs to
 //! collect scoped, structured, and async-aware diagnostics. This module
 //! provides a set of filters for instrumenting Warp applications with `tracing`
 //! spans. [Spans] can be used to associate individual events  with a request,

From 9bbd2a4ee4c4c97a7b282810c4ff69e24a244c99 Mon Sep 17 00:00:00 2001
From: Eliza Weisman <eliza@buoyant.io>
Date: Thu, 16 Jul 2020 12:01:18 -0700
Subject: [PATCH 14/26] add a nice example

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
---
 Cargo.toml          |  1 +
 examples/README.md  |  4 +++
 examples/tracing.rs | 59 +++++++++++++++++++++++++++++++++++++++++++++
 3 files changed, 64 insertions(+)
 create mode 100644 examples/tracing.rs

diff --git a/Cargo.toml b/Cargo.toml
index d52eb83bb..40e1166c6 100644
--- a/Cargo.toml
+++ b/Cargo.toml
@@ -43,6 +43,7 @@ tokio-rustls = { version = "0.13.1", optional = true }
 
 [dev-dependencies]
 pretty_env_logger = "0.4"
+tracing-subscriber = "0.2.7"
 serde_derive = "1.0"
 handlebars = "3.0.0"
 tokio = { version = "0.2", features = ["macros"] }
diff --git a/examples/README.md b/examples/README.md
index 3f5ecb95e..2c7ddc2b4 100644
--- a/examples/README.md
+++ b/examples/README.md
@@ -39,3 +39,7 @@ Hooray! `warp` also includes built-in support for WebSockets
 ### Autoreloading
 
 - [`autoreload.rs`](./autoreload.rs) - Change some code and watch the server reload automatically!
+
+### Debugging
+
+- [`tracing.rs`](./tracing.rs) - Warp has built-in support for rich diagnostics with [`tracing`](https://docs.rs/tracing)!
\ No newline at end of file
diff --git a/examples/tracing.rs b/examples/tracing.rs
new file mode 100644
index 000000000..98c302278
--- /dev/null
+++ b/examples/tracing.rs
@@ -0,0 +1,59 @@
+//! [`tracing`] is a framework for instrumenting Rust programs to
+//! collect scoped, structured, and async-aware diagnostics. This example
+//! demonstrates how the `warp::tracing` module can be used to instrument `warp`
+//! applications with `tracing`.
+//!
+//! [`tracing`]: https://crates.io/tracing
+#![deny(warnings)]
+use tracing_subscriber::fmt::format::FmtSpan;
+use warp::Filter;
+
+#[tokio::main]
+async fn main() {
+    // Filter traces based on the RUST_LOG env var, or, if it's not set,
+    // default to show the output of the example.
+    let filter = std::env::var("RUST_LOG").unwrap_or_else(|_| "tracing=info,warp=debug".to_owned());
+
+    // Configure the default `tracing` subscriber.
+    // The `fmt` subscriber from the `tracing-subscriber` crate logs `tracing`
+    // events to stdout. Other subscribers are available for integrating with
+    // distributed tracing systems such as OpenTelemetry.
+    tracing_subscriber::fmt()
+        // Use the filter we built above to determine which traces to record.
+        .with_env_filter(filter)
+        // Record an event when each span closes. This can be used to time our
+        // routes' durations!
+        .with_span_events(FmtSpan::CLOSE)
+        .init();
+
+    let hello = warp::path("hello")
+        .and(warp::get())
+        // When the `hello` route is called, emit a `tracing` event.
+        .map(|| {
+            tracing::info!("saying hello...");
+            "Hello, World!"
+        })
+        // Wrap the route in a `tracing` span to add the route's name as context
+        // to any events that occur inside it.
+        .with(warp::tracing::context("hello"));
+
+    let goodbye = warp::path("goodbye")
+        .and(warp::get())
+        .map(|| {
+            tracing::info!("saying goodbye...");
+            "So long and thanks for all the fish!"
+        })
+        // We can also provide our own custom `tracing` spans to wrap a route.
+        .with(warp::tracing::custom(|info| {
+            // Construct our own custom span for this route.
+            tracing::info_span!("goodbye", req.path = ?info.path())
+        }));
+
+    let routes = hello
+        .or(goodbye)
+        // Wrap all the routes with a filter that creates a `tracing` span for
+        // each request we receive, including data about the request.
+        .with(warp::tracing());
+
+    warp::serve(routes).run(([127, 0, 0, 1], 3030)).await;
+}

From 9081ba778ad3789f508de83d8ebb06e6e26946fa Mon Sep 17 00:00:00 2001
From: Eliza Weisman <eliza@buoyant.io>
Date: Thu, 16 Jul 2020 12:05:33 -0700
Subject: [PATCH 15/26] API naming pass

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
---
 examples/tracing.rs                  |  8 +++----
 src/filters/mod.rs                   |  2 +-
 src/filters/{tracing.rs => trace.rs} | 36 +++++++++++++---------------
 src/lib.rs                           |  6 ++---
 tests/tracing.rs                     |  2 +-
 5 files changed, 26 insertions(+), 28 deletions(-)
 rename src/filters/{tracing.rs => trace.rs} (92%)

diff --git a/examples/tracing.rs b/examples/tracing.rs
index 98c302278..1e0ecd384 100644
--- a/examples/tracing.rs
+++ b/examples/tracing.rs
@@ -1,6 +1,6 @@
 //! [`tracing`] is a framework for instrumenting Rust programs to
 //! collect scoped, structured, and async-aware diagnostics. This example
-//! demonstrates how the `warp::tracing` module can be used to instrument `warp`
+//! demonstrates how the `warp::trace` module can be used to instrument `warp`
 //! applications with `tracing`.
 //!
 //! [`tracing`]: https://crates.io/tracing
@@ -35,7 +35,7 @@ async fn main() {
         })
         // Wrap the route in a `tracing` span to add the route's name as context
         // to any events that occur inside it.
-        .with(warp::tracing::context("hello"));
+        .with(warp::trace::named("hello"));
 
     let goodbye = warp::path("goodbye")
         .and(warp::get())
@@ -44,7 +44,7 @@ async fn main() {
             "So long and thanks for all the fish!"
         })
         // We can also provide our own custom `tracing` spans to wrap a route.
-        .with(warp::tracing::custom(|info| {
+        .with(warp::trace(|info| {
             // Construct our own custom span for this route.
             tracing::info_span!("goodbye", req.path = ?info.path())
         }));
@@ -53,7 +53,7 @@ async fn main() {
         .or(goodbye)
         // Wrap all the routes with a filter that creates a `tracing` span for
         // each request we receive, including data about the request.
-        .with(warp::tracing());
+        .with(warp::trace::request());
 
     warp::serve(routes).run(([127, 0, 0, 1], 3030)).await;
 }
diff --git a/src/filters/mod.rs b/src/filters/mod.rs
index 1be00a070..4e7a9208a 100644
--- a/src/filters/mod.rs
+++ b/src/filters/mod.rs
@@ -21,7 +21,7 @@ pub mod path;
 pub mod query;
 pub mod reply;
 pub mod sse;
-pub mod tracing;
+pub mod trace;
 #[cfg(feature = "websocket")]
 pub mod ws;
 
diff --git a/src/filters/tracing.rs b/src/filters/trace.rs
similarity index 92%
rename from src/filters/tracing.rs
rename to src/filters/trace.rs
index 7c05eebac..751d5cd83 100644
--- a/src/filters/tracing.rs
+++ b/src/filters/trace.rs
@@ -32,14 +32,14 @@ use self::internal::WithTrace;
 ///
 /// let route = warp::any()
 ///     .map(warp::reply)
-///     .with(warp::tracing());
+///     .with(warp::trace::request);
 /// ```
 ///
 /// [`Span`]: https://docs.rs/tracing/latest/tracing/#spans
 /// [`INFO`]: https://docs.rs/tracing/0.1.16/tracing/struct.Level.html#associatedconstant.INFO
-pub fn tracing() -> Trace<impl Fn(Info) -> Span + Clone> {
+pub fn request() -> Trace<impl Fn(Info) -> Span + Clone> {
     use tracing::field::{display, Empty};
-    let func = move |info: Info| {
+    trace(|info: Info| {
         let span = tracing::info_span!(
             "request",
             remote_addr = Empty,
@@ -64,8 +64,7 @@ pub fn tracing() -> Trace<impl Fn(Info) -> Span + Clone> {
         }
 
         span
-    };
-    Trace { func }
+    })
 }
 
 /// Create a wrapping filter that instruments every request with a custom
@@ -77,21 +76,20 @@ pub fn tracing() -> Trace<impl Fn(Info) -> Span + Clone> {
 /// ```
 /// use warp::Filter;
 ///
-/// let tracing = warp::tracing::custom(|info| {
-///     // Create a span using tracing macros
-///     tracing::info_span!(
-///         "request",
-///         method = %info.method(),
-///         path = %info.path(),
-///     )
-/// });
 /// let route = warp::any()
 ///     .map(warp::reply)
-///     .with(tracing);
+///     .with(warp::trace(|info| {
+///         // Create a span using tracing macros
+///         tracing::info_span!(
+///             "request",
+///             method = %info.method(),
+///             path = %info.path(),
+///         )
+///     });
 /// ```
 ///
 /// [`Span`]: https://docs.rs/tracing/latest/tracing/#spans
-pub fn custom<F>(func: F) -> Trace<F>
+pub fn trace<F>(func: F) -> Trace<F>
 where
     F: Fn(Info) -> Span + Clone,
 {
@@ -111,19 +109,19 @@ where
 ///
 /// let hello = warp::path("hello")
 ///     .map(warp::reply)
-///     .with(warp::tracing::context("hello"));
+///     .with(warp::trace::named("hello"));
 ///
 /// let goodbye = warp::path("goodbye")
 ///     .map(warp::reply)
-///     .with(warp::tracing::context("goodbye"));
+///     .with(warp::trace::named("goodbye"));
 ///
 /// let routes = hello.or(goodbye);
 /// ```
 ///
 /// [`Span`]: https://docs.rs/tracing/latest/tracing/#spans
 /// [`DEBUG`]: https://docs.rs/tracing/0.1.16/tracing/struct.Level.html#associatedconstant.DEBUG
-pub fn context(name: &'static str) -> Trace<impl Fn(Info<'_>) -> tracing::Span + Copy> {
-    custom(move |_| {
+pub fn named(name: &'static str) -> Trace<impl Fn(Info<'_>) -> Span + Copy> {
+    trace(move |_| {
         tracing::debug_span!(
             target: "warp",
             "context",
diff --git a/src/lib.rs b/src/lib.rs
index 518fab389..28874f088 100644
--- a/src/lib.rs
+++ b/src/lib.rs
@@ -143,9 +143,9 @@ pub use self::filters::{
     // query() function
     query::query,
     sse,
-    tracing,
-    // tracing() function
-    tracing::tracing,
+    trace,
+    // trace() function
+    trace::trace,
 };
 // ws() function
 #[cfg(feature = "websocket")]
diff --git a/tests/tracing.rs b/tests/tracing.rs
index 6cd77cdfd..361433bd1 100644
--- a/tests/tracing.rs
+++ b/tests/tracing.rs
@@ -32,7 +32,7 @@ async fn uses_tracing() {
         .map(warp::reply)
         // Here we add the tracing logger which will ensure that all requests has a span with
         // useful information about the request (method, url, version, remote_addr, etc.)
-        .with(warp::tracing());
+        .with(warp::trace());
 
     tracing::info!("logged using tracing macro");
 

From 50d5bd6eb4dfada20dc74ea26622bc8c59179679 Mon Sep 17 00:00:00 2001
From: Eliza Weisman <eliza@buoyant.io>
Date: Thu, 16 Jul 2020 14:41:22 -0700
Subject: [PATCH 16/26] whoops, i broke a test from #408

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
---
 Cargo.toml       | 1 +
 tests/tracing.rs | 2 +-
 2 files changed, 2 insertions(+), 1 deletion(-)

diff --git a/Cargo.toml b/Cargo.toml
index 40e1166c6..f4273f024 100644
--- a/Cargo.toml
+++ b/Cargo.toml
@@ -44,6 +44,7 @@ tokio-rustls = { version = "0.13.1", optional = true }
 [dev-dependencies]
 pretty_env_logger = "0.4"
 tracing-subscriber = "0.2.7"
+tracing-log = "0.1"
 serde_derive = "1.0"
 handlebars = "3.0.0"
 tokio = { version = "0.2", features = ["macros"] }
diff --git a/tests/tracing.rs b/tests/tracing.rs
index 361433bd1..0ae88fbc3 100644
--- a/tests/tracing.rs
+++ b/tests/tracing.rs
@@ -32,7 +32,7 @@ async fn uses_tracing() {
         .map(warp::reply)
         // Here we add the tracing logger which will ensure that all requests has a span with
         // useful information about the request (method, url, version, remote_addr, etc.)
-        .with(warp::trace());
+        .with(warp::trace::request());
 
     tracing::info!("logged using tracing macro");
 

From c7c1828c089a86878c9d237d2b30d65276167a02 Mon Sep 17 00:00:00 2001
From: Eliza Weisman <eliza@buoyant.io>
Date: Thu, 16 Jul 2020 15:22:36 -0700
Subject: [PATCH 17/26] close unclosed delimiter

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
---
 src/filters/trace.rs | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/src/filters/trace.rs b/src/filters/trace.rs
index 751d5cd83..6fbc3acc4 100644
--- a/src/filters/trace.rs
+++ b/src/filters/trace.rs
@@ -85,7 +85,7 @@ pub fn request() -> Trace<impl Fn(Info) -> Span + Clone> {
 ///             method = %info.method(),
 ///             path = %info.path(),
 ///         )
-///     });
+///     }));
 /// ```
 ///
 /// [`Span`]: https://docs.rs/tracing/latest/tracing/#spans

From 783e314000a1a0533f21f2b9e2ae58feabc36619 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Jo=C3=A3o=20Oliveira?= <hello@jxs.pt>
Date: Fri, 17 Jul 2020 02:49:54 +0100
Subject: [PATCH 18/26] fix trace::request doc

---
 src/filters/trace.rs | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/src/filters/trace.rs b/src/filters/trace.rs
index 6fbc3acc4..ae25aa370 100644
--- a/src/filters/trace.rs
+++ b/src/filters/trace.rs
@@ -32,7 +32,7 @@ use self::internal::WithTrace;
 ///
 /// let route = warp::any()
 ///     .map(warp::reply)
-///     .with(warp::trace::request);
+///     .with(warp::trace::request());
 /// ```
 ///
 /// [`Span`]: https://docs.rs/tracing/latest/tracing/#spans

From 7a2df5631cab2b99be04cb08711baa5d6a414f31 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Jo=C3=A3o=20Oliveira?= <hello@jxs.pt>
Date: Fri, 17 Jul 2020 03:12:26 +0100
Subject: [PATCH 19/26] fix trace filter Spans link

---
 src/filters/trace.rs | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/src/filters/trace.rs b/src/filters/trace.rs
index ae25aa370..aeae51929 100644
--- a/src/filters/trace.rs
+++ b/src/filters/trace.rs
@@ -3,11 +3,11 @@
 //! [`tracing`] is a framework for instrumenting Rust programs to
 //! collect scoped, structured, and async-aware diagnostics. This module
 //! provides a set of filters for instrumenting Warp applications with `tracing`
-//! spans. [Spans] can be used to associate individual events  with a request,
+//! spans. [`Spans`] can be used to associate individual events  with a request,
 //! and track contexts through the application.
 //!
 //! [`tracing`]: https://crates.io/tracing
-/// [Spans]: https://docs.rs/tracing/latest/tracing/#spans
+//! [`Spans`]: https://docs.rs/tracing/latest/tracing/#spans
 use tracing::Span;
 
 use std::fmt;

From dcc57fdcf9725560fbfd0fdb961ebb79e5c249c0 Mon Sep 17 00:00:00 2001
From: William Main <william.c.main@gmail.com>
Date: Thu, 16 Jul 2020 20:54:30 -0700
Subject: [PATCH 20/26] Make MissingConnectionUpgrade public (#653) (#654)

Co-authored-by: Billy Main <wmain@netflix.com>
---
 src/filters/ws.rs | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/src/filters/ws.rs b/src/filters/ws.rs
index 20f37af83..bbd1836d2 100644
--- a/src/filters/ws.rs
+++ b/src/filters/ws.rs
@@ -363,8 +363,9 @@ impl Into<Vec<u8>> for Message {
 
 // ===== Rejections =====
 
+/// Connection header did not include 'upgrade'
 #[derive(Debug)]
-pub(crate) struct MissingConnectionUpgrade;
+pub struct MissingConnectionUpgrade;
 
 impl ::std::fmt::Display for MissingConnectionUpgrade {
     fn fmt(&self, f: &mut ::std::fmt::Formatter) -> ::std::fmt::Result {

From 1a939213da4fd640359f6b237fba51d029359c79 Mon Sep 17 00:00:00 2001
From: Eliza Weisman <eliza@buoyant.io>
Date: Fri, 17 Jul 2020 09:54:55 -0700
Subject: [PATCH 21/26] make targets match module path

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
---
 src/filters/trace.rs | 10 +++++-----
 1 file changed, 5 insertions(+), 5 deletions(-)

diff --git a/src/filters/trace.rs b/src/filters/trace.rs
index aeae51929..8e6bb1c98 100644
--- a/src/filters/trace.rs
+++ b/src/filters/trace.rs
@@ -254,11 +254,11 @@ mod internal {
     fn finished_logger<E: IsReject>(reply: &Result<(Traced,), E>) {
         match reply {
             Ok((Traced(resp),)) => {
-                tracing::info!(target: "warp::filters::tracing", status = resp.status().as_u16(), "finished processing with success");
+                tracing::info!(target: "warp::filters::trace", status = resp.status().as_u16(), "finished processing with success");
             }
             Err(e) if e.status().is_server_error() => {
                 tracing::error!(
-                    target: "warp::filters::tracing",
+                    target: "warp::filters::trace",
                     status = e.status().as_u16(),
                     error = ?e,
                     "unable to process request (internal error)"
@@ -266,7 +266,7 @@ mod internal {
             }
             Err(e) if e.status().is_client_error() => {
                 tracing::warn!(
-                    target: "warp::filters::tracing",
+                    target: "warp::filters::trace",
                     status = e.status().as_u16(),
                     error = ?e,
                     "unable to serve request (client error)"
@@ -275,7 +275,7 @@ mod internal {
             Err(e) => {
                 // Either informational or redirect
                 tracing::info!(
-                    target: "warp::filters::tracing",
+                    target: "warp::filters::trace",
                     status = e.status().as_u16(),
                     result = ?e,
                     "finished processing with status"
@@ -308,7 +308,7 @@ mod internal {
             let span = route::with(|route| (self.trace.func)(Info { route }));
             let _entered = span.enter();
 
-            tracing::info!(target: "warp::filters::tracing", "processing request");
+            tracing::info!(target: "warp::filters::trace", "processing request");
             self.filter
                 .filter(Internal)
                 .map_ok(convert_reply as fn(F::Extract) -> Self::Extract)

From f3e676aa4104e7a9c900274fac4886bb8c984278 Mon Sep 17 00:00:00 2001
From: Eliza Weisman <eliza@buoyant.io>
Date: Fri, 17 Jul 2020 09:55:37 -0700
Subject: [PATCH 22/26] rm dead code

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
---
 src/filters/trace.rs | 13 -------------
 1 file changed, 13 deletions(-)

diff --git a/src/filters/trace.rs b/src/filters/trace.rs
index 8e6bb1c98..a7dfcde03 100644
--- a/src/filters/trace.rs
+++ b/src/filters/trace.rs
@@ -10,7 +10,6 @@
 //! [`Spans`]: https://docs.rs/tracing/latest/tracing/#spans
 use tracing::Span;
 
-use std::fmt;
 use std::net::SocketAddr;
 
 use http::{self, header};
@@ -209,18 +208,6 @@ impl<'a> Info<'a> {
     }
 }
 
-struct OptFmt<T>(Option<T>);
-
-impl<T: fmt::Display> fmt::Display for OptFmt<T> {
-    fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
-        if let Some(ref t) = self.0 {
-            fmt::Display::fmt(t, f)
-        } else {
-            f.write_str("-")
-        }
-    }
-}
-
 mod internal {
     use futures::{future::Inspect, future::MapOk, FutureExt, TryFutureExt};
 

From d5aa75d2237c7442c6b13899a224cdc76a04835b Mon Sep 17 00:00:00 2001
From: Eliza Weisman <eliza@buoyant.io>
Date: Fri, 17 Jul 2020 10:28:00 -0700
Subject: [PATCH 23/26] move more verbose request data to a debug event

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
---
 src/filters/trace.rs | 17 +++++++++++++++--
 1 file changed, 15 insertions(+), 2 deletions(-)

diff --git a/src/filters/trace.rs b/src/filters/trace.rs
index a7dfcde03..26b330684 100644
--- a/src/filters/trace.rs
+++ b/src/filters/trace.rs
@@ -46,7 +46,6 @@ pub fn request() -> Trace<impl Fn(Info) -> Span + Clone> {
             path = %info.path(),
             version = ?info.route.version(),
             referer = Empty,
-            user_agent = Empty,
         );
 
         // Record optional fields.
@@ -58,8 +57,17 @@ pub fn request() -> Trace<impl Fn(Info) -> Span + Clone> {
             span.record("referer", &display(referer));
         }
 
+        // The user agent string and the headers are, potentially, quite long,
+        // so let's record them in an event within the generated span, rather
+        // than including them as context on *every* request.
         if let Some(user_agent) = info.user_agent() {
-            span.record("user_agent", &display(user_agent));
+            tracing::debug!(
+                user_agent, headers = ?info.headers(), "received request"
+            );
+        } else {
+            tracing::debug!(
+                headers = ?info.headers(), "received request"
+            );
         }
 
         span
@@ -206,6 +214,11 @@ impl<'a> Info<'a> {
             .get(header::HOST)
             .and_then(|v| v.to_str().ok())
     }
+
+    /// View the request headers.
+    pub fn headers(&self) -> &http::HeaderMap {
+        self.route.headers()
+    }
 }
 
 mod internal {

From 45e357f1365bb83c9c137408e23fde103d8f0476 Mon Sep 17 00:00:00 2001
From: Eliza Weisman <eliza@buoyant.io>
Date: Fri, 17 Jul 2020 10:29:37 -0700
Subject: [PATCH 24/26] dotted field for remote addr

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
---
 src/filters/trace.rs | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/src/filters/trace.rs b/src/filters/trace.rs
index 26b330684..4cf47a39b 100644
--- a/src/filters/trace.rs
+++ b/src/filters/trace.rs
@@ -41,7 +41,7 @@ pub fn request() -> Trace<impl Fn(Info) -> Span + Clone> {
     trace(|info: Info| {
         let span = tracing::info_span!(
             "request",
-            remote_addr = Empty,
+            remote.addr = Empty,
             method = %info.method(),
             path = %info.path(),
             version = ?info.route.version(),
@@ -50,7 +50,7 @@ pub fn request() -> Trace<impl Fn(Info) -> Span + Clone> {
 
         // Record optional fields.
         if let Some(remote_addr) = info.remote_addr() {
-            span.record("remote_addr", &display(remote_addr));
+            span.record("remote.addr", &display(remote_addr));
         }
 
         if let Some(referer) = info.referer() {

From 8502c9c82af1e813fbb73af9b92bf6d4c31c5a26 Mon Sep 17 00:00:00 2001
From: Eliza Weisman <eliza@buoyant.io>
Date: Fri, 17 Jul 2020 10:30:26 -0700
Subject: [PATCH 25/26] fix `named` having a different target

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
---
 src/filters/trace.rs | 8 +-------
 1 file changed, 1 insertion(+), 7 deletions(-)

diff --git a/src/filters/trace.rs b/src/filters/trace.rs
index 4cf47a39b..cb116e6f6 100644
--- a/src/filters/trace.rs
+++ b/src/filters/trace.rs
@@ -128,13 +128,7 @@ where
 /// [`Span`]: https://docs.rs/tracing/latest/tracing/#spans
 /// [`DEBUG`]: https://docs.rs/tracing/0.1.16/tracing/struct.Level.html#associatedconstant.DEBUG
 pub fn named(name: &'static str) -> Trace<impl Fn(Info<'_>) -> Span + Copy> {
-    trace(move |_| {
-        tracing::debug_span!(
-            target: "warp",
-            "context",
-            "{}", name,
-        )
-    })
+    trace(move |_| tracing::debug_span!("context", "{}", name,))
 }
 
 /// Decorates a [`Filter`](crate::Filter) to create a [`tracing`] [span] for

From 2c0cd19b99b4fbdfefcf1916df6dd32975d86bca Mon Sep 17 00:00:00 2001
From: Eliza Weisman <eliza@buoyant.io>
Date: Fri, 17 Jul 2020 11:00:33 -0700
Subject: [PATCH 26/26] don't duplicate user-agents

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
---
 src/filters/trace.rs | 19 +++++++------------
 1 file changed, 7 insertions(+), 12 deletions(-)

diff --git a/src/filters/trace.rs b/src/filters/trace.rs
index cb116e6f6..7a0f63459 100644
--- a/src/filters/trace.rs
+++ b/src/filters/trace.rs
@@ -23,6 +23,8 @@ use self::internal::WithTrace;
 
 /// Create a wrapping filter that instruments every request with a `tracing`
 /// [`Span`] at the [`INFO`] level, containing a summary of the request.
+/// Additionally, if the [`DEBUG`] level is enabled, the span will contain an
+/// event recording the request's headers.
 ///
 /// # Example
 ///
@@ -36,6 +38,7 @@ use self::internal::WithTrace;
 ///
 /// [`Span`]: https://docs.rs/tracing/latest/tracing/#spans
 /// [`INFO`]: https://docs.rs/tracing/0.1.16/tracing/struct.Level.html#associatedconstant.INFO
+/// [`DEBUG`]: https://docs.rs/tracing/0.1.16/tracing/struct.Level.html#associatedconstant.DEBUG
 pub fn request() -> Trace<impl Fn(Info) -> Span + Clone> {
     use tracing::field::{display, Empty};
     trace(|info: Info| {
@@ -57,18 +60,10 @@ pub fn request() -> Trace<impl Fn(Info) -> Span + Clone> {
             span.record("referer", &display(referer));
         }
 
-        // The user agent string and the headers are, potentially, quite long,
-        // so let's record them in an event within the generated span, rather
-        // than including them as context on *every* request.
-        if let Some(user_agent) = info.user_agent() {
-            tracing::debug!(
-                user_agent, headers = ?info.headers(), "received request"
-            );
-        } else {
-            tracing::debug!(
-                headers = ?info.headers(), "received request"
-            );
-        }
+        // The the headers are, potentially, quite long, so let's record them in
+        // an event within the generated span, rather than including them as
+        // context on *every* request.
+        tracing::debug!(parent: &span, headers = ?info.headers(), "received request");
 
         span
     })