From e95457fb22d2db5bffdcd2165a22b14e7adba4da Mon Sep 17 00:00:00 2001 From: Dan Lapid Date: Sat, 10 Oct 2026 07:00:14 +0000 Subject: [PATCH 1/4] Export Workers user spans over OTLP Workers user spans reach a tracing backend today only through Streaming Tail Workers: the Workers Observability tail worker rebuilds them in JavaScript from tail events. Spans built that way are cut off when a Durable Object hands off work, carry coarse I/O-clock timestamps, and are sampled only after they already exist. This gives the runtime what it needs to export user spans itself, as OTLP, the way other Cloudflare services already do: - an OTLP encoder for spans, written in Rust, behind the existing span submitter interface; - a tracer hook that lets the embedder open each invocation's root span, so the invocation and all of its user spans form one exported trace; - precise timestamps for user spans, which no longer reach user code directly. workerd can also export on its own: a new `tracing.otlp` setting sends each invocation's spans to an OTLP/HTTP collector such as a local Jaeger. That makes Workers traces visible in local development without a tail worker. Nothing changes unless an embedder installs the hook or the setting is configured. Co-Authored-By: Claude Opus 5.5 --- deps/rust/Cargo.lock | 24 + deps/rust/Cargo.toml | 3 + src/rust/AGENTS.md | 1 + src/rust/otlp/BUILD.bazel | 16 + src/rust/otlp/attributes.rs | 119 +++ src/rust/otlp/bridge.rs | 203 +++++ src/rust/otlp/buffer.rs | 713 ++++++++++++++++++ src/rust/otlp/lib.rs | 21 + src/rust/otlp/proto.rs | 130 ++++ src/rust/otlp/rules.rs | 249 ++++++ src/workerd/api/tests/BUILD.bazel | 8 + .../api/tests/otlp-tracing-test-collector.js | 188 +++++ src/workerd/api/tests/otlp-tracing-test.js | 112 +++ .../api/tests/otlp-tracing-test.wd-test | 28 + src/workerd/io/BUILD.bazel | 28 + src/workerd/io/invocation-span-test.c++ | 129 ++++ src/workerd/io/invocation-span.c++ | 234 ++++++ src/workerd/io/invocation-span.h | 30 + src/workerd/io/otlp-span-submitter.c++ | 278 +++++++ src/workerd/io/otlp-span-submitter.h | 162 ++++ src/workerd/io/tracer.c++ | 93 ++- src/workerd/io/tracer.h | 39 +- src/workerd/server/BUILD.bazel | 1 + src/workerd/server/server.c++ | 110 ++- src/workerd/server/server.h | 4 + src/workerd/server/workerd.capnp | 24 + 26 files changed, 2935 insertions(+), 12 deletions(-) create mode 100644 src/rust/otlp/BUILD.bazel create mode 100644 src/rust/otlp/attributes.rs create mode 100644 src/rust/otlp/bridge.rs create mode 100644 src/rust/otlp/buffer.rs create mode 100644 src/rust/otlp/lib.rs create mode 100644 src/rust/otlp/proto.rs create mode 100644 src/rust/otlp/rules.rs create mode 100644 src/workerd/api/tests/otlp-tracing-test-collector.js create mode 100644 src/workerd/api/tests/otlp-tracing-test.js create mode 100644 src/workerd/api/tests/otlp-tracing-test.wd-test create mode 100644 src/workerd/io/invocation-span-test.c++ create mode 100644 src/workerd/io/invocation-span.c++ create mode 100644 src/workerd/io/invocation-span.h create mode 100644 src/workerd/io/otlp-span-submitter.c++ create mode 100644 src/workerd/io/otlp-span-submitter.h diff --git a/deps/rust/Cargo.lock b/deps/rust/Cargo.lock index 93f6f67bce3..22589984c2c 100644 --- a/deps/rust/Cargo.lock +++ b/deps/rust/Cargo.lock @@ -471,6 +471,7 @@ dependencies = [ "notify", "pico-args", "proc-macro2", + "prost", "quote", "ruff_python_ast", "ruff_python_parser", @@ -1394,6 +1395,29 @@ dependencies = [ "unicode-ident", ] +[[package]] +name = "prost" +version = "0.14.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "528ac67416ff8646872a3c02cad9cc4ee5dc9f9540c9b10771855c95cb2e5ae1" +dependencies = [ + "bytes", + "prost-derive", +] + +[[package]] +name = "prost-derive" +version = "0.14.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b570b25f7617e43d59005d0990ccb79e950a423952cea19671b7a876da390adf" +dependencies = [ + "anyhow", + "itertools", + "proc-macro2", + "quote", + "syn 2.0.119", +] + [[package]] name = "quote" version = "1.0.47" diff --git a/deps/rust/Cargo.toml b/deps/rust/Cargo.toml index 75108232387..8cb30cfb0e2 100644 --- a/deps/rust/Cargo.toml +++ b/deps/rust/Cargo.toml @@ -51,6 +51,9 @@ hashlink = "0" # kj::UnixEventPort does. nix = { version = "0", features = ["fs", "signal"] } pico-args = "0" +# The OTLP span exporter (src/rust/otlp) encodes its requests with prost. Its messages are written +# out as structs, so neither prost-build nor protoc is involved. +prost = "0.14" ruff_python_ast = { git = "https://github.com/astral-sh/ruff", tag = "0.12.1" } ruff_python_parser = { git = "https://github.com/astral-sh/ruff", tag = "0.12.1" } # param_extractor depends on unbounded_depth feature diff --git a/src/rust/AGENTS.md b/src/rust/AGENTS.md index 60c8e191bdd..d7b9ced4faf 100644 --- a/src/rust/AGENTS.md +++ b/src/rust/AGENTS.md @@ -20,6 +20,7 @@ _Snapshot — the set drifts as crates come and go; `bazel query //src/rust/...` | `api/` | Rust-implemented Node.js APIs; registers modules via `register_nodejs_modules()` | | `encoding/` | WHATWG legacy text decoders via `encoding_rs`; an opaque streaming `Decoder` emits UTF-16 over the CXX bridge | | `kj/` | Rust bindings for KJ library (`http`, `io`, `own` submodules); `Result` = `Result` | +| `otlp/` | OTLP export of user spans: buffers one invocation's spans, decides each span's OTLP form, batches, and encodes `ExportTraceServiceRequest`s with `prost`; no I/O, driven by `io/otlp-span-submitter.{h,c++}` | | `worker/` | Rust counterpart of `workerd::WorkerInterface` (the `worker::Interface` trait) plus FFI bindings; multi-bridge crate | | `cxx-integration/` | Tokio runtime init; called from C++ `main()` before anything else | | `cxx-integration-test/` | Non-production crate exercising Rust/C++ integration: callbacks, shared structs, `Result` error mapping | diff --git a/src/rust/otlp/BUILD.bazel b/src/rust/otlp/BUILD.bazel new file mode 100644 index 00000000000..6d020095987 --- /dev/null +++ b/src/rust/otlp/BUILD.bazel @@ -0,0 +1,16 @@ +load("//:build/wd_rust_crate.bzl", "wd_rust_crate") + +wd_rust_crate( + name = "otlp", + cxx_bridge_src = "bridge.rs", + link_deps = [ + # ada-url is built with its `bundled` feature disabled (see //deps/rust:Cargo.toml), so the + # C++ ada library comes from workerd's existing @ada-url. + "@ada-url", + ], + visibility = ["//visibility:public"], + deps = [ + "@crates_vendor//:ada-url", + "@crates_vendor//:prost", + ], +) diff --git a/src/rust/otlp/attributes.rs b/src/rust/otlp/attributes.rs new file mode 100644 index 00000000000..3881146ba04 --- /dev/null +++ b/src/rust/otlp/attributes.rs @@ -0,0 +1,119 @@ +// Copyright (c) 2026 Cloudflare, Inc. +// Licensed under the Apache 2.0 license found in the LICENSE file or at: +// https://opensource.org/licenses/Apache-2.0 + +use crate::proto; +use crate::proto::any_value::Value; + +/// Span or resource attributes, in the order they were added. +/// +/// Lookups are linear: a span carries a few dozen attributes at most, and the order is what a +/// collector shows. +#[derive(Clone, Debug, Default, PartialEq)] +pub struct Attributes(Vec<(String, Value)>); + +impl Attributes { + /// Appends without looking for an existing entry, for callers whose keys are already distinct. + pub fn push(&mut self, key: impl Into, value: impl IntoValue) { + self.0.push((key.into(), value.into_value())); + } + + /// Replaces the value in place when the key is present, and appends otherwise. + pub fn set(&mut self, key: &str, value: impl IntoValue) { + match self.0.iter_mut().find(|(k, _)| k == key) { + Some((_, existing)) => *existing = value.into_value(), + None => self.push(key, value), + } + } + + /// Appends unless the key is present. + pub fn set_default(&mut self, key: &str, value: impl IntoValue) { + if self.get(key).is_none() { + self.push(key, value); + } + } + + /// Applies `set_default` for every entry of `defaults`. + pub fn set_defaults(&mut self, defaults: &Self) { + for (key, value) in &defaults.0 { + self.set_default(key, value.clone()); + } + } + + pub fn get(&self, key: &str) -> Option<&Value> { + self.0.iter().find(|(k, _)| k == key).map(|(_, v)| v) + } + + /// The value when it is a string. + pub fn string(&self, key: &str) -> Option<&str> { + match self.get(key) { + Some(Value::String(s)) => Some(s), + _ => None, + } + } + + /// The value when it is an integer. + pub fn int(&self, key: &str) -> Option { + match self.get(key) { + Some(Value::Int(i)) => Some(*i), + _ => None, + } + } + + pub fn into_proto(self) -> Vec { + self.0 + .into_iter() + .map(|(key, value)| key_value(key, value)) + .collect() + } +} + +pub fn key_value(key: impl Into, value: impl IntoValue) -> proto::KeyValue { + proto::KeyValue { + key: key.into(), + value: Some(proto::AnyValue { + value: Some(value.into_value()), + }), + } +} + +/// The Rust types an attribute value can be built from. +pub trait IntoValue { + fn into_value(self) -> Value; +} + +impl IntoValue for Value { + fn into_value(self) -> Value { + self + } +} + +impl IntoValue for String { + fn into_value(self) -> Value { + Value::String(self) + } +} + +impl IntoValue for &str { + fn into_value(self) -> Value { + Value::String(self.to_owned()) + } +} + +impl IntoValue for bool { + fn into_value(self) -> Value { + Value::Bool(self) + } +} + +impl IntoValue for i64 { + fn into_value(self) -> Value { + Value::Int(self) + } +} + +impl IntoValue for f64 { + fn into_value(self) -> Value { + Value::Double(self) + } +} diff --git a/src/rust/otlp/bridge.rs b/src/rust/otlp/bridge.rs new file mode 100644 index 00000000000..db6cbda8984 --- /dev/null +++ b/src/rust/otlp/bridge.rs @@ -0,0 +1,203 @@ +// Copyright (c) 2026 Cloudflare, Inc. +// Licensed under the Apache 2.0 license found in the LICENSE file or at: +// https://opensource.org/licenses/Apache-2.0 + +//! The interface C++ drives the crate through. Text crosses as bytes because KJ strings need not +//! be UTF-8; it is converted lossily. + +#![expect( + clippy::boxed_local, + clippy::needless_pass_by_value, + clippy::unnecessary_box_returns, + reason = "the CXX boundary requires these ownership and transport representations" +)] + +use kj_rs::KjMaybe; + +use crate::attributes::Attributes; +use crate::buffer; +use crate::buffer::SpanBuffer; +use crate::proto; + +#[cxx::bridge(namespace = "workerd::rust::otlp")] +mod ffi { + enum StatusCode { + Unset, + Ok, + Error, + } + + /// What is fixed for one invocation's spans. + struct Options { + /// The W3C trace flags, zero when the trace carries none. + trace_flags: u32, + /// The invocation's own span: the one whose kind and status follow the root rules, and + /// whose close hands out the invocation's spans. + root_span_id: u64, + /// Cut the query from `url.full` and leave out `url.query`. + redact_query_string: bool, + /// Leave every timestamp at zero, for tests that compare whole spans. + omit_timestamps: bool, + } + + /// An encoded `ExportTraceServiceRequest` and the number of spans in it. When there is nothing + /// to send yet, `request` is empty and `span_count` is zero. + struct Batch { + request: Vec, + span_count: usize, + } + + extern "Rust" { + /// Span or resource attributes, in the order they were added. + type Attributes; + + fn new_attributes() -> Box; + fn add_string(attributes: &mut Attributes, key: &[u8], value: &[u8]); + fn add_bool(attributes: &mut Attributes, key: &[u8], value: bool); + fn add_int(attributes: &mut Attributes, key: &[u8], value: i64); + fn add_double(attributes: &mut Attributes, key: &[u8], value: f64); + + /// One invocation's spans on their way to a collector. Times are unix nanoseconds. + type SpanBuffer; + + /// `trace_id` is the 16-byte id every span shares. `resource` describes the worker and + /// goes on every request. `default_attributes` are applied to every span at its close + /// without overriding the span's own. + fn new_span_buffer( + trace_id: &[u8], + options: Options, + resource: Box, + default_attributes: Box, + ) -> Box; + + /// Returns false when the span is not buffered: its id is already open, or too many spans + /// are. Updates and the close of such a span are ignored. + fn open_span( + buffer: &mut SpanBuffer, + span_id: u64, + parent_span_id: u64, + name: &[u8], + start: i64, + ) -> bool; + fn set_span_name(buffer: &mut SpanBuffer, span_id: u64, name: &[u8]); + fn set_span_status(buffer: &mut SpanBuffer, span_id: u64, code: StatusCode, message: &[u8]); + fn add_span_exception( + buffer: &mut SpanBuffer, + span_id: u64, + time: i64, + name: &[u8], + message: &[u8], + stack: KjMaybe<&[u8]>, + ); + /// `attributes` are the ones the span ended up with. + fn close_span( + buffer: &mut SpanBuffer, + span_id: u64, + end: i64, + attributes: Box, + ) -> Batch; + /// Ends the invocation: spans still open are closed at `now` and flagged as not ended. + fn finish(buffer: &mut SpanBuffer, now: i64) -> Batch; + } +} + +fn text(bytes: &[u8]) -> String { + String::from_utf8_lossy(bytes).into_owned() +} + +fn batch(batch: Option) -> ffi::Batch { + batch.map_or_else( + || ffi::Batch { + request: Vec::new(), + span_count: 0, + }, + |batch| ffi::Batch { + request: batch.request, + span_count: batch.span_count, + }, + ) +} + +fn new_attributes() -> Box { + Box::default() +} + +fn add_string(attributes: &mut Attributes, key: &[u8], value: &[u8]) { + attributes.push(text(key), text(value)); +} + +fn add_bool(attributes: &mut Attributes, key: &[u8], value: bool) { + attributes.push(text(key), value); +} + +fn add_int(attributes: &mut Attributes, key: &[u8], value: i64) { + attributes.push(text(key), value); +} + +fn add_double(attributes: &mut Attributes, key: &[u8], value: f64) { + attributes.push(text(key), value); +} + +fn new_span_buffer( + trace_id: &[u8], + options: ffi::Options, + resource: Box, + default_attributes: Box, +) -> Box { + let options = buffer::Options { + trace_id: trace_id.to_vec(), + trace_flags: options.trace_flags, + root_span_id: options.root_span_id, + redact_query_string: options.redact_query_string, + omit_timestamps: options.omit_timestamps, + }; + Box::new(SpanBuffer::new(options, *resource, *default_attributes)) +} + +fn open_span( + buffer: &mut SpanBuffer, + span_id: u64, + parent_span_id: u64, + name: &[u8], + start: i64, +) -> bool { + buffer.open(span_id, parent_span_id, text(name), start) +} + +fn set_span_name(buffer: &mut SpanBuffer, span_id: u64, name: &[u8]) { + buffer.set_name(span_id, text(name)); +} + +fn set_span_status(buffer: &mut SpanBuffer, span_id: u64, code: ffi::StatusCode, message: &[u8]) { + let code = match code { + ffi::StatusCode::Ok => proto::StatusCode::Ok, + ffi::StatusCode::Error => proto::StatusCode::Error, + _ => proto::StatusCode::Unset, + }; + buffer.set_status(span_id, code, text(message)); +} + +fn add_span_exception( + buffer: &mut SpanBuffer, + span_id: u64, + time: i64, + name: &[u8], + message: &[u8], + stack: KjMaybe<&[u8]>, +) { + let stack = Option::from(stack).map(text); + buffer.add_exception(span_id, time, text(name), text(message), stack); +} + +fn close_span( + buffer: &mut SpanBuffer, + span_id: u64, + end: i64, + attributes: Box, +) -> ffi::Batch { + batch(buffer.close(span_id, end, *attributes)) +} + +fn finish(buffer: &mut SpanBuffer, now: i64) -> ffi::Batch { + batch(buffer.finish(now)) +} diff --git a/src/rust/otlp/buffer.rs b/src/rust/otlp/buffer.rs new file mode 100644 index 00000000000..2df03e07164 --- /dev/null +++ b/src/rust/otlp/buffer.rs @@ -0,0 +1,713 @@ +// Copyright (c) 2026 Cloudflare, Inc. +// Licensed under the Apache 2.0 license found in the LICENSE file or at: +// https://opensource.org/licenses/Apache-2.0 + +use std::collections::HashMap; +use std::collections::HashSet; + +use prost::Message; + +use crate::attributes::Attributes; +use crate::attributes::key_value; +use crate::proto; +use crate::rules; + +/// A batch is handed out once it reaches either bound. +const MAX_BATCH_SPANS: usize = 512; +const MAX_BATCH_BYTES: usize = 1 << 20; +/// Spans awaiting their close; further opens are refused once this many are buffered. +const MAX_OPEN_SPANS: usize = 1024; + +/// What is fixed for one invocation's spans. +pub struct Options { + /// The 16-byte trace id every span shares. + pub trace_id: Vec, + /// The W3C trace flags, zero when the trace carries none. + pub trace_flags: u32, + /// The invocation's own span. It is the one whose kind and status follow the root rules, and + /// its close is when the invocation's spans are handed out. + pub root_span_id: u64, + pub redact_query_string: bool, + /// Leaves every timestamp at zero, for tests that compare whole spans. + pub omit_timestamps: bool, +} + +/// An encoded `ExportTraceServiceRequest` and the number of spans in it. +pub struct Batch { + pub request: Vec, + pub span_count: usize, +} + +struct OpenSpan { + parent_span_id: u64, + name: String, + start: i64, + sequence_number: i64, + status: Option, + events: Vec, + last_exception_message: Option, +} + +/// One invocation's spans on their way to an OTLP collector. +/// +/// A span is buffered from its open until its close, which is when its attributes arrive and its +/// OTLP form is decided (see [`rules`]). Closed spans collect into a batch that is handed out as an +/// encoded request when the root span closes or the batch grows large. Once the root has closed, +/// every later close is handed out on its own: such spans belong to work that outlives the +/// invocation, and nothing bounds how long the next one would take to arrive. +/// +/// Each span also gets `cloudflare.invocation.sequence.number`, counted in open order so the root +/// is 1, and a start time no other span of the invocation shares. +pub struct SpanBuffer { + options: Options, + resource: proto::Resource, + /// Applied to every span at close without overriding its own attributes. + default_attributes: Attributes, + root_closed: bool, + last_sequence_number: i64, + /// Start times handed out so far, as unix nanoseconds. + start_times: HashSet, + open: HashMap, + closed: Vec, + /// Encoded size of `closed`, kept so a close does not re-measure the batch. + closed_bytes: usize, +} + +impl SpanBuffer { + pub fn new(options: Options, resource: Attributes, default_attributes: Attributes) -> Self { + Self { + options, + resource: proto::Resource { + attributes: resource.into_proto(), + }, + default_attributes, + root_closed: false, + last_sequence_number: 0, + start_times: HashSet::new(), + open: HashMap::new(), + closed: Vec::new(), + closed_bytes: 0, + } + } + + /// Starts buffering a span. Returns false, leaving the buffer unchanged, when the id is already + /// open or too many spans are. + pub fn open(&mut self, span_id: u64, parent_span_id: u64, name: String, start: i64) -> bool { + if self.open.len() >= MAX_OPEN_SPANS || self.open.contains_key(&span_id) { + return false; + } + let mut start = start; + while !self.start_times.insert(start) { + start += 1; + } + self.last_sequence_number += 1; + self.open.insert( + span_id, + OpenSpan { + parent_span_id, + name, + start, + sequence_number: self.last_sequence_number, + status: None, + events: Vec::new(), + last_exception_message: None, + }, + ); + true + } + + /// Renames an open span. Like every update, it is ignored for a span that is not open. + pub fn set_name(&mut self, span_id: u64, name: String) { + if let Some(span) = self.open.get_mut(&span_id) { + span.name = name; + } + } + + /// Records the status the worker set on an open span. + pub fn set_status(&mut self, span_id: u64, code: proto::StatusCode, message: String) { + if let Some(span) = self.open.get_mut(&span_id) { + span.status = Some(proto::Status { + message, + code: code.into(), + }); + } + } + + /// Records an exception on an open span as an `exception` event. + pub fn add_exception( + &mut self, + span_id: u64, + time: i64, + name: String, + message: String, + stack: Option, + ) { + let time_unix_nano = self.timestamp(time); + let Some(span) = self.open.get_mut(&span_id) else { + return; + }; + let mut attributes = vec![ + key_value("exception.type", name), + key_value("exception.message", message.clone()), + ]; + if let Some(stack) = stack { + attributes.push(key_value("exception.stacktrace", stack)); + } + span.events.push(proto::Event { + time_unix_nano, + name: "exception".to_owned(), + attributes, + }); + span.last_exception_message = Some(message); + } + + /// Closes a span with the attributes it ended up with. Returns a batch when one is due. + pub fn close(&mut self, span_id: u64, end: i64, attributes: Attributes) -> Option { + let span = self.open.remove(&span_id)?; + if !self.write(span_id, span, end, attributes) { + return None; + } + let due = self.root_closed + || self.closed.len() >= MAX_BATCH_SPANS + || self.closed_bytes >= MAX_BATCH_BYTES; + if due { self.take_batch() } else { None } + } + + /// Ends the invocation: spans still open are closed at `now`, flagged as not ended, and + /// everything left is handed out. + pub fn finish(&mut self, now: i64) -> Option { + let mut open: Vec<_> = self.open.drain().collect(); + open.sort_by_key(|(_, span)| span.sequence_number); + for (span_id, span) in open { + let mut attributes = Attributes::default(); + attributes.push("cloudflare.warning.type", "span_not_ended"); + attributes.push( + "cloudflare.warning.message", + "The span was still open when the invocation ended.", + ); + self.write(span_id, span, now, attributes); + } + self.take_batch() + } + + /// Adds a closed span to the batch in its OTLP form; false when the span is not reported. + fn write( + &mut self, + span_id: u64, + span: OpenSpan, + end: i64, + mut attributes: Attributes, + ) -> bool { + let is_root = span_id == self.options.root_span_id; + rules::add_url_attributes(&mut attributes, self.options.redact_query_string); + if rules::is_internal_binding_fetch(&span.name, &attributes) { + return false; + } + attributes.set_defaults(&self.default_attributes); + attributes.set( + "cloudflare.invocation.sequence.number", + span.sequence_number, + ); + + let kind = rules::span_kind(&span.name, &attributes, is_root); + let (status, error_type) = resolve_status( + span.status, + span.last_exception_message, + &attributes, + is_root, + ); + let mut attributes = attributes.into_proto(); + if let Some(error_type) = error_type { + attributes.push(key_value("error.type", error_type)); + } + + let parent_span_id = match span.parent_span_id { + 0 => Vec::new(), + id => id.to_be_bytes().to_vec(), + }; + let out = proto::Span { + trace_id: self.options.trace_id.clone(), + span_id: span_id.to_be_bytes().to_vec(), + parent_span_id, + name: span.name, + kind: kind.into(), + start_time_unix_nano: self.timestamp(span.start), + // A span never ends before it starts, whatever the clocks said. + end_time_unix_nano: self.timestamp(end.max(span.start)), + attributes, + events: span.events, + status, + flags: self.options.trace_flags, + }; + self.closed_bytes += out.encoded_len(); + self.closed.push(out); + if is_root { + self.root_closed = true; + } + true + } + + fn take_batch(&mut self) -> Option { + if self.closed.is_empty() { + return None; + } + let spans = std::mem::take(&mut self.closed); + self.closed_bytes = 0; + let span_count = spans.len(); + let request = proto::ExportTraceServiceRequest { + resource_spans: vec![proto::ResourceSpans { + resource: Some(self.resource.clone()), + scope_spans: vec![proto::ScopeSpans { spans }], + }], + }; + Some(Batch { + request: request.encode_to_vec(), + span_count, + }) + } + + fn timestamp(&self, unix_nanos: i64) -> u64 { + if self.options.omit_timestamps { + 0 + } else { + unix_nanos.cast_unsigned() + } + } +} + +/// The status a span is exported with, and the `error.type` attribute that goes with it. +/// +/// A status the worker set to OK or ERROR stands. Otherwise an exception makes the span an error +/// with the last exception's message, and failing that the span's attributes may (see +/// [`rules::derived_error_type`]), which is the only case that adds `error.type`. +fn resolve_status( + status: Option, + last_exception_message: Option, + attributes: &Attributes, + is_root: bool, +) -> (Option, Option) { + let error = i32::from(proto::StatusCode::Error); + if status + .as_ref() + .is_some_and(|status| status.code != i32::from(proto::StatusCode::Unset)) + { + return (status, None); + } + if let Some(message) = last_exception_message { + let status = proto::Status { + message, + code: error, + }; + return (Some(status), None); + } + let Some(error_type) = rules::derived_error_type(attributes, is_root) else { + return (status, None); + }; + let status = proto::Status { + code: error, + ..status.unwrap_or_default() + }; + (Some(status), Some(error_type)) +} + +#[cfg(test)] +mod tests { + use super::*; + use crate::proto::SpanKind; + use crate::proto::StatusCode; + use crate::proto::any_value::Value; + + /// Above every id the tests hand out in a loop. + const ROOT: u64 = 0x1000; + const T0: i64 = 1_000_000_000; + + fn buffer_with(redact_query_string: bool, default_attributes: Attributes) -> SpanBuffer { + let mut resource = Attributes::default(); + resource.push("service.name", "my-worker"); + SpanBuffer::new( + Options { + trace_id: (1..=16).collect(), + trace_flags: 1, + root_span_id: ROOT, + redact_query_string, + omit_timestamps: false, + }, + resource, + default_attributes, + ) + } + + fn buffer() -> SpanBuffer { + buffer_with(false, Attributes::default()) + } + + fn attributes(pairs: &[(&str, Value)]) -> Attributes { + let mut attributes = Attributes::default(); + for (key, value) in pairs { + attributes.push(*key, value.clone()); + } + attributes + } + + fn string(value: &str) -> Value { + Value::String(value.to_owned()) + } + + fn decode(batch: &Batch) -> proto::ExportTraceServiceRequest { + let request = proto::ExportTraceServiceRequest::decode(batch.request.as_slice()).unwrap(); + assert_eq!(request.resource_spans.len(), 1); + assert_eq!(request.resource_spans[0].scope_spans.len(), 1); + assert_eq!(spans(&request).len(), batch.span_count); + request + } + + fn spans(request: &proto::ExportTraceServiceRequest) -> &[proto::Span] { + &request.resource_spans[0].scope_spans[0].spans + } + + fn named<'a>(request: &'a proto::ExportTraceServiceRequest, name: &str) -> &'a proto::Span { + spans(request) + .iter() + .find(|span| span.name == name) + .unwrap() + } + + fn attribute<'a>(attributes: &'a [proto::KeyValue], key: &str) -> Option<&'a Value> { + attributes + .iter() + .find(|kv| kv.key == key) + .and_then(|kv| kv.value.as_ref()?.value.as_ref()) + } + + fn status_code(span: &proto::Span) -> StatusCode { + span.status + .as_ref() + .map_or(StatusCode::Unset, proto::Status::code) + } + + #[test] + fn spans_are_batched_until_the_root_closes() { + let mut defaults = Attributes::default(); + defaults.push("cloudflare.entrypoint", "MyEntrypoint"); + defaults.push("faas.trigger", "not-applied"); + let mut buffer = buffer_with(false, defaults); + + assert!(buffer.open(ROOT, 0x20, "GET".to_owned(), T0)); + assert!(buffer.open(1, ROOT, "fetch".to_owned(), T0)); + // An id that is already open is refused rather than clobbering the open span. + assert!(!buffer.open(1, ROOT, "other".to_owned(), T0)); + assert!(buffer.open(3, ROOT, "my-span".to_owned(), T0)); + buffer.set_name(3, "renamed".to_owned()); + buffer.set_status(3, StatusCode::Error, "boom".to_owned()); + buffer.add_exception(3, T0 + 5, "TypeError".to_owned(), "boom".to_owned(), None); + // Updates for a span that is not open are ignored. + buffer.set_name(2, "ignored".to_owned()); + + // Nothing is handed out until the root closes. + assert!( + buffer + .close(1, T0 + 10, attributes(&[("cached", Value::Bool(true))])) + .is_none() + ); + assert!(buffer.close(3, T0 + 10, Attributes::default()).is_none()); + let batch = buffer + .close( + ROOT, + T0 + 20, + attributes(&[ + ("faas.trigger", string("http")), + ("cloudflare.outcome", string("ok")), + ]), + ) + .unwrap(); + + let request = decode(&batch); + let resource = request.resource_spans[0].resource.as_ref().unwrap(); + assert_eq!( + attribute(&resource.attributes, "service.name"), + Some(&string("my-worker")) + ); + let [fetch, renamed, root] = spans(&request) else { + panic!("expected three spans"); + }; + assert_eq!(fetch.name, "fetch"); + assert_eq!(fetch.trace_id, (1..=16).collect::>()); + assert_eq!(fetch.span_id, [0, 0, 0, 0, 0, 0, 0, 1]); + assert_eq!(fetch.parent_span_id, [0, 0, 0, 0, 0, 0, 0x10, 0]); + assert_eq!(fetch.flags, 1); + assert_eq!( + attribute(&fetch.attributes, "cached"), + Some(&Value::Bool(true)) + ); + assert_eq!(renamed.name, "renamed"); + assert_eq!(status_code(renamed), StatusCode::Error); + assert_eq!(renamed.status.as_ref().unwrap().message, "boom"); + let [exception] = renamed.events.as_slice() else { + panic!("expected one event"); + }; + assert_eq!(exception.name, "exception"); + assert_eq!(exception.time_unix_nano, (T0 + 5).cast_unsigned()); + assert_eq!( + attribute(&exception.attributes, "exception.type"), + Some(&string("TypeError")) + ); + assert_eq!( + attribute(&exception.attributes, "exception.stacktrace"), + None + ); + assert_eq!(root.name, "GET"); + assert_eq!(root.kind(), SpanKind::Server); + assert_eq!(root.status, None); + assert_eq!(root.parent_span_id, [0, 0, 0, 0, 0, 0, 0, 0x20]); + + // Spans are numbered in open order, the root first, and every span carries the default + // attributes, which do not override its own. + for (span, sequence_number) in [(fetch, 2), (renamed, 3), (root, 1)] { + assert_eq!( + attribute(&span.attributes, "cloudflare.invocation.sequence.number"), + Some(&Value::Int(sequence_number)) + ); + assert_eq!( + attribute(&span.attributes, "cloudflare.entrypoint"), + Some(&string("MyEntrypoint")) + ); + } + assert_eq!( + attribute(&fetch.attributes, "faas.trigger"), + Some(&string("not-applied")) + ); + assert_eq!( + attribute(&root.attributes, "faas.trigger"), + Some(&string("http")) + ); + + // A span closing after the root is handed out as soon as it closes. + assert!(buffer.open(4, ROOT, "late".to_owned(), T0)); + let batch = buffer.close(4, T0, Attributes::default()).unwrap(); + assert_eq!(spans(&decode(&batch))[0].name, "late"); + assert!(buffer.finish(T0).is_none()); + } + + #[test] + fn a_full_batch_is_handed_out_and_open_spans_are_capped() { + let mut buffer = buffer(); + for id in 1..MAX_BATCH_SPANS as u64 { + assert!(buffer.open(id, ROOT, "s".to_owned(), T0)); + assert!(buffer.close(id, T0, Attributes::default()).is_none()); + } + assert!(buffer.open(1, ROOT, "s".to_owned(), T0)); + let batch = buffer.close(1, T0, Attributes::default()).unwrap(); + assert_eq!(batch.span_count, MAX_BATCH_SPANS); + + for id in 1..=MAX_OPEN_SPANS as u64 { + assert!(buffer.open(id, ROOT, "s".to_owned(), T0)); + } + assert!(!buffer.open(MAX_OPEN_SPANS as u64 + 1, ROOT, "s".to_owned(), T0)); + + // Spans still open at the end are closed then, flagged, in the order they were opened. + let batch = buffer.finish(T0 - 1).unwrap(); + assert_eq!(batch.span_count, MAX_OPEN_SPANS); + let request = decode(&batch); + let unclosed = spans(&request); + assert_eq!(unclosed[0].span_id, 1u64.to_be_bytes()); + assert_eq!(unclosed[1].span_id, 2u64.to_be_bytes()); + assert_eq!( + attribute(&unclosed[0].attributes, "cloudflare.warning.type"), + Some(&string("span_not_ended")) + ); + assert!(attribute(&unclosed[0].attributes, "cloudflare.warning.message").is_some()); + assert!(unclosed[0].end_time_unix_nano >= unclosed[0].start_time_unix_nano); + assert!(buffer.finish(T0).is_none()); + } + + #[test] + fn a_batch_is_handed_out_once_it_is_large() { + let mut buffer = buffer(); + let big = "x".repeat(MAX_BATCH_BYTES / 2); + assert!(buffer.open(1, ROOT, "s".to_owned(), T0)); + assert!( + buffer + .close(1, T0, attributes(&[("big", string(&big))])) + .is_none() + ); + assert!(buffer.open(2, ROOT, "s".to_owned(), T0)); + let batch = buffer + .close(2, T0, attributes(&[("big", string(&big))])) + .unwrap(); + assert_eq!(batch.span_count, 2); + } + + #[test] + fn kind_status_and_url_rules_apply_at_close() { + let mut buffer = buffer(); + assert!(buffer.open(ROOT, 0, "scheduled".to_owned(), T0)); + for (id, name) in [(1, "fetch"), (2, "fetch"), (3, "queue_send"), (6, "fetch")] { + assert!(buffer.open(id, ROOT, name.to_owned(), T0)); + } + + // A 4xx child becomes an error with error.type; its URL is split into parts. + buffer.close( + 1, + T0, + attributes(&[ + ( + "url.full", + string("https://example.com:8443/a/b?x=1&y#frag"), + ), + ("http.response.status_code", Value::Int(404)), + ]), + ); + // A fetch to a binding's internal host is not reported. + buffer.close( + 2, + T0, + attributes(&[("url.full", string("https://d1/query"))]), + ); + buffer.close(3, T0, Attributes::default()); + // A 2xx is left unset, and an end before the start is moved to the start. + buffer.close( + 6, + T0 - 1, + attributes(&[ + ("url.full", string("http://[::1]")), + ("http.response.status_code", Value::Int(200)), + ]), + ); + // A root with a non-ok outcome is an error, and a consumer for a timer trigger. + let batch = buffer + .close( + ROOT, + T0, + attributes(&[ + ("faas.trigger", string("timer")), + ("cloudflare.outcome", string("exceededCpu")), + ]), + ) + .unwrap(); + let request = decode(&batch); + assert_eq!(batch.span_count, 4); + + let fetch = named(&request, "fetch"); + assert_eq!(fetch.kind(), SpanKind::Client); + assert_eq!(status_code(fetch), StatusCode::Error); + assert_eq!( + attribute(&fetch.attributes, "error.type"), + Some(&string("404")) + ); + assert_eq!( + attribute(&fetch.attributes, "server.port"), + Some(&Value::Int(8443)) + ); + assert_eq!( + attribute(&fetch.attributes, "url.query"), + Some(&string("x=1&y")) + ); + + let queue_send = named(&request, "queue_send"); + assert_eq!(queue_send.kind(), SpanKind::Producer); + // The span that was not reported took a sequence number at open. + assert_eq!( + attribute( + &queue_send.attributes, + "cloudflare.invocation.sequence.number" + ), + Some(&Value::Int(4)) + ); + + let ipv6 = &spans(&request)[2]; + assert_eq!(ipv6.status, None); + assert_eq!(attribute(&ipv6.attributes, "error.type"), None); + assert_eq!(ipv6.end_time_unix_nano, ipv6.start_time_unix_nano); + // Spans opened at the same instant get distinct start times. + assert!(ipv6.start_time_unix_nano > fetch.start_time_unix_nano); + + let root = named(&request, "scheduled"); + assert_eq!(root.kind(), SpanKind::Consumer); + assert_eq!(status_code(root), StatusCode::Error); + assert_eq!( + attribute(&root.attributes, "error.type"), + Some(&string("exceededCpu")) + ); + assert!(root.parent_span_id.is_empty()); + } + + #[test] + fn a_status_the_worker_set_and_exceptions_come_before_derived_errors() { + let mut buffer = buffer_with(true, Attributes::default()); + assert!(buffer.open(ROOT, 0, "GET".to_owned(), T0)); + assert!(buffer.open(1, ROOT, "mine".to_owned(), T0)); + assert!(buffer.open(2, ROOT, "unset".to_owned(), T0)); + buffer.set_status(1, StatusCode::Ok, String::new()); + buffer.set_status(2, StatusCode::Unset, String::new()); + let failed = attributes(&[("http.response.status_code", Value::Int(503))]); + buffer.close(1, T0, failed.clone()); + buffer.close(2, T0, failed); + buffer.add_exception( + ROOT, + T0, + "Error".to_owned(), + "boom".to_owned(), + Some("at fetch".to_owned()), + ); + let batch = buffer + .close( + ROOT, + T0, + attributes(&[ + ("url.full", string("https://example.com/p?secret=1")), + ("http.response.status_code", Value::Int(500)), + ]), + ) + .unwrap(); + let request = decode(&batch); + + let mine = named(&request, "mine"); + assert_eq!(status_code(mine), StatusCode::Ok); + assert_eq!(attribute(&mine.attributes, "error.type"), None); + // An explicit UNSET does not stand in the way of a derived error. + let unset = named(&request, "unset"); + assert_eq!(status_code(unset), StatusCode::Error); + assert_eq!( + attribute(&unset.attributes, "error.type"), + Some(&string("503")) + ); + + let root = named(&request, "GET"); + assert_eq!(status_code(root), StatusCode::Error); + assert_eq!(root.status.as_ref().unwrap().message, "boom"); + assert_eq!(attribute(&root.attributes, "error.type"), None); + assert_eq!( + attribute(&root.events[0].attributes, "exception.stacktrace"), + Some(&string("at fetch")) + ); + assert_eq!( + attribute(&root.attributes, "url.full"), + Some(&string("https://example.com/p")) + ); + assert_eq!(attribute(&root.attributes, "url.query"), None); + } + + #[test] + fn timestamps_can_be_omitted() { + let mut buffer = SpanBuffer::new( + Options { + trace_id: vec![0; 16], + trace_flags: 0, + root_span_id: ROOT, + redact_query_string: false, + omit_timestamps: true, + }, + Attributes::default(), + Attributes::default(), + ); + assert!(buffer.open(ROOT, 0, "GET".to_owned(), T0)); + buffer.add_exception(ROOT, T0, "Error".to_owned(), "boom".to_owned(), None); + let batch = buffer.close(ROOT, T0 + 1, Attributes::default()).unwrap(); + let request = decode(&batch); + let root = named(&request, "GET"); + assert_eq!(root.start_time_unix_nano, 0); + assert_eq!(root.end_time_unix_nano, 0); + assert_eq!(root.events[0].time_unix_nano, 0); + assert_eq!(root.flags, 0); + } +} diff --git a/src/rust/otlp/lib.rs b/src/rust/otlp/lib.rs new file mode 100644 index 00000000000..85fea7f3116 --- /dev/null +++ b/src/rust/otlp/lib.rs @@ -0,0 +1,21 @@ +// Copyright (c) 2026 Cloudflare, Inc. +// Licensed under the Apache 2.0 license found in the LICENSE file or at: +// https://opensource.org/licenses/Apache-2.0 + +// Production code must not panic; test code is exempt via clippy.toml allow-*-in-tests. +#![deny(clippy::expect_used, clippy::panic, clippy::unreachable)] +#![deny(clippy::todo, clippy::unimplemented)] + +//! Turns one invocation's spans into OTLP/HTTP export requests. +//! +//! C++ reports each span's open, updates and close to a `SpanBuffer` (`bridge`), and gets back +//! encoded `ExportTraceServiceRequest`s to POST to a collector's `/v1/traces` as +//! `application/x-protobuf`. Everything between is decided here: what a span looks like in OTLP +//! (`rules`), how spans are batched (`buffer`), and the wire format (`proto`). Sending the request +//! is left to the caller. + +mod attributes; +mod bridge; +mod buffer; +mod proto; +mod rules; diff --git a/src/rust/otlp/proto.rs b/src/rust/otlp/proto.rs new file mode 100644 index 00000000000..a4da4339ec1 --- /dev/null +++ b/src/rust/otlp/proto.rs @@ -0,0 +1,130 @@ +// Copyright (c) 2026 Cloudflare, Inc. +// Licensed under the Apache 2.0 license found in the LICENSE file or at: +// https://opensource.org/licenses/Apache-2.0 + +//! The part of the OTLP trace schema the exporter writes. +//! +//! Field numbers are those of `opentelemetry/proto/{common,resource,trace}/v1` and +//! `collector/trace/v1/trace_service.proto`, which are stable. Fields the exporter never sets are +//! left out; a collector reads them as their defaults. + +#[derive(Clone, PartialEq, prost::Message)] +pub struct ExportTraceServiceRequest { + #[prost(message, repeated, tag = "1")] + pub resource_spans: Vec, +} + +#[derive(Clone, PartialEq, prost::Message)] +pub struct ResourceSpans { + #[prost(message, optional, tag = "1")] + pub resource: Option, + #[prost(message, repeated, tag = "2")] + pub scope_spans: Vec, +} + +#[derive(Clone, PartialEq, prost::Message)] +pub struct Resource { + #[prost(message, repeated, tag = "1")] + pub attributes: Vec, +} + +#[derive(Clone, PartialEq, prost::Message)] +pub struct ScopeSpans { + #[prost(message, repeated, tag = "2")] + pub spans: Vec, +} + +#[derive(Clone, PartialEq, prost::Message)] +#[expect( + clippy::struct_field_names, + reason = "the fields are named as in the OTLP message" +)] +pub struct Span { + #[prost(bytes = "vec", tag = "1")] + pub trace_id: Vec, + #[prost(bytes = "vec", tag = "2")] + pub span_id: Vec, + #[prost(bytes = "vec", tag = "4")] + pub parent_span_id: Vec, + #[prost(string, tag = "5")] + pub name: String, + #[prost(enumeration = "SpanKind", tag = "6")] + pub kind: i32, + #[prost(fixed64, tag = "7")] + pub start_time_unix_nano: u64, + #[prost(fixed64, tag = "8")] + pub end_time_unix_nano: u64, + #[prost(message, repeated, tag = "9")] + pub attributes: Vec, + #[prost(message, repeated, tag = "11")] + pub events: Vec, + #[prost(message, optional, tag = "15")] + pub status: Option, + #[prost(fixed32, tag = "16")] + pub flags: u32, +} + +#[derive(Clone, Copy, Debug, PartialEq, Eq, Hash, PartialOrd, Ord, prost::Enumeration)] +#[repr(i32)] +pub enum SpanKind { + Unspecified = 0, + Internal = 1, + Server = 2, + Client = 3, + Producer = 4, + Consumer = 5, +} + +#[derive(Clone, PartialEq, prost::Message)] +pub struct Event { + #[prost(fixed64, tag = "1")] + pub time_unix_nano: u64, + #[prost(string, tag = "2")] + pub name: String, + #[prost(message, repeated, tag = "3")] + pub attributes: Vec, +} + +#[derive(Clone, PartialEq, Eq, prost::Message)] +pub struct Status { + #[prost(string, tag = "2")] + pub message: String, + #[prost(enumeration = "StatusCode", tag = "3")] + pub code: i32, +} + +#[derive(Clone, Copy, Debug, PartialEq, Eq, Hash, PartialOrd, Ord, prost::Enumeration)] +#[repr(i32)] +pub enum StatusCode { + Unset = 0, + Ok = 1, + Error = 2, +} + +#[derive(Clone, PartialEq, prost::Message)] +pub struct KeyValue { + #[prost(string, tag = "1")] + pub key: String, + #[prost(message, optional, tag = "2")] + pub value: Option, +} + +#[derive(Clone, PartialEq, prost::Message)] +pub struct AnyValue { + #[prost(oneof = "any_value::Value", tags = "1, 2, 3, 4")] + pub value: Option, +} + +pub mod any_value { + #[derive(Clone, PartialEq, prost::Oneof)] + pub enum Value { + #[prost(string, tag = "1")] + String(String), + #[prost(bool, tag = "2")] + Bool(bool), + #[prost(int64, tag = "3")] + Int(i64), + #[prost(double, tag = "4")] + Double(f64), + } +} diff --git a/src/rust/otlp/rules.rs b/src/rust/otlp/rules.rs new file mode 100644 index 00000000000..f1cb8e39d18 --- /dev/null +++ b/src/rust/otlp/rules.rs @@ -0,0 +1,249 @@ +// Copyright (c) 2026 Cloudflare, Inc. +// Licensed under the Apache 2.0 license found in the LICENSE file or at: +// https://opensource.org/licenses/Apache-2.0 + +//! What a span's name and attributes imply for its OTLP form: its kind, an error status the +//! worker did not set itself, the URL attributes, and whether it is reported at all. + +use ada_url::Url; + +use crate::attributes::Attributes; +use crate::proto::SpanKind; + +/// The root span is `Server`, or `Consumer` when the invocation was triggered by a timer, a queue +/// or an email. Every other span describes an outgoing operation: `Producer` for the ones that +/// enqueue work, `Client` otherwise. +pub fn span_kind(name: &str, attributes: &Attributes, is_root: bool) -> SpanKind { + if is_root { + match attributes.string("faas.trigger") { + Some("timer" | "pubsub" | "email") => SpanKind::Consumer, + _ => SpanKind::Server, + } + } else if matches!(name, "queue_send" | "durable_object_storage_setAlarm") { + SpanKind::Producer + } else { + SpanKind::Client + } +} + +/// The `error.type` of a span whose attributes alone make it an error: a root span whose +/// `cloudflare.outcome` is not `ok` or whose response status is 5xx, and any other span whose +/// response status is 4xx or 5xx. +pub fn derived_error_type(attributes: &Attributes, is_root: bool) -> Option { + let status_code = attributes.int("http.response.status_code").unwrap_or(0); + if is_root { + if let Some(outcome) = attributes + .string("cloudflare.outcome") + .filter(|o| *o != "ok") + { + return Some(outcome.to_owned()); + } + (status_code >= 500).then(|| status_code.to_string()) + } else { + (status_code >= 400).then(|| status_code.to_string()) + } +} + +/// Adds the attributes derived from `url.full` (`url.scheme`, `server.address`, `server.port` when +/// the URL names one, `url.path`, `url.query` when there is a query, and `network.protocol.name` +/// for HTTP), keeping any the span already carries. With `redact_query_string` the query and +/// fragment are cut from `url.full` instead and `url.query` is not set. A span without a +/// parseable `url.full` is left alone. +pub fn add_url_attributes(attributes: &mut Attributes, redact_query_string: bool) { + let Some(url) = attributes + .string("url.full") + .and_then(|full| Url::parse(full, None).ok()) + else { + return; + }; + let scheme = url.protocol().trim_end_matches(':'); + + attributes.set_default("url.scheme", scheme); + attributes.set_default("server.address", url.hostname()); + if let Ok(port) = url.port().parse::() { + attributes.set_default("server.port", i64::from(port)); + } + attributes.set_default("url.path", url.pathname()); + if matches!(scheme, "http" | "https") { + attributes.set_default("network.protocol.name", "http"); + } + + let query = url.search().trim_start_matches('?'); + if query.is_empty() { + return; + } + if redact_query_string { + let redacted = format!("{scheme}://{}{}", url.host(), url.pathname()); + attributes.set("url.full", redacted); + } else { + attributes.set_default("url.query", query); + } +} + +/// Whether a `fetch` span targets the placeholder host of a binding that is implemented with an +/// internal fetch (AI, D1, Workflows, Images, Vectorize). Those are an implementation detail of +/// the binding and are not reported. Reads `server.address`, so `add_url_attributes` goes first. +pub fn is_internal_binding_fetch(name: &str, attributes: &Attributes) -> bool { + const INTERNAL_HOSTS: [&str; 6] = [ + "workers-binding.ai", + "d1", + "workflow-binding.local", + "fake.host", + "js.images.cloudflare.com", + "vector-search", + ]; + name == "fetch" + && attributes + .string("server.address") + .is_some_and(|address| INTERNAL_HOSTS.contains(&address)) +} + +#[cfg(test)] +mod tests { + use super::*; + use crate::proto::any_value::Value; + + fn with(pairs: &[(&str, Value)]) -> Attributes { + let mut attributes = Attributes::default(); + for (key, value) in pairs { + attributes.push(*key, value.clone()); + } + attributes + } + + fn string(value: &str) -> Value { + Value::String(value.to_owned()) + } + + #[test] + fn kind_follows_the_trigger_for_the_root_and_the_name_for_children() { + let timer = with(&[("faas.trigger", string("timer"))]); + let http = with(&[("faas.trigger", string("http"))]); + assert_eq!(span_kind("scheduled", &timer, true), SpanKind::Consumer); + assert_eq!(span_kind("GET", &http, true), SpanKind::Server); + assert_eq!( + span_kind("GET", &Attributes::default(), true), + SpanKind::Server + ); + // The trigger only matters on the root. + assert_eq!(span_kind("fetch", &timer, false), SpanKind::Client); + assert_eq!(span_kind("queue_send", &http, false), SpanKind::Producer); + assert_eq!( + span_kind("durable_object_storage_setAlarm", &http, false), + SpanKind::Producer + ); + } + + #[test] + fn error_type_is_derived_from_outcome_and_status_code() { + let status = |code| with(&[("http.response.status_code", Value::Int(code))]); + assert_eq!( + derived_error_type(&status(404), false).as_deref(), + Some("404") + ); + assert_eq!(derived_error_type(&status(399), false), None); + // A 4xx from the worker itself is the worker's answer, not its failure. + assert_eq!(derived_error_type(&status(404), true), None); + assert_eq!( + derived_error_type(&status(503), true).as_deref(), + Some("503") + ); + + let outcome = |outcome| { + with(&[ + ("cloudflare.outcome", string(outcome)), + ("http.response.status_code", Value::Int(500)), + ]) + }; + assert_eq!( + derived_error_type(&outcome("exceededCpu"), true).as_deref(), + Some("exceededCpu") + ); + assert_eq!( + derived_error_type(&outcome("ok"), true).as_deref(), + Some("500") + ); + // The outcome belongs to the root. + assert_eq!( + derived_error_type(&with(&[("cloudflare.outcome", string("exception"))]), false), + None + ); + } + + #[test] + fn url_attributes_are_split_from_url_full() { + let mut attributes = with(&[( + "url.full", + string("https://example.com:8443/a/b?x=1&y#frag"), + )]); + add_url_attributes(&mut attributes, false); + assert_eq!(attributes.string("url.scheme"), Some("https")); + assert_eq!(attributes.string("server.address"), Some("example.com")); + assert_eq!(attributes.int("server.port"), Some(8443)); + assert_eq!(attributes.string("url.path"), Some("/a/b")); + assert_eq!(attributes.string("url.query"), Some("x=1&y")); + assert_eq!(attributes.string("network.protocol.name"), Some("http")); + assert_eq!( + attributes.string("url.full"), + Some("https://example.com:8443/a/b?x=1&y#frag") + ); + } + + #[test] + fn url_without_port_path_or_query() { + let mut attributes = with(&[("url.full", string("http://[::1]"))]); + add_url_attributes(&mut attributes, false); + assert_eq!(attributes.string("server.address"), Some("[::1]")); + assert_eq!(attributes.get("server.port"), None); + assert_eq!(attributes.string("url.path"), Some("/")); + assert_eq!(attributes.get("url.query"), None); + } + + #[test] + fn redaction_cuts_the_query_from_url_full() { + let mut attributes = with(&[("url.full", string("https://example.com:8443/p?secret=1#f"))]); + add_url_attributes(&mut attributes, true); + assert_eq!( + attributes.string("url.full"), + Some("https://example.com:8443/p") + ); + assert_eq!(attributes.string("url.path"), Some("/p")); + assert_eq!(attributes.get("url.query"), None); + + // Nothing to redact: url.full is not rewritten. + let mut attributes = with(&[("url.full", string("https://example.com/p#f"))]); + add_url_attributes(&mut attributes, true); + assert_eq!( + attributes.string("url.full"), + Some("https://example.com/p#f") + ); + } + + #[test] + fn url_attributes_keep_what_the_span_already_carries() { + let mut attributes = with(&[ + ("server.address", string("origin.internal")), + ("url.full", string("https://example.com/p?q=1")), + ]); + add_url_attributes(&mut attributes, false); + assert_eq!(attributes.string("server.address"), Some("origin.internal")); + assert_eq!(attributes.string("url.query"), Some("q=1")); + + // Neither an absent nor an unparseable url.full adds anything. + let mut attributes = with(&[("url.full", string("not a url"))]); + add_url_attributes(&mut attributes, false); + assert_eq!(attributes, with(&[("url.full", string("not a url"))])); + let mut attributes = with(&[("url.full", Value::Int(1))]); + add_url_attributes(&mut attributes, false); + assert_eq!(attributes.get("url.scheme"), None); + } + + #[test] + fn internal_binding_fetches_are_recognised_by_host() { + let to = |address| with(&[("server.address", string(address))]); + assert!(is_internal_binding_fetch("fetch", &to("d1"))); + assert!(!is_internal_binding_fetch("fetch", &to("example.com"))); + assert!(!is_internal_binding_fetch("d1_query", &to("d1"))); + assert!(!is_internal_binding_fetch("fetch", &Attributes::default())); + } +} diff --git a/src/workerd/api/tests/BUILD.bazel b/src/workerd/api/tests/BUILD.bazel index 5f7047b68c1..7a1f15c5757 100644 --- a/src/workerd/api/tests/BUILD.bazel +++ b/src/workerd/api/tests/BUILD.bazel @@ -282,6 +282,14 @@ wd_test( data = ["errorinfo-tail-test.js"], ) +wd_test( + src = "otlp-tracing-test.wd-test", + data = [ + "otlp-tracing-test.js", + "otlp-tracing-test-collector.js", + ], +) + wd_test( src = "tail-cf-gc-test.wd-test", data = ["tail-cf-gc-test.js"], diff --git a/src/workerd/api/tests/otlp-tracing-test-collector.js b/src/workerd/api/tests/otlp-tracing-test-collector.js new file mode 100644 index 00000000000..f0a1f02b7c7 --- /dev/null +++ b/src/workerd/api/tests/otlp-tracing-test-collector.js @@ -0,0 +1,188 @@ +// Copyright (c) 2026 Cloudflare, Inc. +// Licensed under the Apache 2.0 license found in the LICENSE file or at: +// https://opensource.org/licenses/Apache-2.0 +// +// A stand-in for an OpenTelemetry collector. POST /v1/traces takes an OTLP/HTTP protobuf +// ExportTraceServiceRequest; GET /requests returns every request received so far as JSON, with +// the POST's content type beside the decoded resource and spans. + +// Yields [field number, value] for each field of an encoded protobuf message. A varint is a +// BigInt, a 32-bit value a number, and a 64-bit or length-delimited value the bytes themselves. +function* fields(bytes) { + const view = new DataView(bytes.buffer, bytes.byteOffset, bytes.byteLength); + let pos = 0; + const varint = () => { + let result = 0n; + for (let shift = 0n; ; shift += 7n) { + const byte = bytes[pos++]; + result |= BigInt(byte & 0x7f) << shift; + if (!(byte & 0x80)) return result; + } + }; + while (pos < bytes.length) { + const tag = Number(varint()); + const number = tag >> 3; + switch (tag & 7) { + case 0: + yield [number, varint()]; + break; + case 1: + yield [number, bytes.subarray(pos, pos + 8)]; + pos += 8; + break; + case 2: { + const length = Number(varint()); + yield [number, bytes.subarray(pos, pos + length)]; + pos += length; + break; + } + case 5: + yield [number, view.getUint32(pos, true)]; + pos += 4; + break; + default: + throw new Error(`unexpected wire type ${tag & 7}`); + } + } +} + +const text = (bytes) => new TextDecoder().decode(bytes); +const hex = (bytes) => + Array.from(bytes, (byte) => byte.toString(16).padStart(2, '0')).join(''); +const fixed64 = (bytes) => + new DataView(bytes.buffer, bytes.byteOffset, 8).getBigUint64(0, true); + +// opentelemetry.proto.common.v1.AnyValue +function anyValue(bytes) { + for (const [number, value] of fields(bytes)) { + switch (number) { + case 1: + return text(value); + case 2: + return value !== 0n; + case 3: + return Number(BigInt.asIntN(64, value)); + case 4: + return new DataView(value.buffer, value.byteOffset, 8).getFloat64( + 0, + true + ); + } + } + throw new Error('attribute without a value'); +} + +// A repeated opentelemetry.proto.common.v1.KeyValue field, collected into `attributes`. +function addAttribute(attributes, bytes) { + let key; + let value; + for (const [number, field] of fields(bytes)) { + if (number === 1) key = text(field); + if (number === 2) value = anyValue(field); + } + attributes[key] = value; +} + +// opentelemetry.proto.trace.v1.Span.Event +function decodeEvent(bytes) { + const event = { attributes: {} }; + for (const [number, value] of fields(bytes)) { + if (number === 1) event.timeUnixNano = Number(fixed64(value)); + if (number === 2) event.name = text(value); + if (number === 3) addAttribute(event.attributes, value); + } + return event; +} + +// opentelemetry.proto.trace.v1.Status +function decodeStatus(bytes) { + const status = { code: 0, message: '' }; + for (const [number, value] of fields(bytes)) { + if (number === 2) status.message = text(value); + if (number === 3) status.code = Number(value); + } + return status; +} + +// opentelemetry.proto.trace.v1.Span +function decodeSpan(bytes) { + const span = { attributes: {}, events: [] }; + for (const [number, value] of fields(bytes)) { + switch (number) { + case 1: + span.traceId = hex(value); + break; + case 2: + span.spanId = hex(value); + break; + case 4: + span.parentSpanId = hex(value); + break; + case 5: + span.name = text(value); + break; + case 6: + span.kind = Number(value); + break; + case 7: + span.startTimeUnixNano = Number(fixed64(value)); + break; + case 8: + span.endTimeUnixNano = Number(fixed64(value)); + break; + case 9: + addAttribute(span.attributes, value); + break; + case 11: + span.events.push(decodeEvent(value)); + break; + case 15: + span.status = decodeStatus(value); + break; + case 16: + span.flags = value; + break; + } + } + return span; +} + +// opentelemetry.proto.collector.trace.v1.ExportTraceServiceRequest, which the runtime fills with +// one ResourceSpans holding one ScopeSpans. +function decodeRequest(bytes) { + const request = { resource: {}, spans: [] }; + for (const [, resourceSpans] of fields(bytes)) { + for (const [number, value] of fields(resourceSpans)) { + if (number === 1) { + for (const [, attribute] of fields(value)) { + addAttribute(request.resource, attribute); + } + } + if (number === 2) { + for (const [, span] of fields(value)) { + request.spans.push(decodeSpan(span)); + } + } + } + } + return request; +} + +const requests = []; + +export default { + async fetch(request) { + const url = new URL(request.url); + if (request.method === 'POST' && url.pathname === '/v1/traces') { + requests.push({ + contentType: request.headers.get('content-type'), + ...decodeRequest(new Uint8Array(await request.arrayBuffer())), + }); + return new Response(null, { status: 200 }); + } + if (url.pathname === '/requests') { + return Response.json(requests); + } + return new Response('not found', { status: 404 }); + }, +}; diff --git a/src/workerd/api/tests/otlp-tracing-test.js b/src/workerd/api/tests/otlp-tracing-test.js new file mode 100644 index 00000000000..67c4acc79d8 --- /dev/null +++ b/src/workerd/api/tests/otlp-tracing-test.js @@ -0,0 +1,112 @@ +// Copyright (c) 2026 Cloudflare, Inc. +// Licensed under the Apache 2.0 license found in the LICENSE file or at: +// https://opensource.org/licenses/Apache-2.0 +// +// Tests the config's `tracing.otlp`: the spans of an invocation are POSTed to the designated +// service as an OTLP/HTTP protobuf request. +import * as assert from 'node:assert'; + +const SPAN_KIND_SERVER = 2; +const SPAN_KIND_CLIENT = 3; +const STATUS_CODE_ERROR = 2; + +export default { + async fetch(request, env, ctx) { + const url = new URL(request.url); + if (url.pathname === '/leaf') { + return new Response('leaf'); + } + await ctx.tracing.enterSpan('my-span', async (span) => { + span.setAttribute('answer', 42); + span.setAttribute('ratio', 0.5); + span.setAttribute('cached', false); + await (await env.SELF.fetch('http://traced/leaf?secret=1')).text(); + }); + return new Response('not here', { status: 503 }); + }, +}; + +// The requests the collector has received, once there are at least `count` of them. Spans are +// posted after the response that ends their invocation, so the test has to wait for them. +async function collected(env, count) { + for (;;) { + const response = await env.COLLECTOR.fetch('http://collector/requests'); + const requests = await response.json(); + if (requests.length >= count) return requests; + await scheduler.wait(10); + } +} + +export const test = { + async test(ctrl, env) { + const response = await env.SELF.fetch('http://traced/outer?x=1'); + assert.strictEqual(response.status, 503); + await response.text(); + + // One request per invocation: the nested /leaf invocation finishes first. + const requests = await collected(env, 2); + assert.strictEqual(requests.length, 2); + const [leaf, outer] = requests; + for (const request of requests) { + assert.strictEqual(request.contentType, 'application/x-protobuf'); + assert.deepStrictEqual(request.resource, { + 'service.name': 'traced', + 'telemetry.sdk.name': 'workers-runtime', + 'telemetry.sdk.language': 'js', + }); + } + + assert.deepStrictEqual( + outer.spans.map((span) => span.name), + ['fetch', 'my-span', 'GET'] + ); + const [fetch, mySpan, root] = outer.spans; + + // The root describes the invocation. A 5xx response makes it an error. + assert.strictEqual(root.kind, SPAN_KIND_SERVER); + assert.strictEqual(root.parentSpanId, undefined); + assert.strictEqual(root.attributes['faas.trigger'], 'http'); + assert.strictEqual(root.attributes['http.request.method'], 'GET'); + assert.strictEqual(root.attributes['url.full'], 'http://traced/outer?x=1'); + assert.strictEqual(root.attributes['url.path'], '/outer'); + assert.strictEqual(root.attributes['url.query'], 'x=1'); + assert.strictEqual(root.attributes['server.address'], 'traced'); + assert.strictEqual(root.attributes['http.response.status_code'], 503); + assert.strictEqual(root.attributes['cloudflare.outcome'], 'ok'); + assert.strictEqual( + root.attributes['cloudflare.invocation.sequence.number'], + 1 + ); + assert.deepStrictEqual(root.status, { + code: STATUS_CODE_ERROR, + message: '', + }); + assert.strictEqual(root.attributes['error.type'], '503'); + + // A span the worker opened, with each kind of attribute value. + assert.strictEqual(mySpan.parentSpanId, root.spanId); + assert.strictEqual(mySpan.traceId, root.traceId); + assert.strictEqual(mySpan.attributes.answer, 42); + assert.strictEqual(mySpan.attributes.ratio, 0.5); + assert.strictEqual(mySpan.attributes.cached, false); + assert.strictEqual(mySpan.status, undefined); + + // The subrequest made inside it. + assert.strictEqual(fetch.kind, SPAN_KIND_CLIENT); + assert.strictEqual(fetch.parentSpanId, mySpan.spanId); + assert.strictEqual( + fetch.attributes['url.full'], + 'http://traced/leaf?secret=1' + ); + assert.strictEqual(fetch.attributes['url.query'], 'secret=1'); + + // The invocation the subrequest started continues the trace under the fetch span. + assert.deepStrictEqual( + leaf.spans.map((span) => span.name), + ['GET'] + ); + assert.strictEqual(leaf.spans[0].traceId, root.traceId); + assert.strictEqual(leaf.spans[0].parentSpanId, fetch.spanId); + assert.strictEqual(leaf.spans[0].status, undefined); + }, +}; diff --git a/src/workerd/api/tests/otlp-tracing-test.wd-test b/src/workerd/api/tests/otlp-tracing-test.wd-test new file mode 100644 index 00000000000..6e3596dfbcd --- /dev/null +++ b/src/workerd/api/tests/otlp-tracing-test.wd-test @@ -0,0 +1,28 @@ +using Workerd = import "/workerd/workerd.capnp"; + +const unitTests :Workerd.Config = ( + services = [ + (name = "traced", worker = .tracedWorker), + (name = "collector", worker = .collectorWorker), + ], + tracing = (otlp = "collector"), +); + +const tracedWorker :Workerd.Worker = ( + modules = [ + (name = "worker", esModule = embed "otlp-tracing-test.js") + ], + compatibilityFlags = ["nodejs_compat"], + bindings = [ + (name = "SELF", service = "traced"), + (name = "COLLECTOR", service = "collector"), + ], +); + +# Stands in for an OpenTelemetry collector: it decodes the requests POSTed to /v1/traces and +# hands what it has received to the test. +const collectorWorker :Workerd.Worker = ( + modules = [ + (name = "worker", esModule = embed "otlp-tracing-test-collector.js") + ], +); diff --git a/src/workerd/io/BUILD.bazel b/src/workerd/io/BUILD.bazel index 76cdd58056c..fe73eca3b69 100644 --- a/src/workerd/io/BUILD.bazel +++ b/src/workerd/io/BUILD.bazel @@ -35,6 +35,7 @@ wd_cc_library( srcs = [ "features.c++", "hibernation-manager.c++", + "invocation-span.c++", "io-channels.c++", "io-context.c++", "io-own.c++", @@ -50,6 +51,7 @@ wd_cc_library( hdrs = [ "access-info.h", "hibernation-manager.h", + "invocation-span.h", "io-channels.h", "io-context.h", "io-own.h", @@ -364,6 +366,23 @@ wd_cc_library( ], ) +wd_cc_library( + name = "otlp-span-submitter", + srcs = ["otlp-span-submitter.c++"], + hdrs = ["otlp-span-submitter.h"], + implementation_deps = [ + "//src/workerd/util:thread-scopes", + "//src/workerd/util:uuid", + ], + visibility = ["//visibility:public"], + deps = [ + ":io", + "//src/rust/otlp", + "//src/workerd/util:strong-bool", + "@capnp-cpp//src/kj/compat:kj-http", + ], +) + wd_cc_library( name = "worker-interface", srcs = ["worker-interface.c++"], @@ -545,9 +564,18 @@ kj_test( ], ) +kj_test( + src = "invocation-span-test.c++", + deps = [ + ":io", + "//src/workerd/util:thread-scopes", + ], +) + kj_test( src = "trace-test.c++", deps = [ + ":io", ":trace", "//src/workerd/util:thread-scopes", ], diff --git a/src/workerd/io/invocation-span-test.c++ b/src/workerd/io/invocation-span-test.c++ new file mode 100644 index 00000000000..16ffa76fb60 --- /dev/null +++ b/src/workerd/io/invocation-span-test.c++ @@ -0,0 +1,129 @@ +// Copyright (c) 2026 Cloudflare, Inc. +// Licensed under the Apache 2.0 license found in the LICENSE file or at: +// https://opensource.org/licenses/Apache-2.0 + +#include "invocation-span.h" + +#include + +#include +#include + +namespace workerd { +namespace { + +using namespace tracing; + +// Records the span's name and the tags it closes with. +class RecordingObserver final: public SpanObserver { + public: + kj::Rc newChild() override { + return kj::rc(); + } + void onOpen(kj::ConstString operationName, kj::Date) override { + name = kj::mv(operationName); + } + void onUpdateName(kj::ConstString operationName) override { + name = kj::mv(operationName); + } + void onClose(kj::Date, Span::TagMap&& closedTags, kj::Vector&&) override { + tags = kj::mv(closedTags); + } + kj::Date getTime() override { + return kj::UNIX_EPOCH; + } + + kj::ConstString name; + Span::TagMap tags; +}; + +kj::StringPtr stringTag(const Span::TagMap& tags, kj::ConstString key) { + return KJ_ASSERT_NONNULL(tags.find(key), key).get().asPtr(); +} + +int64_t intTag(const Span::TagMap& tags, kj::ConstString key) { + return KJ_ASSERT_NONNULL(tags.find(key), key).get(); +} + +KJ_TEST("describeInvocationSpan names and tags a fetch invocation") { + setPredictableModeForTest(); + auto observer = kj::rc(); + auto& recorded = *observer; + { + SpanBuilder span(observer.addRef(), "invocation"_kjc); + auto headers = kj::arr(FetchEventInfo::Header(kj::str("accept"), kj::str("text/html")), + FetchEventInfo::Header(kj::str("content-length"), kj::str("12")), + FetchEventInfo::Header(kj::str("cookie"), kj::str("secret")), + FetchEventInfo::Header(kj::str("x-length"), kj::str("-1")), + FetchEventInfo::Header(kj::str("user-agent"), kj::str("test-agent/1.0"))); + describeInvocationSpan(span, + FetchEventInfo(kj::HttpMethod::POST, kj::str("https://example.com/path?q=1"), + kj::str(R"({"asn":13335,"country":"US","city":"Austin","region":"Texas",)" + R"("continent":"NA","timezone":"America/Chicago","colo":"DFW"})"), + kj::mv(headers))); + KJ_EXPECT(kj::StringPtr(recorded.name) == "POST"_kj); + setInvocationResponseStatus(span, 201); + setInvocationOutcome(span, EventOutcome::OK, 1 * kj::MILLISECONDS, 2 * kj::MILLISECONDS); + } + auto& tags = recorded.tags; + KJ_EXPECT(stringTag(tags, "faas.trigger"_kjc) == "http"_kj); + KJ_EXPECT(stringTag(tags, "cloudflare.handler_type"_kjc) == "fetch"_kj); + KJ_EXPECT(stringTag(tags, "http.request.method"_kjc) == "POST"_kj); + KJ_EXPECT(stringTag(tags, "url.full"_kjc) == "https://example.com/path?q=1"_kj); + KJ_EXPECT(stringTag(tags, "http.request.header.accept"_kjc) == "text/html"_kj); + KJ_EXPECT(intTag(tags, "http.request.body.size"_kjc) == 12); + KJ_EXPECT(stringTag(tags, "user_agent.original"_kjc) == "test-agent/1.0"_kj); + KJ_EXPECT(tags.find("http.request.header.cookie"_kjc) == kj::none); + KJ_EXPECT(intTag(tags, "cloudflare.asn"_kjc) == 13335); + KJ_EXPECT(stringTag(tags, "geo.country.code"_kjc) == "US"_kj); + KJ_EXPECT(stringTag(tags, "geo.locality.name"_kjc) == "Austin"_kj); + KJ_EXPECT(stringTag(tags, "geo.locality.region"_kjc) == "Texas"_kj); + KJ_EXPECT(stringTag(tags, "geo.continent.code"_kjc) == "NA"_kj); + KJ_EXPECT(stringTag(tags, "geo.timezone"_kjc) == "America/Chicago"_kj); + KJ_EXPECT(tags.find("cloudflare.verified_bot_category"_kjc) == kj::none); + KJ_EXPECT(intTag(tags, "http.response.status_code"_kjc) == 201); + KJ_EXPECT(stringTag(tags, "cloudflare.outcome"_kjc) == "ok"_kj); + // Durations are zero in predictable mode, like the Outcome event's. + KJ_EXPECT(intTag(tags, "cpu_time_ms"_kjc) == 0); + KJ_EXPECT(intTag(tags, "wall_time_ms"_kjc) == 0); +} + +KJ_TEST("describeInvocationSpan names and tags a jsrpc invocation") { + setPredictableModeForTest(); + auto observer = kj::rc(); + auto& recorded = *observer; + { + SpanBuilder span(observer.addRef(), "invocation"_kjc); + describeInvocationSpan(span, JsRpcEventInfo(kj::str("placeholder"))); + KJ_EXPECT(kj::StringPtr(recorded.name) == "jsrpc"_kj); + setInvocationRpcMethod(span, "myMethod"_kj); + setInvocationOutcome( + span, EventOutcome::EXCEEDED_CPU, 0 * kj::MILLISECONDS, 0 * kj::MILLISECONDS); + } + auto& tags = recorded.tags; + KJ_EXPECT(stringTag(tags, "faas.trigger"_kjc) == "jsrpc"_kj); + KJ_EXPECT(stringTag(tags, "cloudflare.handler_type"_kjc) == "jsrpc"_kj); + KJ_EXPECT(stringTag(tags, "jsrpc.method"_kjc) == "myMethod"_kj); + KJ_EXPECT(stringTag(tags, "cloudflare.rpcMethod"_kjc) == "myMethod"_kj); + KJ_EXPECT(tags.find("http.request.method"_kjc) == kj::none); + KJ_EXPECT(stringTag(tags, "cloudflare.outcome"_kjc) == "exceededCpu"_kj); +} + +KJ_TEST("describeInvocationSpan names and tags a scheduled invocation") { + setPredictableModeForTest(); + auto observer = kj::rc(); + auto& recorded = *observer; + { + SpanBuilder span(observer.addRef(), "invocation"_kjc); + describeInvocationSpan(span, ScheduledEventInfo(1709210096789.0, kj::str("*/5 * * * *"))); + KJ_EXPECT(kj::StringPtr(recorded.name) == "scheduled"_kj); + } + auto& tags = recorded.tags; + KJ_EXPECT(stringTag(tags, "faas.trigger"_kjc) == "timer"_kj); + KJ_EXPECT(stringTag(tags, "faas.cron"_kjc) == "*/5 * * * *"_kj); + // The epoch in predictable mode, spelled as JavaScript's Date.prototype.toISOString() would. + KJ_EXPECT(stringTag(tags, "cloudflare.scheduled_time"_kjc) == "1970-01-01T00:00:00.000Z"_kj); +} + +} // namespace +} // namespace workerd diff --git a/src/workerd/io/invocation-span.c++ b/src/workerd/io/invocation-span.c++ new file mode 100644 index 00000000000..be5626cd8b2 --- /dev/null +++ b/src/workerd/io/invocation-span.c++ @@ -0,0 +1,234 @@ +// Copyright (c) 2026 Cloudflare, Inc. +// Licensed under the Apache 2.0 license found in the LICENSE file or at: +// https://opensource.org/licenses/Apache-2.0 + +#include "invocation-span.h" + +#include + +#include +#include +#include + +#include +#include +#include + +namespace workerd { + +namespace { + +// The handler type as the Onset event spells it (`fetch`, `jsrpc`, `scheduled`, ...). +kj::ConstString handlerType(const tracing::EventInfo& info) { + KJ_SWITCH_ONEOF(info) { + KJ_CASE_ONEOF(fetch, tracing::FetchEventInfo) { + return "fetch"_kjc; + } + KJ_CASE_ONEOF(jsRpc, tracing::JsRpcEventInfo) { + return "jsrpc"_kjc; + } + KJ_CASE_ONEOF(scheduled, tracing::ScheduledEventInfo) { + return "scheduled"_kjc; + } + KJ_CASE_ONEOF(alarm, tracing::AlarmEventInfo) { + return "alarm"_kjc; + } + KJ_CASE_ONEOF(queue, tracing::QueueEventInfo) { + return "queue"_kjc; + } + KJ_CASE_ONEOF(email, tracing::EmailEventInfo) { + return "email"_kjc; + } + KJ_CASE_ONEOF(trace, tracing::TraceEventInfo) { + return "trace"_kjc; + } + KJ_CASE_ONEOF(hws, tracing::HibernatableWebSocketEventInfo) { + return "hibernatableWebSocket"_kjc; + } + KJ_CASE_ONEOF(connect, tracing::ConnectEventInfo) { + return "connect"_kjc; + } + KJ_CASE_ONEOF(custom, tracing::CustomEventInfo) { + return "custom"_kjc; + } + } + KJ_UNREACHABLE; +} + +// `faas.trigger` per handler type. `connect` has no streaming tail worker counterpart and is +// reported as `http` like `fetch`. +kj::ConstString faasTrigger(const tracing::EventInfo& info) { + KJ_SWITCH_ONEOF(info) { + KJ_CASE_ONEOF(fetch, tracing::FetchEventInfo) { + return "http"_kjc; + } + KJ_CASE_ONEOF(connect, tracing::ConnectEventInfo) { + return "http"_kjc; + } + KJ_CASE_ONEOF(jsRpc, tracing::JsRpcEventInfo) { + return "jsrpc"_kjc; + } + KJ_CASE_ONEOF(scheduled, tracing::ScheduledEventInfo) { + return "timer"_kjc; + } + KJ_CASE_ONEOF(alarm, tracing::AlarmEventInfo) { + return "timer"_kjc; + } + KJ_CASE_ONEOF(queue, tracing::QueueEventInfo) { + return "pubsub"_kjc; + } + KJ_CASE_ONEOF(email, tracing::EmailEventInfo) { + return "email"_kjc; + } + KJ_CASE_ONEOF(trace, tracing::TraceEventInfo) { + return "trace"_kjc; + } + KJ_CASE_ONEOF(hws, tracing::HibernatableWebSocketEventInfo) { + return "websocket"_kjc; + } + KJ_CASE_ONEOF(custom, tracing::CustomEventInfo) { + return "other"_kjc; + } + } + KJ_UNREACHABLE; +} + +// The request's `cf` object is opaque to the runtime except for these geolocation and network +// fields, which the streaming tail worker's OTel conversion also lifts onto the root span. +void setCfTags(SpanBuilder& span, kj::StringPtr cfJson) { + constexpr std::pair STRING_FIELDS[] = { + {"verifiedBotCategory"_kj, "cloudflare.verified_bot_category"_kj}, + {"timezone"_kj, "geo.timezone"_kj}, + {"continent"_kj, "geo.continent.code"_kj}, + {"country"_kj, "geo.country.code"_kj}, + {"city"_kj, "geo.locality.name"_kj}, + {"region"_kj, "geo.locality.region"_kj}, + }; + capnp::MallocMessageBuilder message; + auto cf = message.initRoot(); + // A `cf` blob that is not a JSON object yields no tags, like the Onset event's consumer. + if (kj::runCatchingExceptions([&]() { capnp::JsonCodec().decodeRaw(cfJson, cf); }) != kj::none || + !cf.isObject()) { + return; + } + for (auto field: cf.getObject()) { + auto name = field.getName().asString(); + auto value = field.getValue(); + if (name == "asn"_kj && value.isNumber()) { + span.setTag("cloudflare.asn"_kjc, static_cast(value.getNumber())); + continue; + } + for (auto& [cfName, key]: STRING_FIELDS) { + if (name == cfName && value.isString()) { + span.setTag(kj::ConstString(kj::str(key)), kj::str(value.getString())); + } + } + } +} + +void setFetchTags(SpanBuilder& span, const tracing::FetchEventInfo& fetch) { + span.setTag("http.request.method"_kjc, kj::str(fetch.method)); + span.setTag("url.full"_kjc, kj::str(fetch.url)); + // Header names are lower-cased when the event info is built (see buildFetchEventInfo()). Only + // the headers below are recorded; the rest may carry credentials or personal data. + for (auto& header: fetch.headers) { + if (header.name == "user-agent"_kj) { + span.setTag("user_agent.original"_kjc, kj::str(header.value)); + } else if (header.name == "content-length"_kj) { + KJ_IF_SOME(size, header.value.tryParseAs()) { + if (size >= 0) span.setTag("http.request.body.size"_kjc, size); + } + } else if (header.name == "accept"_kj || header.name == "accept-encoding"_kj || + header.name == "accept-language"_kj) { + span.setTag( + kj::ConstString(kj::str("http.request.header.", header.name)), kj::str(header.value)); + } + } + setCfTags(span, fetch.cfJson); +} + +// `date` as the ISO 8601 string `Date.prototype.toISOString()` produces, which is how the +// streaming tail worker reports scheduled times. +kj::String isoDateString(kj::Date date) { + int64_t millis = (date - kj::UNIX_EPOCH) / kj::MILLISECONDS; + time_t seconds = millis / 1000; + struct tm t; + KJ_ASSERT(gmtime_r(&seconds, &t) == &t); + char buffer[32]{}; + size_t size = strftime(buffer, sizeof(buffer), "%Y-%m-%dT%H:%M:%S", &t); + size += snprintf(buffer + size, sizeof(buffer) - size, ".%03dZ", static_cast(millis % 1000)); + return kj::str(kj::arrayPtr(buffer, size)); +} + +// Tags specific to the handler type. Mirrors the Onset event, which reports the epoch as the +// scheduled time in predictable mode. +void setEventTags(SpanBuilder& span, const tracing::EventInfo& info) { + bool predictable = isPredictableModeForTest(); + KJ_SWITCH_ONEOF(info) { + KJ_CASE_ONEOF(fetch, tracing::FetchEventInfo) { + setFetchTags(span, fetch); + } + KJ_CASE_ONEOF(scheduled, tracing::ScheduledEventInfo) { + span.setTag("faas.cron"_kjc, kj::str(scheduled.cron)); + // The scheduled time is JavaScript's milliseconds since the epoch. + span.setTag("cloudflare.scheduled_time"_kjc, + isoDateString(predictable ? kj::UNIX_EPOCH + : kj::UNIX_EPOCH + + static_cast(scheduled.scheduledTime) * kj::MILLISECONDS)); + } + KJ_CASE_ONEOF(alarm, tracing::AlarmEventInfo) { + span.setTag("cloudflare.scheduled_time"_kjc, + isoDateString(predictable ? kj::UNIX_EPOCH : alarm.scheduledTime)); + } + KJ_CASE_ONEOF(queue, tracing::QueueEventInfo) { + span.setTag("cloudflare.queue.name"_kjc, kj::str(queue.queueName)); + span.setTag("cloudflare.queue.batch_size"_kjc, static_cast(queue.batchSize)); + } + KJ_CASE_ONEOF(email, tracing::EmailEventInfo) { + span.setTag("cloudflare.email.from"_kjc, kj::str(email.mailFrom)); + span.setTag("cloudflare.email.to"_kjc, kj::str(email.rcptTo)); + span.setTag("cloudflare.email.size"_kjc, static_cast(email.rawSize)); + } + KJ_CASE_ONEOF(trace, tracing::TraceEventInfo) { + span.setTag("cloudflare.trace.count"_kjc, static_cast(trace.traces.size())); + } + KJ_CASE_ONEOF_DEFAULT {} + } +} + +} // namespace + +void describeInvocationSpan(SpanBuilder& span, const tracing::EventInfo& info) { + if (!span.isObserved()) return; + KJ_IF_SOME(fetch, info.tryGet()) { + span.setOperationName(kj::ConstString(kj::str(fetch.method))); + } else { + span.setOperationName(handlerType(info)); + } + span.setTag("faas.trigger"_kjc, faasTrigger(info)); + span.setTag("cloudflare.handler_type"_kjc, handlerType(info)); + setEventTags(span, info); +} + +void setInvocationResponseStatus(SpanBuilder& span, uint statusCode) { + span.setTag("http.response.status_code"_kjc, static_cast(statusCode)); +} + +void setInvocationRpcMethod(SpanBuilder& span, kj::StringPtr methodName) { + span.setTag("jsrpc.method"_kjc, kj::str(methodName)); + // Also under the key the streaming tail worker's OTel conversion uses for the same value. + span.setTag("cloudflare.rpcMethod"_kjc, kj::str(methodName)); +} + +void setInvocationOutcome( + SpanBuilder& span, EventOutcome outcome, kj::Duration cpuTime, kj::Duration wallTime) { + span.setTag("cloudflare.outcome"_kjc, kj::str(outcome)); + // Mirror the Outcome event, which reports zero durations in predictable mode. + bool predictable = isPredictableModeForTest(); + span.setTag( + "cpu_time_ms"_kjc, static_cast(predictable ? 0 : cpuTime / kj::MILLISECONDS)); + span.setTag( + "wall_time_ms"_kjc, static_cast(predictable ? 0 : wallTime / kj::MILLISECONDS)); +} + +} // namespace workerd diff --git a/src/workerd/io/invocation-span.h b/src/workerd/io/invocation-span.h new file mode 100644 index 00000000000..3a7ba86ee7c --- /dev/null +++ b/src/workerd/io/invocation-span.h @@ -0,0 +1,30 @@ +// Copyright (c) 2026 Cloudflare, Inc. +// Licensed under the Apache 2.0 license found in the LICENSE file or at: +// https://opensource.org/licenses/Apache-2.0 + +#pragma once + +// The user span of one Worker invocation, as an embedder that exports user spans itself records it +// (see BaseTracer::setStartInvocationSpanFunc()). The span is named after the handler type, and its +// attributes follow OTel semantic conventions where one exists and otherwise the names the +// streaming tail worker's OTel conversion uses, so both produce the same attributes. + +#include +#include + +namespace workerd { + +// Names `span` after the event and records the event's attributes on it. +void describeInvocationSpan(SpanBuilder& span, const tracing::EventInfo& info); + +// Records the status of the invocation's HTTP response. +void setInvocationResponseStatus(SpanBuilder& span, uint statusCode); + +// Records the method a JS RPC invocation called. +void setInvocationRpcMethod(SpanBuilder& span, kj::StringPtr methodName); + +// Records how the invocation ended. +void setInvocationOutcome( + SpanBuilder& span, EventOutcome outcome, kj::Duration cpuTime, kj::Duration wallTime); + +} // namespace workerd diff --git a/src/workerd/io/otlp-span-submitter.c++ b/src/workerd/io/otlp-span-submitter.c++ new file mode 100644 index 00000000000..84d74901dde --- /dev/null +++ b/src/workerd/io/otlp-span-submitter.c++ @@ -0,0 +1,278 @@ +// Copyright (c) 2026 Cloudflare, Inc. +// Licensed under the Apache 2.0 license found in the LICENSE file or at: +// https://opensource.org/licenses/Apache-2.0 + +#include "otlp-span-submitter.h" + +#include +#include + +#include + +namespace workerd { + +namespace { + +int64_t toUnixNanos(kj::Date date) { + return (date - kj::UNIX_EPOCH) / kj::NANOSECONDS; +} + +// KJ strings need not be UTF-8, so text crosses to Rust as bytes. +::rust::Slice toRust(kj::StringPtr text) { + return text.asBytes().as(); +} + +rust::otlp::StatusCode toRust(tracing::SpanStatusCode code) { + switch (code) { + case tracing::SpanStatusCode::UNSET: + return rust::otlp::StatusCode::Unset; + case tracing::SpanStatusCode::OK: + return rust::otlp::StatusCode::Ok; + case tracing::SpanStatusCode::ERROR: + return rust::otlp::StatusCode::Error; + } + KJ_UNREACHABLE; +} + +void addTag(rust::otlp::Attributes& attributes, const Span::Tag& tag) { + auto key = toRust(tag.key); + KJ_SWITCH_ONEOF(tag.value) { + KJ_CASE_ONEOF(b, bool) { + rust::otlp::add_bool(attributes, key, b); + } + KJ_CASE_ONEOF(i, int64_t) { + rust::otlp::add_int(attributes, key, i); + } + KJ_CASE_ONEOF(d, double) { + rust::otlp::add_double(attributes, key, d); + } + KJ_CASE_ONEOF(s, kj::ConstString) { + rust::otlp::add_string(attributes, key, toRust(s)); + } + } +} + +// `Tags` is a Span::TagMap or an array of Span::Tag. +template +::rust::Box toAttributes(const Tags& tags) { + auto attributes = rust::otlp::new_attributes(); + for (auto& tag: tags) addTag(*attributes, tag); + return attributes; +} + +::rust::Box newSpanBuffer(const tracing::SpanContext& context, + tracing::SpanId rootSpanId, + const OtlpSpanSubmitter::Options& options) { + auto resource = rust::otlp::new_attributes(); + rust::otlp::add_string(*resource, toRust("service.name"_kj), toRust(options.serviceName)); + for (auto& tag: options.resource) addTag(*resource, tag); + + auto traceId = context.getTraceId().toProtobuf(); + uint32_t traceFlags = 0; + KJ_IF_SOME(flags, context.getTraceFlags()) { + traceFlags = uint8_t(flags); + } + return rust::otlp::new_span_buffer(traceId.as(), + { + .trace_flags = traceFlags, + .root_span_id = rootSpanId.getId(), + .redact_query_string = bool(options.redactQueryString), + // As for Jaeger spans, so tests can compare whole spans. + .omit_timestamps = isPredictableModeForTest(), + }, + kj::mv(resource), toAttributes(options.defaultTags)); +} + +Span::TagValue text(kj::StringPtr value) { + return kj::ConstString(kj::str(value)); +} + +} // namespace + +kj::Array makeOtlpResource(const OtlpServiceInfo& service) { + using Tag = Span::Tag; + + kj::Vector tags; + tags.add(Tag{"telemetry.sdk.name"_kjc, text("workers-runtime")}); + tags.add(Tag{"telemetry.sdk.language"_kjc, text("js")}); + KJ_IF_SOME(name, service.scriptName) { + tags.add(Tag{"faas.name"_kjc, text(name)}); + tags.add(Tag{"cloudflare.script_name"_kjc, text(name)}); + } + KJ_IF_SOME(version, service.scriptVersion) { + auto id = version.getId(); + KJ_IF_SOME(uuid, UUID::fromUpperLower(id.getUpper(), id.getLower())) { + tags.add(Tag{"faas.version"_kjc, text(uuid.toString())}); + tags.add(Tag{"cloudflare.script_version.id"_kjc, text(uuid.toString())}); + } + if (version.hasTag()) { + tags.add(Tag{"cloudflare.script_version.tag"_kjc, text(version.getTag())}); + } + if (version.hasMessage()) { + tags.add(Tag{"cloudflare.script_version.message"_kjc, text(version.getMessage())}); + } + } + KJ_IF_SOME(ns, service.dispatchNamespace) { + tags.add(Tag{"cloudflare.dispatch_namespace"_kjc, text(ns)}); + } + KJ_IF_SOME(entrypoint, service.entrypoint) { + tags.add(Tag{"cloudflare.entrypoint"_kjc, text(entrypoint)}); + } + KJ_IF_SOME(colo, service.colo) { + tags.add(Tag{"cloudflare.colo"_kjc, text(colo)}); + } + KJ_IF_SOME(region, service.region) { + tags.add(Tag{"faas.invoked_region"_kjc, text(region)}); + } + KJ_IF_SOME(preview, service.preview) { + tags.add(Tag{"cloudflare.preview.id"_kjc, text(preview.id)}); + tags.add(Tag{"cloudflare.preview.slug"_kjc, text(preview.slug)}); + tags.add(Tag{"cloudflare.preview.name"_kjc, text(preview.name)}); + } + if (service.scriptTags.size() > 0) { + // Span::TagValue has no array form, so the tags travel as one comma-separated string. + tags.add(Tag{"cloudflare.script_tags"_kjc, text(kj::strArray(service.scriptTags, ","))}); + } + constexpr auto ENVIRONMENT_TAG = "cf:environment="_kj; + for (auto& tag: service.scriptTags) { + if (tag.startsWith(ENVIRONMENT_TAG)) { + tags.add(Tag{"deployment.environment.name"_kjc, text(tag.slice(ENVIRONMENT_TAG.size()))}); + } + } + return tags.releaseAsArray(); +} + +kj::Array makeOtlpIdentityTags(const OtlpServiceInfo& service) { + kj::Vector tags(2); + KJ_IF_SOME(entrypoint, service.entrypoint) { + tags.add(Span::Tag{"cloudflare.entrypoint"_kjc, text(entrypoint)}); + } + KJ_IF_SOME(id, service.durableObjectId) { + tags.add(Span::Tag{"cloudflare.durable_object.id"_kjc, text(id)}); + } + return tags.releaseAsArray(); +} + +SpanBuilder startExportedUserSpan(kj::EntropySource& entropySource, + kj::Own exporter, + const tracing::SpanContext& context, + const OtlpSpanSubmitter::Options& options, + kj::ConstString operationName, + tracing::SpanId spanId) { + auto submitter = + kj::refcounted(entropySource, kj::mv(exporter), context, options, spanId); + // The submitter records this span itself, so its observer carries its span id and its parent's. + auto rootSpanId = submitter->getRootSpanId(); + return SpanBuilder( + kj::rc(kj::mv(submitter), context.getTraceId(), context.getTraceFlags(), + rootSpanId, context.getSpanId().orDefault(tracing::SpanId::nullId)), + kj::mv(operationName)); +} + +kj::Promise postOtlpTraces(kj::HttpClient& client, + kj::StringPtr url, + kj::HttpHeaders headers, + kj::Array body) { + headers.setPtr(kj::HttpHeaderId::CONTENT_TYPE, "application/x-protobuf"); + auto request = client.request(kj::HttpMethod::POST, url, headers, body.size()); + co_await request.body->write(body); + request.body = nullptr; + auto response = co_await request.response; + KJ_REQUIRE(response.statusCode / 100 == 2, "OTLP collector rejected spans", response.statusCode, + response.statusText); + // Drain the body so the connection can be reused. + co_await response.body->readAllBytes(); +} + +OtlpSpanSubmitter::OtlpSpanSubmitter(kj::EntropySource& entropySource, + kj::Own exporter, + const tracing::SpanContext& context, + Options options, + tracing::SpanId rootSpan) + : entropySource(entropySource), + predictableSpanId((uint64_t(options.predictableSpanSpace) << 56) + 1), + exporter(kj::mv(exporter)), + rootSpanId(rootSpan == tracing::SpanId::nullId ? makeSpanId() : rootSpan), + buffer(newSpanBuffer(context, rootSpanId, options)) {} + +OtlpSpanSubmitter::~OtlpSpanSubmitter() noexcept(false) { + exportBatch(rust::otlp::finish(*buffer, toUnixNanos(kj::systemPreciseCalendarClock().now()))); +} + +bool OtlpSpanSubmitter::submitSpanOpen(tracing::SpanId spanId, + tracing::SpanId parentSpanId, + kj::ConstString operationName, + kj::Date startTime) { + // The root is named after the handler, not after a runtime span (see describeInvocationSpan()). + if (spanId != rootSpanId && !exporter->exportsRuntimeSpan(operationName)) { + return false; + } + return open(spanId, parentSpanId, operationName, startTime); +} + +bool OtlpSpanSubmitter::submitUserSpanOpen(tracing::SpanId spanId, + tracing::SpanId parentSpanId, + kj::ConstString operationName, + kj::Date startTime) { + if (!exporter->exportsUserSpan(operationName)) { + return false; + } + return open(spanId, parentSpanId, operationName, startTime); +} + +bool OtlpSpanSubmitter::open(tracing::SpanId spanId, + tracing::SpanId parentSpanId, + kj::StringPtr operationName, + kj::Date startTime) { + if (rust::otlp::open_span(*buffer, spanId.getId(), parentSpanId.getId(), toRust(operationName), + toUnixNanos(startTime))) { + return true; + } + exporter->spansDropped(1); + return false; +} + +void OtlpSpanSubmitter::submitSpanClose( + tracing::SpanId spanId, kj::Date startTime, kj::Date endTime, Span::TagMap&& tags) { + exportBatch( + rust::otlp::close_span(*buffer, spanId.getId(), toUnixNanos(endTime), toAttributes(tags))); +} + +void OtlpSpanSubmitter::submitSpanUpdate(tracing::SpanId spanId, tracing::SpanUpdate&& update) { + KJ_SWITCH_ONEOF(update.info) { + KJ_CASE_ONEOF(operationName, kj::ConstString) { + rust::otlp::set_span_name(*buffer, spanId.getId(), toRust(operationName)); + } + KJ_CASE_ONEOF(status, tracing::SpanStatus) { + kj::StringPtr message; + KJ_IF_SOME(m, status.getMessage()) message = m; + rust::otlp::set_span_status( + *buffer, spanId.getId(), toRust(status.getCode()), toRust(message)); + } + } +} + +void OtlpSpanSubmitter::submitSpanException(tracing::SpanId spanId, + kj::Date timestamp, + kj::Maybe code, + kj::String name, + kj::String message, + kj::Maybe stack) { + rust::otlp::add_span_exception(*buffer, spanId.getId(), toUnixNanos(timestamp), toRust(name), + toRust(message), stack.map([](kj::String& s) { return toRust(s); })); +} + +tracing::SpanId OtlpSpanSubmitter::makeSpanId() { + if (isPredictableModeForTest()) { + return tracing::SpanId(predictableSpanId++); + } + return tracing::SpanId::fromEntropy(entropySource); +} + +void OtlpSpanSubmitter::exportBatch(rust::otlp::Batch batch) { + if (batch.span_count == 0) return; + auto request = kj::from(batch.request).attach(kj::mv(batch.request)); + exporter->exportSpans(kj::mv(request), batch.span_count); +} + +} // namespace workerd diff --git a/src/workerd/io/otlp-span-submitter.h b/src/workerd/io/otlp-span-submitter.h new file mode 100644 index 00000000000..46d902085e9 --- /dev/null +++ b/src/workerd/io/otlp-span-submitter.h @@ -0,0 +1,162 @@ +// Copyright (c) 2026 Cloudflare, Inc. +// Licensed under the Apache 2.0 license found in the LICENSE file or at: +// https://opensource.org/licenses/Apache-2.0 + +#pragma once + +// Export of user spans to an OTLP/HTTP collector, independent of any worker tracer. +// startExportedUserSpan() opens the span whose descendants are exported together, typically an +// invocation's (see BaseTracer::setStartInvocationSpanFunc()). OtlpSpanSubmitter is the SpanSubmitter that +// turns those spans into encoded ExportTraceServiceRequests; how spans map onto OTLP and how they +// are batched is decided in Rust (src/rust/otlp). An OtlpSpanExporter says where the requests go, +// and postOtlpTraces() is the POST an exporter makes. + +#include +#include +#include +#include + +#include + +namespace workerd { + +// Whether the query is cut from `url.full` and `url.query` left out. +WD_STRONG_BOOL(RedactQueryString); + +// Where an OtlpSpanSubmitter's spans go, and which spans it takes. Refcounted because the +// submitters of one invocation share it and may outlive the tracer. +class OtlpSpanExporter: public kj::Refcounted { + public: + // `request` is an encoded ExportTraceServiceRequest holding `spanCount` spans. Failures are the + // exporter's to handle: this is called while spans close, including from the submitter's + // destructor. + virtual void exportSpans(kj::Array request, uint spanCount) = 0; + + // Spans the submitter refused because too many were open, or the id was already open. + virtual void spansDropped(uint count) {} + + // Whether a span opened by the runtime, or by user code, is exported under this name. Neither + // is asked about the invocation's root span, which is always exported. + virtual bool exportsRuntimeSpan(const kj::ConstString& operationName) { + return true; + } + virtual bool exportsUserSpan(const kj::ConstString& operationName) { + return true; + } +}; + +// POSTs one request to `url`, a collector's `/v1/traces`, as `application/x-protobuf` along with +// `headers`. Throws unless the collector answers 2xx. `client` and `url` must outlive the promise. +kj::Promise postOtlpTraces(kj::HttpClient& client, + kj::StringPtr url, + kj::HttpHeaders headers, + kj::Array request); + +// What exported spans belong to: `service.name`, followed in the OTLP resource by the rest under +// the names the streaming tail worker's OTel conversion gives them. The entrypoint and Durable +// Object id are also set on every span. +struct OtlpServiceInfo { + kj::StringPtr serviceName; + kj::Maybe scriptName; + kj::Maybe scriptVersion; + kj::Maybe dispatchNamespace; + kj::ArrayPtr scriptTags = nullptr; + kj::Maybe entrypoint; + kj::Maybe durableObjectId; + kj::Maybe preview; + kj::Maybe colo; + kj::Maybe region; +}; + +// The OTLP resource attributes that follow `service.name`, and the tags set on every span. +kj::Array makeOtlpResource(const OtlpServiceInfo& service); +kj::Array makeOtlpIdentityTags(const OtlpServiceInfo& service); + +// The user tracing submitter that exports one span tree through an OtlpSpanExporter. It serves +// the whole tree, because UserSpanObserver::newChild() shares the submitter. A span is held from +// its open to its close; closed spans are batched and exported when the root span closes or the +// batch grows large. Spans that close after the root (waitUntil, Durable Object handoff) are +// exported as they close, because the submitter's destruction, which exports whatever is left, +// may wait for a garbage collection. It holds no tracer or request state, so stale SpanParents +// held in async context storage are safe. +// +// At close each span gets URL attributes derived from `url.full`, the default tags, and +// `cloudflare.invocation.sequence.number`, counted in open order so the root is 1. `fetch` spans +// to a binding's internal host are not exported. Spans still open when the submitter is destroyed +// are closed then and flagged with `cloudflare.warning.type` of `span_not_ended`. +class OtlpSpanSubmitter final: public SpanSubmitter { + public: + struct Options { + // The OTLP resource: `service.name` followed by `resource`. + kj::StringPtr serviceName; + kj::ArrayPtr resource = nullptr; + // Applied to every span at close without overriding the span's own tags. + kj::ArrayPtr defaultTags = nullptr; + RedactQueryString redactQueryString = RedactQueryString::NO; + // In predictable mode span ids count up from 1 with this as their top byte, so that tests can + // tell apart the spans of submitters that share a trace. + uint8_t predictableSpanSpace = 0; + }; + + // `context`'s trace id and flags are shared by every span. The root span is `rootSpanId`, or + // takes the first span id if that is null; see getRootSpanId(). `options` is only read during + // construction. + OtlpSpanSubmitter(kj::EntropySource& entropySource, + kj::Own exporter, + const tracing::SpanContext& context, + Options options, + tracing::SpanId rootSpanId = tracing::SpanId::nullId); + ~OtlpSpanSubmitter() noexcept(false); + KJ_DISALLOW_COPY_AND_MOVE(OtlpSpanSubmitter); + + bool submitSpanOpen(tracing::SpanId spanId, + tracing::SpanId parentSpanId, + kj::ConstString operationName, + kj::Date startTime) override; + bool submitUserSpanOpen(tracing::SpanId spanId, + tracing::SpanId parentSpanId, + kj::ConstString operationName, + kj::Date startTime) override; + // `startTime` is unused: the span keeps the one it was opened with. + void submitSpanClose( + tracing::SpanId spanId, kj::Date startTime, kj::Date endTime, Span::TagMap&& tags) override; + void submitSpanUpdate(tracing::SpanId spanId, tracing::SpanUpdate&& update) override; + void submitSpanException(tracing::SpanId spanId, + kj::Date timestamp, + kj::Maybe code, + kj::String name, + kj::String message, + kj::Maybe stack) override; + + tracing::SpanId makeSpanId() override; + tracing::SpanId getRootSpanId() const { + return rootSpanId; + } + + private: + bool open(tracing::SpanId spanId, + tracing::SpanId parentSpanId, + kj::StringPtr operationName, + kj::Date startTime); + void exportBatch(rust::otlp::Batch batch); + + kj::EntropySource& entropySource; + uint64_t predictableSpanId; + kj::Own exporter; + tracing::SpanId rootSpanId; + ::rust::Box buffer; +}; + +// Opens a span named `operationName` whose spans, its own and its descendants', are exported +// through `exporter` by an OtlpSpanSubmitter with `options`. It continues `context`'s trace with +// its sampling decision, under `context`'s span if it has one. `spanId` is the span's own when it +// already has one, as an invocation's does (see BaseTracer::setStartInvocationSpanFunc()). +// `entropySource` must outlive every one of those spans. +SpanBuilder startExportedUserSpan(kj::EntropySource& entropySource, + kj::Own exporter, + const tracing::SpanContext& context, + const OtlpSpanSubmitter::Options& options, + kj::ConstString operationName, + tracing::SpanId spanId = tracing::SpanId::nullId); + +} // namespace workerd diff --git a/src/workerd/io/tracer.c++ b/src/workerd/io/tracer.c++ index a3e6a124991..78379da9166 100644 --- a/src/workerd/io/tracer.c++ +++ b/src/workerd/io/tracer.c++ @@ -2,6 +2,7 @@ // Licensed under the Apache 2.0 license found in the LICENSE file or at: // https://opensource.org/licenses/Apache-2.0 +#include #include #include #include @@ -276,6 +277,7 @@ void WorkerTracer::addSpanClose(tracing::SpanEndData&& span, kj::Maybe } void WorkerTracer::addSpanUpdate(tracing::SpanId spanId, tracing::SpanUpdate&& update) { + updateInvocationSpan(update); if (pipelineLogLevel == PipelineLogLevel::NONE) { return; } @@ -333,6 +335,11 @@ void WorkerTracer::addSpanException(tracing::SpanId spanId, kj::String name, kj::String message, kj::Maybe stack) { + kj::Maybe stackPtr; + KJ_IF_SOME(s, stack) { + stackPtr = s; + } + recordInvocationSpanException(code, name, message, stackPtr); if (pipelineLogLevel == PipelineLogLevel::NONE) { return; } @@ -342,10 +349,6 @@ void WorkerTracer::addSpanException(tracing::SpanId spanId, auto context = tracing::InvocationSpanContext(topLevelContext.getTraceId(), topLevelContext.getInvocationId(), spanId, topLevelContext.getTraceFlags()); - kj::Maybe stackPtr; - KJ_IF_SOME(s, stack) { - stackPtr = s; - } reportExceptionToTailStream(*writer, context, timestamp, kj::mv(code), name, message, stackPtr); } @@ -389,6 +392,7 @@ void WorkerTracer::setEventInfo( // IoContext is available at this time, capture weakRef. KJ_ASSERT(weakIoContext == kj::none, "tracer can only be used for a single event"); weakIoContext = incomingRequest.getContext().getWeakRef(); + startInvocationSpan(incomingRequest, info); auto& context = incomingRequest.getInvocationSpanContext(); setEventInfoInternal(context, context.getParent().map( @@ -478,6 +482,7 @@ void WorkerTracer::setEventInfoInternal(const tracing::InvocationSpanContext& co } void WorkerTracer::setOutcome(EventOutcome outcome, kj::Duration cpuTime, kj::Duration wallTime) { + endInvocationSpan(outcome, cpuTime, wallTime); trace->outcome = outcome; trace->cpuTime = cpuTime; trace->wallTime = wallTime; @@ -584,6 +589,9 @@ void BaseTracer::adjustSpanTime(tracing::SpanEndData& span, kj::Maybe void WorkerTracer::setReturn( kj::Maybe timestamp, kj::Maybe fetchResponseInfo) { + KJ_IF_SOME(info, fetchResponseInfo) { + setInvocationResponseStatus(invocationSpan, info.statusCode); + } // Match the behavior of setEventInfo(). Any resolution of the TODO comments in setEventInfo() // that are related to this check will probably also affect this function. if (pipelineLogLevel == PipelineLogLevel::NONE) { @@ -621,6 +629,7 @@ void WorkerTracer::setWorkerAttribute(kj::ConstString key, Span::TagValue value) void WorkerTracer::addSpanAttribute(const tracing::InvocationSpanContext& context, kj::ConstString key, tracing::Attribute::Value value) { + setInvocationSpanAttribute(key, value); if (pipelineLogLevel == PipelineLogLevel::NONE || maybeTailStreamWriter == kj::none) { return; } @@ -653,8 +662,79 @@ void WorkerTracer::addSpanAttributeInternal(const tracing::InvocationSpanContext tailStreamWriter->report(context, kj::mv(attributes), timestamp, size); } +void BaseTracer::setStartInvocationSpanFunc(StartInvocationSpanFunc func) { + KJ_ASSERT( + startInvocationSpanFunc == kj::none, "setStartInvocationSpanFunc can only be called once"); + startInvocationSpanFunc = kj::mv(func); +} + +void BaseTracer::startInvocationSpan( + IoContext::IncomingRequest& incomingRequest, const tracing::EventInfo& info) { + KJ_IF_SOME(func, startInvocationSpanFunc) { + invocationSpan = func(incomingRequest.getInvocationSpanContext()); + describeInvocationSpan(invocationSpan, info); + } +} + +void BaseTracer::updateInvocationSpan(const tracing::SpanUpdate& update) { + KJ_SWITCH_ONEOF(update.info) { + KJ_CASE_ONEOF(name, kj::ConstString) { + invocationSpan.setOperationName(name.clone()); + } + KJ_CASE_ONEOF(status, tracing::SpanStatus) { + invocationSpan.setStatus(status.clone()); + } + } +} + +void BaseTracer::setInvocationSpanAttribute( + const kj::ConstString& key, const tracing::Attribute::Value& value) { + // As user code's attributes on its own spans are (see api/tracing.c++). + KJ_SWITCH_ONEOF(value) { + KJ_CASE_ONEOF(s, kj::ConstString) { + invocationSpan.setTag(key.clone(), s.clone(), IsCustomTag::YES); + } + KJ_CASE_ONEOF(b, bool) { + invocationSpan.setTag(key.clone(), b, IsCustomTag::YES); + } + KJ_CASE_ONEOF(d, double) { + invocationSpan.setTag(key.clone(), d, IsCustomTag::YES); + } + KJ_CASE_ONEOF(i, int64_t) { + invocationSpan.setTag(key.clone(), i, IsCustomTag::YES); + } + } +} + +void BaseTracer::recordInvocationSpanException(const kj::Maybe& code, + kj::StringPtr name, + kj::StringPtr message, + kj::Maybe stack) { + if (!invocationSpan.isObserved()) return; + kj::Maybe codeCopy; + KJ_IF_SOME(c, code) { + KJ_SWITCH_ONEOF(c) { + KJ_CASE_ONEOF(s, kj::String) { + codeCopy = tracing::Exception::Code(kj::str(s)); + } + KJ_CASE_ONEOF(d, double) { + codeCopy = tracing::Exception::Code(d); + } + } + } + invocationSpan.recordException(kj::mv(codeCopy), kj::str(name), kj::str(message), + stack.map([](kj::StringPtr s) { return kj::str(s); })); +} + +void BaseTracer::endInvocationSpan( + EventOutcome outcome, kj::Duration cpuTime, kj::Duration wallTime) { + setInvocationOutcome(invocationSpan, outcome, cpuTime, wallTime); + invocationSpan.end(); +} + SpanParent BaseTracer::makeUserRequestSpan( tracing::TraceId traceId, kj::Maybe traceFlags) { + if (invocationSpan.isObserved()) return SpanParent(invocationSpan); KJ_IF_SOME(func, makeUserRequestSpanFunc) { return func(kj::mv(traceId), traceFlags); } else { @@ -665,6 +745,7 @@ SpanParent BaseTracer::makeUserRequestSpan( void WorkerTracer::setJsRpcInfo(const tracing::InvocationSpanContext& context, kj::Date timestamp, const kj::ConstString& methodName) { + setInvocationRpcMethod(invocationSpan, methodName); if (pipelineLogLevel == PipelineLogLevel::NONE) { return; } @@ -747,9 +828,9 @@ void UserSpanObserver::onException(kj::Date timestamp, } } -// Provide I/O time to the tracing system for user spans. +// User spans are timestamped with precise time, not the IoContext's coarsened I/O time. kj::Date UserSpanObserver::getTime() { - return IoContext::current().now(); + return kj::systemPreciseCalendarClock().now(); } tracing::SpanId UserSpanObserver::getSpanId() { diff --git a/src/workerd/io/tracer.h b/src/workerd/io/tracer.h index c36584e3a49..fe02a61006c 100644 --- a/src/workerd/io/tracer.h +++ b/src/workerd/io/tracer.h @@ -108,6 +108,14 @@ class BaseTracer: public kj::Refcounted { // reference the tracer. This can only be set once. void setMakeUserRequestSpanFunc(MakeUserRequestSpanFunc func); + // Has the tracer record the invocation's own span, opened by `func` when the event is set, and + // makes it the root that makeUserRequestSpan() returns. `func` is given the invocation's span + // context, whose ids the span takes. The tracer names and tags the span from the invocation's + // events (see invocation-span.h), including those the worker reports for its active span, and + // ends it with the outcome. + using StartInvocationSpanFunc = kj::Function; + void setStartInvocationSpanFunc(StartInvocationSpanFunc func); + virtual void setJsRpcInfo(const tracing::InvocationSpanContext& context, kj::Date timestamp, const kj::ConstString& methodName) = 0; @@ -128,6 +136,25 @@ class BaseTracer: public kj::Refcounted { // Function to create the root span for the new tracing format. kj::Maybe makeUserRequestSpanFunc; + // For implementations: record on invocationSpan, when the tracer records it, what the invocation + // reports about itself. startInvocationSpan() opens it from setEventInfo() and names it after + // `info`; the update, attribute and exception are those the worker reports for its active span, + // which at the top level is the invocation's. + void startInvocationSpan( + IoContext::IncomingRequest& incomingRequest, const tracing::EventInfo& info); + void updateInvocationSpan(const tracing::SpanUpdate& update); + void setInvocationSpanAttribute( + const kj::ConstString& key, const tracing::Attribute::Value& value); + void recordInvocationSpanException(const kj::Maybe& code, + kj::StringPtr name, + kj::StringPtr message, + kj::Maybe stack); + void endInvocationSpan(EventOutcome outcome, kj::Duration cpuTime, kj::Duration wallTime); + + // See setStartInvocationSpanFunc(). Null unless the tracer records the invocation's span. + kj::Maybe startInvocationSpanFunc; + SpanBuilder invocationSpan = nullptr; + // Time to be reported for the outcome event time. This will be set before the outcome is // dispatched. kj::Date completeTime = kj::UNIX_EPOCH; @@ -283,13 +310,17 @@ class UserSpanObserver final: public SpanObserver { spanId(tracing::SpanId::nullId), parentSpanId(tracing::SpanId::nullId), traceId(nullptr) {} - // constructor for top-level observer with trace ID and optional trace flags + // constructor for top-level observer with trace ID and optional trace flags. `spanId` is set + // when the top-level span is itself recorded by the submitter, as an exported invocation span is + // (see startExportedUserSpan()); `parentSpanId` is then its caller's span, if any. UserSpanObserver(kj::Own submitter, tracing::TraceId traceId, - kj::Maybe traceFlags = kj::none) + kj::Maybe traceFlags = kj::none, + tracing::SpanId spanId = tracing::SpanId::nullId, + tracing::SpanId parentSpanId = tracing::SpanId::nullId) : submitter(kj::mv(submitter)), - spanId(tracing::SpanId::nullId), - parentSpanId(tracing::SpanId::nullId), + spanId(spanId), + parentSpanId(parentSpanId), traceId(kj::mv(traceId)), traceFlags(traceFlags) {} // constructor for subsequent observers attached to a span. `fromUserCode` is true for diff --git a/src/workerd/server/BUILD.bazel b/src/workerd/server/BUILD.bazel index 5d6341affae..c201b487f17 100644 --- a/src/workerd/server/BUILD.bazel +++ b/src/workerd/server/BUILD.bazel @@ -357,6 +357,7 @@ wd_cc_library( "//src/workerd/api:pyodide", "//src/workerd/io", "//src/workerd/io:bundle-fs", + "//src/workerd/io:otlp-span-submitter", "//src/workerd/io:worker-entrypoint", "//src/workerd/jsg", "//src/workerd/util:perfetto", diff --git a/src/workerd/server/server.c++ b/src/workerd/server/server.c++ index dca4ba47aef..9c29896eb9a 100644 --- a/src/workerd/server/server.c++ +++ b/src/workerd/server/server.c++ @@ -23,9 +23,11 @@ #include #include #include +#include #include #include #include +#include #include #include #include @@ -350,6 +352,54 @@ class Server::ActorClass: public IoChannelFactory::ActorClassChannel { } }; +// Posts the spans of every traced worker to the service the config's `tracing.otlp` designates. +// Submitters share it and may be destroyed later than the services, so it runs the POSTs in its +// own task set rather than a service's. +class Server::OtlpExporter final: public OtlpSpanExporter, private kj::TaskSet::ErrorHandler { + public: + OtlpExporter(kj::Own collector, const kj::HttpHeaderTable& headerTable) + : collector(kj::mv(collector)), + headerTable(headerTable) {} + + // The collector's own invocations are not traced: their spans would be exported to itself. + bool isCollector(Service& service) { + KJ_IF_SOME(c, collector) return c->service() == &service; + return false; + } + + // Drops the reference to the collector, like Service::unlink(). Later exports are discarded. + void unlink() { + tasks.clear(); + collector = kj::none; + } + + void exportSpans(kj::Array request, uint spanCount) override { + auto& c = KJ_UNWRAP_OR_RETURN(collector); + // evalNow() so that a collector that cannot start a request is reported like a failed POST. + tasks.add( + kj::evalNow([&]() { return post(c->startRequest({}), headerTable, kj::mv(request)); })); + } + + private: + kj::Maybe> collector; + const kj::HttpHeaderTable& headerTable; + kj::TaskSet tasks{*this}; + + static kj::Promise post(kj::Own worker, + const kj::HttpHeaderTable& headerTable, + kj::Array request) { + auto client = kj::newHttpClient(*worker); + // A service takes an absolute URL; an external server sends its path and makes the host the + // Host header. + co_await postOtlpTraces( + *client, "http://localhost/v1/traces"_kj, kj::HttpHeaders(headerTable), kj::mv(request)); + } + + void taskFailed(kj::Exception&& exception) override { + KJ_LOG(ERROR, "error exporting spans to the OTLP collector", exception); + } +}; + Server::~Server() noexcept { // This destructor is explicitly `noexcept` because if one of the `unlink()`s throws then we'd // have a hard time avoiding a segfault later... and we're shutting down the server anyway so @@ -365,6 +415,7 @@ Server::~Server() noexcept { for (auto& service: services) { service.value->unlink(); } + KJ_IF_SOME(exporter, otlpExporter) exporter->unlink(); // Verify that unlinking actually eliminated cycles. Otherwise we have a memory leak -- and // potentially use-after-free if we allow the `Server` to be destroyed while services still @@ -3487,6 +3538,8 @@ class Server::WorkerService final: public Service, kj::Maybe actorStorage; kj::Array> tails; kj::Array> streamingTails; + // Where this worker's spans are exported, if the config's `tracing.otlp` applies to it. + kj::Maybe> otlp; kj::Array> workerLoaders; kj::Maybe workerdDebugPortNetwork; kj::Maybe workerdDebugPortServer; @@ -4028,6 +4081,7 @@ class Server::WorkerService final: public Service, // need to trace the test event, although this is useful to test that span tracing works, so // we are not implementing a (more complex) mechanism to disable tracing for all test() events // here. + kj::Maybe otlpExporter; if (entrypointName.orDefault("") != "test"_kj) { for (auto& service: channels.tails) { addWorkerIfNotRecursiveTracer(bufferedTailWorkers, *service); @@ -4035,13 +4089,15 @@ class Server::WorkerService final: public Service, for (auto& service: channels.streamingTails) { addWorkerIfNotRecursiveTracer(streamingTailWorkers, *service); } + otlpExporter = + channels.otlp.map([](kj::Own& e) -> OtlpExporter& { return *e; }); } kj::Maybe> workerTracer = kj::none; - if (!bufferedTailWorkers.empty() || !streamingTailWorkers.empty()) { + if (!bufferedTailWorkers.empty() || !streamingTailWorkers.empty() || otlpExporter != kj::none) { // Setting up buffered tail workers support, but only if we actually have tail workers - // configured. + // configured, or spans to export. auto executionModel = actor == kj::none ? ExecutionModel::STATELESS : ExecutionModel::DURABLE_OBJECT; kj::Maybe durableObjectId = kj::none; @@ -4092,6 +4148,31 @@ class Server::WorkerService final: public Service, traceFlags)); }); } + + // The invocation's span, under which its user spans are exported, takes the invocation's ids. + KJ_IF_SOME(exporter, otlpExporter) { + OtlpServiceInfo service{ + .serviceName = serviceName.orDefault("workerd"_kj), + .entrypoint = entrypointName, + }; + KJ_ASSERT_NONNULL(workerTracer) + ->setStartInvocationSpanFunc( + [&entropySource = threadContext.getEntropySource(), exporter = kj::addRef(exporter), + serviceName = kj::str(service.serviceName), resource = makeOtlpResource(service), + identityTags = makeOtlpIdentityTags(service)]( + const tracing::InvocationSpanContext& invocation) mutable { + auto parent = invocation.getParent().map( + [](const tracing::InvocationSpanContext& p) { return p.getSpanId(); }); + return startExportedUserSpan(entropySource, kj::addRef(*exporter), + tracing::SpanContext(invocation.getTraceId(), parent, invocation.getTraceFlags()), + OtlpSpanSubmitter::Options{ + .serviceName = serviceName, + .resource = resource, + .defaultTags = identityTags, + }, + "invocation"_kjc, invocation.getSpanId()); + }); + } kj::Own observer = kj::refcounted(mapAddRef(workerTracer), waitUntilTasks); @@ -6310,6 +6391,10 @@ kj::Promise> Server::makeWorkerImpl(kj::StringPtr result.streamingTails = KJ_MAP(tail, def.streamingTails) { return kj::mv(tail).lookup(*this); }; + KJ_IF_SOME(exporter, otlpExporter) { + if (!exporter->isCollector(workerService)) result.otlp = kj::addRef(*exporter); + } + result.workerLoaders = KJ_MAP(il, def.workerLoaderChannels) { KJ_IF_SOME(id, il.id) { return workerLoaderNamespaces @@ -6774,6 +6859,17 @@ class Server::HttpListener final: public kj::Refcounted { kj::Maybe capnpServer; + // The span the runtime opens for a request as it starts handling it, when spans are exported + // (see TracingOptions.otlp). It starts the trace: the listener has no trace context to continue. + SpanBuilder startRuntimeSpan() { + auto& exporter = *KJ_UNWRAP_OR(owner.otlpExporter, return nullptr); + if (exporter.isCollector(*service)) return nullptr; + return startExportedUserSpan(owner.entropySource, kj::addRef(exporter), + tracing::SpanContext(tracing::TraceId::fromEntropy(owner.entropySource), kj::none, + tracing::TraceFlags(0x01)), + OtlpSpanSubmitter::Options{.serviceName = "workers-runtime"_kj}, "http_request"_kjc); + } + kj::Promise acceptCapnpConnection(kj::AsyncIoStream& conn) { KJ_IF_SOME(s, capnpServer) { return s.accept(conn); @@ -6842,6 +6938,8 @@ class Server::HttpListener final: public kj::Refcounted { TRACE_EVENT("workerd", "Connection:request()"); IoChannelFactory::SubrequestMetadata metadata; metadata.cfBlobJson = mapCopyString(cfBlobJson); + auto runtimeSpan = parent.startRuntimeSpan(); + metadata.userSpanParent = runtimeSpan; Response* wrappedResponse = &response; kj::Own ownResponse; @@ -6878,6 +6976,8 @@ class Server::HttpListener final: public kj::Refcounted { IoChannelFactory::SubrequestMetadata metadata; metadata.cfBlobJson = mapCopyString(cfBlobJson); + auto runtimeSpan = parent.startRuntimeSpan(); + metadata.userSpanParent = runtimeSpan; auto worker = parent.service->startRequest(kj::mv(metadata)); co_return co_await worker->connect(host, headers, connection, response, kj::mv(settings)); @@ -7819,6 +7919,12 @@ kj::Promise Server::startServices(jsg::V8System& v8System, } } + if (config.getTracing().hasOtlp()) { + otlpExporter = kj::refcounted( + lookupService(config.getTracing().getOtlp(), kj::str("tracing.otlp")), + globalContext->headerTable); + } + // Third pass: Cross-link services. for (auto& service: services) { ConfigErrorReporter errorReporter(*this, service.key); diff --git a/src/workerd/server/server.h b/src/workerd/server/server.h index ed3bf13e526..22b977c32fb 100644 --- a/src/workerd/server/server.h +++ b/src/workerd/server/server.h @@ -213,6 +213,10 @@ class Server final: private kj::TaskSet::ErrorHandler, private ChannelTokenHandl kj::HashMap> services; + class OtlpExporter; + // Set when the config's `tracing.otlp` names a collector. + kj::Maybe> otlpExporter; + class ActorNamespace; kj::HashMap actorNamespacesByUniqueKey; diff --git a/src/workerd/server/workerd.capnp b/src/workerd/server/workerd.capnp index 3a1f0b10007..d7a9a45221a 100644 --- a/src/workerd/server/workerd.capnp +++ b/src/workerd/server/workerd.capnp @@ -94,6 +94,30 @@ struct Config { logging @6 : LoggingOptions; # Console and Stdio logging configuration options. + + tracing @7 :TracingOptions; + # Where the spans of Worker invocations are exported. +} + +struct TracingOptions { + otlp @0 :ServiceDesignator; + # Export spans to an OpenTelemetry collector. Every Worker invocation produces a trace: a span + # for the invocation itself, one for each subrequest and binding operation it performs, and any + # the Worker opens with `ctx.tracing.enterSpan()`. They are POSTed to `/v1/traces` on this + # service in the OTLP/HTTP protobuf encoding, so the service is typically an `ExternalServer` + # pointing at a collector's OTLP/HTTP port. For example, to see traces in a local Jaeger: + # + # services = [ + # ..., + # (name = "jaeger", external = (address = "localhost:4318", http = ())), + # ], + # tracing = (otlp = "jaeger"), + # + # Use `HttpOptions.injectRequestHeaders` to send credentials along. The `service.name` resource + # attribute is the name of the Worker's service. A request arriving on a socket starts its trace + # with an `http_request` span of the `workers-runtime` service, under which the invocation's span + # sits. Invocations of the designated service itself are not traced. While this is set, spans are + # not delivered to streaming tail workers. } struct LoggingOptions { From 5c69cc073533fa210fc518811c114d33669b645d Mon Sep 17 00:00:00 2001 From: Dan Lapid Date: Sun, 11 Oct 2026 03:31:20 +0000 Subject: [PATCH 2/4] Note when the internal binding fetch filter can go The filter is a stopgap copied from the Workers Observability tail worker. Record why it is unsatisfying and that it can be removed once every binding talks to its backend over JSRPC. Co-Authored-By: Claude Opus 5.5 --- src/rust/otlp/rules.rs | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/src/rust/otlp/rules.rs b/src/rust/otlp/rules.rs index f1cb8e39d18..c4a5766c336 100644 --- a/src/rust/otlp/rules.rs +++ b/src/rust/otlp/rules.rs @@ -83,6 +83,16 @@ pub fn add_url_attributes(attributes: &mut Attributes, redact_query_string: bool /// Whether a `fetch` span targets the placeholder host of a binding that is implemented with an /// internal fetch (AI, D1, Workflows, Images, Vectorize). Those are an implementation detail of /// the binding and are not reported. Reads `server.address`, so `add_url_attributes` goes first. +/// +/// Ported as is from the Workers Observability tail worker's `CloudflareSpanProcessor`. Matching +/// by host also drops a user's own fetch to one of these hosts, and the dropped span's id has +/// already gone out as the subrequest's parent, so spans the binding's backend exports are +/// orphaned. +/// +/// TODO(cleanup): Remove once every binding talks to its backend over JSRPC. Workflows already +/// do, so `workflow-binding.local` no longer occurs in workerd. Images and AI do for some methods. +/// `fake.host` comes from Browser Rendering's `@cloudflare/puppeteer`, which ships in the user's +/// bundle rather than in workerd. pub fn is_internal_binding_fetch(name: &str, attributes: &Attributes) -> bool { const INTERNAL_HOSTS: [&str; 6] = [ "workers-binding.ai", From 058d36abc61e399d0b12402be79f19f578adcd12 Mon Sep 17 00:00:00 2001 From: Dan Lapid Date: Sun, 11 Oct 2026 04:04:46 +0000 Subject: [PATCH 3/4] Keep binding backend spans under the binding's span Some bindings (D1, AI, Images, Vectorize) reach their backend with an internal fetch to a placeholder host. Those fetch spans were dropped when they ended, but by then their id had already been handed to the backend as its parent, so any spans the backend exported were orphaned at the top of the trace. Decide when the fetch starts instead: a fetch to one of these hosts opens no user span, and the binding's own span (such as d1_run) becomes the subrequest's parent. Matching by host is still a stopgap until every binding talks to its backend over JSRPC. Co-Authored-By: Claude Opus 5.5 --- .../test/d1/d1-api-instrumentation-test.js | 475 +----------------- .../images/images-api-instrumentation-test.js | 456 ----------------- src/rust/otlp/buffer.rs | 29 +- src/rust/otlp/rules.rs | 37 -- src/workerd/api/http.c++ | 55 +- src/workerd/api/http.h | 21 +- src/workerd/io/io-context.c++ | 5 + src/workerd/io/io-context.h | 3 + src/workerd/io/trace.h | 22 +- 9 files changed, 96 insertions(+), 1007 deletions(-) diff --git a/src/cloudflare/internal/test/d1/d1-api-instrumentation-test.js b/src/cloudflare/internal/test/d1/d1-api-instrumentation-test.js index 6a7671cf9c1..137971c41db 100644 --- a/src/cloudflare/internal/test/d1/d1-api-instrumentation-test.js +++ b/src/cloudflare/internal/test/d1/d1-api-instrumentation-test.js @@ -20,18 +20,14 @@ export const test = { async test() { await runInstrumentationTest(state, expectedSpans, { testName: 'D1 instrumentation', - mapFn: (span) => { - // varies test-by-test because random duration in d1-mock.js - if (span['http.response.body.size']) { - span['http.response.body.size'] = 0n; - } - return span; - }, }); }, }; -const allExpectedSpans = [ +// A fetch to the D1 binding's internal host opens no span of its own (see +// isInternalBindingFetch() in api/http.c++), so only the D1 operation spans +// appear. +const expectedSpans = [ // testExec: exec() happy path and error handling (regression test for #5218). { name: 'd1_exec', @@ -48,18 +44,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/execute?resultsFormat=NONE', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 20n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_exec', 'db.system.name': 'cloudflare-d1', @@ -71,18 +55,6 @@ const allExpectedSpans = [ : 'Error in line 1', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/execute?resultsFormat=NONE', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 23n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_run', 'db.system.name': 'cloudflare-d1', @@ -106,18 +78,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/execute?resultsFormat=NONE', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 231n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_all', 'db.system.name': 'cloudflare-d1', @@ -133,18 +93,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 42n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_run', 'db.system.name': 'cloudflare-d1', @@ -160,18 +108,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/execute?resultsFormat=NONE', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 42n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_run', 'db.system.name': 'cloudflare-d1', @@ -187,18 +123,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/execute?resultsFormat=NONE', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 40n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_all', 'db.system.name': 'cloudflare-d1', @@ -220,18 +144,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 223n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_run', 'db.system.name': 'cloudflare-d1', @@ -247,18 +159,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/execute?resultsFormat=NONE', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 40n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_run', 'db.system.name': 'cloudflare-d1', @@ -280,18 +180,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/execute?resultsFormat=NONE', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 223n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_all', 'db.system.name': 'cloudflare-d1', @@ -307,18 +195,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 31n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_all', 'db.system.name': 'cloudflare-d1', @@ -334,18 +210,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 31n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_first', 'db.system.name': 'cloudflare-d1', @@ -361,18 +225,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 31n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_first', 'db.system.name': 'cloudflare-d1', @@ -388,18 +240,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 31n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_all', 'db.system.name': 'cloudflare-d1', @@ -415,18 +255,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 42n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_all', 'db.system.name': 'cloudflare-d1', @@ -442,18 +270,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 42n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_first', 'db.system.name': 'cloudflare-d1', @@ -469,18 +285,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 42n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_first', 'db.system.name': 'cloudflare-d1', @@ -496,18 +300,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 42n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_all', 'db.system.name': 'cloudflare-d1', @@ -523,18 +315,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 61n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_all', 'db.system.name': 'cloudflare-d1', @@ -550,18 +330,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 61n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_first', 'db.system.name': 'cloudflare-d1', @@ -577,18 +345,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 61n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_first', 'db.system.name': 'cloudflare-d1', @@ -604,18 +360,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 61n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_all', 'db.system.name': 'cloudflare-d1', @@ -631,18 +375,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 61n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_all', 'db.system.name': 'cloudflare-d1', @@ -658,18 +390,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 61n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_first', 'db.system.name': 'cloudflare-d1', @@ -685,18 +405,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 61n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_first', 'db.system.name': 'cloudflare-d1', @@ -712,18 +420,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 61n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_batch', 'db.system.name': 'cloudflare-d1', @@ -742,18 +438,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 125n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_first', 'db.system.name': 'cloudflare-d1', @@ -769,18 +453,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 79n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_first', 'db.system.name': 'cloudflare-d1', @@ -796,18 +468,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 79n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_first', 'db.system.name': 'cloudflare-d1', @@ -823,18 +483,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 79n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_first', 'db.system.name': 'cloudflare-d1', @@ -850,18 +498,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 79n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_first', 'db.system.name': 'cloudflare-d1', @@ -877,18 +513,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 79n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_batch', 'db.system.name': 'cloudflare-d1', @@ -909,18 +533,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 298n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_all', 'db.system.name': 'cloudflare-d1', @@ -936,18 +548,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 45n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_all', 'db.system.name': 'cloudflare-d1', @@ -963,18 +563,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 45n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_all', 'db.system.name': 'cloudflare-d1', @@ -990,18 +578,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 45n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_all', 'db.system.name': 'cloudflare-d1', @@ -1017,18 +593,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 45n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_all', 'db.system.name': 'cloudflare-d1', @@ -1044,18 +608,6 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 76n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, { name: 'd1_batch', 'db.system.name': 'cloudflare-d1', @@ -1072,23 +624,4 @@ const allExpectedSpans = [ 'cloudflare.d1.response.served_by_colo': 'DFW', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'http://d1/query?resultsFormat=ROWS_AND_COLUMNS', - 'http.request.header.content-type': 'application/json', - 'http.request.body.size': 117n, - 'http.response.status_code': 200n, - 'http.response.body.size': 0n, - closed: true, - }, ]; - -const expectedSpans = d1BindingJsrpc - ? // The JSRPC binding path does not issue internal HTTP requests to the D1 - // service, so it should not emit the transport-level fetch spans that the - // legacy path produces. The public D1 operation spans are still asserted. - allExpectedSpans.filter((span) => span.name !== 'fetch') - : allExpectedSpans; diff --git a/src/cloudflare/internal/test/images/images-api-instrumentation-test.js b/src/cloudflare/internal/test/images/images-api-instrumentation-test.js index 68c84bdb573..ba74b887e15 100644 --- a/src/cloudflare/internal/test/images/images-api-instrumentation-test.js +++ b/src/cloudflare/internal/test/images/images-api-instrumentation-test.js @@ -16,20 +16,8 @@ export default { export const test = { async test() { - // Use the helper with mapFn to normalize dynamic multipart boundaries await runInstrumentationTest(state, expectedSpans, { testName: 'Images instrumentation', - mapFn: (span) => { - const contentType = span['http.request.header.content-type']; - if (contentType?.startsWith('multipart/form-data; boundary=')) { - return { - ...span, - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - }; - } - return span; - }, }); }, }; @@ -43,18 +31,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 63n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -62,18 +38,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 57n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -82,18 +46,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 88n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -102,18 +54,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 24661n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -122,18 +62,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 24664n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -142,18 +70,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 491605n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -162,18 +78,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 86n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -182,18 +86,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 32855n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -202,18 +94,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 655465n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -221,18 +101,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 58n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -240,18 +108,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 59n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -259,18 +115,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 60n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -278,18 +122,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 63n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -297,18 +129,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 63n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -316,18 +136,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 63n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -338,18 +146,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/png', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 138n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -360,18 +156,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/png', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 255n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -382,18 +166,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/png', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 236n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -404,18 +176,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/png', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 337n, - closed: true, - }, { name: 'images_info', 'cloudflare.binding.type': 'Images', @@ -426,18 +186,6 @@ const expectedSpans = [ 'cloudflare.images.result.height': 123, closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/info', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 63n, - closed: true, - }, { name: 'images_info', 'cloudflare.binding.type': 'Images', @@ -448,18 +196,6 @@ const expectedSpans = [ 'cloudflare.images.result.height': 123, closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/info', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 63n, - closed: true, - }, { name: 'images_info', 'cloudflare.binding.type': 'Images', @@ -468,18 +204,6 @@ const expectedSpans = [ 'error.type': 'ERROR 123: Bad request', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/info', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 409n, - 'http.response.body.size': 22n, - closed: true, - }, { name: 'images_info', 'cloudflare.binding.type': 'Images', @@ -487,18 +211,6 @@ const expectedSpans = [ 'cloudflare.images.result.format': 'image/svg+xml', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/info', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 26n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -506,18 +218,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 72n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -525,18 +225,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 72n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -548,18 +236,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/jpeg', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 409n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -570,18 +246,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 359n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -589,18 +253,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 60n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -608,18 +260,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 60n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -627,18 +267,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 60n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -646,18 +274,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/png', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 141n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -665,18 +281,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/png', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 168n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -685,18 +289,6 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/png', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 194n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -706,18 +298,6 @@ const expectedSpans = [ 'cloudflare.images.options.anim': true, closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 102n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -728,18 +308,6 @@ const expectedSpans = [ 'error.type': 'ERROR 123: Bad request', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 409n, - 'http.response.body.size': 22n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', @@ -748,36 +316,12 @@ const expectedSpans = [ 'cloudflare.images.options.format': 'image/avif', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 88n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', 'cloudflare.images.canvas.type': 'image', closed: true, }, - { - name: 'fetch', - 'network.protocol.name': 'http', - 'network.protocol.version': 'HTTP/1.1', - 'http.request.method': 'POST', - 'url.full': 'https://js.images.cloudflare.com/transform', - 'http.request.header.content-type': - 'multipart/form-data; boundary=', - 'http.response.status_code': 200n, - 'http.response.body.size': 60n, - closed: true, - }, { name: 'images_output', 'cloudflare.binding.type': 'Images', diff --git a/src/rust/otlp/buffer.rs b/src/rust/otlp/buffer.rs index 2df03e07164..9fdd9d81d5a 100644 --- a/src/rust/otlp/buffer.rs +++ b/src/rust/otlp/buffer.rs @@ -164,9 +164,7 @@ impl SpanBuffer { /// Closes a span with the attributes it ended up with. Returns a batch when one is due. pub fn close(&mut self, span_id: u64, end: i64, attributes: Attributes) -> Option { let span = self.open.remove(&span_id)?; - if !self.write(span_id, span, end, attributes) { - return None; - } + self.write(span_id, span, end, attributes); let due = self.root_closed || self.closed.len() >= MAX_BATCH_SPANS || self.closed_bytes >= MAX_BATCH_BYTES; @@ -190,19 +188,10 @@ impl SpanBuffer { self.take_batch() } - /// Adds a closed span to the batch in its OTLP form; false when the span is not reported. - fn write( - &mut self, - span_id: u64, - span: OpenSpan, - end: i64, - mut attributes: Attributes, - ) -> bool { + /// Adds a closed span to the batch in its OTLP form. + fn write(&mut self, span_id: u64, span: OpenSpan, end: i64, mut attributes: Attributes) { let is_root = span_id == self.options.root_span_id; rules::add_url_attributes(&mut attributes, self.options.redact_query_string); - if rules::is_internal_binding_fetch(&span.name, &attributes) { - return false; - } attributes.set_defaults(&self.default_attributes); attributes.set( "cloudflare.invocation.sequence.number", @@ -244,7 +233,6 @@ impl SpanBuffer { if is_root { self.root_closed = true; } - true } fn take_batch(&mut self) -> Option { @@ -541,7 +529,7 @@ mod tests { fn kind_status_and_url_rules_apply_at_close() { let mut buffer = buffer(); assert!(buffer.open(ROOT, 0, "scheduled".to_owned(), T0)); - for (id, name) in [(1, "fetch"), (2, "fetch"), (3, "queue_send"), (6, "fetch")] { + for (id, name) in [(1, "fetch"), (3, "queue_send"), (6, "fetch")] { assert!(buffer.open(id, ROOT, name.to_owned(), T0)); } @@ -557,12 +545,6 @@ mod tests { ("http.response.status_code", Value::Int(404)), ]), ); - // A fetch to a binding's internal host is not reported. - buffer.close( - 2, - T0, - attributes(&[("url.full", string("https://d1/query"))]), - ); buffer.close(3, T0, Attributes::default()); // A 2xx is left unset, and an end before the start is moved to the start. buffer.close( @@ -605,13 +587,12 @@ mod tests { let queue_send = named(&request, "queue_send"); assert_eq!(queue_send.kind(), SpanKind::Producer); - // The span that was not reported took a sequence number at open. assert_eq!( attribute( &queue_send.attributes, "cloudflare.invocation.sequence.number" ), - Some(&Value::Int(4)) + Some(&Value::Int(3)) ); let ipv6 = &spans(&request)[2]; diff --git a/src/rust/otlp/rules.rs b/src/rust/otlp/rules.rs index c4a5766c336..2ac9d3753d2 100644 --- a/src/rust/otlp/rules.rs +++ b/src/rust/otlp/rules.rs @@ -80,34 +80,6 @@ pub fn add_url_attributes(attributes: &mut Attributes, redact_query_string: bool } } -/// Whether a `fetch` span targets the placeholder host of a binding that is implemented with an -/// internal fetch (AI, D1, Workflows, Images, Vectorize). Those are an implementation detail of -/// the binding and are not reported. Reads `server.address`, so `add_url_attributes` goes first. -/// -/// Ported as is from the Workers Observability tail worker's `CloudflareSpanProcessor`. Matching -/// by host also drops a user's own fetch to one of these hosts, and the dropped span's id has -/// already gone out as the subrequest's parent, so spans the binding's backend exports are -/// orphaned. -/// -/// TODO(cleanup): Remove once every binding talks to its backend over JSRPC. Workflows already -/// do, so `workflow-binding.local` no longer occurs in workerd. Images and AI do for some methods. -/// `fake.host` comes from Browser Rendering's `@cloudflare/puppeteer`, which ships in the user's -/// bundle rather than in workerd. -pub fn is_internal_binding_fetch(name: &str, attributes: &Attributes) -> bool { - const INTERNAL_HOSTS: [&str; 6] = [ - "workers-binding.ai", - "d1", - "workflow-binding.local", - "fake.host", - "js.images.cloudflare.com", - "vector-search", - ]; - name == "fetch" - && attributes - .string("server.address") - .is_some_and(|address| INTERNAL_HOSTS.contains(&address)) -} - #[cfg(test)] mod tests { use super::*; @@ -247,13 +219,4 @@ mod tests { add_url_attributes(&mut attributes, false); assert_eq!(attributes.get("url.scheme"), None); } - - #[test] - fn internal_binding_fetches_are_recognised_by_host() { - let to = |address| with(&[("server.address", string(address))]); - assert!(is_internal_binding_fetch("fetch", &to("d1"))); - assert!(!is_internal_binding_fetch("fetch", &to("example.com"))); - assert!(!is_internal_binding_fetch("d1_query", &to("d1"))); - assert!(!is_internal_binding_fetch("fetch", &Attributes::default())); - } } diff --git a/src/workerd/api/http.c++ b/src/workerd/api/http.c++ index c9226efc9a4..06c17305501 100644 --- a/src/workerd/api/http.c++ +++ b/src/workerd/api/http.c++ @@ -1471,6 +1471,31 @@ namespace { // Fetch spec requires (suggests?) 20: https://fetch.spec.whatwg.org/#http-redirect-fetch constexpr auto MAX_REDIRECT_COUNT = 20; +// Whether a fetch goes to the placeholder host of a binding that is implemented with an internal +// fetch (AI, D1, Workflows, Browser Rendering, Images, Vectorize). Such a fetch is an +// implementation detail of the binding: it opens no user span, so the binding's own span (e.g. +// `d1_run`) is the subrequest's user span parent. The hosts are the Workers Observability tail +// worker's, which used to drop these spans when they ended. +// +// TODO(cleanup): Remove once every binding talks to its backend over JSRPC. Workflows already +// do, so `workflow-binding.local` no longer occurs in workerd. Images and AI do for some methods. +// `fake.host` comes from Browser Rendering's `@cloudflare/puppeteer`, which ships in the user's +// bundle rather than in workerd. Matching by host also omits the span of a user's own fetch to +// one of these hosts. +bool isInternalBindingFetch(const kj::Url& url) { + constexpr kj::StringPtr INTERNAL_HOSTS[] = {"workers-binding.ai"_kj, "d1"_kj, + "workflow-binding.local"_kj, "fake.host"_kj, "js.images.cloudflare.com"_kj, + "vector-search"_kj}; + kj::ArrayPtr host = url.host; + KJ_IF_SOME(colon, url.host.findFirst(':')) { + host = host.first(colon); + } + for (auto internalHost: INTERNAL_HOSTS) { + if (host == internalHost.asArray()) return true; + } + return false; +} + struct ActorFetchFailure { kj::Exception exception; }; @@ -1706,8 +1731,8 @@ jsg::Promise> fetchImplNoOutputLockAttempt(jsg::Lock& js, maybeClientWithTracing = fetcher->getClientForActorCallAttempt( ioContext, kj::mv(cfBlobJson), "fetch"_kjc, kj::mv(attempt)); } else { - maybeClientWithTracing = - fetcher->getClientWithTracing(ioContext, kj::mv(cfBlobJson), "fetch"_kjc); + maybeClientWithTracing = fetcher->getClientWithTracing(ioContext, kj::mv(cfBlobJson), + "fetch"_kjc, OmitUserSpan(isInternalBindingFetch(urlList.back()))); } auto clientWithTracing = kj::mv(KJ_ASSERT_NONNULL(maybeClientWithTracing)); auto traceContext = kj::mv(clientWithTracing.traceContext); @@ -2746,8 +2771,9 @@ kj::Own Fetcher::getClient( Fetcher::ClientWithTracing Fetcher::getClientWithTracing(IoContext& ioContext, kj::Maybe cfStr, - kj::ConstString operationName) { - return buildClient(ioContext, kj::mv(cfStr), kj::mv(operationName)); + kj::ConstString operationName, + OmitUserSpan omitUserSpan) { + return buildClient(ioContext, kj::mv(cfStr), kj::mv(operationName), omitUserSpan); } Fetcher::ClientWithTracing Fetcher::getClientForActorCallAttempt(IoContext& ioContext, @@ -2786,13 +2812,15 @@ Fetcher::ClientWithTracing Fetcher::getClientForActorCallAttempt(IoContext& ioCo } Fetcher::ClientWithTracing Fetcher::wrapWithInnerSpan( - OutgoingFactory::Result result, kj::ConstString operationName) { + OutgoingFactory::Result result, kj::ConstString operationName, OmitUserSpan omitUserSpan) { KJ_IF_SOME(parents, result.spanParents) { // Factories populate `spanParents` unconditionally. Only build the inner span when tracing is // actually observed; otherwise returning a (non-recording) TraceContext would still force the // fetch hot path to eagerly evaluate span tags (method, URL, etc.) that end up discarded. if (parents.isObserved()) { - return ClientWithTracing{kj::mv(result.client), parents.newChild(kj::mv(operationName))}; + return ClientWithTracing{kj::mv(result.client), + omitUserSpan ? parents.newChildWithoutUserSpan(kj::mv(operationName)) + : parents.newChild(kj::mv(operationName))}; } } return ClientWithTracing{kj::mv(result.client), kj::none}; @@ -2800,15 +2828,20 @@ Fetcher::ClientWithTracing Fetcher::wrapWithInnerSpan( Fetcher::ClientWithTracing Fetcher::buildClient(IoContext& ioContext, kj::Maybe cfStr, - kj::ConstString operationName) { + kj::ConstString operationName, + OmitUserSpan omitUserSpan) { + auto makeTraceContext = [&]() { + return omitUserSpan ? ioContext.makeTraceSpanWithoutUserSpan(kj::mv(operationName)) + : ioContext.makeUserTraceSpan(kj::mv(operationName)); + }; KJ_SWITCH_ONEOF(channelOrClientFactory) { KJ_CASE_ONEOF(channel, uint) { - auto traceContext = ioContext.makeUserTraceSpan(kj::mv(operationName)); + auto traceContext = makeTraceContext(); auto client = ioContext.getSubrequestChannel(channel, isInHouse, kj::mv(cfStr), traceContext); return ClientWithTracing{kj::mv(client), kj::mv(traceContext)}; } KJ_CASE_ONEOF(channel, IoOwn) { - auto traceContext = ioContext.makeUserTraceSpan(kj::mv(operationName)); + auto traceContext = makeTraceContext(); auto client = ioContext.getSubrequest( [&](TraceContext& tracing, IoChannelFactory& ioChannelFactory) { return channel->startRequest({.cfBlobJson = kj::mv(cfStr), @@ -2827,12 +2860,12 @@ Fetcher::ClientWithTracing Fetcher::buildClient(IoContext& ioContext, // tree shows `outerSpan -> operationName`. auto result = outgoingFactory->newSingleUseClient(kj::mv(cfStr), [](TraceContext&) -> kj::Maybe { return kj::none; }); - return wrapWithInnerSpan(kj::mv(result), kj::mv(operationName)); + return wrapWithInnerSpan(kj::mv(result), kj::mv(operationName), omitUserSpan); } KJ_CASE_ONEOF(outgoingFactory, kj::Own) { auto result = outgoingFactory->newSingleUseClient(ioContext, kj::mv(cfStr), [](TraceContext&) -> kj::Maybe { return kj::none; }); - return wrapWithInnerSpan(kj::mv(result), kj::mv(operationName)); + return wrapWithInnerSpan(kj::mv(result), kj::mv(operationName), omitUserSpan); } } KJ_UNREACHABLE; diff --git a/src/workerd/api/http.h b/src/workerd/api/http.h index 21d4b88995e..2370a20cbef 100644 --- a/src/workerd/api/http.h +++ b/src/workerd/api/http.h @@ -34,6 +34,7 @@ WD_STRONG_BOOL(IsHyperdrive); // For fetchers a `cloudflare-internal:` wrapper module keeps private. An ungated wildcard makes // every otherwise-missing property resolve to an RPC method, which user code can observe. WD_STRONG_BOOL(RpcCompatGateBypassed); +WD_STRONG_BOOL(OmitUserSpan); // Base class for Request and Response. In JavaScript, this class is a mixin, meaning no one will // be instantiating objects of this type -- it exists solely to house body-related functionality @@ -340,8 +341,13 @@ class Fetcher: public JsRpcClientProvider { // Get client and optionally create trace context, all in one call. // - [[nodiscard]] ClientWithTracing getClientWithTracing( - IoContext& ioContext, kj::Maybe cfStr, kj::ConstString operationName); + // + // With `omitUserSpan`, the operation gets only an internal span, and the subrequest's user span + // parent is the current user span. + [[nodiscard]] ClientWithTracing getClientWithTracing(IoContext& ioContext, + kj::Maybe cfStr, + kj::ConstString operationName, + OmitUserSpan omitUserSpan = OmitUserSpan::NO); [[nodiscard]] ClientWithTracing getClientForActorCallAttempt(IoContext& ioContext, kj::Maybe cfStr, @@ -566,8 +572,10 @@ class Fetcher: public JsRpcClientProvider { jsg::Deserializer& deserializer, RpcCompatGateBypassed rpcCompatGateBypassed); - [[nodiscard]] ClientWithTracing buildClient( - IoContext& ioContext, kj::Maybe cfStr, kj::ConstString operationName); + [[nodiscard]] ClientWithTracing buildClient(IoContext& ioContext, + kj::Maybe cfStr, + kj::ConstString operationName, + OmitUserSpan omitUserSpan = OmitUserSpan::NO); [[nodiscard]] ClientWithTracing buildClient(IoContext& ioContext, kj::Maybe cfStr, kj::ConstString operationName, @@ -576,8 +584,9 @@ class Fetcher: public JsRpcClientProvider { // Wraps an OutgoingFactory result, nesting an inner operation span under the factory's outer // dispatch span when it created one. Factories that create no dispatch span // (result.spanParents == kj::none) yield no inner span and no trace context. - [[nodiscard]] static ClientWithTracing wrapWithInnerSpan( - OutgoingFactory::Result result, kj::ConstString operationName); + [[nodiscard]] static ClientWithTracing wrapWithInnerSpan(OutgoingFactory::Result result, + kj::ConstString operationName, + OmitUserSpan omitUserSpan = OmitUserSpan::NO); kj::OneOf, diff --git a/src/workerd/io/io-context.c++ b/src/workerd/io/io-context.c++ index 3a75fa6e6cf..0bd4b506b33 100644 --- a/src/workerd/io/io-context.c++ +++ b/src/workerd/io/io-context.c++ @@ -1348,6 +1348,11 @@ TraceContext IoContext::makeUserTraceSpan(kj::ConstString operationName) { return parents.newChild(kj::mv(operationName)); } +TraceContext IoContext::makeTraceSpanWithoutUserSpan(kj::ConstString operationName) { + TraceContextParent parents(getCurrentTraceSpan(), getCurrentUserTraceSpan()); + return parents.newChildWithoutUserSpan(kj::mv(operationName)); +} + void IoContext::taskFailed(kj::Exception&& exception) { if (waitUntilStatusValue == EventOutcome::OK) { KJ_IF_SOME(status, limitEnforcer->getLimitsExceeded()) { diff --git a/src/workerd/io/io-context.h b/src/workerd/io/io-context.h index 605fc3cb6e8..4991e0135e8 100644 --- a/src/workerd/io/io-context.h +++ b/src/workerd/io/io-context.h @@ -1145,6 +1145,9 @@ class IoContext final: public kj::Refcounted, private kj::TaskSet::ErrorHandler // Returns both an internal and a user tracing span, this ensures that all user spans are // available in internal tracing. [[nodiscard]] TraceContext makeUserTraceSpan(kj::ConstString operationName); + // Like makeUserTraceSpan(), but opens only the internal span; the current user span is the + // user span parent of whatever runs under it. + [[nodiscard]] TraceContext makeTraceSpanWithoutUserSpan(kj::ConstString operationName); // Gets a CapabilityServerSet representing the capnp capabilities hosted by this request or // actor context. This allows us to implement the CapnpCapability::unwrap() method on diff --git a/src/workerd/io/trace.h b/src/workerd/io/trace.h index 20dbc89a7c4..d971e881892 100644 --- a/src/workerd/io/trace.h +++ b/src/workerd/io/trace.h @@ -1464,6 +1464,9 @@ class TraceContextParent { } [[nodiscard]] TraceContext newChild(kj::ConstString operationName); + // Like newChild(), but opens only the internal span: the user span parent passes through, so + // work done under the result nests directly under the current user span. + [[nodiscard]] TraceContext newChildWithoutUserSpan(kj::ConstString operationName); private: SpanParent internalSpan; @@ -1479,6 +1482,10 @@ class TraceContext { TraceContext(kj::Badge, SpanBuilder span, SpanBuilder userSpan) : span(kj::mv(span)), userSpan(kj::mv(userSpan)) {} + TraceContext(kj::Badge, SpanBuilder span, SpanParent userSpanParent) + : span(kj::mv(span)), + userSpan(nullptr), + userSpanParent(kj::mv(userSpanParent)) {} TraceContext(TraceContext&& other) = default; TraceContext& operator=(TraceContext&& other) = default; KJ_DISALLOW_COPY(TraceContext); @@ -1486,18 +1493,22 @@ class TraceContext { // Set a tag on both the internal span and user span. void setTag(kj::ConstString key, SpanBuilder::TagInitValue value); bool isObserved() { - return span.isObserved() || userSpan.isObserved(); + return span.isObserved() || userSpan.isObserved() || + userSpanParent.map([](SpanParent& p) { return p.isObserved(); }).orDefault(false); } SpanParent getInternalSpanParent() { return SpanParent(span); } SpanParent getUserSpanParent() { + KJ_IF_SOME(parent, userSpanParent) { + return parent.addRef(); + } return SpanParent(userSpan); } TraceContextParent getSpanParents() { - return TraceContextParent(SpanParent(span), SpanParent(userSpan)); + return TraceContextParent(SpanParent(span), getUserSpanParent()); } // Like getSpanParents(), but returns kj::none when neither span is observed. Use this when the @@ -1512,6 +1523,8 @@ class TraceContext { private: SpanBuilder span; SpanBuilder userSpan; + // Set instead of `userSpan` by TraceContextParent::newChildWithoutUserSpan(). + kj::Maybe userSpanParent; }; inline TraceContext TraceContextParent::newChild(kj::ConstString operationName) { @@ -1522,6 +1535,11 @@ inline TraceContext TraceContextParent::newChild(kj::ConstString operationName) return TraceContext(kj::Badge(), kj::mv(internalChild), kj::mv(userChild)); } +inline TraceContext TraceContextParent::newChildWithoutUserSpan(kj::ConstString operationName) { + return TraceContext(kj::Badge(), internalSpan.newChild(kj::mv(operationName)), + userSpan.addRef()); +} + // RAII object that measures the time duration over its lifetime. It tags this duration onto a // given request span using a specified tag name. Ideal for automatically tracking and logging // execution times within a scoped block. From 02c93263e8b381f93b1a30f240e7d207f5a2502e Mon Sep 17 00:00:00 2001 From: Dan Lapid Date: Sun, 11 Oct 2026 17:48:48 +0000 Subject: [PATCH 4/4] Record invocation-level exceptions on the exported root span An uncaught exception reported for the invocation went only to the streaming tail, so the exported root span had the exception outcome but no exception event and no status message. Record it on the root, as tail-built traces did. An exception reported while one of the worker's own spans is active belongs to that span and is left off the root. When an exception supplies the status message, still derive error.type, so every ERROR span carries one. Co-Authored-By: Claude Opus 5.5 --- src/rust/otlp/buffer.rs | 11 +++++--- src/workerd/api/tests/otlp-tracing-test.js | 29 ++++++++++++++++++++++ src/workerd/io/tracer.c++ | 17 ++++++++++--- src/workerd/io/tracer.h | 7 ++++++ 4 files changed, 57 insertions(+), 7 deletions(-) diff --git a/src/rust/otlp/buffer.rs b/src/rust/otlp/buffer.rs index 9fdd9d81d5a..f83ed0a2386 100644 --- a/src/rust/otlp/buffer.rs +++ b/src/rust/otlp/buffer.rs @@ -281,14 +281,16 @@ fn resolve_status( { return (status, None); } + let error_type = rules::derived_error_type(attributes, is_root); if let Some(message) = last_exception_message { + // The exception describes the error; error.type, when derivable, still classifies it. let status = proto::Status { message, code: error, }; - return (Some(status), None); + return (Some(status), error_type); } - let Some(error_type) = rules::derived_error_type(attributes, is_root) else { + let Some(error_type) = error_type else { return (status, None); }; let status = proto::Status { @@ -656,7 +658,10 @@ mod tests { let root = named(&request, "GET"); assert_eq!(status_code(root), StatusCode::Error); assert_eq!(root.status.as_ref().unwrap().message, "boom"); - assert_eq!(attribute(&root.attributes, "error.type"), None); + assert_eq!( + attribute(&root.attributes, "error.type"), + Some(&string("500")) + ); assert_eq!( attribute(&root.events[0].attributes, "exception.stacktrace"), Some(&string("at fetch")) diff --git a/src/workerd/api/tests/otlp-tracing-test.js b/src/workerd/api/tests/otlp-tracing-test.js index 67c4acc79d8..26e33bef3f7 100644 --- a/src/workerd/api/tests/otlp-tracing-test.js +++ b/src/workerd/api/tests/otlp-tracing-test.js @@ -16,6 +16,9 @@ export default { if (url.pathname === '/leaf') { return new Response('leaf'); } + if (url.pathname === '/throw') { + throw new Error('handler failed'); + } await ctx.tracing.enterSpan('my-span', async (span) => { span.setAttribute('answer', 42); span.setAttribute('ratio', 0.5); @@ -108,5 +111,31 @@ export const test = { assert.strictEqual(leaf.spans[0].traceId, root.traceId); assert.strictEqual(leaf.spans[0].parentSpanId, fetch.spanId); assert.strictEqual(leaf.spans[0].status, undefined); + + // An uncaught exception is recorded on the root, and its message is the error status's. + await assert.rejects(env.SELF.fetch('http://traced/throw')); + const [, , thrown] = await collected(env, 3); + assert.deepStrictEqual( + thrown.spans.map((span) => span.name), + ['GET'] + ); + const [thrownRoot] = thrown.spans; + assert.strictEqual( + thrownRoot.attributes['cloudflare.outcome'], + 'exception' + ); + assert.strictEqual(thrownRoot.attributes['error.type'], 'exception'); + assert.deepStrictEqual(thrownRoot.status, { + code: STATUS_CODE_ERROR, + message: 'handler failed', + }); + assert.deepStrictEqual( + thrownRoot.events.map((event) => event.name), + ['exception'] + ); + const { attributes } = thrownRoot.events[0]; + assert.strictEqual(attributes['exception.type'], 'Error'); + assert.strictEqual(attributes['exception.message'], 'handler failed'); + assert.match(attributes['exception.stacktrace'], /at Object\.fetch/); }, }; diff --git a/src/workerd/io/tracer.c++ b/src/workerd/io/tracer.c++ index 78379da9166..c457568c752 100644 --- a/src/workerd/io/tracer.c++ +++ b/src/workerd/io/tracer.c++ @@ -295,6 +295,11 @@ void WorkerTracer::addException(const tracing::InvocationSpanContext& context, kj::String name, kj::String message, kj::Maybe stack) { + kj::Maybe stackPtr; + KJ_IF_SOME(s, stack) { + stackPtr = s; + } + recordInvocationLevelException(context, name, message, stackPtr); // TODO(someday): For now, we're using logLevel == none as a hint to avoid doing anything // expensive while tracing. We may eventually want separate configuration for exceptions vs. // logs. @@ -307,10 +312,6 @@ void WorkerTracer::addException(const tracing::InvocationSpanContext& context, messageSize += s.size(); } KJ_IF_SOME(writer, maybeTailStreamWriter) { - kj::Maybe stackPtr; - KJ_IF_SOME(s, stack) { - stackPtr = s; - } reportExceptionToTailStream(*writer, context, timestamp, kj::none, name, message, stackPtr); } @@ -726,6 +727,14 @@ void BaseTracer::recordInvocationSpanException(const kj::Maybe stack) { + if (context.getSpanId() != SpanParent(invocationSpan).getSpanId()) return; + recordInvocationSpanException(kj::none, name, message, stack); +} + void BaseTracer::endInvocationSpan( EventOutcome outcome, kj::Duration cpuTime, kj::Duration wallTime) { setInvocationOutcome(invocationSpan, outcome, cpuTime, wallTime); diff --git a/src/workerd/io/tracer.h b/src/workerd/io/tracer.h index fe02a61006c..0e4dc98407e 100644 --- a/src/workerd/io/tracer.h +++ b/src/workerd/io/tracer.h @@ -149,6 +149,13 @@ class BaseTracer: public kj::Refcounted { kj::StringPtr name, kj::StringPtr message, kj::Maybe stack); + // Records an exception reported at the invocation level (an uncaught exception, for example), + // unless `context` names a user span other than the invocation's: such an exception belongs to + // that span. + void recordInvocationLevelException(const tracing::InvocationSpanContext& context, + kj::StringPtr name, + kj::StringPtr message, + kj::Maybe stack); void endInvocationSpan(EventOutcome outcome, kj::Duration cpuTime, kj::Duration wallTime); // See setStartInvocationSpanFunc(). Null unless the tracer records the invocation's span.