Merge pull request #148 from connorsmith256/feat/add-log-level

Feat/add log level

rpc-rs/Cargo.toml

@@ -1,6 +1,6 @@
 [package]
 name = "wasmbus-rpc"
-version = "0.12.0"
+version = "0.13.0"
 authors = [ "wasmcloud Team" ]
 license = "Apache-2.0"
 description = "Runtime library for actors and capability providers"

rpc-rs/codegen.toml

@@ -2,7 +2,7 @@
 
 [[models]]
 # wasmbus-core
-url = "https://cdn.jsdelivr.net/gh/wasmcloud/interfaces@2c89bb706c6f2785a926dcde78ebc6a511a33206/core/wasmcloud-core.smithy"
+url = "https://cdn.jsdelivr.net/gh/wasmcloud/interfaces/core/wasmcloud-core.smithy"
 
 [[models]]
 # wasmbus-model

rpc-rs/src/provider.rs

@@ -201,6 +201,10 @@ impl HostBridge {
         &self.host_data.lattice_rpc_prefix
     }
 
+    pub fn log_level(&self) -> Option<&str> {
+        self.host_data.log_level.as_deref()
+    }
+
     /// Returns the configuration values as a json string.
     /// Caller may need to deserialize, and may want to cache the results
     /// if the data is large or this method is called frequently.

rpc-rs/src/provider_main.rs

@@ -7,18 +7,22 @@ use std::str::FromStr;
 use once_cell::sync::OnceCell;
 #[cfg(feature = "otel")]
 use opentelemetry::sdk::{
-    trace::{self, IdGenerator, Sampler},
+    trace::{self, IdGenerator, Sampler, Tracer},
     Resource,
 };
 #[cfg(feature = "otel")]
+use opentelemetry::trace::TraceError;
+#[cfg(feature = "otel")]
 use opentelemetry_otlp::{Protocol, WithExportConfig};
 use tracing::{Event, Subscriber};
+use tracing_subscriber::fmt::format::{DefaultFields, JsonFields};
 use tracing_subscriber::fmt::{
     format::{Format, Full, Json, Writer},
     time::SystemTime,
     FmtContext, FormatEvent, FormatFields,
 };
 use tracing_subscriber::{
+    filter::LevelFilter,
     layer::{Layered, SubscriberExt},
     registry::LookupSpan,
     EnvFilter, Layer, Registry,
@@ -134,6 +138,7 @@ where
     configure_tracing(
         friendly_name.unwrap_or_else(|| host_data.provider_key.clone()),
         host_data.structured_logging,
+        host_data.log_level.clone(),
     );
 
     let (shutdown_tx, mut shutdown_rx) = tokio::sync::broadcast::channel::<bool>(1);
@@ -290,90 +295,164 @@ where
 }
 
 #[cfg(not(feature = "otel"))]
-fn configure_tracing(_: String, structured_logging_enabled: bool) {
-    let filter = get_env_filter();
-    let layer = get_log_layer(structured_logging_enabled);
-    let subscriber = tracing_subscriber::Registry::default().with(filter).with(layer);
-    if let Err(e) = tracing::subscriber::set_global_default(subscriber) {
-        eprintln!("Logger was already created by provider, continuing: {e}");
+fn configure_tracing(
+    _: String,
+    structured_logging_enabled: bool,
+    log_level_override: Option<String>,
+) {
+    let base_reg = tracing_subscriber::Registry::default();
+    let level_filter = get_level_filter(log_level_override);
+
+    let res = if structured_logging_enabled {
+        let log_layer = get_json_log_layer();
+        let layered = base_reg.with(level_filter).with(log_layer);
+        tracing::subscriber::set_global_default(layered)
+    } else {
+        let log_layer = get_default_log_layer();
+        let layered = base_reg.with(level_filter).with(log_layer);
+        tracing::subscriber::set_global_default(layered)
+    };
+
+    if let Err(err) = res {
+        eprintln!(
+            "Logger/tracer was already created by provider, continuing: {}",
+            err
+        );
     }
 }
 
 #[cfg(feature = "otel")]
-fn configure_tracing(provider_name: String, structured_logging_enabled: bool) {
-    let env_filter_layer = get_env_filter();
-    let log_layer = get_log_layer(structured_logging_enabled);
-    let subscriber = tracing_subscriber::Registry::default()
-        .with(env_filter_layer)
-        .with(log_layer);
-    let res = if std::env::var_os("OTEL_TRACES_EXPORTER")
+fn configure_tracing(
+    provider_name: String,
+    structured_logging_enabled: bool,
+    log_level_override: Option<String>,
+) {
+    let base_reg = tracing_subscriber::Registry::default();
+    let level_filter = get_level_filter(log_level_override);
+
+    let maybe_tracer = (std::env::var_os("OTEL_TRACES_EXPORTER")
         .unwrap_or_default()
         .to_ascii_lowercase()
-        == "otlp"
-    {
-        let mut tracing_endpoint = std::env::var("OTEL_EXPORTER_OTLP_ENDPOINT")
-            .unwrap_or_else(|_| format!("http://localhost:55681{}", TRACING_PATH));
-        if !tracing_endpoint.ends_with(TRACING_PATH) {
-            tracing_endpoint.push_str(TRACING_PATH);
+        == "otlp")
+        .then(|| get_tracer(provider_name));
+
+    let res = match (maybe_tracer, structured_logging_enabled) {
+        (Some(Ok(t)), true) => {
+            let log_layer = get_json_log_layer();
+            let tracing_layer = tracing_opentelemetry::layer().with_tracer(t);
+            let layered = base_reg.with(level_filter).with(log_layer).with(tracing_layer);
+            tracing::subscriber::set_global_default(layered)
         }
-        match opentelemetry_otlp::new_pipeline()
-            .tracing()
-            .with_exporter(
-                opentelemetry_otlp::new_exporter()
-                    .http()
-                    .with_endpoint(tracing_endpoint)
-                    .with_protocol(Protocol::HttpBinary),
-            )
-            .with_trace_config(
-                trace::config()
-                    .with_sampler(Sampler::AlwaysOn)
-                    .with_id_generator(IdGenerator::default())
-                    .with_max_events_per_span(64)
-                    .with_max_attributes_per_span(16)
-                    .with_max_events_per_span(16)
-                    .with_resource(Resource::new(vec![opentelemetry::KeyValue::new(
-                        "service.name",
-                        provider_name,
-                    )])),
-            )
-            .install_batch(opentelemetry::runtime::Tokio)
-        {
-            Ok(t) => tracing::subscriber::set_global_default(
-                subscriber.with(tracing_opentelemetry::layer().with_tracer(t)),
-            ),
-            Err(e) => {
-                eprintln!(
-                    "Unable to configure OTEL tracing, defaulting to logging only: {:?}",
-                    e
-                );
-                tracing::subscriber::set_global_default(subscriber)
-            }
+        (Some(Ok(t)), false) => {
+            let log_layer = get_default_log_layer();
+            let tracing_layer = tracing_opentelemetry::layer().with_tracer(t);
+            let layered = base_reg.with(level_filter).with(log_layer).with(tracing_layer);
+            tracing::subscriber::set_global_default(layered)
+        }
+        (Some(Err(err)), true) => {
+            eprintln!("Unable to configure OTEL tracing, defaulting to logging only: {err:?}");
+            let log_layer = get_json_log_layer();
+            let layered = base_reg.with(level_filter).with(log_layer);
+            tracing::subscriber::set_global_default(layered)
+        }
+        (Some(Err(err)), false) => {
+            eprintln!("Unable to configure OTEL tracing, defaulting to logging only: {err:?}");
+            let log_layer = get_default_log_layer();
+            let layered = base_reg.with(level_filter).with(log_layer);
+            tracing::subscriber::set_global_default(layered)
+        }
+        (None, true) => {
+            let log_layer = get_json_log_layer();
+            let layered = base_reg.with(level_filter).with(log_layer);
+            tracing::subscriber::set_global_default(layered)
+        }
+        (None, false) => {
+            let log_layer = get_default_log_layer();
+            let layered = base_reg.with(level_filter).with(log_layer);
+            tracing::subscriber::set_global_default(layered)
         }
-    } else {
-        tracing::subscriber::set_global_default(subscriber)
     };
-    if let Err(e) = res {
+
+    if let Err(err) = res {
         eprintln!(
             "Logger/tracer was already created by provider, continuing: {}",
-            e
+            err
         );
     }
 }
 
-fn get_log_layer(structured_logging_enabled: bool) -> impl Layer<Layered<EnvFilter, Registry>> {
-    let log_layer = tracing_subscriber::fmt::layer()
-        .with_writer(LockedWriter::new)
-        .with_ansi(atty::is(atty::Stream::Stderr));
-    if structured_logging_enabled {
-        log_layer.event_format(JsonOrNot::Json(Format::default().json()))
-    } else {
-        log_layer.event_format(JsonOrNot::Not(Format::default()))
+#[cfg(feature = "otel")]
+fn get_tracer(provider_name: String) -> Result<Tracer, TraceError> {
+    let mut tracing_endpoint = std::env::var("OTEL_EXPORTER_OTLP_ENDPOINT")
+        .unwrap_or_else(|_| format!("http://localhost:55681{}", TRACING_PATH));
+    if !tracing_endpoint.ends_with(TRACING_PATH) {
+        tracing_endpoint.push_str(TRACING_PATH);
     }
+    opentelemetry_otlp::new_pipeline()
+        .tracing()
+        .with_exporter(
+            opentelemetry_otlp::new_exporter()
+                .http()
+                .with_endpoint(tracing_endpoint)
+                .with_protocol(Protocol::HttpBinary),
+        )
+        .with_trace_config(
+            trace::config()
+                .with_sampler(Sampler::AlwaysOn)
+                .with_id_generator(IdGenerator::default())
+                .with_max_events_per_span(64)
+                .with_max_attributes_per_span(16)
+                .with_max_events_per_span(16)
+                .with_resource(Resource::new(vec![opentelemetry::KeyValue::new(
+                    "service.name",
+                    provider_name,
+                )])),
+        )
+        .install_batch(opentelemetry::runtime::Tokio)
 }
 
-fn get_env_filter() -> EnvFilter {
-    EnvFilter::try_from_default_env().unwrap_or_else(|e| {
-        eprintln!("RUST_LOG was not set or the given directive was invalid: {e:?}\nDefaulting logger to `info` level");
-        EnvFilter::default().add_directive(tracing_subscriber::filter::LevelFilter::INFO.into())
-    })
+fn get_default_log_layer() -> impl Layer<Layered<EnvFilter, Registry>> {
+    tracing_subscriber::fmt::layer()
+        .with_writer(LockedWriter::new)
+        .with_ansi(atty::is(atty::Stream::Stderr))
+        .event_format(JsonOrNot::Not(Format::default()))
+        .fmt_fields(DefaultFields::new())
+}
+
+fn get_json_log_layer() -> impl Layer<Layered<EnvFilter, Registry>> {
+    tracing_subscriber::fmt::layer()
+        .with_writer(LockedWriter::new)
+        .with_ansi(atty::is(atty::Stream::Stderr))
+        .event_format(JsonOrNot::Json(Format::default().json()))
+        .fmt_fields(JsonFields::new())
+}
+
+fn get_level_filter(log_level_override: Option<String>) -> EnvFilter {
+    let builder = EnvFilter::builder().with_default_directive(LevelFilter::INFO.into());
+
+    let rust_log = std::env::var("RUST_LOG");
+    let directives = if let Some(log_level) = log_level_override {
+        if rust_log.is_ok() {
+            eprintln!("Log level is now provided by the host. RUST_LOG will be ignored");
+        }
+        log_level
+    } else if let Ok(log_level) = rust_log {
+        // fallback to env var if host didn't provide level
+        log_level
+    } else {
+        // default
+        eprintln!("Log level was not set by host or environment variable.\nDefaulting logger to `info` level");
+        "".to_string()
+    };
+
+    match builder.parse(directives) {
+        Ok(filter) => filter,
+        Err(err) => {
+            eprintln!("Failed to parse log level: {err:?}\nDefaulting logger to `info` level");
+            // NOTE: we considered using parse_lossy here and decided against it, since parse_lossy
+            // will use partial successes from the parse. Instead, we want to give the user a clear
+            // sign that their log level config couldn't parse
+            EnvFilter::default().add_directive(tracing_subscriber::filter::LevelFilter::INFO.into())
+        }
+    }
 }