Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

tracing: make Entered !Send #1001

Merged
merged 5 commits into from
Sep 30, 2020
Merged
Show file tree
Hide file tree
Changes from 4 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
126 changes: 61 additions & 65 deletions examples/examples/hyper-echo.rs
Original file line number Diff line number Diff line change
Expand Up @@ -16,78 +16,75 @@ async fn echo(req: Request<Body>) -> Result<Response<Body>, hyper::Error> {
uri = ?req.uri(),
headers = ?req.headers()
);
let _enter = span.enter();
info!("received request");
let mut response = Response::new(Body::empty());
async move {
info!("received request");
let mut response = Response::new(Body::empty());

let (rsp_span, resp) = match (req.method(), req.uri().path()) {
// Serve some instructions at /
(&Method::GET, "/") => {
const BODY: &str = "Try POSTing data to /echo";
*response.body_mut() = Body::from(BODY);
(span!(Level::INFO, "response", body = %(&BODY)), response)
}
match (req.method(), req.uri().path()) {
// Serve some instructions at /
(&Method::GET, "/") => {
const BODY: &str = "Try POSTing data to /echo";
*response.body_mut() = Body::from(BODY);
info!(body = %(&BODY), "response",);
Ok(response)
}

// Simply echo the body back to the client.
(&Method::POST, "/echo") => {
let span = span!(Level::INFO, "response", response_kind = %"echo");
*response.body_mut() = req.into_body();
(span, response)
}
// Simply echo the body back to the client.
(&Method::POST, "/echo") => {
info!(response_kind = %"echo", "response");
*response.body_mut() = req.into_body();
Ok(response)
}

// Convert to uppercase before sending back to client.
(&Method::POST, "/echo/uppercase") => {
let body = hyper::body::to_bytes(req).await?;
let upper = body
.iter()
.map(|byte| byte.to_ascii_uppercase())
.collect::<Vec<u8>>();
debug!(
body = ?str::from_utf8(&body[..]),
uppercased = ?str::from_utf8(&upper[..]),
"uppercased request body"
);
// Convert to uppercase before sending back to client.
(&Method::POST, "/echo/uppercase") => {
let body = hyper::body::to_bytes(req).await?;
let upper = body
.iter()
.map(|byte| byte.to_ascii_uppercase())
.collect::<Vec<u8>>();
debug!(
body = ?str::from_utf8(&body[..]),
uppercased = ?str::from_utf8(&upper[..]),
"uppercased request body"
);

*response.body_mut() = Body::from(upper);
(
span!(Level::INFO, "response", response_kind = %"uppercase"),
response,
)
}
info!(response_kind = %"uppercase", "response");
*response.body_mut() = Body::from(upper);
Ok(response)
}

// Reverse the entire body before sending back to the client.
(&Method::POST, "/echo/reversed") => {
let span = span!(Level::TRACE, "response", response_kind = %"reversed");
let _enter = span.enter();
let body = hyper::body::to_bytes(req).await?;
let reversed = body.iter().rev().cloned().collect::<Vec<u8>>();
debug!(
body = ?str::from_utf8(&body[..]),
"reversed request body"
);
*response.body_mut() = Body::from(reversed);
(
span!(Level::INFO, "reversed", body = ?(&response.body())),
response,
)
}
// Reverse the entire body before sending back to the client.
(&Method::POST, "/echo/reversed") => {
async move {
let body = hyper::body::to_bytes(req).await?;
let reversed = body.iter().rev().cloned().collect::<Vec<u8>>();
debug!(
body = ?str::from_utf8(&body[..]),
"reversed request body"
);
*response.body_mut() = Body::from(reversed);
info!(body = ?(&response.body()), "response");
Ok(response)
}
.instrument(span!(Level::TRACE, "response", response_kind = %"reversed"))
.await
}

// The 404 Not Found route...
_ => {
*response.status_mut() = StatusCode::NOT_FOUND;
(
span!(
Level::TRACE,
"response",
// The 404 Not Found route...
_ => {
*response.status_mut() = StatusCode::NOT_FOUND;
info!(
body = ?(),
status = ?StatusCode::NOT_FOUND,
),
response,
)
"response",
);
Ok(response)
}
}
};
let f = async { resp }.instrument(rsp_span);
Ok(f.await)
}
.instrument(span)
.await
}

#[tokio::main]
Expand All @@ -107,14 +104,13 @@ async fn main() -> Result<(), Box<dyn std::error::Error>> {

let local_addr: std::net::SocketAddr = ([127, 0, 0, 1], 3000).into();
let server_span = span!(Level::TRACE, "server", %local_addr);
let _enter = server_span.enter();

let service = make_service_fn(|_| async { Ok::<_, hyper::Error>(service_fn(echo)) });
let server = Server::bind(&local_addr)
.serve(service)
.instrument(server_span.clone());

info!("listening...");
info!(parent: &server_span, "listening...");
server.await?;

Ok(())
Expand Down
20 changes: 18 additions & 2 deletions tracing/src/span.rs
Original file line number Diff line number Diff line change
Expand Up @@ -318,6 +318,7 @@ pub use tracing_core::span::{Attributes, Id, Record};
use crate::stdlib::{
cmp, fmt,
hash::{Hash, Hasher},
marker::PhantomData,
};
use crate::{
dispatcher::{self, Dispatch},
Expand Down Expand Up @@ -379,6 +380,7 @@ pub(crate) struct Inner {
#[must_use = "once a span has been entered, it should be exited"]
pub struct Entered<'a> {
span: &'a Span,
_not_send: PhantomData<crate::stdlib::sync::MutexGuard<'static, ()>>,
}

/// `log` target for all span lifecycle (creation/enter/exit/close) records.
Expand Down Expand Up @@ -562,7 +564,17 @@ impl Span {
/// will call [`Subscriber::exit`]. If the span is disabled, this does
/// nothing.
///
/// # In Asynchronous Code
/// <div class="information">
/// <div class="tooltip ignore" style="">ⓘ<span class="tooltiptext">Note</span></div>
/// </div>
/// <div class="example-wrap" style="display:inline-block">
/// <pre class="ignore" style="white-space:normal;font:inherit;">
/// <strong>Note</strong>: The returned
/// <a href="../struct.Entered.html"><code>Entered</code></a> guard does not
/// implement <code>Send</code>. Dropping the guard will exit <em>this</em> span,
/// and if the guard is sent to another thread and dropped there, that thread may
/// never have entered this span. Thus, <code>Entered</code> should not be sent
/// between threads.</pre></div>
///
/// **Warning**: in asynchronous code that uses [async/await syntax][syntax],
/// `Span::enter` should be used very carefully or avoided entirely. Holding
Expand Down Expand Up @@ -755,7 +767,10 @@ impl Span {
}
}}

Entered { span: self }
Entered {
span: self,
_not_send: PhantomData,
}
}

/// Executes the given function in the context of this span.
Expand Down Expand Up @@ -1280,4 +1295,5 @@ mod test {

trait AssertSync: Sync {}
impl AssertSync for Span {}
impl<'a> AssertSync for Entered<'a> {}
}