/build/source/nativelink-util/src/telemetry.rs
Line | Count | Source |
1 | | // Copyright 2025 The NativeLink Authors. All rights reserved. |
2 | | // |
3 | | // Licensed under the Functional Source License, Version 1.1, Apache 2.0 Future License (the "License"); |
4 | | // you may not use this file except in compliance with the License. |
5 | | // You may obtain a copy of the License at |
6 | | // |
7 | | // See LICENSE file for details |
8 | | // |
9 | | // Unless required by applicable law or agreed to in writing, software |
10 | | // distributed under the License is distributed on an "AS IS" BASIS, |
11 | | // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. |
12 | | // See the License for the specific language governing permissions and |
13 | | // limitations under the License. |
14 | | |
15 | | use core::default::Default; |
16 | | use std::collections::HashMap; |
17 | | use std::env; |
18 | | use std::sync::{Arc, OnceLock}; |
19 | | |
20 | | use base64::Engine; |
21 | | use base64::prelude::BASE64_STANDARD_NO_PAD; |
22 | | use ginepro::LoadBalancedChannel; |
23 | | use hyper::http::Response; |
24 | | use nativelink_error::{Code, ResultExt, make_err}; |
25 | | use nativelink_proto::build::bazel::remote::execution::v2::RequestMetadata; |
26 | | use opentelemetry::propagation::TextMapCompositePropagator; |
27 | | use opentelemetry::trace::{TraceContextExt, Tracer, TracerProvider}; |
28 | | use opentelemetry::{KeyValue, global}; |
29 | | use opentelemetry_appender_tracing::layer::OpenTelemetryTracingBridge; |
30 | | use opentelemetry_http::HeaderExtractor; |
31 | | use opentelemetry_otlp::{ |
32 | | LogExporter, MetricExporter, Protocol, SpanExporter, WithExportConfig, WithTonicConfig, |
33 | | }; |
34 | | use opentelemetry_sdk::Resource; |
35 | | use opentelemetry_sdk::logs::SdkLoggerProvider; |
36 | | use opentelemetry_sdk::metrics::SdkMeterProvider; |
37 | | use opentelemetry_sdk::propagation::{BaggagePropagator, TraceContextPropagator}; |
38 | | use opentelemetry_sdk::trace::SdkTracerProvider; |
39 | | use opentelemetry_semantic_conventions::attribute::ENDUSER_ID; |
40 | | use prost::Message; |
41 | | use tracing::debug; |
42 | | use tracing::metadata::LevelFilter; |
43 | | use tracing_opentelemetry::{MetricsLayer, layer}; |
44 | | use tracing_subscriber::filter::Directive; |
45 | | use tracing_subscriber::prelude::__tracing_subscriber_SubscriberExt; |
46 | | use tracing_subscriber::util::SubscriberInitExt; |
47 | | use tracing_subscriber::{EnvFilter, Layer, Registry, fmt, registry}; |
48 | | use uuid::Uuid; |
49 | | |
50 | | use crate::origin_event::{BAZEL_METADATA_KEY, request_metadata_to_baggage}; |
51 | | |
52 | | /// The OTLP "service.name" field for all nativelink services. |
53 | | const NATIVELINK_SERVICE_NAME: &str = "nativelink"; |
54 | | |
55 | | // An `EnvFilter` to filter out non-nativelink information. |
56 | | // |
57 | | // See: https://github.com/open-telemetry/opentelemetry-rust/issues/2877 |
58 | | // |
59 | | // Note that `EnvFilter` doesn't implement `clone`, so create a new one for |
60 | | // each telemetry kind. |
61 | 0 | fn otlp_filter() -> EnvFilter { |
62 | 0 | fn expect_parse(directive: &str) -> Directive { |
63 | 0 | directive |
64 | 0 | .parse() |
65 | 0 | .unwrap_or_else(|_| panic!("Static directive '{directive}' failed to parse")) |
66 | 0 | } |
67 | | |
68 | 0 | EnvFilter::builder() |
69 | 0 | .with_default_directive(LevelFilter::INFO.into()) |
70 | 0 | .from_env_lossy() |
71 | 0 | .add_directive(expect_parse("hyper=off")) |
72 | 0 | .add_directive(expect_parse("tonic=off")) |
73 | 0 | .add_directive(expect_parse("h2=off")) |
74 | 0 | .add_directive(expect_parse("reqwest=off")) |
75 | 0 | .add_directive(expect_parse("tower=off")) |
76 | 0 | } |
77 | | |
78 | | // Create a tracing layer intended for stdout printing. |
79 | | // |
80 | | // The output of this layer is configurable via the `NL_LOG` environment |
81 | | // variable. |
82 | 0 | fn tracing_stdout_layer() -> impl Layer<Registry> { |
83 | 0 | let nl_log_fmt = env::var("NL_LOG").unwrap_or_else(|_| "pretty".to_string()); |
84 | | |
85 | 0 | let stdout_filter = otlp_filter(); |
86 | | |
87 | 0 | match nl_log_fmt.as_str() { |
88 | 0 | "compact" => fmt::layer() |
89 | 0 | .compact() |
90 | 0 | .with_timer(fmt::time::time()) |
91 | 0 | .with_filter(stdout_filter) |
92 | 0 | .boxed(), |
93 | 0 | "json" => fmt::layer() |
94 | 0 | .json() |
95 | 0 | .with_timer(fmt::time::time()) |
96 | 0 | .with_filter(stdout_filter) |
97 | 0 | .boxed(), |
98 | 0 | _ => fmt::layer() |
99 | 0 | .pretty() |
100 | 0 | .with_timer(fmt::time::time()) |
101 | 0 | .with_filter(stdout_filter) |
102 | 0 | .boxed(), |
103 | | } |
104 | 0 | } |
105 | | |
106 | | /// Initialize tracing with OpenTelemetry support. |
107 | | /// |
108 | | /// # Errors |
109 | | /// |
110 | | /// Returns `Err` if logging was already initialized or if the exporters can't |
111 | | /// be initialized. |
112 | 0 | pub async fn init_tracing() -> Result<(), nativelink_error::Error> { |
113 | | static INITIALIZED: OnceLock<()> = OnceLock::new(); |
114 | | |
115 | | if INITIALIZED.get().is_some() { |
116 | | return Err(make_err!(Code::Internal, "Logging already initialized")); |
117 | | } |
118 | | |
119 | | // We currently use a UUIDv4 for "service.instance.id" as per: |
120 | | // https://opentelemetry.io/docs/specs/semconv/attributes-registry/service/ |
121 | | // This might change as we get a better understanding of its use cases in the |
122 | | // context of broader observability infrastructure. |
123 | | let resource = Resource::builder() |
124 | | .with_service_name(NATIVELINK_SERVICE_NAME) |
125 | | .with_attribute(KeyValue::new( |
126 | | "service.instance.id", |
127 | | Uuid::new_v4().to_string(), |
128 | | )) |
129 | | .build(); |
130 | | |
131 | | let propagator = TextMapCompositePropagator::new(vec![ |
132 | | Box::new(BaggagePropagator::new()), |
133 | | Box::new(TraceContextPropagator::new()), |
134 | | ]); |
135 | | global::set_text_map_propagator(propagator); |
136 | | |
137 | | let maybe_channel = maybe_load_balanced_channel().await; |
138 | | |
139 | | // Logs |
140 | | let mut log_exporter_builder = LogExporter::builder().with_tonic(); |
141 | | if let Some(channel) = maybe_channel.clone() { |
142 | | log_exporter_builder = log_exporter_builder.with_channel(channel.into()); |
143 | | } |
144 | | let otlp_log_layer = OpenTelemetryTracingBridge::new( |
145 | | &SdkLoggerProvider::builder() |
146 | | .with_resource(resource.clone()) |
147 | | .with_batch_exporter( |
148 | | log_exporter_builder |
149 | | .with_protocol(Protocol::Grpc) |
150 | | .build() |
151 | | .map_err(|e| make_err!(Code::Internal, "{e}")) |
152 | | .err_tip(|| "While creating OpenTelemetry OTLP Log exporter")?, |
153 | | ) |
154 | | .build(), |
155 | | ) |
156 | | .with_filter(otlp_filter()); |
157 | | |
158 | | // Traces |
159 | | let mut span_exporter_builder = SpanExporter::builder().with_tonic(); |
160 | | if let Some(channel) = maybe_channel.clone() { |
161 | | span_exporter_builder = span_exporter_builder.with_channel(channel.into()); |
162 | | } |
163 | | let otlp_trace_layer = layer() |
164 | | .with_tracer( |
165 | | SdkTracerProvider::builder() |
166 | | .with_resource(resource.clone()) |
167 | | .with_batch_exporter( |
168 | | span_exporter_builder |
169 | | .with_protocol(Protocol::Grpc) |
170 | | .build() |
171 | | .map_err(|e| make_err!(Code::Internal, "{e}")) |
172 | | .err_tip(|| "While creating OpenTelemetry OTLP Span exporter")?, |
173 | | ) |
174 | | .build() |
175 | | .tracer(NATIVELINK_SERVICE_NAME), |
176 | | ) |
177 | | .with_filter(otlp_filter()); |
178 | | |
179 | | // Metrics |
180 | | let mut metric_exporter_builder = MetricExporter::builder().with_tonic(); |
181 | | if let Some(channel) = maybe_channel { |
182 | | metric_exporter_builder = metric_exporter_builder.with_channel(channel.into()); |
183 | | } |
184 | | let meter_provider = SdkMeterProvider::builder() |
185 | | .with_resource(resource) |
186 | | .with_periodic_exporter( |
187 | | metric_exporter_builder |
188 | | .with_protocol(Protocol::Grpc) |
189 | | .build() |
190 | | .map_err(|e| make_err!(Code::Internal, "{e}")) |
191 | | .err_tip(|| "While creating OpenTelemetry OTLP Metric exporter")?, |
192 | | ) |
193 | | .build(); |
194 | | |
195 | | global::set_meter_provider(meter_provider.clone()); |
196 | | |
197 | | let otlp_metrics_layer = MetricsLayer::new(meter_provider).with_filter(otlp_filter()); |
198 | | |
199 | | registry() |
200 | | .with(tracing_stdout_layer()) |
201 | | .with(otlp_log_layer) |
202 | | .with(otlp_trace_layer) |
203 | | .with(otlp_metrics_layer) |
204 | | .init(); |
205 | | |
206 | | INITIALIZED.set(()).unwrap_or(()); |
207 | | |
208 | | Ok(()) |
209 | | } |
210 | | |
211 | | /// Environment variable pointing OTLP exporters at a load-balanced endpoint. |
212 | | pub const NL_OTEL_ENDPOINT: &str = "NL_OTEL_ENDPOINT"; |
213 | | |
214 | | /// Creates a load-balanced gRPC channel for the endpoint configured via |
215 | | /// [`NL_OTEL_ENDPOINT`], or returns `None` if the variable isn't set. |
216 | | /// |
217 | | /// Public so that integration tests can verify that exporters behave the |
218 | | /// same with and without the load-balanced channel. |
219 | 2 | pub async fn maybe_load_balanced_channel() -> Option<LoadBalancedChannel> { |
220 | 2 | match env::var(NL_OTEL_ENDPOINT) { |
221 | 0 | Ok(endpoint) => { |
222 | 0 | let url = Url::parse(endpoint.as_str()) |
223 | 0 | .map_err(|e| { |
224 | 0 | make_err!(Code::Internal, "Unable to parse endpoint {endpoint}: {e:?}") |
225 | 0 | }) |
226 | 0 | .unwrap(); |
227 | | |
228 | 0 | let host = url |
229 | 0 | .host() |
230 | 0 | .err_tip(|| format!("Unable to get host from endpoint {endpoint}")) |
231 | 0 | .unwrap(); |
232 | 0 | let port = url |
233 | 0 | .port() |
234 | 0 | .err_tip(|| format!("Unable to get port from endpoint {endpoint}")) |
235 | 0 | .unwrap(); |
236 | | |
237 | | Some( |
238 | 0 | LoadBalancedChannel::builder((host.to_string(), port)) |
239 | 0 | .channel() |
240 | 0 | .await |
241 | 0 | .map_err(|e| make_err!(Code::Internal, "Invalid hostname '{endpoint}': {e}")) |
242 | 0 | .unwrap(), |
243 | | ) |
244 | | } |
245 | 2 | Err(_) => None, |
246 | | } |
247 | 2 | } |
248 | | /// This is the header that bazel sends when using the `--remote_header` flag. |
249 | | /// TODO(palfrey): Bazel supports other headers, and we should optimize their usage. |
250 | | const BAZEL_REQUESTMETADATA_HEADER: &str = "build.bazel.remote.execution.v2.requestmetadata-bin"; |
251 | | |
252 | | use opentelemetry::baggage::BaggageExt; |
253 | | use opentelemetry::context::FutureExt; |
254 | | use url::Url; |
255 | | |
256 | | /// ASCII headers from an inbound client request, stored in the task context |
257 | | /// so that outgoing upstream calls can forward them (e.g. JWT auth tokens). |
258 | | #[derive(Clone, Debug, Default)] |
259 | | pub struct ClientHeaders(pub Arc<HashMap<String, String>>); |
260 | | |
261 | | #[derive(Debug, Clone)] |
262 | | pub struct OtlpMiddleware<S> { |
263 | | inner: S, |
264 | | identity_required: bool, |
265 | | } |
266 | | |
267 | | impl<S> OtlpMiddleware<S> { |
268 | 3 | const fn new(inner: S, identity_required: bool) -> Self { |
269 | 3 | Self { |
270 | 3 | inner, |
271 | 3 | identity_required, |
272 | 3 | } |
273 | 3 | } |
274 | | } |
275 | | |
276 | | impl<S, ReqBody, ResBody> tower::Service<hyper::http::Request<ReqBody>> for OtlpMiddleware<S> |
277 | | where |
278 | | S: tower::Service<hyper::http::Request<ReqBody>, Response = Response<ResBody>> |
279 | | + Clone |
280 | | + Send |
281 | | + 'static, |
282 | | S::Future: Send + 'static, |
283 | | ReqBody: core::fmt::Debug + Send + 'static, |
284 | | ResBody: From<String> + Send + 'static + Default, |
285 | | { |
286 | | type Response = S::Response; |
287 | | type Error = S::Error; |
288 | | type Future = futures::future::BoxFuture<'static, Result<Self::Response, Self::Error>>; |
289 | | |
290 | 3 | fn poll_ready( |
291 | 3 | &mut self, |
292 | 3 | cx: &mut core::task::Context<'_>, |
293 | 3 | ) -> core::task::Poll<Result<(), Self::Error>> { |
294 | 3 | self.inner.poll_ready(cx) |
295 | 3 | } |
296 | | |
297 | 3 | fn call(&mut self, req: hyper::http::Request<ReqBody>) -> Self::Future { |
298 | | // We must take the current `inner` and not the clone. |
299 | | // See: <https://docs.rs/tower/latest/tower/trait.Service.html#be-careful-when-cloning-inner-services> |
300 | 3 | let clone = self.inner.clone(); |
301 | 3 | let mut inner = core::mem::replace(&mut self.inner, clone); |
302 | | |
303 | | // Capture all ASCII-valued request headers before req is consumed, so |
304 | | // they can be forwarded to upstream services (e.g. JWT auth tokens). |
305 | 3 | let client_headers = ClientHeaders(Arc::new( |
306 | 3 | req.headers() |
307 | 3 | .iter() |
308 | 3 | .filter_map(|(name, value)| {2 |
309 | 2 | value |
310 | 2 | .to_str() |
311 | 2 | .ok() |
312 | 2 | .map(|v| (name.as_str().to_lowercase(), v.to_string())) |
313 | 2 | }) |
314 | 3 | .collect(), |
315 | | )); |
316 | | |
317 | 3 | let parent_cx = global::get_text_map_propagator(|propagator| { |
318 | 3 | propagator.extract(&HeaderExtractor(req.headers())) |
319 | 3 | }); |
320 | | |
321 | 3 | let identity = parent_cx |
322 | 3 | .baggage() |
323 | 3 | .get(ENDUSER_ID) |
324 | 3 | .map(|value| value.as_str()1 .to_string1 ()) |
325 | 3 | .unwrap_or_default(); |
326 | | |
327 | 3 | if identity.is_empty() { |
328 | 2 | if self.identity_required { |
329 | 0 | return Box::pin(async move { |
330 | 0 | Ok(tonic::Status::failed_precondition( |
331 | 0 | r" |
332 | 0 |
|
333 | 0 | NativeLink instance configured to require this OpenTelemetry Baggage header: |
334 | 0 |
|
335 | 0 | `Baggage: enduser.id=YOUR_IDENTITY` |
336 | 0 |
|
337 | 0 | ", |
338 | 0 | ) |
339 | 0 | .into_http()) |
340 | 0 | }); |
341 | 2 | } |
342 | | } else { |
343 | 1 | debug!("Baggage enduser.id: {identity}"); |
344 | | } |
345 | | |
346 | 3 | let tracer = global::tracer("origin_middleware"); |
347 | 3 | let span = tracer |
348 | 3 | .span_builder("origin_request") |
349 | 3 | .with_kind(opentelemetry::trace::SpanKind::Server) |
350 | 3 | .start_with_context(&tracer, &parent_cx); |
351 | | |
352 | 3 | let mut cx = parent_cx.with_span(span); |
353 | | |
354 | 3 | if let Some(bazel_header0 ) = req.headers().get(BAZEL_REQUESTMETADATA_HEADER) |
355 | 0 | && let Ok(decoded) = BASE64_STANDARD_NO_PAD.decode(bazel_header.as_bytes()) |
356 | 0 | && let Ok(metadata) = RequestMetadata::decode(decoded.as_slice()) |
357 | | { |
358 | 0 | let metadata_str = format!("{metadata:?}"); |
359 | 0 | debug!("Baggage Bazel request metadata: {metadata_str}"); |
360 | 0 | cx = cx.with_baggage(vec![ |
361 | 0 | KeyValue::new(BAZEL_METADATA_KEY, request_metadata_to_baggage(&metadata)), |
362 | 0 | KeyValue::new(ENDUSER_ID, identity), |
363 | | ]); |
364 | 3 | } |
365 | | |
366 | 3 | let cx = cx.with_value(client_headers); |
367 | 3 | Box::pin(async move { inner.call(req).with_context(cx).await }) |
368 | 3 | } |
369 | | } |
370 | | |
371 | | #[derive(Debug, Clone, Copy)] |
372 | | pub struct OtlpLayer { |
373 | | identity_required: bool, |
374 | | } |
375 | | |
376 | | impl OtlpLayer { |
377 | 0 | pub const fn new(identity_required: bool) -> Self { |
378 | 0 | Self { identity_required } |
379 | 0 | } |
380 | | } |
381 | | |
382 | | impl<S> tower::Layer<S> for OtlpLayer { |
383 | | type Service = OtlpMiddleware<S>; |
384 | | |
385 | 3 | fn layer(&self, service: S) -> Self::Service { |
386 | 3 | OtlpMiddleware::new(service, self.identity_required) |
387 | 3 | } |
388 | | } |
389 | | |
390 | | #[cfg(test)] |
391 | | mod tests { |
392 | | use nativelink_macro::nativelink_test; |
393 | | use serial_test::serial; |
394 | | |
395 | | use super::*; |
396 | | |
397 | | // ginepro's default resolver (hickory-dns) reads /etc/resolv.conf, which |
398 | | // doesn't exist in sandboxed environments (e.g. Nix builds). |
399 | | #[cfg(unix)] |
400 | 1 | fn dns_configured() -> bool { |
401 | 1 | std::path::Path::new("/etc/resolv.conf").exists() |
402 | 1 | } |
403 | | #[cfg(not(unix))] |
404 | | const fn dns_configured() -> bool { |
405 | | true |
406 | | } |
407 | | |
408 | | // Env vars are process-global, so concurrent writes would be a data race |
409 | | // on Unix. `#[serial(env)]` serializes all env-mutating tests. |
410 | | #[serial(env)] |
411 | | #[nativelink_test("crate")] |
412 | | async fn channel_absent_when_env_not_set() { |
413 | | // SAFETY: `#[serial(env)]` serializes all env-var writes across tests. |
414 | | unsafe { env::remove_var(NL_OTEL_ENDPOINT) }; |
415 | | assert!( |
416 | | maybe_load_balanced_channel().await.is_none(), |
417 | | "Expected None when {NL_OTEL_ENDPOINT} is unset" |
418 | | ); |
419 | | } |
420 | | |
421 | | #[serial(env)] |
422 | | #[nativelink_test("crate")] |
423 | | async fn channel_present_when_valid_endpoint_set() { |
424 | | if !dns_configured() { |
425 | | eprintln!( |
426 | | "Skipping channel_present_when_valid_endpoint_set: no DNS configuration \ |
427 | | available (e.g. sandboxed Nix build)" |
428 | | ); |
429 | | return; |
430 | | } |
431 | | // SAFETY: `#[serial(env)]` serializes all env-var writes across tests. |
432 | | unsafe { env::set_var(NL_OTEL_ENDPOINT, "http://localhost:4317") }; |
433 | | let result = maybe_load_balanced_channel().await; |
434 | | // SAFETY: `#[serial(env)]` serializes all env-var writes across tests. |
435 | | unsafe { env::remove_var(NL_OTEL_ENDPOINT) }; |
436 | | assert!( |
437 | | result.is_some(), |
438 | | "Expected Some(channel) when {NL_OTEL_ENDPOINT} points to a valid URL" |
439 | | ); |
440 | | } |
441 | | } |