telemetry_subscribers/
lib.rs

1// Copyright (c) Mysten Labs, Inc.
2// SPDX-License-Identifier: Apache-2.0
3
4use atomic_float::AtomicF64;
5use crossterm::tty::IsTty;
6use once_cell::sync::Lazy;
7use opentelemetry::{
8    Context, KeyValue,
9    trace::{Link, SamplingResult, SpanKind, TraceId, TracerProvider as _},
10};
11use opentelemetry_otlp::WithExportConfig;
12use opentelemetry_sdk::trace::Sampler;
13use opentelemetry_sdk::{
14    self, Resource, runtime,
15    trace::{BatchSpanProcessor, ShouldSample, TracerProvider},
16};
17use span_latency_prom::PrometheusSpanLatencyLayer;
18use std::collections::HashMap;
19use std::path::{Path, PathBuf};
20use std::time::Duration;
21use std::{
22    env,
23    io::{Write, stderr},
24    str::FromStr,
25    sync::{Arc, Mutex, atomic::Ordering},
26};
27use tracing::dispatcher::DefaultGuard;
28use tracing::metadata::LevelFilter;
29use tracing::{Level, error, info};
30use tracing_appender::non_blocking::{NonBlocking, WorkerGuard};
31use tracing_error::ErrorLayer;
32use tracing_subscriber::{
33    EnvFilter, Layer, Registry,
34    filter::{self, FilterExt},
35    fmt::{self, format::Pretty},
36    layer::SubscriberExt,
37    reload,
38};
39
40use crate::file_exporter::{CachedOpenFile, FileExporter};
41use crate::test_layer::TestLayer;
42
43mod file_exporter;
44pub mod span_latency_prom;
45mod test_layer;
46
47/// Global filter layer that rejects callsites above the configured levels at registration time.
48///
49/// Without this, per-layer filtering causes the Registry to return `Interest::always()` for
50/// every callsite. That means trace-level `#[instrument]` spans are allocated in the slab,
51/// have their per-layer filters walked, and are immediately discarded — all at significant cost.
52/// The same applies to events below the env filter threshold.
53///
54/// By rejecting high-verbosity callsites globally, `Span::new` short-circuits to
55/// `Span::none()` and event macros short-circuit before formatting arguments.
56struct GlobalLevelFilter {
57    max_span_level: LevelFilter,
58    /// The maximum event level any layer will accept. Loaded from the EnvFilter's
59    /// max_level_hint and updated via a shared atomic when the filter is reloaded.
60    max_event_level: Arc<std::sync::atomic::AtomicU8>,
61}
62
63impl GlobalLevelFilter {
64    fn load_max_event_level(&self) -> LevelFilter {
65        level_filter_from_u8(self.max_event_level.load(Ordering::Relaxed))
66    }
67
68    fn exceeds_max_level(&self, metadata: &tracing::Metadata<'_>) -> bool {
69        if metadata.is_span() {
70            LevelFilter::from_level(*metadata.level()) > self.max_span_level
71        } else {
72            let max = self.load_max_event_level();
73            !max.eq(&LevelFilter::OFF) && LevelFilter::from_level(*metadata.level()) > max
74        }
75    }
76}
77
78fn level_filter_to_u8(lf: LevelFilter) -> u8 {
79    match lf {
80        LevelFilter::OFF => 0,
81        LevelFilter::ERROR => 1,
82        LevelFilter::WARN => 2,
83        LevelFilter::INFO => 3,
84        LevelFilter::DEBUG => 4,
85        LevelFilter::TRACE => 5,
86    }
87}
88
89fn level_filter_from_u8(v: u8) -> LevelFilter {
90    match v {
91        0 => LevelFilter::OFF,
92        1 => LevelFilter::ERROR,
93        2 => LevelFilter::WARN,
94        3 => LevelFilter::INFO,
95        4 => LevelFilter::DEBUG,
96        _ => LevelFilter::TRACE,
97    }
98}
99
100impl<S: tracing::Subscriber> Layer<S> for GlobalLevelFilter {
101    fn register_callsite(
102        &self,
103        metadata: &'static tracing::Metadata<'static>,
104    ) -> tracing::subscriber::Interest {
105        if self.exceeds_max_level(metadata) {
106            tracing::subscriber::Interest::never()
107        } else {
108            // Return always() for passing callsites. The final interest will be
109            // determined by the Registry (which returns sometimes() when per-layer
110            // filters are present). We intentionally do NOT override enabled() —
111            // doing so would add an extra check to every enabled() walk, which the
112            // per-layer filters already handle. For dynamic env filter reloads,
113            // rebuild_interest_cache() re-calls register_callsite with our updated
114            // atomic max_event_level.
115            tracing::subscriber::Interest::always()
116        }
117    }
118
119    fn max_level_hint(&self) -> Option<LevelFilter> {
120        let event = self.load_max_event_level();
121        Some(std::cmp::max(self.max_span_level, event))
122    }
123}
124
125/// Alias for a type-erased error type.
126pub type BoxError = Box<dyn std::error::Error + Send + Sync + 'static>;
127
128/// Output format for a per-target log route (see [`TelemetryConfig::log_tails`]). Inferred
129/// from the route's file extension.
130#[derive(Clone, Copy, Debug, PartialEq, Eq, Default)]
131pub enum LogFormat {
132    Json,
133    #[default]
134    Text,
135}
136
137impl LogFormat {
138    /// Infer the output format from a log file's extension: the common newline-delimited
139    /// JSON extensions `jsonl` and `ndjson` (case-insensitive) select [`LogFormat::Json`];
140    /// every other extension (including `.json` and `.log`) and none default to
141    /// [`LogFormat::Text`].
142    fn from_path(path: &Path) -> Self {
143        if let Some(ext) = path.extension().and_then(|ext| ext.to_str())
144            && (ext.eq_ignore_ascii_case("jsonl") || ext.eq_ignore_ascii_case("ndjson"))
145        {
146            LogFormat::Json
147        } else {
148            LogFormat::Text
149        }
150    }
151}
152
153/// A per-target output route: *additionally* write `target`'s logs to `file`. Configured via
154/// the `RUST_LOG_TAILS` env var, e.g. `graphql_request=/var/log/sui/graphql_request.jsonl`.
155#[derive(Clone, Debug)]
156pub struct LogTail {
157    pub target: String,
158    pub format: LogFormat,
159    pub file: PathBuf,
160}
161
162/// Configuration for different logging/tracing options
163/// ===
164/// - json_log_output: Output JSON logs to stdout only.
165/// - log_tails: Additional per-target log files via RUST_LOG_TAILS.
166/// - log_file: If defined, write output to a file starting with this name, ex app.log
167/// - log_level: error/warn/info/debug/trace, defaults to info
168#[derive(Default, Clone, Debug)]
169pub struct TelemetryConfig {
170    pub enable_otlp_tracing: bool,
171    /// Enables Tokio Console debugging on port 6669
172    pub tokio_console: bool,
173    /// Output JSON logs.
174    pub json_log_output: bool,
175    /// If defined, write output to a file starting with this name, ex app.log
176    pub log_file: Option<String>,
177    /// Log level to set, defaults to info
178    pub log_string: Option<String>,
179    /// Span level - what level of spans should be created.  Note this is not same as logging level.
180    /// If set to None, then defaults to INFO. Use LevelFilter::OFF to disable all spans.
181    pub span_level: Option<LevelFilter>,
182    /// Set a panic hook
183    pub panic_hook: bool,
184    /// Crash on panic
185    pub crash_on_panic: bool,
186    /// Optional Prometheus registry - if present, all enabled span latencies are measured
187    pub prom_registry: Option<prometheus::Registry>,
188    /// Disable the PrometheusSpanLatencyLayer even when a prom_registry is set.
189    pub disable_span_latency: bool,
190    pub sample_rate: f64,
191    /// Add directive to include trace logs with provided target
192    pub trace_target: Option<Vec<String>>,
193    /// Print unadorned logs from the target on standard error if this is a tty
194    pub user_info_target: Vec<String>,
195    /// Per-target output routing — one [`LogTail`] per entry — populated from the
196    /// `RUST_LOG_TAILS` env var. See [`TelemetryConfig::with_log_tail`] for how each tail
197    /// is emitted.
198    pub log_tails: Vec<LogTail>,
199    // Sets the subscriber created by this config to be the global default. Defaults to true if not set.
200    pub set_global_default: bool,
201    // Add error layer to capture trace spans. Defaults to false if not set.
202    pub enable_error_layer: bool,
203    // Capture output for tests. Defaults to false if not set.
204    pub enable_test_layer: bool,
205}
206
207#[must_use]
208#[allow(dead_code)]
209pub struct TelemetryGuards {
210    worker_guard: WorkerGuard,
211    /// Flush guards for any per-target log files (`RUST_LOG_TAILS`). Held so the
212    /// background writer threads keep flushing until the guards are dropped.
213    file_guards: Vec<WorkerGuard>,
214    provider: Option<TracerProvider>,
215    subscriber: Option<DefaultGuard>,
216}
217
218impl TelemetryGuards {
219    fn new(
220        config: TelemetryConfig,
221        worker_guard: WorkerGuard,
222        file_guards: Vec<WorkerGuard>,
223        provider: Option<TracerProvider>,
224        subscriber: Option<DefaultGuard>,
225    ) -> Self {
226        // Do not set the global config if subscriber is present because a global subscriber was not set.
227        if subscriber.is_none() {
228            set_global_telemetry_config(config);
229        }
230        Self {
231            worker_guard,
232            file_guards,
233            provider,
234            subscriber,
235        }
236    }
237}
238
239impl Drop for TelemetryGuards {
240    fn drop(&mut self) {
241        clear_global_telemetry_config();
242    }
243}
244
245#[derive(Clone, Debug)]
246pub struct FilterHandle {
247    reload: reload::Handle<EnvFilter, Registry>,
248    /// Shared with GlobalLevelFilter so that reloading the env filter also
249    /// updates the global event-level gate.
250    max_event_level: Option<Arc<std::sync::atomic::AtomicU8>>,
251}
252
253impl FilterHandle {
254    pub fn update<S: AsRef<str>>(&self, directives: S) -> Result<(), BoxError> {
255        let filter = EnvFilter::try_new(directives)?;
256        if let Some(ref max_level) = self.max_event_level {
257            let hint = filter.max_level_hint().unwrap_or(LevelFilter::TRACE);
258            max_level.store(level_filter_to_u8(hint), Ordering::Relaxed);
259        }
260        self.reload.reload(filter)?;
261        Ok(())
262    }
263
264    pub fn get(&self) -> Result<String, BoxError> {
265        self.reload
266            .with_current(|filter| filter.to_string())
267            .map_err(Into::into)
268    }
269}
270
271pub struct TracingHandle {
272    log: FilterHandle,
273    trace: Option<FilterHandle>,
274    file_output: CachedOpenFile,
275    test_layer: Option<TestLayer>,
276    sampler: SamplingFilter,
277}
278
279impl TracingHandle {
280    pub fn update_log<S: AsRef<str>>(&self, directives: S) -> Result<(), BoxError> {
281        self.log.update(directives)
282    }
283
284    pub fn get_log(&self) -> Result<String, BoxError> {
285        self.log.get()
286    }
287
288    pub fn update_sampling_rate(&self, sample_rate: f64) {
289        self.sampler.update_sampling_rate(sample_rate);
290    }
291
292    pub fn update_trace_file<S: AsRef<str>>(&self, trace_file: S) -> Result<(), BoxError> {
293        let trace_path = PathBuf::from_str(trace_file.as_ref())?;
294        self.file_output.update_path(trace_path)?;
295        Ok(())
296    }
297
298    pub fn update_trace_filter<S: AsRef<str>>(
299        &self,
300        directives: S,
301        duration: Duration,
302    ) -> Result<(), BoxError> {
303        if let Some(trace) = &self.trace {
304            let res = trace.update(directives);
305            // after duration is elapsed, reset to the env setting
306            let trace = trace.clone();
307            let trace_filter_env = env::var("TRACE_FILTER").unwrap_or_else(|_| "off".to_string());
308            tokio::spawn(async move {
309                tokio::time::sleep(duration).await;
310                if let Err(e) = trace.update(trace_filter_env) {
311                    error!("failed to reset trace filter: {}", e);
312                }
313            });
314            res
315        } else {
316            info!("tracing not enabled, ignoring update");
317            Ok(())
318        }
319    }
320
321    pub fn clear_file_output(&self) {
322        self.file_output.clear_path();
323    }
324
325    pub fn reset_trace(&self) {
326        if let Some(trace) = &self.trace {
327            let trace_filter_env = env::var("TRACE_FILTER").unwrap_or_else(|_| "off".to_string());
328            if let Err(e) = trace.update(trace_filter_env) {
329                error!("failed to reset trace filter: {}", e);
330            }
331        }
332    }
333
334    pub fn get_test_layer_events(&self) -> Vec<String> {
335        self.test_layer
336            .as_ref()
337            .expect("test layer not enabled")
338            .get_events()
339    }
340}
341
342fn get_output(log_file: Option<String>) -> (NonBlocking, WorkerGuard) {
343    if let Some(logfile_prefix) = log_file {
344        let file_appender = tracing_appender::rolling::daily("", logfile_prefix);
345        tracing_appender::non_blocking(file_appender)
346    } else {
347        tracing_appender::non_blocking(stderr())
348    }
349}
350
351/// Open a per-target log file (`RUST_LOG_TAILS`), pre-creating its parent directory.
352/// Panics `init()` if the directory cannot be created, rather than silently dropping the
353/// target's file sink.
354fn open_tail_file(path: &Path) -> (NonBlocking, WorkerGuard) {
355    if let Some(parent) = path.parent()
356        && !parent.as_os_str().is_empty()
357    {
358        std::fs::create_dir_all(parent).unwrap_or_else(|e| {
359            panic!(
360                "telemetry: cannot create directory for RUST_LOG_TAILS file {}: {e}",
361                path.display()
362            )
363        });
364    }
365    let file_appender = tracing_appender::rolling::daily("", path);
366    tracing_appender::non_blocking(file_appender)
367}
368
369// NOTE: this function is copied from tracing's panic_hook example
370fn set_panic_hook(crash_on_panic: bool) {
371    let default_panic_handler = std::panic::take_hook();
372
373    // Set a panic hook that records the panic as a `tracing` event at the
374    // `ERROR` verbosity level.
375    //
376    // If we are currently in a span when the panic occurred, the logged event
377    // will include the current span, allowing the context in which the panic
378    // occurred to be recorded.
379    std::panic::set_hook(Box::new(move |panic| {
380        // If the panic has a source location, record it as structured fields.
381        if let Some(location) = panic.location() {
382            // On nightly Rust, where the `PanicInfo` type also exposes a
383            // `message()` method returning just the message, we could record
384            // just the message instead of the entire `fmt::Display`
385            // implementation, avoiding the duplicated location
386            tracing::error!(
387                message = %panic,
388                panic.file = location.file(),
389                panic.line = location.line(),
390                panic.column = location.column(),
391            );
392        } else {
393            tracing::error!(message = %panic);
394        }
395
396        default_panic_handler(panic);
397
398        // We're panicking so we can't do anything about the flush failing
399        let _ = std::io::stderr().flush();
400        let _ = std::io::stdout().flush();
401
402        if crash_on_panic {
403            // Kill the process
404            std::process::exit(12);
405        }
406    }));
407}
408
409static GLOBAL_CONFIG: Lazy<Arc<Mutex<Option<TelemetryConfig>>>> =
410    Lazy::new(|| Arc::new(Mutex::new(None)));
411
412fn set_global_telemetry_config(config: TelemetryConfig) {
413    let mut global_config = GLOBAL_CONFIG.lock().unwrap();
414    assert!(global_config.is_none());
415    *global_config = Some(config);
416}
417
418fn clear_global_telemetry_config() {
419    let mut global_config = GLOBAL_CONFIG.lock().unwrap();
420    *global_config = None;
421}
422
423pub fn get_global_telemetry_config() -> Option<TelemetryConfig> {
424    let global_config = GLOBAL_CONFIG.lock().unwrap();
425    global_config.clone()
426}
427
428fn parse_log_tails(spec: &str) -> Vec<LogTail> {
429    spec.split(',')
430        .map(str::trim)
431        .filter(|entry| !entry.is_empty())
432        .map(parse_log_tail_entry)
433        .collect()
434}
435
436fn parse_log_tail_entry(entry: &str) -> LogTail {
437    if let Some((target, file)) = entry.split_once('=') {
438        let (target, file) = (target.trim(), file.trim());
439        if !target.is_empty() && !file.is_empty() {
440            let file = PathBuf::from(file);
441            let format = LogFormat::from_path(&file);
442            return LogTail {
443                target: target.to_owned(),
444                format,
445                file,
446            };
447        }
448    }
449    panic!(
450        "telemetry: invalid RUST_LOG_TAILS entry {entry:?}: a `=file` path is \
451         required, e.g. `graphql_request=/var/log/sui/graphql_request.jsonl`"
452    )
453}
454
455impl TelemetryConfig {
456    pub fn new() -> Self {
457        Self {
458            enable_otlp_tracing: false,
459            tokio_console: false,
460            json_log_output: false,
461            log_file: None,
462            log_string: None,
463            span_level: None,
464            panic_hook: true,
465            crash_on_panic: false,
466            prom_registry: None,
467            disable_span_latency: false,
468            sample_rate: 1.0,
469            trace_target: None,
470            user_info_target: Vec::new(),
471            log_tails: Vec::new(),
472            set_global_default: true,
473            enable_error_layer: false,
474            enable_test_layer: false,
475        }
476    }
477
478    pub fn with_json(mut self) -> Self {
479        self.json_log_output = true;
480        self
481    }
482
483    pub fn with_log_level(mut self, log_string: &str) -> Self {
484        self.log_string = Some(log_string.to_owned());
485        self
486    }
487
488    pub fn with_span_level(mut self, span_level: Level) -> Self {
489        self.span_level = Some(LevelFilter::from_level(span_level));
490        self
491    }
492
493    pub fn with_log_file(mut self, filename: &str) -> Self {
494        self.log_file = Some(filename.to_owned());
495        self
496    }
497
498    pub fn with_prom_registry(mut self, registry: &prometheus::Registry) -> Self {
499        self.prom_registry = Some(registry.clone());
500        self
501    }
502
503    pub fn with_disable_span_latency(mut self, disable: bool) -> Self {
504        self.disable_span_latency = disable;
505        self
506    }
507
508    pub fn with_sample_rate(mut self, rate: f64) -> Self {
509        self.sample_rate = rate;
510        self
511    }
512
513    pub fn with_trace_target(mut self, target: &str) -> Self {
514        match self.trace_target {
515            Some(ref mut v) => v.push(target.to_owned()),
516            None => self.trace_target = Some(vec![target.to_owned()]),
517        };
518
519        self
520    }
521
522    /// Adds `target` to the list of modules that will have their info & above logs printed
523    /// unadorned to standard error (for non-json output)
524    pub fn with_user_info_target(mut self, target: &str) -> Self {
525        self.user_info_target.push(target.to_owned());
526        self
527    }
528
529    /// Adds a `RUST_LOG_TAILS`-style routing rule: *additionally* write `target`'s logs to
530    /// `file`, in a format inferred from its extension.
531    pub fn with_log_tail(mut self, target: &str, file: impl Into<PathBuf>) -> Self {
532        let file = file.into();
533        let format = LogFormat::from_path(&file);
534        self.log_tails.push(LogTail {
535            target: target.to_owned(),
536            format,
537            file,
538        });
539        self
540    }
541
542    pub fn with_set_global_default(mut self, set_global_default: bool) -> Self {
543        self.set_global_default = set_global_default;
544        self
545    }
546
547    pub fn with_enable_error_layer(mut self, enable_error_layer: bool) -> Self {
548        self.enable_error_layer = enable_error_layer;
549        self
550    }
551
552    pub fn with_enable_test_layer(mut self, enable_test_layer: bool) -> Self {
553        self.enable_test_layer = enable_test_layer;
554        self
555    }
556
557    pub fn with_env(mut self) -> Self {
558        if env::var("CRASH_ON_PANIC").is_ok() {
559            self.crash_on_panic = true
560        }
561
562        if env::var("TRACE_FILTER").is_ok() {
563            self.enable_otlp_tracing = true
564        }
565
566        if env::var("RUST_LOG_JSON").is_ok() {
567            self.json_log_output = true;
568        }
569
570        if let Ok(spec) = env::var("RUST_LOG_TAILS") {
571            self.log_tails = parse_log_tails(&spec);
572        }
573
574        if env::var("TOKIO_CONSOLE").is_ok() {
575            self.tokio_console = true;
576        }
577
578        if let Ok(span_level) = env::var("TOKIO_SPAN_LEVEL") {
579            self.span_level =
580                Some(LevelFilter::from_str(&span_level).expect("Cannot parse TOKIO_SPAN_LEVEL"));
581        }
582
583        if let Ok(filepath) = env::var("RUST_LOG_FILE") {
584            self.log_file = Some(filepath);
585        }
586
587        if let Ok(sample_rate) = env::var("SAMPLE_RATE") {
588            self.sample_rate = sample_rate.parse().expect("Cannot parse SAMPLE_RATE");
589        }
590
591        if let Ok(enable_error_layer) = env::var("ENABLE_ERROR_LAYER") {
592            self.enable_error_layer = enable_error_layer
593                .parse()
594                .expect("Cannot parse ENABLE_ERROR_LAYER");
595        }
596
597        self
598    }
599
600    pub fn init(self) -> (TelemetryGuards, TracingHandle) {
601        let config = self;
602        let config_clone = config.clone();
603
604        // Setup an EnvFilter for filtering logging output layers.
605        // NOTE: we don't want to use this to filter all layers.  That causes problems for layers with
606        // different filtering needs, including tokio-console/console-subscriber, and it also doesn't
607        // fit with the span creation needs for distributed tracing and other span-based tools.
608        let mut directives = config.log_string.unwrap_or_else(|| "info".into());
609        if let Some(targets) = config.trace_target {
610            for target in targets {
611                directives.push_str(&format!(",{}=trace", target));
612            }
613        }
614        let env_filter = EnvFilter::try_from_default_env()
615            .unwrap_or_else(|_| EnvFilter::new(directives.clone()));
616        // When the test layer is enabled, it accepts events at any level without a
617        // per-layer filter, so global event-level filtering would hide events the
618        // test wants to capture. Disable it by pinning max_event_level to TRACE
619        // (and skip propagating env filter reloads into it).
620        let max_event_level_seed = if config.enable_test_layer {
621            LevelFilter::TRACE
622        } else {
623            env_filter.max_level_hint().unwrap_or(LevelFilter::TRACE)
624        };
625        let max_event_level = Arc::new(std::sync::atomic::AtomicU8::new(level_filter_to_u8(
626            max_event_level_seed,
627        )));
628        let (log_filter, reload_handle) = reload::Layer::new(env_filter);
629        let log_filter_handle = FilterHandle {
630            reload: reload_handle,
631            max_event_level: if config.enable_test_layer {
632                None
633            } else {
634                Some(max_event_level.clone())
635            },
636        };
637
638        // Separate span level filter.
639        // This is a dumb filter for now - allows all spans that are below a given level.
640        // TODO: implement a sampling filter
641        let span_level = config
642            .span_level
643            .unwrap_or(LevelFilter::from_level(Level::INFO));
644        let span_filter = filter::filter_fn(move |metadata| {
645            metadata.is_span() && LevelFilter::from_level(*metadata.level()) <= span_level
646        });
647
648        let mut layers = Vec::new();
649
650        // tokio-console layer
651        // Please see https://docs.rs/console-subscriber/latest/console_subscriber/struct.Builder.html#configuration
652        // for environment vars/config options
653        if config.tokio_console {
654            layers.push(console_subscriber::spawn().boxed());
655        }
656
657        if let Some(registry) = config.prom_registry
658            && !config.disable_span_latency
659        {
660            let span_lat_layer = PrometheusSpanLatencyLayer::try_new(&registry, 15)
661                .expect("Could not initialize span latency layer");
662            layers.push(span_lat_layer.with_filter(span_filter.clone()).boxed());
663        }
664
665        let mut trace_filter_handle = None;
666        let mut file_output = CachedOpenFile::new::<&str>(None).unwrap();
667        let mut provider = None;
668        let sampler = SamplingFilter::new(config.sample_rate);
669        let service_name = env::var("OTEL_SERVICE_NAME").unwrap_or("sui-node".to_owned());
670
671        if config.enable_otlp_tracing {
672            let trace_file = env::var("TRACE_FILE").ok();
673            let mut otel_kv_vec = vec![opentelemetry::KeyValue::new(
674                "service.name",
675                service_name.clone(),
676            )];
677            if let Ok(namespace) = env::var("NAMESPACE") {
678                otel_kv_vec.push(opentelemetry::KeyValue::new("service.namespace", namespace));
679            }
680            if let Ok(hostname) = env::var("HOSTNAME") {
681                otel_kv_vec.push(opentelemetry::KeyValue::new("host", hostname));
682            }
683            if let Ok(network) = env::var("NETWORK") {
684                otel_kv_vec.push(opentelemetry::KeyValue::new("network", network));
685            }
686
687            let resource = Resource::new(otel_kv_vec);
688            let sampler = Sampler::ParentBased(Box::new(sampler.clone()));
689
690            // We can either do file output or OTLP, but not both. tracing-opentelemetry
691            // only supports a single tracer at a time.
692            let telemetry = if let Some(trace_file) = trace_file {
693                let exporter =
694                    FileExporter::new(Some(trace_file.into())).expect("Failed to create exporter");
695                file_output = exporter.cached_open_file.clone();
696                let processor = BatchSpanProcessor::builder(exporter, runtime::Tokio).build();
697
698                let p = TracerProvider::builder()
699                    .with_resource(resource)
700                    .with_sampler(sampler)
701                    .with_span_processor(processor)
702                    .build();
703
704                let tracer = p.tracer(service_name);
705                provider = Some(p);
706
707                tracing_opentelemetry::layer().with_tracer(tracer)
708            } else {
709                let endpoint = env::var("OTLP_ENDPOINT")
710                    .unwrap_or_else(|_| "http://localhost:4317".to_string());
711                let otlp_exporter = opentelemetry_otlp::SpanExporter::builder()
712                    .with_tonic()
713                    .with_endpoint(endpoint)
714                    .build()
715                    .unwrap();
716                let tracer_provider = opentelemetry_sdk::trace::TracerProvider::builder()
717                    .with_resource(resource)
718                    .with_sampler(sampler)
719                    .with_batch_exporter(otlp_exporter, runtime::Tokio)
720                    .build();
721                let tracer = tracer_provider.tracer(service_name);
722                tracing_opentelemetry::layer().with_tracer(tracer)
723            };
724
725            // Enable Trace Contexts for tying spans together
726            opentelemetry::global::set_text_map_propagator(
727                opentelemetry_sdk::propagation::TraceContextPropagator::new(),
728            );
729
730            let trace_env_filter = EnvFilter::try_from_env("TRACE_FILTER").unwrap();
731            let (trace_env_filter, reload_handle) = reload::Layer::new(trace_env_filter);
732            trace_filter_handle = Some(FilterHandle {
733                reload: reload_handle,
734                max_event_level: None,
735            });
736
737            layers.push(telemetry.with_filter(trace_env_filter).boxed());
738        }
739
740        let (nb_output, worker_guard) = get_output(config.log_file.clone());
741        // Flush guards for any per-target files opened below; kept alive in TelemetryGuards.
742        let mut file_guards: Vec<WorkerGuard> = Vec::new();
743        if config.json_log_output {
744            // Output to file or to stderr in a newline-delimited JSON format
745            let json_layer = fmt::layer()
746                .with_file(true)
747                .with_line_number(true)
748                .json()
749                .with_writer(nb_output)
750                .with_filter(log_filter)
751                .boxed();
752            layers.push(json_layer);
753        } else {
754            let with_ansi = config.log_file.is_none() && stderr().is_tty();
755
756            // Main human-readable layer — always emits everything permitted by the env
757            // filter (`RUST_LOG`).
758            let fmt_layer = fmt::layer()
759                .with_ansi(with_ansi)
760                .with_writer(nb_output.clone())
761                .with_filter(log_filter)
762                .boxed();
763            layers.push(fmt_layer);
764
765            if config.log_file.is_none() && stderr().is_tty() && !config.user_info_target.is_empty()
766            {
767                // Add another printer that prints unadorned info messages to stderr
768                let mut directives = String::from("none");
769                for target in config.user_info_target {
770                    directives.push_str(&format!(",{target}=info"));
771                }
772
773                let fmt_layer = fmt::layer()
774                    .with_ansi(config.log_file.is_none() && stderr().is_tty())
775                    .event_format(
776                        fmt::format()
777                            .without_time()
778                            .with_target(false)
779                            .with_level(false),
780                    )
781                    .with_writer(nb_output)
782                    .with_filter(EnvFilter::new(directives))
783                    .boxed();
784
785                layers.push(fmt_layer);
786            }
787        }
788
789        if !config.log_tails.is_empty() {
790            // One non-blocking writer per unique file, shared by that file's layers.
791            let mut file_writers: HashMap<PathBuf, NonBlocking> = HashMap::new();
792            for path in config.log_tails.iter().map(|t| &t.file) {
793                if !file_writers.contains_key(path) {
794                    let (writer, guard) = open_tail_file(path);
795                    file_writers.insert(path.clone(), writer);
796                    file_guards.push(guard);
797                }
798            }
799
800            // One layer per routed target: its format, written to its file.
801            for log_tail in &config.log_tails {
802                let writer = file_writers
803                    .get(&log_tail.file)
804                    .cloned()
805                    .expect("a writer was created above for every target's file");
806                // Target restriction (matches this target at any level) ANDed with an EnvFilter
807                // (built like the main one) so `RUST_LOG`'s per-target level is the binding gate.
808                let target_filter = filter::Targets::new()
809                    .with_target(log_tail.target.clone(), LevelFilter::TRACE)
810                    .and(
811                        EnvFilter::try_from_default_env()
812                            .unwrap_or_else(|_| EnvFilter::new(directives.clone())),
813                    );
814                let layer = match log_tail.format {
815                    LogFormat::Json => fmt::layer()
816                        .with_file(true)
817                        .with_line_number(true)
818                        .json()
819                        .with_writer(writer)
820                        .with_filter(target_filter)
821                        .boxed(),
822                    LogFormat::Text => fmt::layer()
823                        .with_ansi(false)
824                        .with_writer(writer)
825                        .with_filter(target_filter)
826                        .boxed(),
827                };
828                layers.push(layer);
829            }
830        }
831
832        if config.enable_error_layer {
833            layers.push(ErrorLayer::new(Pretty::default()).boxed())
834        }
835
836        let test_layer = if config.enable_test_layer {
837            let test_layer = TestLayer::new();
838            layers.push(test_layer.clone().boxed());
839            Some(test_layer)
840        } else {
841            None
842        };
843
844        // Global level filter: rejects span callsites above span_level and event
845        // callsites above the env filter's max level at registration time, preventing
846        // the Registry from dispatching callsites that every per-layer filter would
847        // immediately discard.
848        //
849        // Must be stacked on top of `layers` via `.with()` rather than pushed into the
850        // Vec. `Vec<Layer>::register_callsite` returns the most permissive Interest
851        // across its layers, so a `never()` from this filter would be overridden by
852        // any layer (e.g. fmt+EnvFilter) returning `sometimes()`. As an outer
853        // `Layered`, `pick_interest` short-circuits to `never()` and the inner stack
854        // is never consulted.
855        let global_filter = GlobalLevelFilter {
856            max_span_level: span_level,
857            max_event_level,
858        };
859        let subscriber = tracing_subscriber::registry()
860            .with(layers)
861            .with(global_filter);
862        let subscriber_guard = if config.set_global_default {
863            tracing::subscriber::set_global_default(subscriber)
864                .expect("unable to initialize tracing subscriber");
865            None
866        } else {
867            Some(tracing::subscriber::set_default(subscriber))
868        };
869
870        if config.panic_hook {
871            set_panic_hook(config.crash_on_panic);
872        }
873
874        // The guard must be returned and kept in the main fn of the app, as when it's dropped then the output
875        // gets flushed and closed. If this is dropped too early then no output will appear!
876        let guards = TelemetryGuards::new(
877            config_clone,
878            worker_guard,
879            file_guards,
880            provider,
881            subscriber_guard,
882        );
883
884        (
885            guards,
886            TracingHandle {
887                log: log_filter_handle,
888                trace: trace_filter_handle,
889                file_output,
890                test_layer,
891                sampler,
892            },
893        )
894    }
895}
896
897// Like Sampler::TraceIdRatioBased, but can be updated at runtime
898#[derive(Debug, Clone)]
899struct SamplingFilter {
900    // Sampling filter needs to be fast, so we avoid a mutex.
901    sample_rate: Arc<AtomicF64>,
902}
903
904impl SamplingFilter {
905    fn new(sample_rate: f64) -> Self {
906        SamplingFilter {
907            sample_rate: Arc::new(AtomicF64::new(Self::clamp(sample_rate))),
908        }
909    }
910
911    fn clamp(sample_rate: f64) -> f64 {
912        // clamp sample rate to between 0.0001 and 1.0
913        sample_rate.clamp(0.0001, 1.0)
914    }
915
916    fn update_sampling_rate(&self, sample_rate: f64) {
917        // clamp sample rate to between 0.0001 and 1.0
918        let sample_rate = Self::clamp(sample_rate);
919        self.sample_rate.store(sample_rate, Ordering::Relaxed);
920    }
921}
922
923impl ShouldSample for SamplingFilter {
924    fn should_sample(
925        &self,
926        parent_context: Option<&Context>,
927        trace_id: TraceId,
928        name: &str,
929        span_kind: &SpanKind,
930        attributes: &[KeyValue],
931        links: &[Link],
932    ) -> SamplingResult {
933        let sample_rate = self.sample_rate.load(Ordering::Relaxed);
934        let sampler = Sampler::TraceIdRatioBased(sample_rate);
935
936        sampler.should_sample(parent_context, trace_id, name, span_kind, attributes, links)
937    }
938}
939
940/// Globally set a tracing subscriber suitable for testing environments
941pub fn init_for_testing() {
942    static LOGGER: Lazy<()> = Lazy::new(|| {
943        let subscriber = ::tracing_subscriber::FmtSubscriber::builder()
944            .with_env_filter(
945                EnvFilter::builder()
946                    .with_default_directive(LevelFilter::INFO.into())
947                    .from_env_lossy(),
948            )
949            .with_file(true)
950            .with_line_number(true)
951            .with_test_writer()
952            .finish();
953        ::tracing::subscriber::set_global_default(subscriber)
954            .expect("unable to initialize logging for tests");
955    });
956
957    Lazy::force(&LOGGER);
958}
959
960#[cfg(test)]
961mod tests {
962    use super::*;
963    use prometheus::proto::MetricType;
964    use std::time::Duration;
965    use tracing::{debug, debug_span, info, trace_span, warn};
966
967    #[test]
968    #[should_panic]
969    fn test_telemetry_init() {
970        let registry = prometheus::Registry::new();
971        // Default logging level is INFO, but here we set the span level to DEBUG.  TRACE spans should be ignored.
972        let config = TelemetryConfig::new()
973            .with_span_level(Level::DEBUG)
974            .with_prom_registry(&registry);
975        let _guard = config.init();
976
977        info!(a = 1, "This will be INFO.");
978        // Spans are debug level or below, so they won't be printed out either.  However latencies
979        // should be recorded for at least one span
980        debug_span!("yo span yo").in_scope(|| {
981            // This debug log will not print out, log level set to INFO by default
982            debug!(a = 2, "This will be DEBUG.");
983            std::thread::sleep(Duration::from_millis(100));
984            warn!(a = 3, "This will be WARNING.");
985        });
986
987        // This span won't be enabled
988        trace_span!("this span should not be created").in_scope(|| {
989            info!("This log appears, but surrounding span is not created");
990            std::thread::sleep(Duration::from_millis(100));
991        });
992
993        let metrics = registry.gather();
994        // There should be 1 metricFamily and 1 metric
995        assert_eq!(metrics.len(), 1);
996        assert_eq!(metrics[0].name(), "tracing_span_latencies");
997        assert_eq!(metrics[0].get_field_type(), MetricType::HISTOGRAM);
998        let inner = metrics[0].get_metric();
999        assert_eq!(inner.len(), 1);
1000        let labels = inner[0].get_label();
1001        assert_eq!(labels.len(), 1);
1002        assert_eq!(labels[0].name(), "span_name");
1003        assert_eq!(labels[0].value(), "yo span yo");
1004
1005        panic!("This should cause error logs to be printed out!");
1006    }
1007
1008    // Both the following tests should be able to "race" to initialize logging without causing a
1009    // panic
1010    #[test]
1011    fn testing_logger_1() {
1012        init_for_testing();
1013    }
1014
1015    #[test]
1016    fn testing_logger_2() {
1017        init_for_testing();
1018    }
1019
1020    #[test]
1021    fn with_log_tail_appends() {
1022        // Format is inferred from the file extension.
1023        let config = TelemetryConfig::new()
1024            .with_log_tail("graphql_request", "/var/log/x.ndjson")
1025            .with_log_tail("foo", "/var/log/foo.log");
1026        assert_eq!(config.log_tails.len(), 2);
1027        assert_eq!(config.log_tails[0].target, "graphql_request");
1028        assert_eq!(config.log_tails[0].format, LogFormat::Json);
1029        assert_eq!(config.log_tails[0].file, PathBuf::from("/var/log/x.ndjson"));
1030        assert_eq!(config.log_tails[1].target, "foo");
1031        assert_eq!(config.log_tails[1].format, LogFormat::Text);
1032        assert_eq!(config.log_tails[1].file, PathBuf::from("/var/log/foo.log"));
1033    }
1034
1035    #[test]
1036    fn parse_log_tails_infers_format_from_extension() {
1037        // `target=file`, comma-separated, with surrounding whitespace; the file extension
1038        // selects the format.
1039        let t = parse_log_tails(
1040            "a=/var/log/a.jsonl, b=/var/log/b.ndjson , c=/var/log/c.log, d=/var/log/d.JSONL, e=/var/log/e.json",
1041        );
1042        assert_eq!(t.len(), 5);
1043        let got: Vec<_> = t
1044            .iter()
1045            .map(|lt| (&*lt.target, lt.format, lt.file.clone()))
1046            .collect();
1047        assert_eq!(
1048            got,
1049            vec![
1050                ("a", LogFormat::Json, PathBuf::from("/var/log/a.jsonl")),
1051                ("b", LogFormat::Json, PathBuf::from("/var/log/b.ndjson")),
1052                ("c", LogFormat::Text, PathBuf::from("/var/log/c.log")),
1053                // Extension match is case-insensitive.
1054                ("d", LogFormat::Json, PathBuf::from("/var/log/d.JSONL")),
1055                // `.json` is a single JSON document, not newline-delimited → text.
1056                ("e", LogFormat::Text, PathBuf::from("/var/log/e.json")),
1057            ]
1058        );
1059
1060        // Empty / whitespace-only entries are skipped (they are absent, not malformed).
1061        assert!(parse_log_tails("").is_empty());
1062        assert!(parse_log_tails("  ,  , ").is_empty());
1063    }
1064
1065    #[test]
1066    #[should_panic(expected = "invalid RUST_LOG_TAILS entry")]
1067    fn parse_log_tails_panics_without_file() {
1068        // A non-empty entry without a `=file` is a misconfiguration → hard-fail init.
1069        let _ = parse_log_tails("graphql_request");
1070    }
1071
1072    #[test]
1073    #[should_panic(expected = "invalid RUST_LOG_TAILS entry")]
1074    fn parse_log_tails_panics_on_empty_file() {
1075        let _ = parse_log_tails("a=");
1076    }
1077
1078    #[test]
1079    #[should_panic(expected = "invalid RUST_LOG_TAILS entry")]
1080    fn parse_log_tails_panics_on_empty_target() {
1081        let _ = parse_log_tails("=/var/log/x.log");
1082    }
1083
1084    #[test]
1085    #[should_panic(expected = "invalid RUST_LOG_TAILS entry")]
1086    fn parse_log_tails_panics_on_one_bad_entry_among_valid() {
1087        // A single malformed entry fails the whole parse, even alongside valid ones.
1088        let _ = parse_log_tails("bare, ok=/var/log/ok.jsonl");
1089    }
1090
1091    #[test]
1092    #[should_panic(expected = "cannot create directory for RUST_LOG_TAILS file")]
1093    fn open_tail_file_panics_on_uncreatable_dir() {
1094        // `/dev/null` is not a directory, so create_dir_all under it fails deterministically —
1095        // a bad RUST_LOG_TAILS file path must hard-fail init rather than silently degrade.
1096        let _ = open_tail_file(Path::new("/dev/null/x/test.log"));
1097    }
1098}