Coverage Report

Created: 2026-09-18 20:40

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