From 3b141de434795801babf0a90668d9bd2b38bd2eb Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Thu, 16 Jul 2020 10:10:46 -0700 Subject: [PATCH 1/3] migrate internal diagnostics to `tracing` Signed-off-by: Eliza Weisman --- 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; pub(crate) fn body() -> impl Filter + 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 + Copy pub fn content_length_limit(limit: u64) -> impl Filter + 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 + 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 + Copy { pub fn aggregate() -> impl Filter + 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() -> impl Filter() -> impl Filter() -> impl Filter 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() -> impl Filter 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() -> impl Filter 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) -> impl FilterClone, 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, tail: &str) -> Result 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, 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( name: &'static str, ) -> impl Filter, 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( pub(crate) fn header2( ) -> impl Filter, 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::() .and_then(|val| if val == header { @@ -139,7 +139,7 @@ pub fn exact( value: &'static str, ) -> impl Filter + 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 + 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, 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 + Copy { pub fn param( ) -> impl Filter, 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( ) -> impl Filter, 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 SseFormat for SseJson { 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 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 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 >::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 + '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 + '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 Date: Thu, 16 Jul 2020 11:15:32 -0700 Subject: [PATCH 2/3] add tracing spans to servers Signed-off-by: Eliza Weisman --- 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 + '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>, { 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(self, incoming: I) @@ -445,10 +451,10 @@ where /// *This function requires the `"tls"` feature.* pub async fn run(self, addr: impl Into + '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 Date: Thu, 16 Jul 2020 11:22:12 -0700 Subject: [PATCH 3/3] whoops, forgot the `tracing-futures` dep Signed-off-by: Eliza Weisman --- 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 }