From 8d2241943d294508314e5c3fd2ab31b4a1ccbdbf Mon Sep 17 00:00:00 2001 From: Caleb Schoepp Date: Wed, 11 Sep 2024 12:07:08 -0600 Subject: [PATCH] Bump OTel version to v0.23.0, break logging, implement a bit more observe Signed-off-by: Caleb Schoepp --- Cargo.lock | 121 +++++++----------------------- Cargo.toml | 6 +- crates/factor-observe/Cargo.toml | 1 - crates/factor-observe/src/host.rs | 28 ++++--- crates/telemetry/Cargo.toml | 5 +- crates/telemetry/src/logs.rs | 103 ++++++++++++------------- crates/world/src/conversions.rs | 20 +++-- 7 files changed, 110 insertions(+), 174 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index d435dd5d7..a57dae991 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2329,10 +2329,10 @@ version = "0.19.0" dependencies = [ "futures", "hex", - "opentelemetry 0.23.0", - "opentelemetry-otlp 0.16.0", - "opentelemetry-proto 0.6.0", - "opentelemetry_sdk 0.23.0", + "opentelemetry", + "opentelemetry-otlp", + "opentelemetry-proto", + "opentelemetry_sdk", "serde 1.0.197", "tokio", "tokio-stream", @@ -5026,21 +5026,6 @@ 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" version = "0.23.0" @@ -5057,36 +5042,15 @@ dependencies = [ [[package]] name = "opentelemetry-http" -version = "0.11.1" +version = "0.12.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "7690dc77bf776713848c4faa6501157469017eaf332baccd4eb1cea928743d94" +checksum = "b0ba633e55c5ea6f431875ba55e71664f2fa5d3a90bd34ec9302eecc41c865dd" dependencies = [ "async-trait", "bytes", "http 0.2.12", - "opentelemetry 0.22.0", - "reqwest 0.11.27", -] - -[[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 0.22.0", - "opentelemetry-http", - "opentelemetry-proto 0.5.0", - "opentelemetry-semantic-conventions", - "opentelemetry_sdk 0.22.1", - "prost", + "opentelemetry", "reqwest 0.11.27", - "thiserror", - "tokio", - "tonic", ] [[package]] @@ -5098,35 +5062,25 @@ dependencies = [ "async-trait", "futures-core", "http 0.2.12", - "opentelemetry 0.23.0", - "opentelemetry-proto 0.6.0", - "opentelemetry_sdk 0.23.0", + "opentelemetry", + "opentelemetry-http", + "opentelemetry-proto", + "opentelemetry_sdk", "prost", + "reqwest 0.11.27", "thiserror", "tokio", "tonic", ] -[[package]] -name = "opentelemetry-proto" -version = "0.5.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "3a8fddc9b68f5b80dae9d6f510b88e02396f006ad48cac349411fbecc80caae4" -dependencies = [ - "opentelemetry 0.22.0", - "opentelemetry_sdk 0.22.1", - "prost", - "tonic", -] - [[package]] name = "opentelemetry-proto" version = "0.6.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "984806e6cf27f2b49282e2a05e288f30594f3dbc74eb7a6e99422bc48ed78162" dependencies = [ - "opentelemetry 0.23.0", - "opentelemetry_sdk 0.23.0", + "opentelemetry", + "opentelemetry_sdk", "prost", "tonic", ] @@ -5137,29 +5091,6 @@ 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 0.22.0", - "ordered-float 4.2.0", - "percent-encoding", - "rand 0.8.5", - "serde_json", - "thiserror", - "tokio", - "tokio-stream", -] - [[package]] name = "opentelemetry_sdk" version = "0.23.0" @@ -5174,7 +5105,7 @@ dependencies = [ "glob", "lazy_static 1.4.0", "once_cell", - "opentelemetry 0.23.0", + "opentelemetry", "ordered-float 4.2.0", "percent-encoding", "rand 0.8.5", @@ -7404,9 +7335,8 @@ dependencies = [ "futures-executor", "indexmap 2.2.6", "once_cell", - "opentelemetry 0.22.0", - "opentelemetry-otlp 0.15.0", - "opentelemetry_sdk 0.22.1", + "opentelemetry", + "opentelemetry_sdk", "serde 1.0.197", "spin-app", "spin-core", @@ -8001,10 +7931,11 @@ dependencies = [ "anyhow", "http 0.2.12", "http 1.1.0", - "opentelemetry 0.22.0", - "opentelemetry-otlp 0.15.0", + "once_cell", + "opentelemetry", + "opentelemetry-otlp", "opentelemetry-semantic-conventions", - "opentelemetry_sdk 0.22.1", + "opentelemetry_sdk", "terminal", "tracing", "tracing-appender", @@ -8143,7 +8074,7 @@ version = "2.8.0-pre0" dependencies = [ "anyhow", "async-trait", - "opentelemetry 0.22.0", + "opentelemetry", "wasmtime", ] @@ -8984,14 +8915,14 @@ dependencies = [ [[package]] name = "tracing-opentelemetry" -version = "0.23.0" +version = "0.24.0" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "a9be14ba1bbe4ab79e9229f7f89fab8d120b865859f10527f31c033e599d2284" +checksum = "f68803492bf28ab40aeccaecc7021096bd256baf7ca77c3d425d89b35a7be4e4" dependencies = [ "js-sys", "once_cell", - "opentelemetry 0.22.0", - "opentelemetry_sdk 0.22.1", + "opentelemetry", + "opentelemetry_sdk", "smallvec", "tracing", "tracing-core", diff --git a/Cargo.toml b/Cargo.toml index 557cecc33..e8a710d46 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -128,12 +128,12 @@ anyhow = "1.0.75" conformance-tests = { git = "https://github.com/fermyon/conformance-tests", rev = "387b7f375df59e6254a7c29cf4a53507a9f46d32" } http-body-util = "0.1.0" hyper = { version = "1.0.0", features = ["full"] } -opentelemetry = { version = "0.22.0", features = ["metrics", "trace", "logs"] } -opentelemetry_sdk = { version = "0.22.1", features = ["rt-tokio", "logs_level_enabled"] } +opentelemetry = { version = "0.23.0", features = ["metrics", "trace", "logs"] } +opentelemetry_sdk = { version = "0.23.0", features = ["rt-tokio", "logs_level_enabled", "metrics"] } reqwest = { version = "0.12", features = ["stream", "blocking"] } test-environment = { git = "https://github.com/fermyon/conformance-tests", rev = "387b7f375df59e6254a7c29cf4a53507a9f46d32" } tracing = { version = "0.1", features = ["log"] } -tracing-opentelemetry = { version = "0.23.0", default-features = false, features = ["metrics"] } +tracing-opentelemetry = { version = "0.24.0", default-features = false, features = ["metrics"] } wasi-common-preview1 = { version = "22.0.0", package = "wasi-common", features = [ "tokio", diff --git a/crates/factor-observe/Cargo.toml b/crates/factor-observe/Cargo.toml index 099abe089..58e923f5c 100644 --- a/crates/factor-observe/Cargo.toml +++ b/crates/factor-observe/Cargo.toml @@ -13,7 +13,6 @@ indexmap = "2.2.6" once_cell = "1" opentelemetry = { workspace = true } opentelemetry_sdk = { workspace = true } -opentelemetry-otlp = { version = "0.15.0", default-features=false, features = ["http-proto", "trace", "http", "reqwest-client", "metrics", "grpc-tonic"] } serde = "1.0.188" spin-app = { path = "../app" } spin-core = { path = "../core" } diff --git a/crates/factor-observe/src/host.rs b/crates/factor-observe/src/host.rs index c5ad99226..83ca780de 100644 --- a/crates/factor-observe/src/host.rs +++ b/crates/factor-observe/src/host.rs @@ -1,6 +1,4 @@ -use std::time::Duration; use std::time::SystemTime; -use std::time::UNIX_EPOCH; use anyhow::anyhow; use anyhow::Result; @@ -21,6 +19,7 @@ impl traces::Host for InstanceState {} #[async_trait] impl traces::HostSpan for InstanceState { // TODO(Caleb): Make this implicit logic make more sense (the indexmap seems wrong) + // TODO(Caleb): Properly implement this async fn start( &mut self, name: String, @@ -122,9 +121,7 @@ impl traces::HostSpan for InstanceState { .get_mut(resource.rep()) { let timestamp = if let Some(timestamp) = timestamp { - UNIX_EPOCH - + Duration::from_secs(timestamp.seconds) - + Duration::from_nanos(timestamp.nanoseconds as u64) + timestamp.into() } else { SystemTime::now() }; @@ -148,16 +145,21 @@ impl traces::HostSpan for InstanceState { async fn add_link( &mut self, resource: Resource, - _link: traces::Link, + link: traces::Link, ) -> Result<()> { - if let Some(_guest_span) = self + if let Some(guest_span) = self .state .write() .unwrap() .guest_spans .get_mut(resource.rep()) { - todo!("update otel versions -> guest_span.inner.add_link(link.into());"); + guest_span.inner.add_link( + // TODO(Caleb): Do I actually want to cause a trap in this case or should it be fallible? + link.span_context.try_into()?, + link.attributes.into_iter().map(Into::into).collect(), + ); + Ok(()) } else { Err(anyhow!("BUG: cannot find resource in table")) } @@ -200,7 +202,7 @@ impl traces::HostSpan for InstanceState { async fn end( &mut self, resource: Resource, - _timestamp: Option, + timestamp: Option, ) -> Result<()> { if let Some(guest_span) = self .state @@ -209,7 +211,11 @@ impl traces::HostSpan for InstanceState { .guest_spans .get_mut(resource.rep()) { - guest_span.inner.end(); + if let Some(timestamp) = timestamp { + guest_span.inner.end_with_timestamp(timestamp.into()); + } else { + guest_span.inner.end(); + } Ok(()) } else { Err(anyhow!("BUG: cannot find resource in table")) @@ -223,6 +229,6 @@ impl traces::HostSpan for InstanceState { } } -// TODO(Caleb): Improve debug tracing in failure cases // TODO(Caleb): Move the tests from integration.rs to here // TODO(Caleb): Write tests somewhere for all the finicky type conversion stuff +// TODO(Caleb): Maybe introduce macro to reduce boilerplate of finding resource diff --git a/crates/telemetry/Cargo.toml b/crates/telemetry/Cargo.toml index aab52780a..7c5225a3d 100644 --- a/crates/telemetry/Cargo.toml +++ b/crates/telemetry/Cargo.toml @@ -8,10 +8,11 @@ edition = { workspace = true } anyhow = { workspace = true } http0 = { version = "0.2.9", package = "http" } http1 = { version = "1.0.0", package = "http" } +once_cell = "1.19.0" opentelemetry = { workspace = true } -opentelemetry-otlp = { version = "0.15.0", default-features = false, features = ["http-proto", "trace", "http", "reqwest-client", "metrics", "grpc-tonic", "logs"] } -opentelemetry-semantic-conventions = "0.14.0" opentelemetry_sdk = { workspace = true } +opentelemetry-otlp = { version = "0.16.0", default-features = false, features = ["http-proto", "trace", "http", "reqwest-client", "metrics", "grpc-tonic", "logs"] } +opentelemetry-semantic-conventions = "0.14.0" terminal = { path = "../terminal" } tracing = { version = "0.1.37", features = ["log"] } tracing-appender = "0.2.2" diff --git a/crates/telemetry/src/logs.rs b/crates/telemetry/src/logs.rs index b1f623c53..5463e0e6a 100644 --- a/crates/telemetry/src/logs.rs +++ b/crates/telemetry/src/logs.rs @@ -26,25 +26,26 @@ pub fn handle_app_log(buf: &[u8]) { /// Forward the app log to OTel. fn app_log_to_otel(buf: &[u8]) { - if !otel_logs_enabled() { - return; - } + // TODO(Caleb): Either use logging appender of build our own global logger provider storage + // if !otel_logs_enabled() { + // return; + // } - let logger = global::logger_provider().logger("spin"); - if let Ok(s) = std::str::from_utf8(buf) { - logger.emit( - opentelemetry::logs::LogRecord::builder() - .with_body(s.to_owned()) - .build(), - ); - } else { - logger.emit( - opentelemetry::logs::LogRecord::builder() - .with_body(escape_non_utf8_buf(buf)) - .with_attribute("app_log_non_utf8", true) - .build(), - ); - } + // let logger = global::logger_provider().logger("spin"); + // if let Ok(s) = std::str::from_utf8(buf) { + // logger.emit( + // opentelemetry::logs::LogRecord::builder() + // .with_body(s.to_owned()) + // .build(), + // ); + // } else { + // logger.emit( + // opentelemetry::logs::LogRecord::builder() + // .with_body(escape_non_utf8_buf(buf)) + // .with_attribute("app_log_non_utf8", true) + // .build(), + // ); + // } } /// Takes a Spin application log and emits it as a tracing event. This acts as a compatibility layer @@ -71,42 +72,42 @@ fn escape_non_utf8_buf(buf: &[u8]) -> String { /// Initialize the OTel logging backend. pub(crate) fn init_otel_logging_backend(spin_version: String) -> anyhow::Result<()> { - 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), - ], - ); + // 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_LOGS_PROTOCOL to - // determine whether we should use http/protobuf or grpc. - let exporter_builder: LogExporterBuilder = match OtlpProtocol::logs_protocol_from_env() { - OtlpProtocol::Grpc => opentelemetry_otlp::new_exporter().tonic().into(), - OtlpProtocol::HttpProtobuf => opentelemetry_otlp::new_exporter().http().into(), - OtlpProtocol::HttpJson => bail!("http/json OTLP protocol is not supported"), - }; + // // 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_LOGS_PROTOCOL to + // // determine whether we should use http/protobuf or grpc. + // let exporter_builder: LogExporterBuilder = match OtlpProtocol::logs_protocol_from_env() { + // OtlpProtocol::Grpc => opentelemetry_otlp::new_exporter().tonic().into(), + // OtlpProtocol::HttpProtobuf => opentelemetry_otlp::new_exporter().http().into(), + // OtlpProtocol::HttpJson => bail!("http/json OTLP protocol is not supported"), + // }; - let provider = opentelemetry_sdk::logs::LoggerProvider::builder() - .with_config(opentelemetry_sdk::logs::config().with_resource(resource)) - .with_log_processor( - BatchLogProcessor::builder( - exporter_builder.build_log_exporter()?, - opentelemetry_sdk::runtime::Tokio, - ) - .with_batch_config(BatchConfigBuilder::default().build()) - .build(), - ) - .build(); + // let provider = opentelemetry_sdk::logs::LoggerProvider::builder() + // .with_config(opentelemetry_sdk::logs::config().with_resource(resource)) + // .with_log_processor( + // BatchLogProcessor::builder( + // exporter_builder.build_log_exporter()?, + // opentelemetry_sdk::runtime::Tokio, + // ) + // .with_batch_config(BatchConfigBuilder::default().build()) + // .build(), + // ) + // .build(); - global::set_logger_provider(provider); + // global::set_logger_provider(provider); Ok(()) } diff --git a/crates/world/src/conversions.rs b/crates/world/src/conversions.rs index d232263f7..70851c48e 100644 --- a/crates/world/src/conversions.rs +++ b/crates/world/src/conversions.rs @@ -222,6 +222,7 @@ mod llm { mod observe { use super::*; use opentelemetry::StringValue; + use std::time::{Duration, SystemTime, UNIX_EPOCH}; use wasi::observe::traces; impl From for opentelemetry::Value { @@ -311,17 +312,6 @@ mod observe { } } - impl TryFrom for opentelemetry::trace::Link { - type Error = wasmtime::Error; - - fn try_from(link: traces::Link) -> anyhow::Result { - Ok(Self::new( - link.span_context.try_into()?, - link.attributes.into_iter().map(Into::into).collect(), - )) - } - } - impl From for opentelemetry::trace::Status { fn from(status: traces::Status) -> Self { match status { @@ -333,4 +323,12 @@ mod observe { } } } + + impl From for SystemTime { + fn from(timestamp: traces::Datetime) -> Self { + UNIX_EPOCH + + Duration::from_secs(timestamp.seconds) + + Duration::from_nanos(timestamp.nanoseconds as u64) + } + } }