openvmm_entry/
tracing_init.rs

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
// Copyright (c) Microsoft Corporation.
// Licensed under the MIT License.

use anyhow::Context as _;
use anyhow::anyhow;
use std::io::IsTerminal;
use tracing_subscriber::fmt::format::FmtSpan;
use tracing_subscriber::fmt::format::Format;
use tracing_subscriber::fmt::time::uptime;

/// Reads an environment variable, falling back to a legacy variable (replacing
/// "OPENVMM_" with "HVLITE_") if the original is not set.
fn legacy_openvmm_env(name: &str) -> Result<String, std::env::VarError> {
    std::env::var(name).or_else(|_| {
        std::env::var(format!(
            "HVLITE_{}",
            name.strip_prefix("OPENVMM_").unwrap_or(name)
        ))
    })
}

/// Enables tracing output to stderr.
pub fn enable_tracing() -> anyhow::Result<()> {
    use tracing_subscriber::fmt::writer::BoxMakeWriter;
    use tracing_subscriber::layer::SubscriberExt;
    use tracing_subscriber::util::SubscriberInitExt;

    // Enable tracing for paravisor_log by default since this is passed through
    // from the guest (but still allow it to be disabled via OPENVMM_LOG).
    let base = "paravisor_log=trace";
    let filter = if let Ok(filter) = legacy_openvmm_env("OPENVMM_LOG") {
        tracing_subscriber::EnvFilter::try_new(format!("{base},{filter}"))
            .context("invalid OPENVMM_LOG")?
    } else {
        tracing_subscriber::EnvFilter::default()
            .add_directive(tracing::metadata::LevelFilter::INFO.into())
            .add_directive(base.parse().unwrap())
    };

    if legacy_openvmm_env("OPENVMM_DISABLE_TRACING_RATELIMITS").is_ok_and(|v| !v.is_empty()) {
        tracelimit::disable_rate_limiting(true);
    }

    let is_terminal = std::io::stderr().is_terminal();
    let writer = if is_terminal {
        // Convert LF to CRLF in logs since the output terminal may be in raw mode.
        BoxMakeWriter::new(|| tracing_helpers::formatter::CrlfWriter::new(std::io::stderr()))
    } else {
        BoxMakeWriter::new(std::io::stderr)
    };

    let format = Format::default()
        .with_timer(uptime())
        .with_ansi(is_terminal);
    let fmt_layer = tracing_subscriber::fmt::layer()
        .event_format(format)
        .with_span_events(FmtSpan::NEW | FmtSpan::CLOSE)
        .fmt_fields(tracing_helpers::formatter::FieldFormatter)
        .log_internal_errors(true)
        .with_writer(writer);

    let sub = tracing_subscriber::Registry::default()
        .with(fmt_layer)
        .with(filter);

    // Enable an ETW layer on Windows.
    // TODO: include the process name and maybe a VM ID?
    #[cfg(windows)]
    let sub = sub.with(
        win_etw_tracing::TracelogSubscriber::new(
            winapi::shared::guiddef::GUID::from(
                "22bc55fe-2116-5adc-12fb-3fadfd7e360c"
                    .parse::<guid::Guid>()
                    .unwrap(),
            ),
            "Microsoft.HvLite",
        )
        .map_err(|e| anyhow!("failed to start ETW provider: {:?}", e))?,
    );

    sub.try_init()
        .map_err(|e| anyhow!(e).context("failed to enable tracing"))?;

    Ok(())
}