Allows adding properties to the span (#43)

Provides reqwest-tracing with a trait ReqwestOtelSpanBackend, allowing custom fields/behaviour to be defined.

This is a breaking change as the TracingMiddleware signature now requires you to define a ReqwestOtelSpanBackend to provide it with the desired span behaviour.

Co-authored-by: Alessandro Zanin <ale.zanin90@gmail.com>
Co-authored-by: tl-flavio-barinas <flavio.barinas@truelayer.com>
Co-authored-by: Marco Tormento <tl-marco-tormento@users.noreply.github.com>
tower
Alessandro Zanin 2022-06-30 15:54:54 +02:00 committed by GitHub
parent 8a6b2ea571
commit 13ca870d20
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
9 changed files with 428 additions and 120 deletions

View File

@ -25,9 +25,9 @@ The `reqwest-middleware` client exposes the same interface as a plain `reqwest`
# ...
[dependencies]
reqwest = "0.11"
reqwest-middleware = "0.1.1"
reqwest-retry = "0.1.1"
reqwest-tracing = "0.2.0"
reqwest-middleware = "0.1.6"
reqwest-retry = "0.1.5"
reqwest-tracing = "0.2.3"
tokio = { version = "1.12.0", features = ["macros", "rt-multi-thread"] }
```
@ -42,7 +42,7 @@ async fn main() {
let retry_policy = ExponentialBackoff::builder().build_with_max_retries(3);
let client = ClientBuilder::new(reqwest::Client::new())
// Trace HTTP requests. See the tracing crate to make use of these traces.
.with(TracingMiddleware)
.with(TracingMiddleware::default())
// Retry failed requests.
.with(RetryTransientMiddleware::new_with_policy(retry_policy))
.build();

View File

@ -6,6 +6,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
## [Unreleased]
# [0.3.0] - 2022-06-10
### Breaking
- Created `ReqwestOtelSpanBackend` trait with `reqwest_otel_span` macro to provide extendable default request otel fields
## [0.2.3] - 2022-06-23
### Fixed
- Fix how we set the OpenTelemetry span status, based on the HTTP response status.

View File

@ -1,6 +1,6 @@
[package]
name = "reqwest-tracing"
version = "0.2.3"
version = "0.3.0-alpha.0"
authors = ["Rodrigo Gryzinski <rodrigo.gryzinski@truelayer.com>"]
edition = "2018"
description = "Opentracing middleware for reqwest."

View File

@ -20,7 +20,7 @@ opentelemetry = "0.17"
reqwest = "0.11"
reqwest-middleware = "0.1.1"
reqwest-retry = "0.1.1"
reqwest-tracing = { version = "0.2.1", features = ["opentelemetry_0_17"] }
reqwest-tracing = { version = "0.3.0", features = ["opentelemetry_0_17"] }
tokio = { version = "1.12.0", features = ["macros", "rt-multi-thread"] }
tracing = "0.1"
tracing-opentelemetry = "0.17"
@ -28,12 +28,31 @@ tracing-subscriber = "0.3"
```
```rust,skip
use reqwest_tracing::{default_on_request_end, reqwest_otel_span, ReqwestOtelSpanBackend, TracingMiddleware};
use opentelemetry::sdk::export::trace::stdout;
use reqwest_middleware::ClientBuilder;
use reqwest_tracing::TracingMiddleware;
use reqwest::{Request, Response};
use reqwest_middleware::{ClientBuilder, Result};
use std::time::Instant;
use task_local_extensions::Extensions;
use tracing::Span;
use tracing_subscriber::layer::SubscriberExt;
use tracing_subscriber::Registry;
pub struct TimeTrace;
impl ReqwestOtelSpanBackend for TimeTrace {
fn on_request_start(req: &Request, extension: &mut Extensions) -> Span {
extension.insert(Instant::now());
reqwest_otel_span!(req, time_elapsed = tracing::field::Empty)
}
fn on_request_end(span: &Span, outcome: &Result<Response>, extension: &mut Extensions) {
let time_elapsed = extension.get::<Instant>().unwrap().elapsed().as_millis() as i64;
default_on_request_end(span, outcome);
span.record("time_elapsed", &time_elapsed);
}
}
#[tokio::main]
async fn main() {
let tracer = stdout::new_pipeline().install_simple();
@ -46,7 +65,7 @@ async fn main() {
async fn run() {
let client = ClientBuilder::new(reqwest::Client::new())
.with(TracingMiddleware)
.with(TracingMiddleware::<TimeTrace>::new())
.build();
client.get("https://truelayer.com").send().await.unwrap();

View File

@ -1,6 +1,38 @@
//! Opentracing middleware implementation for [`reqwest-middleware`].
//! Opentracing middleware implementation for [`reqwest_middleware`].
//!
//! Attach [`TracingMiddleware`] to your client to automatically trace HTTP requests.
//!
//! In this example we define a custom span builder to calculate the request time elapsed and we register the [`TracingMiddleware`].
//! ```rust
//! use reqwest_middleware::Result;
//! use task_local_extensions::Extensions;
//! use reqwest::{Request, Response};
//! use reqwest_middleware::ClientBuilder;
//! use reqwest_tracing::{
//! default_on_request_end, reqwest_otel_span, ReqwestOtelSpanBackend, TracingMiddleware
//! };
//! use tracing::Span;
//! use std::time::{Duration, Instant};
//!
//! pub struct TimeTrace;
//!
//! impl ReqwestOtelSpanBackend for TimeTrace {
//! fn on_request_start(req: &Request, extension: &mut Extensions) -> Span {
//! extension.insert(Instant::now());
//! reqwest_otel_span!(req, time_elapsed = tracing::field::Empty)
//! }
//!
//! fn on_request_end(span: &Span, outcome: &Result<Response>, extension: &mut Extensions) {
//! let time_elapsed = extension.get::<Instant>().unwrap().elapsed().as_millis() as i64;
//! default_on_request_end(span, outcome);
//! span.record("time_elapsed", &time_elapsed);
//! }
//! }
//!
//! let http = ClientBuilder::new(reqwest::Client::new())
//! .with(TracingMiddleware::<TimeTrace>::new())
//! .build();
//! ```
mod middleware;
#[cfg(any(
@ -11,5 +43,14 @@ mod middleware;
feature = "opentelemetry_0_17",
))]
mod otel;
mod reqwest_otel_span_builder;
pub use middleware::TracingMiddleware;
pub use reqwest_otel_span_builder::{
default_on_request_end, default_on_request_failure, default_on_request_success,
DefaultSpanBackend, ReqwestOtelSpanBackend, ERROR_CAUSE_CHAIN, ERROR_MESSAGE, HTTP_HOST,
HTTP_METHOD, HTTP_SCHEME, HTTP_STATUS_CODE, HTTP_USER_AGENT, NET_HOST_PORT, OTEL_KIND,
OTEL_NAME, OTEL_STATUS_CODE,
};
#[doc(hidden)]
pub mod reqwest_otel_span_macro;

View File

@ -1,45 +1,49 @@
use reqwest::header::{HeaderMap, HeaderValue};
use reqwest::{Request, Response, StatusCode as RequestStatusCode};
use reqwest_middleware::{Error, Middleware, Next, Result};
use reqwest::{Request, Response};
use reqwest_middleware::{Middleware, Next, Result};
use task_local_extensions::Extensions;
use tracing::Instrument;
use crate::{DefaultSpanBackend, ReqwestOtelSpanBackend};
/// Middleware for tracing requests using the current Opentelemetry Context.
pub struct TracingMiddleware;
pub struct TracingMiddleware<S: ReqwestOtelSpanBackend> {
span_backend: std::marker::PhantomData<S>,
}
impl<S: ReqwestOtelSpanBackend> TracingMiddleware<S> {
pub fn new() -> TracingMiddleware<S> {
TracingMiddleware {
span_backend: Default::default(),
}
}
}
impl Default for TracingMiddleware<DefaultSpanBackend> {
fn default() -> Self {
TracingMiddleware::new()
}
}
impl<S: ReqwestOtelSpanBackend> Clone for TracingMiddleware<S> {
fn clone(&self) -> Self {
Self::new()
}
}
#[async_trait::async_trait]
impl Middleware for TracingMiddleware {
impl<ReqwestOtelSpan> Middleware for TracingMiddleware<ReqwestOtelSpan>
where
ReqwestOtelSpan: ReqwestOtelSpanBackend + Sync + Send + 'static,
{
async fn handle(
&self,
req: Request,
extensions: &mut Extensions,
next: Next<'_>,
) -> Result<Response> {
let request_span = {
let method = req.method();
let scheme = req.url().scheme();
let host = req.url().host_str().unwrap_or("");
let host_port = req.url().port().unwrap_or(0) as i64;
let path = req.url().path();
let otel_name = format!("{} {}", method, path);
let request_span = ReqwestOtelSpan::on_request_start(&req, extensions);
tracing::info_span!(
"HTTP request",
http.method = %method,
http.scheme = %scheme,
http.host = %host,
net.host.port = %host_port,
otel.kind = "client",
otel.name = %otel_name,
otel.status_code = tracing::field::Empty,
http.user_agent = tracing::field::Empty,
http.status_code = tracing::field::Empty,
error.message = tracing::field::Empty,
error.cause_chain = tracing::field::Empty,
)
};
async {
let outcome_future = async {
// Adds tracing headers to the given request to propagate the OpenTelemetry context to downstream revivers of the request.
// Spans added by downstream consumers will be part of the same trace.
#[cfg(any(
@ -53,77 +57,10 @@ impl Middleware for TracingMiddleware {
// Run the request
let outcome = next.run(req, extensions).await;
match &outcome {
Ok(response) => {
// The request ran successfully
let span_status = get_span_status(response.status());
let status_code = response.status().as_u16() as i64;
let user_agent = get_header_value("user_agent", response.headers());
if let Some(span_status) = span_status {
request_span.record("otel.status_code", &span_status);
}
request_span.record("http.status_code", &status_code);
request_span.record("http.user_agent", &user_agent.as_str());
}
Err(e) => {
// The request didn't run successfully
let error_message = e.to_string();
let error_cause_chain = format!("{:?}", e);
request_span.record("otel.status_code", &"ERROR");
request_span.record("error.message", &error_message.as_str());
request_span.record("error.cause_chain", &error_cause_chain.as_str());
if let Error::Reqwest(e) = e {
request_span.record(
"http.status_code",
&e.status()
.map(|s| s.to_string())
.unwrap_or_else(|| "".to_string())
.as_str(),
);
}
}
}
ReqwestOtelSpan::on_request_end(&request_span, &outcome, extensions);
outcome
}
.instrument(request_span.clone())
.await
}
}
};
fn get_header_value(key: &str, headers: &HeaderMap) -> String {
let header_default = &HeaderValue::from_static("");
format!("{:?}", headers.get(key).unwrap_or(header_default)).replace('"', "")
}
/// HTTP Mapping <https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/trace/semantic_conventions/http.md#status>
///
/// Maps the the http status to an Opentelemetry span status following the the specified convention above.
fn get_span_status(request_status: RequestStatusCode) -> Option<&'static str> {
match request_status.as_u16() {
// Span Status MUST be left unset if HTTP status code was in the 1xx, 2xx or 3xx ranges, unless there was
// another error (e.g., network error receiving the response body; or 3xx codes with max redirects exceeded),
// in which case status MUST be set to Error.
100..=399 => None,
// For HTTP status codes in the 4xx range span status MUST be left unset in case of SpanKind.SERVER and MUST be
// set to Error in case of SpanKind.CLIENT.
400..=499 => Some("ERROR"),
// For HTTP status codes in the 5xx range, as well as any other code the client failed to interpret, span
// status MUST be set to Error.
_ => Some("ERROR"),
}
}
#[cfg(test)]
mod tests {
use super::*;
#[test]
fn get_header_value_for_span_attribute() {
let expect = "IMPORTANT_HEADER";
let mut header_map = HeaderMap::new();
header_map.insert("test", expect.parse().unwrap());
let value = get_header_value("test", &header_map);
assert_eq!(value, expect);
outcome_future.instrument(request_span.clone()).await
}
}

View File

@ -119,7 +119,7 @@ mod test {
.await;
let client = ClientBuilder::new(reqwest::Client::new())
.with(TracingMiddleware)
.with(TracingMiddleware::default())
.build();
let resp = client

View File

@ -0,0 +1,138 @@
use reqwest::header::{HeaderMap, HeaderValue};
use reqwest::{Request, Response, StatusCode as RequestStatusCode};
use reqwest_middleware::{Error, Result};
use task_local_extensions::Extensions;
use tracing::Span;
use crate::reqwest_otel_span;
/// The `http.method` field added to the span by [`reqwest_otel_span`]
pub const HTTP_METHOD: &str = "http.method";
/// The `http.scheme` field added to the span by [`reqwest_otel_span`]
pub const HTTP_SCHEME: &str = "http.scheme";
/// The `http.host` field added to the span by [`reqwest_otel_span`]
pub const HTTP_HOST: &str = "http.host";
/// The `host.port` field added to the span by [`reqwest_otel_span`]
pub const NET_HOST_PORT: &str = "net.host.port";
/// The `otel.kind` field added to the span by [`reqwest_otel_span`]
pub const OTEL_KIND: &str = "otel.kind";
/// The `otel.name` field added to the span by [`reqwest_otel_span`]
pub const OTEL_NAME: &str = "otel.name";
/// The `otel.status.code` field added to the span by [`reqwest_otel_span`]
pub const OTEL_STATUS_CODE: &str = "otel.status_code";
/// The `error.message` field added to the span by [`reqwest_otel_span`]
pub const ERROR_MESSAGE: &str = "error.message";
/// The `error.cause_chain` field added to the span by [`reqwest_otel_span`]
pub const ERROR_CAUSE_CHAIN: &str = "error.cause_chain";
/// The `http.status_code` field added to the span by [`reqwest_otel_span`]
pub const HTTP_STATUS_CODE: &str = "http.status_code";
/// The `http.user_agent` added to the span by [`reqwest_otel_span`]
pub const HTTP_USER_AGENT: &str = "http.user_agent";
/// [`ReqwestOtelSpanBackend`] allows you to customise the span attached by
/// [`TracingMiddleware`] to incoming requests.
///
/// Check out [`reqwest_otel_span`] documentation for examples.
///
/// [`TracingMiddleware`]: crate::middleware::TracingMiddleware.
pub trait ReqwestOtelSpanBackend {
/// Initalized a new span before the request is executed.
fn on_request_start(req: &Request, extension: &mut Extensions) -> Span;
/// Runs after the request call has executed.
fn on_request_end(span: &Span, outcome: &Result<Response>, extension: &mut Extensions);
}
/// Populates default success/failure fields for a given [`reqwest_otel_span!`] span.
#[inline]
pub fn default_on_request_end(span: &Span, outcome: &Result<Response>) {
match outcome {
Ok(res) => default_on_request_success(span, res),
Err(err) => default_on_request_failure(span, err),
}
}
/// Populates default success fields for a given [`reqwest_otel_span!`] span.
#[inline]
pub fn default_on_request_success(span: &Span, response: &Response) {
let span_status = get_span_status(response.status());
let status_code = response.status().as_u16() as i64;
let user_agent = get_header_value("user_agent", response.headers());
if let Some(span_status) = span_status {
span.record(OTEL_STATUS_CODE, &span_status);
}
span.record(HTTP_STATUS_CODE, &status_code);
span.record(HTTP_USER_AGENT, &user_agent.as_str());
}
/// Populates default failure fields for a given [`reqwest_otel_span!`] span.
#[inline]
pub fn default_on_request_failure(span: &Span, e: &Error) {
let error_message = e.to_string();
let error_cause_chain = format!("{:?}", e);
span.record(OTEL_STATUS_CODE, &"ERROR");
span.record(ERROR_MESSAGE, &error_message.as_str());
span.record(ERROR_CAUSE_CHAIN, &error_cause_chain.as_str());
if let Error::Reqwest(e) = e {
span.record(
HTTP_STATUS_CODE,
&e.status()
.map(|s| s.to_string())
.unwrap_or_else(|| "".to_string())
.as_str(),
);
}
}
/// The default [`ReqwestOtelSpanBackend`] for [`TracingMiddleware`].
///
/// [`TracingMiddleware`]: crate::middleware::TracingMiddleware
pub struct DefaultSpanBackend;
impl ReqwestOtelSpanBackend for DefaultSpanBackend {
fn on_request_start(req: &Request, _: &mut Extensions) -> Span {
reqwest_otel_span!(req)
}
fn on_request_end(span: &Span, outcome: &Result<Response>, _: &mut Extensions) {
default_on_request_end(span, outcome)
}
}
fn get_header_value(key: &str, headers: &HeaderMap) -> String {
let header_default = &HeaderValue::from_static("");
format!("{:?}", headers.get(key).unwrap_or(header_default)).replace('"', "")
}
/// HTTP Mapping <https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/trace/semantic_conventions/http.md#status>
///
/// Maps the the http status to an Opentelemetry span status following the the specified convention above.
fn get_span_status(request_status: RequestStatusCode) -> Option<&'static str> {
match request_status.as_u16() {
// Span Status MUST be left unset if HTTP status code was in the 1xx, 2xx or 3xx ranges, unless there was
// another error (e.g., network error receiving the response body; or 3xx codes with max redirects exceeded),
// in which case status MUST be set to Error.
100..=399 => None,
// For HTTP status codes in the 4xx range span status MUST be left unset in case of SpanKind.SERVER and MUST be
// set to Error in case of SpanKind.CLIENT.
400..=499 => Some("ERROR"),
// For HTTP status codes in the 5xx range, as well as any other code the client failed to interpret, span
// status MUST be set to Error.
_ => Some("ERROR"),
}
}
#[cfg(test)]
mod tests {
use super::*;
#[test]
fn get_header_value_for_span_attribute() {
let expect = "IMPORTANT_HEADER";
let mut header_map = HeaderMap::new();
header_map.insert("test", expect.parse().unwrap());
let value = get_header_value("test", &header_map);
assert_eq!(value, expect);
}
}

View File

@ -0,0 +1,169 @@
#[macro_export]
/// [`reqwest_otel_span!`] creates a new [`tracing::Span`].
/// It empowers you to add custom properties to the span on top of the default properties provided by the macro
///
/// Default Fields:
/// - http.method
/// - http.scheme
/// - http.host
/// - net.host
/// - otel.kind
/// - otel.name
/// - otel.status_code
/// - http.user_agent
/// - http.status_code
/// - error.message
/// - error.cause_chain
///
/// Here are some convenient functions to checkout [`default_on_request_success`], [`default_on_request_failure`],
/// and [`default_on_request_end`].
///
/// # Why a macro?
///
/// [`tracing`] requires all the properties attached to a span to be declared upfront, when the span is created.
/// You cannot add new ones afterwards.
/// This makes it extremely fast, but it pushes us to reach for macros when we need some level of composition.
///
/// # Macro syntax
///
/// The first argument passed to [`reqwest_otel_span!`] is a reference to an [`reqwest::Request`].
///
/// ```rust
/// use reqwest_middleware::Result;
/// use task_local_extensions::Extensions;
/// use reqwest::{Request, Response};
/// use reqwest_tracing::{
/// default_on_request_end, reqwest_otel_span, ReqwestOtelSpanBackend
/// };
/// use tracing::Span;
///
/// pub struct CustomReqwestOtelSpanBackend;
///
/// impl ReqwestOtelSpanBackend for CustomReqwestOtelSpanBackend {
/// fn on_request_start(req: &Request, _extension: &mut Extensions) -> Span {
/// reqwest_otel_span!(req)
/// }
///
/// fn on_request_end(span: &Span, outcome: &Result<Response>, _extension: &mut Extensions) {
/// default_on_request_end(span, outcome)
/// }
/// }
/// ```
///
/// If nothing else is specified, the span generated by `reqwest_otel_span!` is identical to the one you'd
/// get by using [`DefaultSpanBackend`].
///
/// You can define new fields following the same syntax of [`tracing::info_span!`] for fields:
///
/// ```rust,should_panic
/// use reqwest_tracing::reqwest_otel_span;
/// # let request: &reqwest::Request = todo!();
///
/// // Define a `time_elapsed` field as empty. It might be populated later.
/// reqwest_otel_span!(request, time_elapsed = tracing::field::Empty);
///
/// // Define a `name` field with a known value, `AppName`.
/// reqwest_otel_span!(request, name = "AppName");
///
/// // Define an `app_id` field using the variable with the same name as value.
/// let app_id = "XYZ";
/// reqwest_otel_span!(request, app_id);
///
/// // All together
/// reqwest_otel_span!(request, time_elapsed = tracing::field::Empty, name = "AppName", app_id);
/// ```
///
/// You can also choose to customise the level of the generated span:
///
/// ```rust,should_panic
/// use reqwest_tracing::reqwest_otel_span;
/// use tracing::Level;
/// # let request: &reqwest::Request = todo!();
///
/// // Reduce the log level for service endpoints/probes
/// let level = if request.method().as_str() == "POST" {
/// Level::DEBUG
/// } else {
/// Level::INFO
/// };
///
/// // `level =` MUST be the first argument.
/// reqwest_otel_span!(level = level, request);
/// ```
///
///
/// [`DefaultSpanBackend`]: crate::reqwest_otel_span_builder::DefaultSpanBackend
/// [`default_on_request_success`]: crate::reqwest_otel_span_builder::default_on_request_success
/// [`default_on_request_failure`]: crate::reqwest_otel_span_builder::default_on_request_failure
/// [`default_on_request_end`]: crate::reqwest_otel_span_builder::default_on_request_end
macro_rules! reqwest_otel_span {
// Vanilla root span at default INFO level, with no additional fields
($request:ident) => {
reqwest_otel_span!($request,)
};
// Vanilla root span, with no additional fields but custom level
(level=$level:expr, $request:ident) => {
reqwest_otel_span!(level=$level, $request,)
};
// Root span with additional fields, default INFO level
($request:ident, $($field:tt)*) => {
reqwest_otel_span!(level=$crate::reqwest_otel_span_macro::private::Level::INFO, $request, $($field)*)
};
// Root span with additional fields and custom level
(level=$level:expr, $request:ident, $($field:tt)*) => {
{
let method = $request.method();
let scheme = $request.url().scheme();
let host = $request.url().host_str().unwrap_or("");
let host_port = $request.url().port().unwrap_or(0) as i64;
let path = $request.url().path();
let otel_name = format!("{} {}", method, path);
macro_rules! request_span {
($lvl:expr) => {
$crate::reqwest_otel_span_macro::private::span!(
$lvl,
"HTTP request",
http.method = %method,
http.scheme = %scheme,
http.host = %host,
net.host.port = %host_port,
otel.kind = "client",
otel.name = %otel_name,
otel.status_code = tracing::field::Empty,
http.user_agent = tracing::field::Empty,
http.status_code = tracing::field::Empty,
error.message = tracing::field::Empty,
error.cause_chain = tracing::field::Empty,
$($field)*
)
}
}
let span = match $level {
$crate::reqwest_otel_span_macro::private::Level::TRACE => {
request_span!($crate::reqwest_otel_span_macro::private::Level::TRACE)
},
$crate::reqwest_otel_span_macro::private::Level::DEBUG => {
request_span!($crate::reqwest_otel_span_macro::private::Level::DEBUG)
},
$crate::reqwest_otel_span_macro::private::Level::INFO => {
request_span!($crate::reqwest_otel_span_macro::private::Level::INFO)
},
$crate::reqwest_otel_span_macro::private::Level::WARN => {
request_span!($crate::reqwest_otel_span_macro::private::Level::WARN)
},
$crate::reqwest_otel_span_macro::private::Level::ERROR => {
request_span!($crate::reqwest_otel_span_macro::private::Level::ERROR)
},
};
span
}
}
}
#[doc(hidden)]
pub mod private {
#[doc(hidden)]
pub use tracing::{span, Level};
}