test: (wip) adapt unit tests to use tracing output

Author: rami3l

src/test.rs

@@ -224,71 +224,113 @@ where
     f(&rustup_home)
 }
 
-#[cfg(feature = "otel")]
 use once_cell::sync::Lazy;
 
 /// A tokio runtime for the sync tests, permitting the use of tracing. This is
 /// never shutdown, instead it is just dropped at end of process.
-#[cfg(feature = "otel")]
 static TRACE_RUNTIME: Lazy<tokio::runtime::Runtime> =
     Lazy::new(|| tokio::runtime::Runtime::new().unwrap());
-/// A tracer for the tests.
+
 #[cfg(feature = "otel")]
-static TRACER: Lazy<opentelemetry_sdk::trace::Tracer> = Lazy::new(|| {
-    use std::time::Duration;
-
-    use opentelemetry::{global, KeyValue};
-    use opentelemetry_otlp::WithExportConfig;
-    use opentelemetry_sdk::{
-        propagation::TraceContextPropagator,
-        trace::{self, Sampler},
-        Resource,
-    };
+type Tracer = opentelemetry_sdk::trace::Tracer;
+
+#[cfg(not(feature = "otel"))]
+type Tracer = ();
+
+/// A tracer for the tests.
+static TRACER: Lazy<Tracer> = Lazy::new(|| {
+    use crate::currentprocess::{filesource::StderrSource, varsource::VarSource};
+
     use tokio::runtime::Handle;
-    use tracing_subscriber::{layer::SubscriberExt, EnvFilter, Registry};
+    use tracing_subscriber::{fmt, layer::SubscriberExt, EnvFilter, Layer, Registry};
 
     // Use the current runtime, or the sync test runtime otherwise.
     let handle = match Handle::try_current() {
         Ok(handle) => handle,
         Err(_) => TRACE_RUNTIME.handle().clone(),
     };
+
     let _guard = handle.enter();
+    // TODO: However this will not be set before running the actual test. What now?
+    let curr_process = currentprocess::process();
+    let has_ansi = curr_process.stderr().is_a_tty();
 
-    let tracer = opentelemetry_otlp::new_pipeline()
-        .tracing()
-        .with_exporter(
-            opentelemetry_otlp::new_exporter()
-                .tonic()
-                .with_timeout(Duration::from_secs(3)),
-        )
-        .with_trace_config(
-            trace::config()
-                .with_sampler(Sampler::AlwaysOn)
-                .with_resource(Resource::new(vec![KeyValue::new("service.name", "rustup")])),
-        )
-        .install_batch(opentelemetry_sdk::runtime::Tokio)
-        .unwrap();
-
-    global::set_text_map_propagator(TraceContextPropagator::new());
-    let env_filter = EnvFilter::try_from_default_env().unwrap_or(EnvFilter::new("INFO"));
-    let telemetry = tracing_opentelemetry::layer().with_tracer(tracer.clone());
-    let subscriber = Registry::default().with(env_filter).with(telemetry);
+    #[cfg(feature = "otel")]
+    let tracer = {
+        use std::time::Duration;
+
+        use opentelemetry::KeyValue;
+        use opentelemetry_otlp::WithExportConfig;
+        use opentelemetry_sdk::{
+            trace::{self, Sampler},
+            Resource,
+        };
+        opentelemetry_otlp::new_pipeline()
+            .tracing()
+            .with_exporter(
+                opentelemetry_otlp::new_exporter()
+                    .tonic()
+                    .with_timeout(Duration::from_secs(3)),
+            )
+            .with_trace_config(
+                trace::config()
+                    .with_sampler(Sampler::AlwaysOn)
+                    .with_resource(Resource::new(vec![KeyValue::new("service.name", "rustup")])),
+            )
+            .install_batch(opentelemetry_sdk::runtime::Tokio)
+            .unwrap()
+    };
+    #[cfg(feature = "otel")]
+    let telemetry = {
+        use opentelemetry::global;
+        use opentelemetry_sdk::propagation::TraceContextPropagator;
+
+        global::set_text_map_propagator(TraceContextPropagator::new());
+
+        let env_filter = EnvFilter::try_from_default_env().unwrap_or(EnvFilter::new("INFO"));
+        tracing_opentelemetry::layer()
+            .with_tracer(tracer.clone())
+            .with_filter(env_filter)
+    };
+    let console_logger = {
+        let is_verbose = curr_process.var_os("RUST_LOG").is_some();
+        let logger = fmt::layer()
+            .with_writer(move || curr_process.stderr())
+            .with_ansi(has_ansi);
+        if is_verbose {
+            let env_filter =
+                EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("INFO"));
+            logger.compact().with_filter(env_filter).boxed()
+        } else {
+            // Receive log lines from Rustup only.
+            let env_filter = EnvFilter::new("rustup=DEBUG");
+            logger
+                .event_format(crate::cli::log::EventFormatter)
+                .with_filter(env_filter)
+                .boxed()
+        }
+    };
+    let subscriber = {
+        #[cfg(feature = "otel")]
+        {
+            Registry::default().with(console_logger).with(telemetry)
+        }
+        #[cfg(not(feature = "otel"))]
+        {
+            Registry::default().with(console_logger)
+        }
+    };
     tracing::subscriber::set_global_default(subscriber).unwrap();
+    #[cfg(feature = "otel")]
     tracer
 });
 
 pub fn before_test() {
-    #[cfg(feature = "otel")]
-    {
-        Lazy::force(&TRACER);
-    }
+    Lazy::force(&TRACER);
 }
 
 pub async fn before_test_async() {
-    #[cfg(feature = "otel")]
-    {
-        Lazy::force(&TRACER);
-    }
+    Lazy::force(&TRACER);
 }
 
 pub fn after_test() {