actix/actix-extras
1
0
Fork 0
mirror of https://github.com/actix/actix-extras.git synced 2025-02-22 18:33:18 +01:00
Code Issues Releases Wiki Activity

Adopt OpenTelemetry's semantic convention (#15)

Browse Source 
* Add http.route.

* Align all fields with OpenTelemetry's semantic conventions.

* Add span kind.

* Emit event for errors.
Add OTEL status code.

* Create otel.status_code field as empty.

* Fix errors.

* Add (feature-gated) support for OpenTelemetry span propagation.

* Capture the trace id as an attribute on the span.

* Change message.

* Log the newly-generated trace id if there is no parent context.

* Define a root_span macro as a stepping stone to allow crate users to add their own fields to the root span.

* Add comments.

* mut is no longer necessary.

* Allow users to customise generation of the root span. Split recording fields on span end from emission of log record. Make log record on error optional via feature flag.

* Provide constructor + default implementation.

* Explode into multiple modules.
Fix various paths/private imports in root_span.

* Rename module to root_span_macro.

* Add a new extractor to retrieve the root span.

* Document crate.

* Docs!

* Add section on OTEL.

* Mention actix-web-opentelemetry.

* Add OpenTelemetry example.

* Improve readme.

* Add custom root span example.

Co-authored-by: LukeMathWalker <contact@palmieri.com>
This commit is contained in:
Luca Palmieri 2021-04-25 12:19:27 +01:00 committed by GitHub
parent 1025372493
commit 7da6ea91ac
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
14 changed files with 1057 additions and 207 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

10
Cargo.toml
View File

@ -1,3 +1,6 @@
[workspace]
members = [".", "examples/opentelemetry", "examples/custom-root-span"]
[package]
name = "tracing-actix-web"
version = "0.3.0-beta.3"
@ -15,12 +18,19 @@ description = "Structured logging middleware for actix-web."
keywords = ["http", "actix-web", "tracing", "logging"]
categories = ["asynchronous", "web-programming"]
[features]
default = ["opentelemetry_0_13", "emit_event_on_error"]
opentelemetry_0_13 = ["opentelemetry", "tracing-opentelemetry"]
emit_event_on_error = []
[dependencies]
actix-web = "4.0.0-beta.6"
tracing = "0.1.19"
tracing-futures = "0.2.4"
futures = "0.3.5"
uuid = { version = "0.8.1", features = ["v4"] }
opentelemetry = { version = "0.13", optional = true }
tracing-opentelemetry = { version = "0.12", optional = true }
[dev-dependencies]
tracing-subscriber = { version = "0.2.12", features = ["registry", "env-filter"] }

17
examples/custom-root-span/Cargo.toml Normal file
View File

@ -0,0 +1,17 @@
[package]
name = "custom-root-span"
version = "0.1.0"
authors = ["LukeMathWalker <contact@lpalmieri.com>"]
edition = "2018"
# See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html
[dependencies]
actix-web = "4.0.0-beta.6"
opentelemetry = { version = "0.13", features = ["rt-tokio-current-thread"] }
opentelemetry-jaeger = { version = "0.12", features = ["tokio"] }
tracing-opentelemetry = { version = "0.12" }
tracing = "0.1.19"
tracing-subscriber = { version = "0.2.12", features = ["registry", "env-filter"] }
tracing-bunyan-formatter = "0.1.6"
tracing-actix-web = { path = "../.." }

38
examples/custom-root-span/README.md Normal file
View File

@ -0,0 +1,38 @@
# Custom root span
## Running
You can launch this example with
```bash
cargo run
```
An `actix-web` application will be listening on port `8080`.
You can fire requests to it with:
```bash
curl -v http://localhost:8080/hello
```
```text
Hello world!
```
or
```bash
curl -v http://localhost:8080/hello/my-name
```
```text
Hello my-name!
```
## Visualising traces
Spans will be also printed to the console in JSON format, as structured log records.
You can look at the exported spans in your browser by visiting [http://localhost:16686](http://localhost:16686) if you launch a Jaeger instance:
```bash
docker run -d -p6831:6831/udp -p6832:6832/udp -p16686:16686 jaegertracing/all-in-one:latest
```

93
examples/custom-root-span/src/main.rs Normal file
View File

@ -0,0 +1,93 @@
use actix_web::dev::{ServiceRequest, ServiceResponse};
use actix_web::{web, App, Error, HttpServer};
use opentelemetry::{
global, runtime::TokioCurrentThread, sdk::propagation::TraceContextPropagator,
};
use std::io;
use tracing::Span;
use tracing_actix_web::{DefaultRootSpanBuilder, RootSpan, RootSpanBuilder, TracingLogger};
use tracing_bunyan_formatter::{BunyanFormattingLayer, JsonStorageLayer};
use tracing_subscriber::layer::SubscriberExt;
use tracing_subscriber::{EnvFilter, Registry};
/// We will define a custom root span builder to capture additional fields, specific
/// to our application, on top of the ones provided by `DefaultRootSpanBuilder` out of the box.
pub struct CustomRootSpanBuilder;
impl RootSpanBuilder for CustomRootSpanBuilder {
fn on_request_start(request: &ServiceRequest) -> Span {
// Not sure why you'd be keen to capture this, but it's an example and we try to keep it simple
let n_headers = request.headers().len();
// We set `cloud_provider` to a constant value.
//
// `name` is not known at this point - we delegate the responsibility to populate it
// to the `personal_hello` handler. We MUST declare the field though, otherwise
// `span.record("caller_name", XXX)` will just be silently ignored by `tracing`.
tracing_actix_web::root_span!(
request,
n_headers,
cloud_provider = "localhost",
caller_name = tracing::field::Empty
)
}
fn on_request_end<B>(span: Span, outcome: &Result<ServiceResponse<B>, Error>) {
// Capture the standard fields when the request finishes.
DefaultRootSpanBuilder::on_request_end(span, outcome);
}
}
async fn hello() -> &'static str {
"Hello world!"
}
async fn personal_hello(root_span: RootSpan, name: web::Path<String>) -> String {
// Add more context to the root span of the request.
root_span.record("caller_name", &name.as_str());
format!("Hello {}!", name)
}
#[actix_web::main]
async fn main() -> io::Result<()> {
init_telemetry();
HttpServer::new(move || {
App::new()
.wrap(TracingLogger::<CustomRootSpanBuilder>::new())
.service(web::resource("/hello").to(hello))
.service(web::resource("/hello/{name}").to(personal_hello))
})
.bind("127.0.0.1:8080")?
.run()
.await?;
// Ensure all spans have been shipped to Jaeger.
opentelemetry::global::shutdown_tracer_provider();
Ok(())
}
/// Init a `tracing` subscriber that prints spans to stdout as well as
/// ships them to Jaeger.
///
/// Check the `opentelemetry` example for more details.
fn init_telemetry() {
let app_name = "tracing-actix-web-demo";
global::set_text_map_propagator(TraceContextPropagator::new());
let tracer = opentelemetry_jaeger::new_pipeline()
.with_service_name(app_name)
.install_batch(TokioCurrentThread)
.expect("Failed to install OpenTelemetry tracer.");
let env_filter = EnvFilter::try_from_default_env().unwrap_or(EnvFilter::new("info"));
let telemetry = tracing_opentelemetry::layer().with_tracer(tracer);
let formatting_layer = BunyanFormattingLayer::new(app_name.into(), std::io::stdout);
let subscriber = Registry::default()
.with(env_filter)
.with(telemetry)
.with(JsonStorageLayer)
.with(formatting_layer);
tracing::subscriber::set_global_default(subscriber)
.expect("Failed to install `tracing` subscriber.")
}

17
examples/opentelemetry/Cargo.toml Normal file
View File

@ -0,0 +1,17 @@
[package]
name = "otel"
version = "0.1.0"
authors = ["Luca Palmieri <rust@lpalmieri.com>"]
edition = "2018"
license = "MIT/Apache-2.0"
[dependencies]
actix-web = "4.0.0-beta.6"
tracing = "0.1.19"
opentelemetry = { version = "0.13", features = ["rt-tokio-current-thread"] }
opentelemetry-jaeger = { version = "0.12", features = ["tokio"] }
tracing-opentelemetry = { version = "0.12" }
tracing-subscriber = { version = "0.2.12", features = ["registry", "env-filter"] }
tracing-bunyan-formatter = "0.1.6"
tracing-actix-web = { path = "../.." }

33
examples/opentelemetry/README.md Normal file
View File

@ -0,0 +1,33 @@
# OpenTelemetry integration
## Prerequisites
To execute this example you need a running Jaeger instance.
You can launch one using Docker:
```bash
docker run -d -p6831:6831/udp -p6832:6832/udp -p16686:16686 jaegertracing/all-in-one:latest
```
## Running
You can launch this example with
```bash
cargo run
```
An `actix-web` application will be listening on port `8080`.
You can fire requests to it with:
```bash
curl -v http://localhost:8080/hello
```
```text
Hello world!
```
## Traces
You can look at the exported traces in your browser by visiting [http://localhost:16686](http://localhost:16686).
Spans will be also printed to the console in JSON format, as structured log records.

60
examples/opentelemetry/src/main.rs Normal file
View File

@ -0,0 +1,60 @@
use actix_web::{web, App, HttpServer};
use opentelemetry::{
global, runtime::TokioCurrentThread, sdk::propagation::TraceContextPropagator,
};
use std::io;
use tracing_actix_web::TracingLogger;
use tracing_bunyan_formatter::{BunyanFormattingLayer, JsonStorageLayer};
use tracing_subscriber::layer::SubscriberExt;
use tracing_subscriber::{EnvFilter, Registry};
async fn hello() -> &'static str {
"Hello world!"
}
fn init_telemetry() {
let app_name = "tracing-actix-web-demo";
// Start a new Jaeger trace pipeline.
// Spans are exported in batch - recommended setup for a production application.
global::set_text_map_propagator(TraceContextPropagator::new());
let tracer = opentelemetry_jaeger::new_pipeline()
.with_service_name(app_name)
.install_batch(TokioCurrentThread)
.expect("Failed to install OpenTelemetry tracer.");
// Filter based on level - trace, debug, info, warn, error
// Tunable via `RUST_LOG` env variable
let env_filter = EnvFilter::try_from_default_env().unwrap_or(EnvFilter::new("info"));
// Create a `tracing` layer using the Jaeger tracer
let telemetry = tracing_opentelemetry::layer().with_tracer(tracer);
// Create a `tracing` layer to emit spans as structured logs to stdout
let formatting_layer = BunyanFormattingLayer::new(app_name.into(), std::io::stdout);
// Combined them all together in a `tracing` subscriber
let subscriber = Registry::default()
.with(env_filter)
.with(telemetry)
.with(JsonStorageLayer)
.with(formatting_layer);
tracing::subscriber::set_global_default(subscriber)
.expect("Failed to install `tracing` subscriber.")
}
#[actix_web::main]
async fn main() -> io::Result<()> {
init_telemetry();
HttpServer::new(move || {
App::new()
.wrap(TracingLogger::default())
.service(web::resource("/hello").to(hello))
})
.bind("127.0.0.1:8080")?
.run()
.await?;
// Ensure all spans have been shipped to Jaeger.
opentelemetry::global::shutdown_tracer_provider();
Ok(())
}

444
src/lib.rs
View File

@ -1,215 +1,245 @@
//! `tracing-actix-web` provides [`TracingLogger`], a middleware to log request and response info
//! when using the [`actix-web`] framework.
//! `tracing-actix-web` provides [`TracingLogger`], a middleware to collect telemetry data from applications
//! built on top of the [`actix-web`] framework.
//!
//! [`TracingLogger`] is designed as a drop-in replacement of [`actix-web`]'s [`Logger`].
//! # How to install
//!
//! [`Logger`] is built on top of the [`log`] crate: you need to use regular expressions to parse
//! the request information out of the logged message.
//! Add `tracing-actix-web` to your dependencies:
//! ```toml
//! [dependencies]
//! # ...
//! tracing-actix-web = "0.4.0-beta.1"
//! tracing = "0.1"
//! actix-web = "4.0.0-beta.6"
//! ```
//!
//! [`TracingLogger`] relies on [`tracing`], a modern instrumentation framework for structured
//! logging: all request information is captured as a machine-parsable set of key-value pairs.
//! It also enables propagation of context information to children spans.
//! `tracing-actix-web` exposes two feature flags:
//!
//! [`TracingLogger`]: struct.TracingLogger.html
//! [`actix-web`]: https://docs.rs/actix-web
//! [`Logger`]: https://docs.rs/actix-web/3.0.2/actix_web/middleware/struct.Logger.html
//! [`log`]: https://docs.rs/log
//! [`tracing`]: https://docs.rs/tracing
use actix_web::dev::{Payload, Service, ServiceRequest, ServiceResponse, Transform};
use actix_web::{Error, FromRequest, HttpMessage, HttpRequest};
use futures::future::{ok, ready, Ready};
use futures::task::{Context, Poll};
use std::future::Future;
use std::pin::Pin;
use tracing::Span;
use tracing_futures::Instrument;
use uuid::Uuid;
//! - `opentelemetry_0_13`: attach [OpenTelemetry](https://github.com/open-telemetry/opentelemetry-rust)'s context to the root span;
//! - `emit_event_on_error`: emit a [`tracing`] event when request processing fails with an error.
//!
//! They are both enabled by default.
//!
//! # Getting started
//!
//! ```rust,compile_fail
//! use actix_web::{App, web, HttpServer};
//! use tracing_actix_web::TracingLogger;
//!
//! fn main() {
//! // Init your `tracing` subscriber here!
//!
//! let server = HttpServer::new(|| {
//! App::new()
//! // Mount `TracingLogger` as a middleware
//! .wrap(TracingLogger::default())
//! .service( /* */ )
//! });
//! }
//! ```
//!
//! Check out [the examples on GitHub] to get a taste of how [`TracingLogger`] can be used to observe and monitor your
//! application.
//!
//! # `tracing`: who art thou?
//!
//! [`TracingLogger`] is built on top of [`tracing`], a modern instrumentation framework with
//! [a vibrant ecosystem](https://github.com/tokio-rs/tracing#related-crates).
//!
//! `tracing-actix-web`'s documentation provides a crash course in how to use [`tracing`] to instrument an `actix-web` application.
//! If you want to learn more check out ["Are we observable yet?"](https://www.lpalmieri.com/posts/2020-09-27-zero-to-production-4-are-we-observable-yet/) -
//! it provides an in-depth introduction to the crate and the problems it solves within the bigger picture of [observability](https://docs.honeycomb.io/learning-about-observability/).
//!
//! # The root span
//!
//! [`tracing::Span`] is the key abstraction in [`tracing`]: it represents a unit of work in your system.
//! A [`tracing::Span`] has a beginning and an end. It can include one or more **child spans** to represent sub-unit
//! of works within a larger task.
//!
//! When your application receives a request, [`TracingLogger`] creates a new span - we call it the **[root span]**.
//! All the spans created _while_ processing the request will be children of the root span.
//!
//! [`tracing`] empowers us to attach structured properties to a span as a collection of key-value pairs.
//! Those properties can then be queried in a variety of tools (e.g. ElasticSearch, Honeycomb, DataDog) to
//! understand what is happening in your system.
//!
//! # Customisation via [`RootSpanBuilder`]
//!
//! Troubleshooting becomes much easier when the root span has a _rich context_ - e.g. you can understand most of what
//! happened when processing the request just by looking at the properties attached to the corresponding root span.
//!
//! You might have heard of this technique as the [canonical log line pattern](https://stripe.com/blog/canonical-log-lines),
//! popularised by Stripe. It is more recently discussed in terms of [high-cardinality events](https://www.honeycomb.io/blog/observability-a-manifesto/)
//! by Honeycomb and other vendors in the observability space.
//!
//! [`TracingLogger`] gives you a chance to use the very same pattern: you can customise the properties attached
//! to the root span in order to capture the context relevant to your specific domain.
//!
//! [`TracingLogger::default`] is equivalent to:
//!
//! ```rust
//! use tracing_actix_web::{TracingLogger, DefaultRootSpanBuilder};
//!
//! // Two ways to initialise TracingLogger with the default root span builder
//! let default = TracingLogger::default();
//! let another_way = TracingLogger::<DefaultRootSpanBuilder>::new();
//! ```
//!
//! We are delegating the construction of the root span to [`DefaultRootSpanBuilder`].
//! [`DefaultRootSpanBuilder`] captures, out of the box, several dimensions that are usually relevant when looking at an HTTP
//! API: method, version, route, etc. - check out its documentation for an extensive list.
//!
//! You can customise the root span by providing your own implementation of the [`RootSpanBuilder`] trait.
//! Let's imagine, for example, that our system cares about a client identifier embedded inside an authorization header.
//! We could add a `client_id` property to the root span using a custom builder, `DomainRootSpanBuilder`:
//!
//! ```rust
//! use actix_web::dev::{ServiceResponse, ServiceRequest};
//! use actix_web::Error;
//! use tracing_actix_web::{TracingLogger, DefaultRootSpanBuilder, RootSpanBuilder};
//! use tracing::Span;
//!
//! pub struct DomainRootSpanBuilder;
//!
//! impl RootSpanBuilder for DomainRootSpanBuilder {
//! fn on_request_start(request: &ServiceRequest) -> Span {
//! let client_id: &str = todo!("Somehow extract it from the authorization header");
//! tracing::info_span!("Request", client_id)
//! }
//!
//! fn on_request_end<B>(_span: Span, _outcome: &Result<ServiceResponse<B>, Error>) {}
//! }
//!
//! let custom_middleware = TracingLogger::<DomainRootSpanBuilder>::new();
//! ```
//!
//! There is an issue, though: `client_id` is the _only_ property we are capturing.
//! With `DomainRootSpanBuilder`, as it is, we do not get any of that useful HTTP-related information provided by
//! [`DefaultRootSpanBuilder`].
//!
//! We can do better!
//!
//! ```rust
//! use actix_web::dev::{ServiceResponse, ServiceRequest};
//! use actix_web::Error;
//! use tracing_actix_web::{TracingLogger, DefaultRootSpanBuilder, RootSpanBuilder};
//! use tracing::Span;
//!
//! pub struct DomainRootSpanBuilder;
//!
//! impl RootSpanBuilder for DomainRootSpanBuilder {
//! fn on_request_start(request: &ServiceRequest) -> Span {
//! let client_id: &str = todo!("Somehow extract it from the authorization header");
//! tracing_actix_web::root_span!(request, client_id)
//! }
//!
//! fn on_request_end<B>(span: Span, outcome: &Result<ServiceResponse<B>, Error>) {
//! DefaultRootSpanBuilder::on_request_end(span, outcome);
//! }
//! }
//!
//! let custom_middleware = TracingLogger::<DomainRootSpanBuilder>::new();
//! ```
//!
//! [`root_span!`] is a macro provided by `tracing-actix-web`: it creates a new span by combining all the HTTP properties tracked
//! by [`DefaultRootSpanBuilder`] with the custom ones you specify when calling it (e.g. `client_id` in our example).
//!
//! We need to use a macro because `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.
//!
//! # The [`RootSpan`] extractor
//!
//! It often happens that not all information about a task is known upfront, encoded in the incoming request.
//! You can use the [`RootSpan`] extractor to grab the root span in your handlers and attach more information
//! to your root span as it becomes available:
//!
//! ```rust
//! use actix_web::dev::{ServiceResponse, ServiceRequest};
//! use actix_web::{Error, HttpResponse};
//! use tracing_actix_web::{RootSpan, DefaultRootSpanBuilder, RootSpanBuilder};
//! use tracing::Span;
//! use actix_web::get;
//! use tracing_actix_web::RequestId;
//! use uuid::Uuid;
//!
//! #[get("/")]
//! async fn handler(root_span: RootSpan) -> HttpResponse {
//! let application_id: &str = todo!("Some domain logic");
//! // Record the property value against the root span
//! root_span.record("application_id", &application_id);
//!
//! // [...]
//! # todo!()
//! }
//!
//! pub struct DomainRootSpanBuilder;
//!
//! impl RootSpanBuilder for DomainRootSpanBuilder {
//! fn on_request_start(request: &ServiceRequest) -> Span {
//! let client_id: &str = todo!("Somehow extract it from the authorization header");
//! // All fields you want to capture must be declared upfront.
//! // If you don't know the value (yet), use tracing's `Empty`
//! tracing_actix_web::root_span!(
//! request,
//! client_id, application_id = tracing::field::Empty
//! )
//! }
//!
//! fn on_request_end<B>(span: Span, response: &Result<ServiceResponse<B>, Error>) {
//! DefaultRootSpanBuilder::on_request_end(span, response);
//! }
//! }
//! ```
//!
//! # The [`RequestId`] extractor
//!
//! `tracing-actix-web` generates a unique identifier for each incoming request, the **request id**.
//!
//! You can extract the request id using the [`RequestId`] extractor:
//!
//! ```rust
//! use actix_web::get;
//! use tracing_actix_web::RequestId;
//! use uuid::Uuid;
//!
//! #[get("/")]
//! async fn index(request_id: RequestId) -> String {
//! format!("{}", request_id)
//! }
//! ```
//!
//! # OpenTelemetry integration
//!
//! `tracing-actix-web` follows [OpenTelemetry's semantic convention](https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/overview.md#spancontext)
//! for field names.
//! Furthermore, if you have not disabled the `opentelemetry_0_13` feature flag, `tracing-actix-web` automatically
//! performs trace propagation according to the OpenTelemetry standard.
//! It tries to extract the OpenTelemetry context out of the headers of incoming requests and, when it finds one, it sets
//! it as the remote context for the current root span.
//!
//! If you add [`tracing-opentelemetry::OpenTelemetryLayer`](https://docs.rs/tracing-opentelemetry/0.12.0/tracing_opentelemetry/struct.OpenTelemetryLayer.html)
//! in your `tracing::Subscriber` you will be able to export the root span (and all its children) as OpenTelemetry spans.
//!
//! Check out the [relevant example in the GitHub repository] for reference.
//!
//! You can find an alternative integration of `actix-web` with OpenTelemetry in [`actix-web-opentelemetry`](https://github.com/OutThereLabs/actix-web-opentelemetry)
//! - parts of this project were heavily inspired by their implementation. They provide support for metrics
//! and instrumentation for the `awc` HTTP client, both out of scope for `tracing-actix-web`.
//!
//! [root span]: crate::RootSpan
//! [`actix-web`]: https://docs.rs/actix-web/4.0.0-beta.6/actix_web/index.html
mod middleware;
mod request_id;
mod root_span;
mod root_span_builder;
/// `TracingLogger` is a middleware to log request and response info in a structured format.
///
/// `TracingLogger` is designed as a drop-in replacement of [`actix-web`]'s [`Logger`].
///
/// [`Logger`] is built on top of the [`log`] crate: you need to use regular expressions to parse
/// the request information out of the logged message.
///
/// `TracingLogger` relies on [`tracing`], a modern instrumentation framework for structured
/// logging: all request information is captured as a machine-parsable set of key-value pairs.
/// It also enables propagation of context information to children spans.
///
/// ## Usage
///
/// Register `TracingLogger` as a middleware for your application using `.wrap` on `App`.
/// Add a `Subscriber` implementation to output logs to the console.
///
/// ```rust
/// use actix_web::middleware::Logger;
/// use actix_web::App;
/// use tracing::{Subscriber, subscriber::set_global_default};
/// use tracing_actix_web::TracingLogger;
/// use tracing_log::LogTracer;
/// use tracing_bunyan_formatter::{BunyanFormattingLayer, JsonStorageLayer};
/// use tracing_subscriber::{layer::SubscriberExt, EnvFilter, Registry};
///
/// /// Compose multiple layers into a `tracing`'s subscriber.
/// pub fn get_subscriber(
/// name: String,
/// env_filter: String
/// ) -> impl Subscriber + Send + Sync {
/// let env_filter = EnvFilter::try_from_default_env()
/// .unwrap_or(EnvFilter::new(env_filter));
/// let formatting_layer = BunyanFormattingLayer::new(
/// name.into(),
/// std::io::stdout
/// );
/// Registry::default()
/// .with(env_filter)
/// .with(JsonStorageLayer)
/// .with(formatting_layer)
/// }
///
/// /// Register a subscriber as global default to process span data.
/// ///
/// /// It should only be called once!
/// pub fn init_subscriber(subscriber: impl Subscriber + Send + Sync) {
/// LogTracer::init().expect("Failed to set logger");
/// set_global_default(subscriber).expect("Failed to set subscriber");
/// }
///
/// fn main() {
/// let subscriber = get_subscriber("app".into(), "info".into());
/// init_subscriber(subscriber);
///
/// let app = App::new().wrap(TracingLogger);
/// }
/// ```
///
/// [`actix-web`]: https://docs.rs/actix-web
/// [`Logger`]: https://docs.rs/actix-web/3.0.2/actix_web/middleware/struct.Logger.html
/// [`log`]: https://docs.rs/log
/// [`tracing`]: https://docs.rs/tracing
pub struct TracingLogger;
impl<S, B> Transform<S, ServiceRequest> for TracingLogger
where
S: Service<ServiceRequest, Response = ServiceResponse<B>, Error = Error>,
S::Future: 'static,
B: 'static,
{
type Response = ServiceResponse<B>;
type Error = Error;
type Transform = TracingLoggerMiddleware<S>;
type InitError = ();
type Future = Ready<Result<Self::Transform, Self::InitError>>;
fn new_transform(&self, service: S) -> Self::Future {
ok(TracingLoggerMiddleware { service })
}
}
pub use middleware::TracingLogger;
pub use request_id::RequestId;
pub use root_span::RootSpan;
pub use root_span_builder::{DefaultRootSpanBuilder, RootSpanBuilder};
#[doc(hidden)]
pub struct TracingLoggerMiddleware<S> {
service: S,
}
pub mod root_span_macro;
/// A unique identifier for each incomming request. This ID is added to the logger span, even if
/// the `RequestId` is never extracted.
///
/// Extracting a `RequestId` when the `TracingLogger` middleware is not registered, will result in
/// a internal server error.
///
/// # Usage
/// ```rust
/// use actix_web::get;
/// use tracing_actix_web::RequestId;
/// use uuid::Uuid;
///
/// #[get("/")]
/// async fn index(request_id: RequestId) -> String {
/// format!("{}", request_id)
/// }
///
/// #[get("/2")]
/// async fn index2(request_id: RequestId) -> String {
/// let uuid: Uuid = request_id.into();
/// format!("{}", uuid)
/// }
/// ```
#[derive(Clone, Copy)]
pub struct RequestId(Uuid);
impl std::ops::Deref for RequestId {
type Target = Uuid;
fn deref(&self) -> &Self::Target {
&self.0
}
}
impl std::convert::Into<Uuid> for RequestId {
fn into(self) -> Uuid {
self.0
}
}
impl std::fmt::Display for RequestId {
fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
write!(f, "{}", self.0)
}
}
impl<S, B> Service<ServiceRequest> for TracingLoggerMiddleware<S>
where
S: Service<ServiceRequest, Response = ServiceResponse<B>, Error = Error>,
S::Future: 'static,
B: 'static,
{
type Response = ServiceResponse<B>;
type Error = Error;
type Future = Pin<Box<dyn Future<Output = Result<Self::Response, Self::Error>>>>;
fn poll_ready(&self, cx: &mut Context<'_>) -> Poll<Result<(), Self::Error>> {
self.service.poll_ready(cx)
}
fn call(&self, req: ServiceRequest) -> Self::Future {
let user_agent = req
.headers()
.get("User-Agent")
.map(|h| h.to_str().unwrap_or(""))
.unwrap_or("");
let request_id = RequestId(Uuid::new_v4());
let span = tracing::info_span!(
"Request",
http.method = %req.method(),
request_path = %req.path(),
user_agent = %user_agent,
client_ip_address = %req.connection_info().realip_remote_addr().unwrap_or(""),
request_id = %request_id.0,
status_code = tracing::field::Empty,
);
req.extensions_mut().insert(request_id);
let fut = self.service.call(req);
Box::pin(
async move {
let outcome = fut.await;
let status_code = match &outcome {
Ok(response) => response.response().status(),
Err(error) => error.as_response_error().status_code(),
};
Span::current().record("status_code", &status_code.as_u16());
outcome
}
.instrument(span),
)
}
}
impl FromRequest for RequestId {
type Error = ();
type Future = Ready<Result<Self, Self::Error>>;
type Config = ();
fn from_request(req: &HttpRequest, _: &mut Payload) -> Self::Future {
ready(req.extensions().get::<RequestId>().copied().ok_or(()))
}
}
#[cfg(feature = "opentelemetry_0_13")]
mod otel;

162
src/middleware.rs Normal file
View File

@ -0,0 +1,162 @@
use crate::{DefaultRootSpanBuilder, RequestId, RootSpan, RootSpanBuilder};
use actix_web::dev::{Service, ServiceRequest, ServiceResponse, Transform};
use actix_web::{Error, HttpMessage};
use futures::future::{ok, Ready};
use futures::task::{Context, Poll};
use std::future::Future;
use std::pin::Pin;
use tracing::Span;
use tracing_futures::Instrument;
/// `TracingLogger` is a middleware to capture structured diagnostic when processing an HTTP request.
/// Check the crate-level documentation for an in-depth introduction.
///
/// `TracingLogger` is designed as a drop-in replacement of [`actix-web`]'s [`Logger`].
///
/// # Usage
///
/// Register `TracingLogger` as a middleware for your application using `.wrap` on `App`.
/// In this example we add a [`tracing::Subscriber`] to output structured logs to the console.
///
/// ```rust
/// use actix_web::middleware::Logger;
/// use actix_web::App;
/// use tracing::{Subscriber, subscriber::set_global_default};
/// use tracing_actix_web::TracingLogger;
/// use tracing_log::LogTracer;
/// use tracing_bunyan_formatter::{BunyanFormattingLayer, JsonStorageLayer};
/// use tracing_subscriber::{layer::SubscriberExt, EnvFilter, Registry};
///
/// /// Compose multiple layers into a `tracing`'s subscriber.
/// pub fn get_subscriber(
/// name: String,
/// env_filter: String
/// ) -> impl Subscriber + Send + Sync {
/// let env_filter = EnvFilter::try_from_default_env()
/// .unwrap_or(EnvFilter::new(env_filter));
/// let formatting_layer = BunyanFormattingLayer::new(
/// name.into(),
/// std::io::stdout
/// );
/// Registry::default()
/// .with(env_filter)
/// .with(JsonStorageLayer)
/// .with(formatting_layer)
/// }
///
/// /// Register a subscriber as global default to process span data.
/// ///
/// /// It should only be called once!
/// pub fn init_subscriber(subscriber: impl Subscriber + Send + Sync) {
/// LogTracer::init().expect("Failed to set logger");
/// set_global_default(subscriber).expect("Failed to set subscriber");
/// }
///
/// fn main() {
/// let subscriber = get_subscriber("app".into(), "info".into());
/// init_subscriber(subscriber);
///
/// let app = App::new().wrap(TracingLogger::default());
/// }
/// ```
///
/// [`actix-web`]: https://docs.rs/actix-web
/// [`Logger`]: https://docs.rs/actix-web/3.0.2/actix_web/middleware/struct.Logger.html
/// [`tracing`]: https://docs.rs/tracing
pub struct TracingLogger<RootSpan: RootSpanBuilder> {
root_span_builder: std::marker::PhantomData<RootSpan>,
}
impl<RootSpan: RootSpanBuilder> Clone for TracingLogger<RootSpan> {
fn clone(&self) -> Self {
Self::new()
}
}
impl Default for TracingLogger<DefaultRootSpanBuilder> {
fn default() -> Self {
TracingLogger::new()
}
}
impl<RootSpan: RootSpanBuilder> TracingLogger<RootSpan> {
pub fn new() -> TracingLogger<RootSpan> {
TracingLogger {
root_span_builder: Default::default(),
}
}
}
impl<S, B, RootSpan> Transform<S, ServiceRequest> for TracingLogger<RootSpan>
where
S: Service<ServiceRequest, Response = ServiceResponse<B>, Error = Error>,
S::Future: 'static,
B: 'static,
RootSpan: RootSpanBuilder,
{
type Response = ServiceResponse<B>;
type Error = Error;
type Transform = TracingLoggerMiddleware<S, RootSpan>;
type InitError = ();
type Future = Ready<Result<Self::Transform, Self::InitError>>;
fn new_transform(&self, service: S) -> Self::Future {
ok(TracingLoggerMiddleware {
service,
root_span_builder: std::marker::PhantomData::default(),
})
}
}
#[doc(hidden)]
pub struct TracingLoggerMiddleware<S, RootSpanBuilder> {
service: S,
root_span_builder: std::marker::PhantomData<RootSpanBuilder>,
}
impl<S, B, RootSpanType> Service<ServiceRequest> for TracingLoggerMiddleware<S, RootSpanType>
where
S: Service<ServiceRequest, Response = ServiceResponse<B>, Error = Error>,
S::Future: 'static,
B: 'static,
RootSpanType: RootSpanBuilder,
{
type Response = ServiceResponse<B>;
type Error = Error;
type Future = Pin<Box<dyn Future<Output = Result<Self::Response, Self::Error>>>>;
fn poll_ready(&self, cx: &mut Context<'_>) -> Poll<Result<(), Self::Error>> {
self.service.poll_ready(cx)
}
fn call(&self, req: ServiceRequest) -> Self::Future {
req.extensions_mut().insert(RequestId::generate());
let root_span = RootSpanType::on_request_start(&req);
let root_span_wrapper = RootSpan::new(root_span.clone());
req.extensions_mut().insert(root_span_wrapper);
let fut = self.service.call(req);
Box::pin(
async move {
let outcome = fut.await;
RootSpanType::on_request_end(Span::current(), &outcome);
#[cfg(feature = "emit_event_on_error")]
if let Err(error) = &outcome {
let response_error = error.as_response_error();
let status_code = response_error.status_code();
let error_msg_prefix =
"Error encountered while processing the incoming HTTP request";
if status_code.is_client_error() {
tracing::warn!("{}: {:?}", error_msg_prefix, response_error);
} else {
tracing::error!("{}: {:?}", error_msg_prefix, response_error);
}
}
outcome
}
.instrument(root_span),
)
}
}

21
src/otel.rs Normal file
View File

@ -0,0 +1,21 @@
use opentelemetry::propagation::Extractor;
pub(crate) struct RequestHeaderCarrier<'a> {
headers: &'a actix_web::http::HeaderMap,
}
impl<'a> RequestHeaderCarrier<'a> {
pub(crate) fn new(headers: &'a actix_web::http::HeaderMap) -> Self {
RequestHeaderCarrier { headers }
}
}
impl<'a> Extractor for RequestHeaderCarrier<'a> {
fn get(&self, key: &str) -> Option<&str> {
self.headers.get(key).and_then(|v| v.to_str().ok())
}
fn keys(&self) -> Vec<&str> {
self.headers.keys().map(|header| header.as_str()).collect()
}
}

64
src/request_id.rs Normal file
View File

@ -0,0 +1,64 @@
use actix_web::dev::Payload;
use actix_web::{FromRequest, HttpRequest};
use std::future::{ready, Ready};
use uuid::Uuid;
/// A unique identifier generated for each incoming request.
///
/// Extracting a `RequestId` when the `TracingLogger` middleware is not registered will result in
/// an internal server error.
///
/// # Usage
/// ```rust
/// use actix_web::get;
/// use tracing_actix_web::RequestId;
/// use uuid::Uuid;
///
/// #[get("/")]
/// async fn index(request_id: RequestId) -> String {
/// format!("{}", request_id)
/// }
///
/// #[get("/2")]
/// async fn index2(request_id: RequestId) -> String {
/// let uuid: Uuid = request_id.into();
/// format!("{}", uuid)
/// }
/// ```
#[derive(Clone, Copy)]
pub struct RequestId(Uuid);
impl RequestId {
pub(crate) fn generate() -> Self {
Self(Uuid::new_v4())
}
}
impl std::ops::Deref for RequestId {
type Target = Uuid;
fn deref(&self) -> &Self::Target {
&self.0
}
}
impl std::convert::Into<Uuid> for RequestId {
fn into(self) -> Uuid {
self.0
}
}
impl std::fmt::Display for RequestId {
fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
write!(f, "{}", self.0)
}
}
impl FromRequest for RequestId {
type Error = ();
type Future = Ready<Result<Self, Self::Error>>;
type Config = ();
fn from_request(req: &HttpRequest, _: &mut Payload) -> Self::Future {
ready(req.extensions().get::<RequestId>().copied().ok_or(()))
}
}

57
src/root_span.rs Normal file
View File

@ -0,0 +1,57 @@
use actix_web::dev::Payload;
use actix_web::{FromRequest, HttpRequest};
use std::future::{ready, Ready};
use tracing::Span;
#[derive(Clone)]
/// The root span associated to the in-flight current request.
///
/// It can be used to populate additional properties using values computed or retrieved in the request
/// handler - see the crate-level documentation for more details.
///
/// Extracting a `RootSpan` when the `TracingLogger` middleware is not registered will result in
/// an internal server error.
///
/// # Usage
/// ```rust
/// use actix_web::get;
/// use tracing_actix_web::RootSpan;
/// use uuid::Uuid;
///
/// #[get("/")]
/// async fn index(root_span: RootSpan) -> String {
/// root_span.record("route", &"/");
/// # "Hello".to_string()
/// }
/// ```
pub struct RootSpan(Span);
impl RootSpan {
pub(crate) fn new(span: Span) -> Self {
Self(span)
}
}
impl std::ops::Deref for RootSpan {
type Target = Span;
fn deref(&self) -> &Self::Target {
&self.0
}
}
impl std::convert::Into<Span> for RootSpan {
fn into(self) -> Span {
self.0
}
}
impl FromRequest for RootSpan {
type Error = ();
type Future = Ready<Result<Self, Self::Error>>;
type Config = ();
fn from_request(req: &HttpRequest, _: &mut Payload) -> Self::Future {
ready(req.extensions().get::<RootSpan>().cloned().ok_or(()))
}
}

59
src/root_span_builder.rs Normal file
View File

@ -0,0 +1,59 @@
use crate::root_span;
use actix_web::dev::{ServiceRequest, ServiceResponse};
use actix_web::Error;
use tracing::Span;
/// `RootSpanBuilder` allows you to customise the root span attached by
/// [`TracingLogger`] to incoming requests.
///
/// [`TracingLogger`]: crate::TracingLogger
pub trait RootSpanBuilder {
fn on_request_start(request: &ServiceRequest) -> Span;
fn on_request_end<B>(span: Span, outcome: &Result<ServiceResponse<B>, Error>);
}
/// The default [`RootSpanBuilder`] for [`TracingLogger`].
///
/// It captures:
/// - HTTP method (`http.method`);
/// - HTTP route (`http.route`), with templated parameters;
/// - HTTP version (`http.flavor`);
/// - HTTP host (`http.host`);
/// - Client IP (`http.client_ip`);
/// - User agent (`http.user_agent`);
/// - Request path (`http.target`);
/// - Status code (`http.status_code`);
/// - [Request id](crate::RequestId) (`request_id`);
/// - [OpenTelemetry trace identifier](https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/overview.md#spancontext) (`trace_id`). Empty if the feature is not enabled;
/// - OpenTelemetry span kind, set to `server` (`otel.kind`).
///
/// All field names follow [OpenTelemetry's semantic convention](https://github.com/open-telemetry/opentelemetry-specification/tree/main/specification/trace/semantic_conventions).
///
/// [`TracingLogger`]: crate::TracingLogger
pub struct DefaultRootSpanBuilder;
impl RootSpanBuilder for DefaultRootSpanBuilder {
fn on_request_start(request: &ServiceRequest) -> Span {
root_span!(request)
}
fn on_request_end<B>(span: Span, outcome: &Result<ServiceResponse<B>, Error>) {
match &outcome {
Ok(response) => {
span.record("http.status_code", &response.response().status().as_u16());
span.record("otel.status_code", &"OK");
}
Err(error) => {
let response_error = error.as_response_error();
let status_code = response_error.status_code();
span.record("http.status_code", &status_code.as_u16());
if status_code.is_client_error() {
span.record("otel.status_code", &"OK");
} else {
span.record("otel.status_code", &"ERROR");
}
}
};
}
}

189
src/root_span_macro.rs Normal file
View File

@ -0,0 +1,189 @@
#[macro_export]
/// [`root_span!`] creates a new [`tracing::Span`].
/// It empowers you to add custom properties to the root span on top of the HTTP properties tracked
/// by [`DefaultRootSpanBuilder`].
///
/// # 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 `root_span!` must be a reference to an [`actix_web::dev::ServiceRequest`].
///
/// ```rust
/// use actix_web::dev::{ServiceResponse, ServiceRequest};
/// use actix_web::Error;
/// use tracing_actix_web::{TracingLogger, DefaultRootSpanBuilder, RootSpanBuilder, root_span};
/// use tracing::Span;
///
/// pub struct CustomRootSpanBuilder;
///
/// impl RootSpanBuilder for CustomRootSpanBuilder {
/// fn on_request_start(request: &ServiceRequest) -> Span {
/// root_span!(request)
/// }
///
/// fn on_request_end<B>(span: Span, outcome: &Result<ServiceResponse<B>, Error>) {
/// DefaultRootSpanBuilder::on_request_end(span, outcome);
/// }
/// }
/// ```
///
/// If nothing else is specified, the span generated by `root_span!` is identical to the one you'd
/// get by using `DefaultRootSpanBuilder`.
///
/// You can define new fields following the same syntax of `tracing::info_span!` for fields:
///
/// ```rust,should_panic
/// # let request: &actix_web::dev::ServiceRequest = todo!();
///
/// // Define a `client_id` field as empty. It might be populated later.
/// tracing_actix_web::root_span!(request, client_id = tracing::field::Empty);
///
/// // Define a `name` field with a known value, `AppName`.
/// tracing_actix_web::root_span!(request, name = "AppName");
///
/// // Define an `app_id` field using the variable with the same name as value.
/// let app_id = "XYZ";
/// tracing_actix_web::root_span!(request, app_id);
///
/// // All together
/// tracing_actix_web::root_span!(request, client_id = tracing::field::Empty, name = "AppName", app_id);
/// ```
///
/// [`DefaultRootSpanBuilder`]: crate::DefaultRootSpanBuilder
macro_rules! root_span {
// Vanilla root span, with no additional fields
($request:ident) => {
root_span!($request,)
};
// One or more additional fields, comma separated
($request:ident, $($field:tt)*) => {
{
let user_agent = $request
.headers()
.get("User-Agent")
.map(|h| h.to_str().unwrap_or(""))
.unwrap_or("");
let http_route: std::borrow::Cow<'static, str> = $request
.match_pattern()
.map(Into::into)
.unwrap_or_else(|| "default".into());
let http_method = $crate::root_span_macro::private::http_method_str($request.method());
let connection_info = $request.connection_info();
let request_id = $crate::root_span_macro::private::get_request_id($request);
let span = $crate::root_span_macro::private::tracing::info_span!(
"HTTP request",
http.method = %http_method,
http.route = %http_route,
http.flavor = %$crate::root_span_macro::private::http_flavor($request.version()),
http.scheme = %$crate::root_span_macro::private::http_scheme(connection_info.scheme()),
http.host = %connection_info.host(),
http.client_ip = %$request.connection_info().realip_remote_addr().unwrap_or(""),
http.user_agent = %user_agent,
http.target = %$request.uri().path_and_query().map(|p| p.as_str()).unwrap_or(""),
http.status_code = $crate::root_span_macro::private::tracing::field::Empty,
otel.kind = "server",
otel.status_code = $crate::root_span_macro::private::tracing::field::Empty,
trace_id = $crate::root_span_macro::private::tracing::field::Empty,
request_id = %request_id,
$($field)*
);
std::mem::drop(connection_info);
$crate::root_span_macro::private::set_otel_parent(&$request, &span);
span
}
};
}
#[doc(hidden)]
pub mod private {
//! This module exposes and re-exports various functions and traits as public in order to leverage them
//! in the code generated by the `root_span` macro.
//! Items in this module are not part of the public interface of `tracing-actix-web` - they are considered
//! implementation details and will change without notice in patch, minor and major releases.
use crate::RequestId;
use actix_web::dev::ServiceRequest;
use actix_web::http::{Method, Version};
use std::borrow::Cow;
pub use tracing;
#[cfg(not(feature = "opentelemetry_0_13"))]
#[doc(hidden)]
pub fn set_otel_parent(_req: &ServiceRequest, _span: &tracing::Span) {
// No-op if the OpenTelemetry feature is not active
}
#[cfg(feature = "opentelemetry_0_13")]
#[doc(hidden)]
pub fn set_otel_parent(req: &ServiceRequest, span: &tracing::Span) {
use opentelemetry::trace::TraceContextExt as _;
use tracing_opentelemetry::OpenTelemetrySpanExt as _;
let parent_context = opentelemetry::global::get_text_map_propagator(|propagator| {
propagator.extract(&crate::otel::RequestHeaderCarrier::new(req.headers()))
});
span.set_parent(parent_context);
// If we have a remote parent span, this will be the parent's trace identifier.
// If not, it will be the newly generated trace identifier with this request as root span.
let trace_id = span.context().span().span_context().trace_id().to_hex();
span.record("trace_id", &tracing::field::display(trace_id));
}
#[doc(hidden)]
#[inline]
pub fn http_method_str(method: &Method) -> Cow<'static, str> {
match method {
&Method::OPTIONS => "OPTIONS".into(),
&Method::GET => "GET".into(),
&Method::POST => "POST".into(),
&Method::PUT => "PUT".into(),
&Method::DELETE => "DELETE".into(),
&Method::HEAD => "HEAD".into(),
&Method::TRACE => "TRACE".into(),
&Method::CONNECT => "CONNECT".into(),
&Method::PATCH => "PATCH".into(),
other => other.to_string().into(),
}
}
#[doc(hidden)]
#[inline]
pub fn http_flavor(version: Version) -> Cow<'static, str> {
match version {
Version::HTTP_09 => "0.9".into(),
Version::HTTP_10 => "1.0".into(),
Version::HTTP_11 => "1.1".into(),
Version::HTTP_2 => "2.0".into(),
Version::HTTP_3 => "3.0".into(),
other => format!("{:?}", other).into(),
}
}
#[doc(hidden)]
#[inline]
pub fn http_scheme(scheme: &str) -> Cow<'static, str> {
match scheme {
"http" => "http".into(),
"https" => "https".into(),
other => other.to_string().into(),
}
}
#[doc(hidden)]
pub fn generate_request_id() -> RequestId {
RequestId::generate()
}
#[doc(hidden)]
pub fn get_request_id(request: &ServiceRequest) -> RequestId {
use actix_web::HttpMessage;
request.extensions().get::<RequestId>().cloned().unwrap()
}
}