diff --git a/Cargo.lock b/Cargo.lock index bd12c4ef8d..2ba681976c 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -4211,12 +4211,108 @@ dependencies = [ "vcpkg", ] +[[package]] +name = "opentelemetry" +version = "0.22.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "900d57987be3f2aeb70d385fff9b27fb74c5723cc9a52d904d4f9c807a0667bf" +dependencies = [ + "futures-core", + "futures-sink", + "js-sys", + "once_cell", + "pin-project-lite", + "thiserror", + "urlencoding", +] + +[[package]] +name = "opentelemetry-http" +version = "0.11.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7cbfa5308166ca861434f0b0913569579b8e587430a3d6bcd7fd671921ec145a" +dependencies = [ + "async-trait", + "bytes", + "http 0.2.12", + "opentelemetry", + "reqwest", +] + +[[package]] +name = "opentelemetry-otlp" +version = "0.15.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1a016b8d9495c639af2145ac22387dcb88e44118e45320d9238fbf4e7889abcb" +dependencies = [ + "async-trait", + "futures-core", + "http 0.2.12", + "opentelemetry", + "opentelemetry-http", + "opentelemetry-proto", + "opentelemetry-semantic-conventions", + "opentelemetry_sdk", + "prost", + "reqwest", + "thiserror", +] + +[[package]] +name = "opentelemetry-proto" +version = "0.5.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3a8fddc9b68f5b80dae9d6f510b88e02396f006ad48cac349411fbecc80caae4" +dependencies = [ + "opentelemetry", + "opentelemetry_sdk", + "prost", + "tonic", +] + +[[package]] +name = "opentelemetry-semantic-conventions" +version = "0.14.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f9ab5bd6c42fb9349dcf28af2ba9a0667f697f9bdcca045d39f2cec5543e2910" + +[[package]] +name = "opentelemetry_sdk" +version = "0.22.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9e90c7113be649e31e9a0f8b5ee24ed7a16923b322c3c5ab6367469c049d6b7e" +dependencies = [ + "async-trait", + "crossbeam-channel", + "futures-channel", + "futures-executor", + "futures-util", + "glob", + "once_cell", + "opentelemetry", + "ordered-float", + "percent-encoding", + "rand 0.8.5", + "thiserror", + "tokio", + "tokio-stream", +] + [[package]] name = "option-ext" version = "0.2.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "04744f49eae99ab78e0d5c0b603ab218f515ea8cfe5a456d7629ad883a3b6e7d" +[[package]] +name = "ordered-float" +version = "4.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a76df7075c7d4d01fdcb46c912dd17fba5b60c78ea480b475f2b6ab6f666584e" +dependencies = [ + "num-traits", +] + [[package]] name = "os_str_bytes" version = "6.6.1" @@ -4782,6 +4878,29 @@ dependencies = [ "tokio-stream", ] +[[package]] +name = "prost" +version = "0.12.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "146c289cda302b98a28d40c8b3b90498d6e526dd24ac2ecea73e4e491685b94a" +dependencies = [ + "bytes", + "prost-derive", +] + +[[package]] +name = "prost-derive" +version = "0.12.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "efb6c9a1dd1def8e2124d17e83a20af56f1570d6c2d2bd9e266ccb768df3840e" +dependencies = [ + "anyhow", + "itertools 0.11.0", + "proc-macro2", + "quote", + "syn 2.0.52", +] + [[package]] name = "psm" version = "0.1.21" @@ -5899,6 +6018,7 @@ dependencies = [ "spin-manifest", "spin-oci", "spin-plugins", + "spin-telemetry", "spin-templates", "spin-trigger", "spin-trigger-http", @@ -5973,6 +6093,7 @@ dependencies = [ "io-extras", "rustix 0.37.27", "spin-componentize", + "spin-telemetry", "system-interface", "tempfile", "tokio", @@ -6141,6 +6262,7 @@ dependencies = [ "serde_json", "spin-core", "spin-llm", + "spin-telemetry", "spin-world", "tracing", ] @@ -6330,6 +6452,24 @@ dependencies = [ "tokio", ] +[[package]] +name = "spin-telemetry" +version = "2.4.0-pre0" +dependencies = [ + "anyhow", + "http 0.2.12", + "http 1.1.0", + "opentelemetry", + "opentelemetry-otlp", + "opentelemetry-semantic-conventions", + "opentelemetry_sdk", + "tracing", + "tracing-appender", + "tracing-opentelemetry", + "tracing-subscriber", + "url", +] + [[package]] name = "spin-templates" version = "2.4.0-pre0" @@ -6458,6 +6598,7 @@ dependencies = [ "spin-core", "spin-http", "spin-outbound-networking", + "spin-telemetry", "spin-testing", "spin-trigger", "spin-world", @@ -7194,6 +7335,27 @@ dependencies = [ "winnow 0.6.5", ] +[[package]] +name = "tonic" +version = "0.11.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "76c4eb7a4e9ef9d4763600161f12f5070b92a578e1b634db88a6887844c91a13" +dependencies = [ + "async-trait", + "base64 0.21.7", + "bytes", + "http 0.2.12", + "http-body 0.4.6", + "percent-encoding", + "pin-project", + "prost", + "tokio", + "tokio-stream", + "tower-layer", + "tower-service", + "tracing", +] + [[package]] name = "tower" version = "0.4.13" @@ -7233,6 +7395,18 @@ dependencies = [ "tracing-core", ] +[[package]] +name = "tracing-appender" +version = "0.2.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3566e8ce28cc0a3fe42519fc80e6b4c943cc4c8cef275620eb8dac2d3d4e06cf" +dependencies = [ + "crossbeam-channel", + "thiserror", + "time", + "tracing-subscriber", +] + [[package]] name = "tracing-attributes" version = "0.1.27" @@ -7265,6 +7439,34 @@ dependencies = [ "tracing-core", ] +[[package]] +name = "tracing-opentelemetry" +version = "0.23.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a9be14ba1bbe4ab79e9229f7f89fab8d120b865859f10527f31c033e599d2284" +dependencies = [ + "js-sys", + "once_cell", + "opentelemetry", + "opentelemetry_sdk", + "smallvec", + "tracing", + "tracing-core", + "tracing-log", + "tracing-subscriber", + "web-time", +] + +[[package]] +name = "tracing-serde" +version = "0.1.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bc6b213177105856957181934e4920de57730fc69bf42c37ee5bb664d406d9e1" +dependencies = [ + "serde", + "tracing-core", +] + [[package]] name = "tracing-subscriber" version = "0.3.18" @@ -7275,12 +7477,15 @@ dependencies = [ "nu-ansi-term", "once_cell", "regex", + "serde", + "serde_json", "sharded-slab", "smallvec", "thread_local", "tracing", "tracing-core", "tracing-log", + "tracing-serde", ] [[package]] @@ -8218,6 +8423,16 @@ dependencies = [ "wasm-bindgen", ] +[[package]] +name = "web-time" +version = "1.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5a6580f308b1fad9207618087a65c04e7a10bc77e02c8e84e9b00dd4b12fa0bb" +dependencies = [ + "js-sys", + "wasm-bindgen", +] + [[package]] name = "webpki" version = "0.22.4" diff --git a/Cargo.toml b/Cargo.toml index 4a3806513e..904cd4ad3f 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -61,6 +61,7 @@ spin-locked-app = { path = "crates/locked-app" } spin-manifest = { path = "crates/manifest" } spin-oci = { path = "crates/oci" } spin-plugins = { path = "crates/plugins" } +spin-telemetry = { path = "crates/telemetry" } spin-templates = { path = "crates/templates" } spin-trigger = { path = "crates/trigger" } spin-trigger-http = { path = "crates/trigger-http" } diff --git a/crates/core/Cargo.toml b/crates/core/Cargo.toml index a76b84c8af..ce34593fa6 100644 --- a/crates/core/Cargo.toml +++ b/crates/core/Cargo.toml @@ -18,6 +18,7 @@ cap-std = "2.0.0" cap-primitives = "2.0.0" tokio = "1.0" bytes = "1.0" +spin-telemetry = { path = "../telemetry" } [target.'cfg(unix)'.dependencies] rustix = "0.37.19" diff --git a/crates/core/src/lib.rs b/crates/core/src/lib.rs index 5340d44c25..e9885da3b5 100644 --- a/crates/core/src/lib.rs +++ b/crates/core/src/lib.rs @@ -195,15 +195,17 @@ impl WasiHttpView for Data { &mut self.table } + #[instrument(name = "start_outbound_http_request", skip_all, fields(otel.kind = "client"))] fn send_request( &mut self, - request: wasmtime_wasi_http::types::OutgoingRequest, + mut request: wasmtime_wasi_http::types::OutgoingRequest, ) -> wasmtime::Result< wasmtime::component::Resource, > where Self: Sized, { + spin_telemetry::inject_trace_context(&mut request.request); T::send_request(self, request) } } @@ -393,14 +395,14 @@ impl Engine { } /// Creates a new [`InstancePre`] for the given [`Component`]. - #[instrument(skip_all)] + #[instrument(skip_all, level = "debug")] pub fn instantiate_pre(&self, component: &Component) -> Result> { let inner = self.linker.instantiate_pre(component)?; Ok(InstancePre { inner }) } /// Creates a new [`ModuleInstancePre`] for the given [`Module`]. - #[instrument(skip_all)] + #[instrument(skip_all, level = "debug")] pub fn module_instantiate_pre(&self, module: &Module) -> Result> { let inner = self.module_linker.instantiate_pre(module)?; Ok(ModuleInstancePre { inner }) @@ -429,7 +431,7 @@ pub struct InstancePre { impl InstancePre { /// Instantiates this instance with the given [`Store`]. - #[instrument(skip_all)] + #[instrument(skip_all, level = "debug")] pub async fn instantiate_async(&self, store: &mut Store) -> Result { self.inner.instantiate_async(store).await } @@ -458,7 +460,7 @@ pub struct ModuleInstancePre { impl ModuleInstancePre { /// Instantiates this instance with the given [`Store`]. - #[instrument(skip_all)] + #[instrument(skip_all, level = "debug")] pub async fn instantiate_async(&self, store: &mut Store) -> Result { self.inner.instantiate_async(store).await } diff --git a/crates/llm-local/src/lib.rs b/crates/llm-local/src/lib.rs index 120f9e4dfb..b50e033546 100644 --- a/crates/llm-local/src/lib.rs +++ b/crates/llm-local/src/lib.rs @@ -21,6 +21,7 @@ use std::{ sync::{Arc, Mutex}, }; use tokenizers::PaddingParams; +use tracing::instrument; #[derive(Clone)] pub struct LocalLlmEngine { @@ -32,6 +33,7 @@ pub struct LocalLlmEngine { #[async_trait] impl LlmEngine for LocalLlmEngine { + #[instrument(name = "llm_generate_local_inference", skip(self, prompt))] async fn infer( &mut self, model: wasi_llm::InferencingModel, @@ -91,6 +93,7 @@ impl LlmEngine for LocalLlmEngine { Ok(response) } + #[instrument(name = "llm_generate_local_embeddings", skip(self, data))] async fn generate_embeddings( &mut self, model: wasi_llm::EmbeddingModel, diff --git a/crates/llm-remote-http/Cargo.toml b/crates/llm-remote-http/Cargo.toml index 9759d8624c..f7358f2f91 100644 --- a/crates/llm-remote-http/Cargo.toml +++ b/crates/llm-remote-http/Cargo.toml @@ -12,6 +12,7 @@ serde = { version = "1.0.150", features = ["derive"] } serde_json = "1.0" spin-core = { path = "../core" } spin-llm = { path = "../llm" } +spin-telemetry = { path = "../telemetry" } spin-world = { path = "../world" } reqwest = { version = "0.11", features = ["gzip", "json"] } tracing = { workspace = true } diff --git a/crates/llm-remote-http/src/lib.rs b/crates/llm-remote-http/src/lib.rs index 15c29baf60..d308d51f76 100644 --- a/crates/llm-remote-http/src/lib.rs +++ b/crates/llm-remote-http/src/lib.rs @@ -8,6 +8,7 @@ use serde_json::json; use spin_core::async_trait; use spin_llm::LlmEngine; use spin_world::v2::llm::{self as wasi_llm}; +use tracing::instrument; #[derive(Clone)] pub struct RemoteHttpLlmEngine { @@ -54,6 +55,7 @@ struct EmbeddingResponseBody { #[async_trait] impl LlmEngine for RemoteHttpLlmEngine { + #[instrument(name = "llm_generate_remote_inference", skip(self, prompt), fields(otel.kind = "client"))] async fn infer( &mut self, model: wasi_llm::InferencingModel, @@ -69,6 +71,8 @@ impl LlmEngine for RemoteHttpLlmEngine { wasi_llm::Error::RuntimeError("Failed to create authorization header".to_string()) })?, ); + spin_telemetry::inject_trace_context(&mut headers); + let inference_options = InferRequestBodyParams { max_tokens: params.max_tokens, repeat_penalty: params.repeat_penalty, @@ -114,6 +118,7 @@ impl LlmEngine for RemoteHttpLlmEngine { } } + #[instrument(name = "llm_generate_remote_embeddings", skip(self, data), fields(otel.kind = "client"))] async fn generate_embeddings( &mut self, model: wasi_llm::EmbeddingModel, @@ -128,6 +133,7 @@ impl LlmEngine for RemoteHttpLlmEngine { wasi_llm::Error::RuntimeError("Failed to create authorization header".to_string()) })?, ); + spin_telemetry::inject_trace_context(&mut headers); let body = serde_json::to_string(&json!({ "model": model, diff --git a/crates/telemetry/Cargo.toml b/crates/telemetry/Cargo.toml new file mode 100644 index 0000000000..8e13bc4aec --- /dev/null +++ b/crates/telemetry/Cargo.toml @@ -0,0 +1,19 @@ +[package] +name = "spin-telemetry" +version = { workspace = true } +authors = { workspace = true } +edition = { workspace = true } + +[dependencies] +anyhow = { workspace = true } +http0 = { version = "0.2.9", package = "http" } +http1 = { version = "1.0.0", package = "http" } +opentelemetry = { version = "0.22.0", features = [ "metrics", "trace"] } +opentelemetry_sdk = { version = "0.22.1", features = ["rt-tokio"] } +opentelemetry-otlp = { version = "0.15.0", default_features=false, features = ["http-proto", "trace", "http", "reqwest-client", "metrics"] } +opentelemetry-semantic-conventions = "0.14.0" +tracing = { version = "0.1.37", features = ["log"] } +tracing-appender = "0.2.2" +tracing-opentelemetry = "0.23.0" +tracing-subscriber = { version = "0.3.17", features = ["env-filter", "json", "registry"] } +url = "2.2.2" diff --git a/crates/telemetry/src/detector.rs b/crates/telemetry/src/detector.rs new file mode 100644 index 0000000000..0c10ae5907 --- /dev/null +++ b/crates/telemetry/src/detector.rs @@ -0,0 +1,47 @@ +use std::{env, time::Duration}; + +use opentelemetry::{Key, KeyValue, Value}; +use opentelemetry_sdk::{ + resource::{EnvResourceDetector, ResourceDetector}, + Resource, +}; + +const OTEL_SERVICE_NAME: &str = "OTEL_SERVICE_NAME"; + +/// Custom resource detector for Spin relevant attributes service.name and service.version. +/// +/// To set service.name this detector will first try `OTEL_SERVICE_NAME` env. If it's not available, +/// then it will check the `OTEL_RESOURCE_ATTRIBUTES` env and see if it contains `service.name` +/// resource. If it's also not available, it will use `spin`. +/// +/// To set service.version, it will use the spin_version passed in new. +#[derive(Debug)] +pub struct SpinResourceDetector { + spin_version: String, +} + +impl SpinResourceDetector { + /// Create a new instance of SpinResourceDetector. + pub fn new(spin_version: String) -> Self { + SpinResourceDetector { spin_version } + } +} + +impl ResourceDetector for SpinResourceDetector { + fn detect(&self, _timeout: Duration) -> Resource { + let service_name = env::var(OTEL_SERVICE_NAME) + .ok() + .filter(|s| !s.is_empty()) + .map(Value::from) + .or_else(|| { + EnvResourceDetector::new() + .detect(Duration::from_secs(0)) + .get(Key::new("service.name")) + }) + .unwrap_or_else(|| "spin".into()); + Resource::new(vec![ + KeyValue::new("service.name", service_name), + KeyValue::new("service.version", self.spin_version.clone()), + ]) + } +} diff --git a/crates/telemetry/src/lib.rs b/crates/telemetry/src/lib.rs new file mode 100644 index 0000000000..32d0ddd803 --- /dev/null +++ b/crates/telemetry/src/lib.rs @@ -0,0 +1,97 @@ +use std::io::IsTerminal; + +use opentelemetry_sdk::propagation::TraceContextPropagator; +use tracing_subscriber::{fmt, prelude::*, registry, EnvFilter, Layer}; + +pub mod detector; +mod propagation; +mod traces; + +pub use propagation::extract_trace_context; +pub use propagation::inject_trace_context; + +/// Initializes telemetry for Spin using the [tracing] library. +/// +/// Under the hood this involves initializing a [tracing::Subscriber] with multiple [Layer]s. One +/// [Layer] emits [tracing] events to stderr, and another sends spans to an OTEL collector. +/// +/// Configuration is pulled from the environment. +pub fn init(spin_version: String) -> anyhow::Result { + // This layer will print all tracing library log messages to stderr. + let fmt_layer = fmt::layer() + .with_writer(std::io::stderr) + .with_ansi(std::io::stderr().is_terminal()) + .with_filter( + EnvFilter::from_default_env() + .add_directive("wasmtime_wasi_http=warn".parse()?) + .add_directive("watchexec=off".parse()?), + ); + + // We only want to build the otel layer if the user passed some endpoint configuration and it wasn't explicitly disabled. + let build_otel_layer = !otel_sdk_disabled() && otel_enabled(); + let otel_layer = if build_otel_layer { + // In this case we want to set the error handler to log errors to the tracing layer. + opentelemetry::global::set_error_handler(otel_error_handler)?; + + Some(traces::otel_tracing_layer(spin_version)?) + } else { + None + }; + + // Build a registry subscriber with the layers we want to use. + registry().with(otel_layer).with(fmt_layer).init(); + + // Used to propagate trace information in the standard W3C TraceContext format. Even if the otel + // layer is disabled we still want to propagate trace context. + opentelemetry::global::set_text_map_propagator(TraceContextPropagator::new()); + + Ok(ShutdownGuard) +} + +/// Returns a boolean indicating if the OTEL layer should be enabled. +/// +/// It is considered enabled if any of the following environment variables are set and not empty: +/// - `OTEL_EXPORTER_OTLP_ENDPOINT` +/// - `OTEL_EXPORTER_OTLP_TRACES_ENDPOINT` +/// - `OTEL_EXPORTER_OTLP_METRICS_ENDPOINT` +/// +/// Note that this is overridden if OTEL_SDK_DISABLED is set and not empty. +fn otel_enabled() -> bool { + const ENABLING_VARS: &[&str] = &[ + "OTEL_EXPORTER_OTLP_ENDPOINT", + "OTEL_EXPORTER_OTLP_TRACES_ENDPOINT", + "OTEL_EXPORTER_OTLP_METRICS_ENDPOINT", + ]; + ENABLING_VARS + .iter() + .any(|key| std::env::var_os(key).is_some_and(|val| !val.is_empty())) +} + +/// Returns a boolean indicating if the OTEL SDK should be disabled for all signals. +/// +/// It is considered disabled if the environment variable `OTEL_SDK_DISABLED` is set and not empty. +fn otel_sdk_disabled() -> bool { + std::env::var_os("OTEL_SDK_DISABLED").is_some_and(|val| !val.is_empty()) +} + +fn otel_error_handler(err: opentelemetry::global::Error) { + static FIRST_OTEL_ERROR: std::sync::Once = std::sync::Once::new(); + FIRST_OTEL_ERROR.call_once(|| { + tracing::error!("There has been an error with the OpenTelemetry system, traces and metrics are likely failing to export"); + tracing::error!("Further OpenTelemetry errors will be logged at DEBUG level") + }); + tracing::debug!(?err, "OpenTelemetry error"); +} + +/// An RAII implementation for connection to open telemetry services. +/// +/// Shutdown of the open telemetry services will happen on `Drop`. +#[must_use] +pub struct ShutdownGuard; + +impl Drop for ShutdownGuard { + fn drop(&mut self) { + // Give tracer provider a chance to flush any pending traces. + opentelemetry::global::shutdown_tracer_provider(); + } +} diff --git a/crates/telemetry/src/propagation.rs b/crates/telemetry/src/propagation.rs new file mode 100644 index 0000000000..203962d6b9 --- /dev/null +++ b/crates/telemetry/src/propagation.rs @@ -0,0 +1,110 @@ +use opentelemetry::{ + global, + propagation::{Extractor, Injector}, +}; +use tracing_opentelemetry::OpenTelemetrySpanExt; + +/// Injects the current W3C TraceContext into the provided request. +pub fn inject_trace_context<'a>(req: impl Into>) { + let mut injector = req.into(); + global::get_text_map_propagator(|propagator| { + let context = tracing::Span::current().context(); + propagator.inject_context(&context, &mut injector); + }); +} + +/// Extracts the W3C TraceContext from the provided request and sets it as the parent of the +/// current span. +pub fn extract_trace_context<'a>(req: impl Into>) { + let extractor = req.into(); + let parent_context = + global::get_text_map_propagator(|propagator| propagator.extract(&extractor)); + tracing::Span::current().set_parent(parent_context); +} + +pub enum HeaderInjector<'a> { + Http0(&'a mut http0::HeaderMap), + Http1(&'a mut http1::HeaderMap), +} + +impl<'a> Injector for HeaderInjector<'a> { + fn set(&mut self, key: &str, value: String) { + match self { + HeaderInjector::Http0(headers) => { + if let Ok(name) = http0::header::HeaderName::from_bytes(key.as_bytes()) { + if let Ok(val) = http0::header::HeaderValue::from_str(&value) { + headers.insert(name, val); + } + } + } + HeaderInjector::Http1(headers) => { + if let Ok(name) = http1::header::HeaderName::from_bytes(key.as_bytes()) { + if let Ok(val) = http1::header::HeaderValue::from_str(&value) { + headers.insert(name, val); + } + } + } + } + } +} + +impl<'a, T> From<&'a mut http0::Request> for HeaderInjector<'a> { + fn from(req: &'a mut http0::Request) -> Self { + Self::Http0(req.headers_mut()) + } +} + +impl<'a, T> From<&'a mut http1::Request> for HeaderInjector<'a> { + fn from(req: &'a mut http1::Request) -> Self { + Self::Http1(req.headers_mut()) + } +} + +impl<'a> From<&'a mut http0::HeaderMap> for HeaderInjector<'a> { + fn from(headers: &'a mut http0::HeaderMap) -> Self { + Self::Http0(headers) + } +} + +impl<'a> From<&'a mut http1::HeaderMap> for HeaderInjector<'a> { + fn from(headers: &'a mut http1::HeaderMap) -> Self { + Self::Http1(headers) + } +} + +pub enum HeaderExtractor<'a> { + Http0(&'a http0::HeaderMap), + Http1(&'a http1::HeaderMap), +} + +impl<'a> Extractor for HeaderExtractor<'a> { + fn get(&self, key: &str) -> Option<&str> { + match self { + HeaderExtractor::Http0(headers) => { + headers.get(key).map(|v| v.to_str().unwrap_or_default()) + } + HeaderExtractor::Http1(headers) => { + headers.get(key).map(|v| v.to_str().unwrap_or_default()) + } + } + } + + fn keys(&self) -> Vec<&str> { + match self { + HeaderExtractor::Http0(headers) => headers.keys().map(|k| k.as_str()).collect(), + HeaderExtractor::Http1(headers) => headers.keys().map(|k| k.as_str()).collect(), + } + } +} + +impl<'a, T> From<&'a http0::Request> for HeaderExtractor<'a> { + fn from(req: &'a http0::Request) -> Self { + Self::Http0(req.headers()) + } +} + +impl<'a, T> From<&'a http1::Request> for HeaderExtractor<'a> { + fn from(req: &'a http1::Request) -> Self { + Self::Http1(req.headers()) + } +} diff --git a/crates/telemetry/src/traces.rs b/crates/telemetry/src/traces.rs new file mode 100644 index 0000000000..5f2de1c43a --- /dev/null +++ b/crates/telemetry/src/traces.rs @@ -0,0 +1,96 @@ +use std::time::Duration; + +use opentelemetry_otlp::WithExportConfig; +use opentelemetry_otlp::{OTEL_EXPORTER_OTLP_ENDPOINT, OTEL_EXPORTER_OTLP_TRACES_ENDPOINT}; +use opentelemetry_sdk::{ + resource::{EnvResourceDetector, TelemetryResourceDetector}, + trace::Tracer, + Resource, +}; +use tracing_opentelemetry::OpenTelemetryLayer; +use tracing_subscriber::{EnvFilter, Layer, Registry}; + +use crate::detector::SpinResourceDetector; + +/// Constructs a layer for the tracing subscriber that sends spans to an OTEL collector. +/// +/// It pulls OTEL configuration from the environment based on the variables defined +/// [here](https://opentelemetry.io/docs/specs/otel/protocol/exporter/) and +/// [here](https://opentelemetry.io/docs/specs/otel/configuration/sdk-environment-variables/#general-sdk-configuration). +pub(crate) fn otel_tracing_layer( + spin_version: String, +) -> anyhow::Result< + tracing_subscriber::filter::Filtered, EnvFilter, Registry>, +> { + let resource = Resource::from_detectors( + Duration::from_secs(5), + vec![ + // Set service.name from env OTEL_SERVICE_NAME > env OTEL_RESOURCE_ATTRIBUTES > spin + // Set service.version from Spin metadata + Box::new(SpinResourceDetector::new(spin_version)), + // Sets fields from env OTEL_RESOURCE_ATTRIBUTES + Box::new(EnvResourceDetector::new()), + // Sets telemetry.sdk{name, language, version} + Box::new(TelemetryResourceDetector), + ], + ); + + // This will configure the exporter based on the OTEL_EXPORTER_* environment variables. We + // currently default to using the HTTP exporter but in the future we could select off of the + // combination of OTEL_EXPORTER_OTLP_PROTOCOL and OTEL_EXPORTER_OTLP_TRACES_PROTOCOL to + // determine whether we should use http/protobuf or grpc. + let mut exporter = opentelemetry_otlp::new_exporter().http(); + if let Some(endpoint) = fix_endpoint_bug() { + exporter = exporter.with_endpoint(endpoint); + } + + let tracer = opentelemetry_otlp::new_pipeline() + .tracing() + .with_exporter(exporter) + .with_trace_config(opentelemetry_sdk::trace::config().with_resource(resource)) + .install_batch(opentelemetry_sdk::runtime::Tokio)?; + + let env_filter = match EnvFilter::try_from_env("SPIN_OTEL_TRACING_LEVEL") { + Ok(filter) => filter, + // If it isn't set or it fails to parse default to info + Err(_) => EnvFilter::new("info"), + }; + + Ok(tracing_opentelemetry::layer() + .with_tracer(tracer) + .with_threads(false) + .with_filter(env_filter)) +} + +// This mitigation was taken from https://github.com/neondatabase/neon/blob/main/libs/tracing-utils/src/lib.rs +// +// opentelemetry-otlp v0.15.0 has a bug in how it uses the +// OTEL_EXPORTER_OTLP_ENDPOINT env variable. According to the +// OpenTelemetry spec at +// , +// the full exporter URL is formed by appending "/v1/traces" to the value +// of OTEL_EXPORTER_OTLP_ENDPOINT. However, opentelemetry-otlp only does +// that with the grpc-tonic exporter. Other exporters, like the HTTP +// exporter, use the URL from OTEL_EXPORTER_OTLP_ENDPOINT as is, without +// appending "/v1/traces". +// +// See https://github.com/open-telemetry/opentelemetry-rust/pull/950 +// +// Work around that by checking OTEL_EXPORTER_OTLP_ENDPOINT, and setting +// the endpoint url with the "/v1/traces" path ourselves. If the bug is +// fixed in a later version, we can remove this code. But if we don't +// remember to remove this, it won't do any harm either, as the crate will +// just ignore the OTEL_EXPORTER_OTLP_ENDPOINT setting when the endpoint +// is set directly with `with_endpoint`. +fn fix_endpoint_bug() -> Option { + if std::env::var(OTEL_EXPORTER_OTLP_TRACES_ENDPOINT).is_err() { + if let Ok(mut endpoint) = std::env::var(OTEL_EXPORTER_OTLP_ENDPOINT) { + if !endpoint.ends_with('/') { + endpoint.push('/'); + } + endpoint.push_str("v1/traces"); + return Some(endpoint); + } + } + None +} diff --git a/crates/trigger-http/Cargo.toml b/crates/trigger-http/Cargo.toml index a5c79301a7..98c4ba3894 100644 --- a/crates/trigger-http/Cargo.toml +++ b/crates/trigger-http/Cargo.toml @@ -27,6 +27,7 @@ spin-app = { path = "../app" } spin-core = { path = "../core" } spin-http = { path = "../http" } spin-outbound-networking = { path = "../outbound-networking" } +spin-telemetry = { path = "../telemetry" } spin-trigger = { path = "../trigger" } spin-world = { path = "../world" } terminal = { path = "../terminal" } diff --git a/crates/trigger-http/src/handler.rs b/crates/trigger-http/src/handler.rs index 779b199469..ec025e0061 100644 --- a/crates/trigger-http/src/handler.rs +++ b/crates/trigger-http/src/handler.rs @@ -17,6 +17,7 @@ use spin_trigger::TriggerAppEngine; use spin_world::v1::http_types; use std::sync::Arc; use tokio::{sync::oneshot, task}; +use tracing::{instrument, Instrument}; use wasmtime_wasi_http::{proxy::Proxy, WasiHttpView}; #[derive(Clone)] @@ -24,6 +25,7 @@ pub struct HttpHandlerExecutor; #[async_trait] impl HttpExecutor for HttpHandlerExecutor { + #[instrument(name = "execute_wasm", skip_all, fields(otel.kind = "server"))] async fn execute( &self, engine: Arc>, @@ -210,29 +212,40 @@ impl HttpHandlerExecutor { None => Handler::Latest(Proxy::new(&mut store, &instance)?), }; - let handle = task::spawn(async move { - let result = match handler { - Handler::Latest(proxy) => { - proxy - .wasi_http_incoming_handler() - .call_handle(&mut store, request, response) - .await - } - Handler::Handler2023_10_18(proxy) => { - proxy.call_handle(&mut store, request, response).await - } - Handler::Handler2023_11_10(proxy) => { - proxy.call_handle(&mut store, request, response).await - } - }; + let span = tracing::debug_span!("execute_wasi"); + let handle = task::spawn( + async move { + let result = match handler { + Handler::Latest(proxy) => { + proxy + .wasi_http_incoming_handler() + .call_handle(&mut store, request, response) + .instrument(span) + .await + } + Handler::Handler2023_10_18(proxy) => { + proxy + .call_handle(&mut store, request, response) + .instrument(span) + .await + } + Handler::Handler2023_11_10(proxy) => { + proxy + .call_handle(&mut store, request, response) + .instrument(span) + .await + } + }; - tracing::trace!( - "wasi-http memory consumed: {}", - store.as_ref().data().memory_consumed() - ); + tracing::trace!( + "wasi-http memory consumed: {}", + store.as_ref().data().memory_consumed() + ); - result - }); + result + } + .in_current_span(), + ); match response_rx.await { Ok(response) => { diff --git a/crates/trigger-http/src/lib.rs b/crates/trigger-http/src/lib.rs index c9ead9ee62..e4db3fbd1b 100644 --- a/crates/trigger-http/src/lib.rs +++ b/crates/trigger-http/src/lib.rs @@ -41,7 +41,7 @@ use tokio::{ net::TcpListener, task, }; -use tracing::log; +use tracing::{log, Instrument}; use wasmtime_wasi_http::{body::HyperIncomingBody as Body, WasiHttpView}; use crate::{handler::HttpHandlerExecutor, wagi::WagiHttpExecutor}; @@ -231,6 +231,8 @@ impl HttpTrigger { set_req_uri(&mut req, scheme)?; strip_forbidden_headers(&mut req); + spin_telemetry::extract_trace_context(&req); + log::info!( "Processing request for application {} on URI {}", &self.engine.app_name, @@ -336,6 +338,22 @@ impl HttpTrigger { TokioIo::new(stream), service_fn(move |request| { let self_ = self_.clone(); + let span = tracing::info_span!( + "handle_http_request", + "otel.kind" = "server", + "http.request.method" = %request.method(), + "network.peer.address" = %addr.ip(), + "network.peer.port" = %addr.port(), + "network.protocol.name" = "http", + "url.path" = request.uri().path(), + "url.query" = request.uri().query().unwrap_or(""), + "url.scheme" = request.uri().scheme_str().unwrap_or(""), + "client.address" = request.headers().get("x-forwarded-for").and_then(|val| val.to_str().ok()), + // TODO(Caleb): Recorded later + // "error.type" = Empty, + // "http.response.status_code" = Empty, + // "http.route" = Empty, + ); async move { self_ .handle( @@ -346,6 +364,7 @@ impl HttpTrigger { Scheme::HTTP, addr, ) + .instrument(span) .await } }), diff --git a/examples/spin-timer/Cargo.lock b/examples/spin-timer/Cargo.lock index 208662cb41..742fa6e45b 100644 --- a/examples/spin-timer/Cargo.lock +++ b/examples/spin-timer/Cargo.lock @@ -2162,6 +2162,15 @@ version = "0.1.3" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "58093314a45e00c77d5c508f76e77c3396afbbc0d01506e7fae47b018bac2b1d" +[[package]] +name = "matchers" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8263075bb86c5a1b1427b5ae862e8889656f126e9f77c484496e8b47cf5c5558" +dependencies = [ + "regex-automata 0.1.10", +] + [[package]] name = "maybe-owned" version = "0.3.4" @@ -2381,6 +2390,16 @@ dependencies = [ "minimal-lexical", ] +[[package]] +name = "nu-ansi-term" +version = "0.46.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "77a8165726e8236064dbb45459242600304b42a5ea24ee2948e18e023bf7ba84" +dependencies = [ + "overload", + "winapi", +] + [[package]] name = "num-bigint" version = "0.4.4" @@ -2525,12 +2544,108 @@ dependencies = [ "vcpkg", ] +[[package]] +name = "opentelemetry" +version = "0.22.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "900d57987be3f2aeb70d385fff9b27fb74c5723cc9a52d904d4f9c807a0667bf" +dependencies = [ + "futures-core", + "futures-sink", + "js-sys", + "once_cell", + "pin-project-lite", + "thiserror", + "urlencoding", +] + +[[package]] +name = "opentelemetry-http" +version = "0.11.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7cbfa5308166ca861434f0b0913569579b8e587430a3d6bcd7fd671921ec145a" +dependencies = [ + "async-trait", + "bytes", + "http 0.2.11", + "opentelemetry", + "reqwest", +] + +[[package]] +name = "opentelemetry-otlp" +version = "0.15.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1a016b8d9495c639af2145ac22387dcb88e44118e45320d9238fbf4e7889abcb" +dependencies = [ + "async-trait", + "futures-core", + "http 0.2.11", + "opentelemetry", + "opentelemetry-http", + "opentelemetry-proto", + "opentelemetry-semantic-conventions", + "opentelemetry_sdk", + "prost", + "reqwest", + "thiserror", +] + +[[package]] +name = "opentelemetry-proto" +version = "0.5.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3a8fddc9b68f5b80dae9d6f510b88e02396f006ad48cac349411fbecc80caae4" +dependencies = [ + "opentelemetry", + "opentelemetry_sdk", + "prost", + "tonic", +] + +[[package]] +name = "opentelemetry-semantic-conventions" +version = "0.14.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f9ab5bd6c42fb9349dcf28af2ba9a0667f697f9bdcca045d39f2cec5543e2910" + +[[package]] +name = "opentelemetry_sdk" +version = "0.22.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9e90c7113be649e31e9a0f8b5ee24ed7a16923b322c3c5ab6367469c049d6b7e" +dependencies = [ + "async-trait", + "crossbeam-channel", + "futures-channel", + "futures-executor", + "futures-util", + "glob", + "once_cell", + "opentelemetry", + "ordered-float", + "percent-encoding", + "rand 0.8.5", + "thiserror", + "tokio", + "tokio-stream", +] + [[package]] name = "option-ext" version = "0.2.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "04744f49eae99ab78e0d5c0b603ab218f515ea8cfe5a456d7629ad883a3b6e7d" +[[package]] +name = "ordered-float" +version = "4.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a76df7075c7d4d01fdcb46c912dd17fba5b60c78ea480b475f2b6ab6f666584e" +dependencies = [ + "num-traits", +] + [[package]] name = "os_str_bytes" version = "6.6.1" @@ -2649,6 +2764,12 @@ dependencies = [ "tracing", ] +[[package]] +name = "overload" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b15813163c1d831bf4a13c3610c05c0d03b39feb07f7e09fa234dac9b15aaf39" + [[package]] name = "parking" version = "2.2.0" @@ -2924,6 +3045,29 @@ dependencies = [ "yansi", ] +[[package]] +name = "prost" +version = "0.12.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "146c289cda302b98a28d40c8b3b90498d6e526dd24ac2ecea73e4e491685b94a" +dependencies = [ + "bytes", + "prost-derive", +] + +[[package]] +name = "prost-derive" +version = "0.12.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "efb6c9a1dd1def8e2124d17e83a20af56f1570d6c2d2bd9e266ccb768df3840e" +dependencies = [ + "anyhow", + "itertools 0.10.5", + "proc-macro2", + "quote", + "syn 2.0.48", +] + [[package]] name = "psm" version = "0.1.21" @@ -3107,10 +3251,19 @@ checksum = "b62dbe01f0b06f9d8dc7d49e05a0785f153b00b2c227856282f671e0318c9b15" dependencies = [ "aho-corasick 1.1.2", "memchr", - "regex-automata", + "regex-automata 0.4.5", "regex-syntax 0.8.2", ] +[[package]] +name = "regex-automata" +version = "0.1.10" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "6c230d73fb8d8c1b9c0b3135c5142a8acee3a0558fb8db5cf1cb65f8d7862132" +dependencies = [ + "regex-syntax 0.6.29", +] + [[package]] name = "regex-automata" version = "0.4.5" @@ -3122,6 +3275,12 @@ dependencies = [ "regex-syntax 0.8.2", ] +[[package]] +name = "regex-syntax" +version = "0.6.29" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f162c6dd7b008981e4d40210aca20b4bd0f9b60ca9271061b07f78537722f2e1" + [[package]] name = "regex-syntax" version = "0.7.5" @@ -3603,6 +3762,15 @@ dependencies = [ "digest", ] +[[package]] +name = "sharded-slab" +version = "0.1.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f40ca3c46823713e0d4209592e8d6e826aa57e928f09752619fc696c499637f6" +dependencies = [ + "lazy_static", +] + [[package]] name = "shellexpand" version = "2.1.2" @@ -3741,6 +3909,7 @@ dependencies = [ "crossbeam-channel", "io-extras", "rustix 0.37.27", + "spin-telemetry", "system-interface", "tokio", "tracing", @@ -3843,6 +4012,7 @@ dependencies = [ "serde_json", "spin-core", "spin-llm", + "spin-telemetry", "spin-world", "tracing", ] @@ -3974,6 +4144,24 @@ dependencies = [ "tokio", ] +[[package]] +name = "spin-telemetry" +version = "2.4.0-pre0" +dependencies = [ + "anyhow", + "http 0.2.11", + "http 1.0.0", + "opentelemetry", + "opentelemetry-otlp", + "opentelemetry-semantic-conventions", + "opentelemetry_sdk", + "tracing", + "tracing-appender", + "tracing-opentelemetry", + "tracing-subscriber", + "url", +] + [[package]] name = "spin-trigger" version = "2.4.0-pre0" @@ -4274,6 +4462,16 @@ dependencies = [ "syn 2.0.48", ] +[[package]] +name = "thread_local" +version = "1.1.8" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8b9ef9bad013ada3808854ceac7b46812a6465ba368859a37e2100283d2d719c" +dependencies = [ + "cfg-if", + "once_cell", +] + [[package]] name = "time" version = "0.3.34" @@ -4536,6 +4734,27 @@ dependencies = [ "winnow", ] +[[package]] +name = "tonic" +version = "0.11.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "76c4eb7a4e9ef9d4763600161f12f5070b92a578e1b634db88a6887844c91a13" +dependencies = [ + "async-trait", + "base64 0.21.7", + "bytes", + "http 0.2.11", + "http-body 0.4.6", + "percent-encoding", + "pin-project", + "prost", + "tokio", + "tokio-stream", + "tower-layer", + "tower-service", + "tracing", +] + [[package]] name = "tower" version = "0.4.13" @@ -4575,6 +4794,18 @@ dependencies = [ "tracing-core", ] +[[package]] +name = "tracing-appender" +version = "0.2.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3566e8ce28cc0a3fe42519fc80e6b4c943cc4c8cef275620eb8dac2d3d4e06cf" +dependencies = [ + "crossbeam-channel", + "thiserror", + "time", + "tracing-subscriber", +] + [[package]] name = "tracing-attributes" version = "0.1.27" @@ -4593,6 +4824,67 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "c06d3da6113f116aaee68e4d601191614c9053067f9ab7f6edbcb161237daa54" dependencies = [ "once_cell", + "valuable", +] + +[[package]] +name = "tracing-log" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ee855f1f400bd0e5c02d150ae5de3840039a3f54b025156404e34c23c03f47c3" +dependencies = [ + "log", + "once_cell", + "tracing-core", +] + +[[package]] +name = "tracing-opentelemetry" +version = "0.23.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a9be14ba1bbe4ab79e9229f7f89fab8d120b865859f10527f31c033e599d2284" +dependencies = [ + "js-sys", + "once_cell", + "opentelemetry", + "opentelemetry_sdk", + "smallvec", + "tracing", + "tracing-core", + "tracing-log", + "tracing-subscriber", + "web-time", +] + +[[package]] +name = "tracing-serde" +version = "0.1.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bc6b213177105856957181934e4920de57730fc69bf42c37ee5bb664d406d9e1" +dependencies = [ + "serde", + "tracing-core", +] + +[[package]] +name = "tracing-subscriber" +version = "0.3.18" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ad0f048c97dbd9faa9b7df56362b8ebcaa52adb06b498c050d2f4e32f90a7a8b" +dependencies = [ + "matchers", + "nu-ansi-term", + "once_cell", + "regex", + "serde", + "serde_json", + "sharded-slab", + "smallvec", + "thread_local", + "tracing", + "tracing-core", + "tracing-log", + "tracing-serde", ] [[package]] @@ -4739,6 +5031,12 @@ dependencies = [ "getrandom 0.2.12", ] +[[package]] +name = "valuable" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "830b7e5d4d90034032940e4ace0d9a9a057e7a45cd94e6c007832e39edb82f6d" + [[package]] name = "vaultrs" version = "0.6.2" @@ -5365,6 +5663,16 @@ dependencies = [ "wasm-bindgen", ] +[[package]] +name = "web-time" +version = "1.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5a6580f308b1fad9207618087a65c04e7a10bc77e02c8e84e9b00dd4b12fa0bb" +dependencies = [ + "js-sys", + "wasm-bindgen", +] + [[package]] name = "webpki-roots" version = "0.25.4" diff --git a/src/bin/spin.rs b/src/bin/spin.rs index 0fd018988b..481f48d0c3 100644 --- a/src/bin/spin.rs +++ b/src/bin/spin.rs @@ -1,6 +1,5 @@ -use anyhow::Error; +use anyhow::{Context, Error}; use clap::{CommandFactory, FromArgMatches, Parser, Subcommand}; -use is_terminal::IsTerminal; use lazy_static::lazy_static; use spin_cli::commands::external::predefined_externals; use spin_cli::commands::{ @@ -42,15 +41,8 @@ async fn main() { } async fn _main() -> anyhow::Result<()> { - tracing_subscriber::fmt() - .with_writer(std::io::stderr) - .with_env_filter( - tracing_subscriber::EnvFilter::from_default_env() - .add_directive("wasmtime_wasi_http=warn".parse()?) - .add_directive("watchexec=off".parse()?), - ) - .with_ansi(std::io::stderr().is_terminal()) - .init(); + let _telemetry_guard = + spin_telemetry::init(VERSION.to_string()).context("Failed to initialize telemetry")?; let plugin_help_entries = plugin_help_entries(); diff --git a/tests/integration.rs b/tests/integration.rs index 7057437902..762e9b3fa2 100644 --- a/tests/integration.rs +++ b/tests/integration.rs @@ -13,6 +13,24 @@ mod integration_tests { }; use anyhow::Context; + /// Helper macro to assert that a condition is true eventually + #[cfg(feature = "extern-dependencies-tests")] + macro_rules! assert_eventually { + ($e:expr, $t:expr) => { + let mut i = 0; + loop { + if $e { + break; + } else if i > $t * 10 { + assert!($e); + break; + } + std::thread::sleep(std::time::Duration::from_millis(100)); + i += 1; + } + }; + } + #[test] /// Test that the --key-value flag works as expected fn key_value_cli_flag() -> anyhow::Result<()> { @@ -75,23 +93,6 @@ mod integration_tests { #[cfg(feature = "extern-dependencies-tests")] /// Test that basic redis trigger support works fn redis_smoke_test() -> anyhow::Result<()> { - /// Helper macro to assert that a condition is true eventually - macro_rules! assert_eventually { - ($e:expr) => { - let mut i = 0; - loop { - if $e { - break; - } else if i > 20 { - assert!($e); - break; - } - std::thread::sleep(std::time::Duration::from_millis(100)); - i += 1; - } - }; - } - use anyhow::Context; use redis::Commands; run_test( @@ -110,24 +111,94 @@ mod integration_tests { redis .publish("my-channel", "msg-from-test") .context("could not publish test message to redis")?; - assert_eventually!({ - match env.read_file(".spin/logs/hello_stdout.txt") { - Ok(logs) => { - let logs = String::from_utf8_lossy(&logs); - logs.contains("Got message: 'msg-from-test'") - } - Err(e) - if e.downcast_ref() - .map(|e: &std::io::Error| e.kind() == std::io::ErrorKind::NotFound) - .unwrap_or_default() => - { - false + assert_eventually!( + { + match env.read_file(".spin/logs/hello_stdout.txt") { + Ok(logs) => { + let logs = String::from_utf8_lossy(&logs); + logs.contains("Got message: 'msg-from-test'") + } + Err(e) + if e.downcast_ref() + .map(|e: &std::io::Error| { + e.kind() == std::io::ErrorKind::NotFound + }) + .unwrap_or_default() => + { + false + } + Err(e) => { + return Err( + anyhow::anyhow!("could not read stdout file: {e}").into() + ) + } } - Err(e) => { - return Err(anyhow::anyhow!("could not read stdout file: {e}").into()) + }, + 2 + ); + Ok(()) + }, + )?; + + Ok(()) + } + + #[test] + #[cfg(feature = "extern-dependencies-tests")] + /// Test that basic otel tracing works + fn otel_smoke_test() -> anyhow::Result<()> { + use anyhow::Context; + + use crate::testcases::run_test_inited; + run_test_inited( + "otel-smoke-test", + SpinAppType::Http, + [], + testing_framework::ServicesConfig::new(vec!["jaeger".into()])?, + |env| { + let otel_port = env + .services_mut() + .get_port(4318)? + .context("expected a port for Jaeger")?; + env.set_env_var( + "OTEL_EXPORTER_OTLP_ENDPOINT", + format!("http://localhost:{}", otel_port), + ); + Ok(()) + }, + move |env| { + let spin = env.runtime_mut(); + assert_spin_request( + spin, + Request::new(Method::GET, "/test/hello"), + Response::new_with_body(200, "Hello, Fermyon!\n"), + )?; + + assert_eventually!( + { + let jaeger_port = env + .services_mut() + .get_port(16686)? + .context("no jaeger port was exposed by test services")?; + let url = format!("http://localhost:{jaeger_port}/api/traces?service=spin"); + match reqwest::blocking::get(&url).context("failed to get jaeger traces")? { + resp if resp.status().is_success() => { + let traces: serde_json::Value = + resp.json().context("failed to parse jaeger traces")?; + let traces = + traces.get("data").context("jaeger traces has no data")?; + let traces = + traces.as_array().context("jaeger traces is not an array")?; + !traces.is_empty() + } + _resp => { + eprintln!("failed to get jaeger traces:"); + false + } } - } - }); + }, + 20 + ); Ok(()) }, )?; @@ -682,7 +753,7 @@ Caused by: #[test] fn spin_up_gives_help_on_new_app() -> anyhow::Result<()> { - let env = testing_framework::TestEnvironment::<()>::boot( + let mut env = testing_framework::TestEnvironment::<()>::boot( &testing_framework::ServicesConfig::none(), )?; @@ -702,7 +773,7 @@ route = "/..." testing_framework::runtimes::spin_cli::SpinCli::start( &spin_binary(), - &env, + &mut env, Vec::::new(), SpinAppType::None, )?; @@ -720,7 +791,7 @@ route = "/..." #[test] fn spin_up_help_build_does_not_build() -> anyhow::Result<()> { - let env = testing_framework::TestEnvironment::<()>::boot( + let mut env = testing_framework::TestEnvironment::<()>::boot( &testing_framework::ServicesConfig::none(), )?; @@ -742,7 +813,7 @@ route = "/..." testing_framework::runtimes::spin_cli::SpinCli::start( &spin_binary(), - &env, + &mut env, Vec::::new(), SpinAppType::None, )?; diff --git a/tests/runtime-tests/README.md b/tests/runtime-tests/README.md index 0f776e7446..f06a6dd567 100644 --- a/tests/runtime-tests/README.md +++ b/tests/runtime-tests/README.md @@ -7,7 +7,7 @@ For the purposes of these tests, an "application" is a collection of the followi * A spin.toml manifest * Optional runtime-config.toml files -## What are runtime tests supposed test and not test? +## What are runtime tests supposed to test and not test? Runtime tests are meant to test the runtime functionality of Spin. In other words, they ensure that a valid combination of Spin manifest and some number of Spin compliant WebAssembly binaries perform in expected ways or fail in expected ways. diff --git a/tests/testcases/mod.rs b/tests/testcases/mod.rs index 58d86a5831..30424ee8eb 100644 --- a/tests/testcases/mod.rs +++ b/tests/testcases/mod.rs @@ -348,7 +348,7 @@ pub fn bootstrap_smoke_test( let spin_up_args = spin_up_args(&mut env)?; let spin = testing_framework::runtimes::spin_cli::SpinCli::start( &spin_binary(), - &env, + &mut env, spin_up_args, spin_app_type, )?; diff --git a/tests/testcases/otel-smoke-test/spin.toml b/tests/testcases/otel-smoke-test/spin.toml new file mode 100644 index 0000000000..c5911038b5 --- /dev/null +++ b/tests/testcases/otel-smoke-test/spin.toml @@ -0,0 +1,12 @@ +spin_version = "1" +authors = ["Fermyon Engineering "] +description = "A simple application that returns hello and goodbye." +name = "head-rust-sdk-http" +trigger = { type = "http", base = "/test" } +version = "1.0.0" + +[[component]] +id = "hello" +source = "%{source=hello-world}" +[component.trigger] +route = "/hello/..." diff --git a/tests/testing-framework/services/jaeger.Dockerfile b/tests/testing-framework/services/jaeger.Dockerfile new file mode 100644 index 0000000000..285f173496 --- /dev/null +++ b/tests/testing-framework/services/jaeger.Dockerfile @@ -0,0 +1,5 @@ +FROM jaegertracing/all-in-one:1.55 + +ENV COLLECTOR_OTLP_ENABLED=true + +HEALTHCHECK --interval=2s CMD wget -qO - http://localhost:14269/health diff --git a/tests/testing-framework/src/runtimes/spin_cli.rs b/tests/testing-framework/src/runtimes/spin_cli.rs index 8db34d56d8..ad6a74439f 100644 --- a/tests/testing-framework/src/runtimes/spin_cli.rs +++ b/tests/testing-framework/src/runtimes/spin_cli.rs @@ -26,7 +26,7 @@ impl SpinCli { /// Start Spin using the binary at `spin_binary_path` in the `env` testing environment pub fn start( spin_binary_path: &Path, - env: &TestEnvironment, + env: &mut TestEnvironment, spin_up_args: Vec>, app_type: SpinAppType, ) -> anyhow::Result { @@ -40,18 +40,22 @@ impl SpinCli { /// Start Spin assuming an HTTP app in `env` testing directory using the binary at `spin_binary_path` pub fn start_http( spin_binary_path: &Path, - env: &TestEnvironment, + env: &mut TestEnvironment, spin_up_args: Vec>, ) -> anyhow::Result { let port = get_random_port()?; - let mut child = Command::new(spin_binary_path) + let mut spin_cmd = Command::new(spin_binary_path); + let child = spin_cmd .arg("up") .current_dir(env.path()) .args(["--listen", &format!("127.0.0.1:{port}")]) .args(spin_up_args) .stdout(Stdio::piped()) - .stderr(Stdio::piped()) - .spawn()?; + .stderr(Stdio::piped()); + for (key, value) in env.env_vars() { + child.env(key, value); + } + let mut child = child.spawn()?; let stdout = OutputStream::new(child.stdout.take().unwrap()); let stderr = OutputStream::new(child.stderr.take().unwrap()); log::debug!("Awaiting spin binary to start up on port {port}..."); @@ -97,7 +101,7 @@ impl SpinCli { /// Start Spin assuming a Redis app in `env` testing directory using the binary at `spin_binary_path` pub fn start_redis( spin_binary_path: &Path, - env: &TestEnvironment, + env: &mut TestEnvironment, spin_up_args: Vec>, ) -> anyhow::Result { let mut child = Command::new(spin_binary_path) @@ -130,7 +134,7 @@ impl SpinCli { fn attempt_start( spin_binary_path: &Path, - env: &TestEnvironment, + env: &mut TestEnvironment, spin_up_args: Vec>, ) -> anyhow::Result { let mut child = Command::new(spin_binary_path) diff --git a/tests/testing-framework/src/test_environment.rs b/tests/testing-framework/src/test_environment.rs index 30c2070246..58d98820f3 100644 --- a/tests/testing-framework/src/test_environment.rs +++ b/tests/testing-framework/src/test_environment.rs @@ -1,4 +1,7 @@ -use std::path::{Path, PathBuf}; +use std::{ + collections::HashMap, + path::{Path, PathBuf}, +}; use crate::{ runtimes::{in_process_spin::InProcessSpin, spin_cli::SpinCli, SpinAppType}, @@ -15,6 +18,7 @@ pub struct TestEnvironment { temp: temp_dir::TempDir, services: Services, runtime: Option, + env_vars: HashMap, } impl TestEnvironment { @@ -52,6 +56,7 @@ impl TestEnvironment { temp, services, runtime: None, + env_vars: HashMap::new(), }) } @@ -61,6 +66,7 @@ impl TestEnvironment { temp: self.temp, services: self.services, runtime: Some(runtime), + env_vars: self.env_vars, }; this.error().context("testing environment is not healthy")?; Ok(this) @@ -161,6 +167,16 @@ impl TestEnvironment { pub fn path(&self) -> &Path { self.temp.path() } + + /// Set an environment variable in the test environment + pub fn set_env_var(&mut self, key: impl Into, value: impl Into) { + self.env_vars.insert(key.into(), value.into()); + } + + /// Get the environment variables in the test environment + pub fn env_vars(&self) -> &HashMap { + &self.env_vars + } } /// Configuration for a test environment