Merge branch 'kobi-improve-logging' into 'master'

feat(BOUN-893): some more labels, logging level See merge request dfinity-lab/public/ic!16407
dfinity · Dec 13, 2023 · a2fd0b8 · a2fd0b8
2 parents f28abc2 + 3c9fb1d
commit a2fd0b8
Show file tree

Hide file tree

Showing 5 changed files with 56 additions and 6 deletions.
diff --git a/rs/boundary_node/ic_boundary/src/cli.rs b/rs/boundary_node/ic_boundary/src/cli.rs
@@ -166,6 +166,9 @@ pub struct MonitoringConfig {
     /// The socket used to export metrics.
     #[clap(long, default_value = "127.0.0.1:9090")]
     pub metrics_addr: SocketAddr,
+    /// Maximum logging level
+    #[clap(long, default_value = "info")]
+    pub max_logging_level: tracing::Level,
 }
 
 #[derive(Args)]

diff --git a/rs/boundary_node/ic_boundary/src/core.rs b/rs/boundary_node/ic_boundary/src/core.rs
@@ -285,7 +285,11 @@ pub async fn main(cli: Cli) -> Result<(), Error> {
         cli.listen.http_port,
     ))
     .acceptor(DefaultAcceptor)
-    .serve(routers_http.clone().into_make_service());
+    .serve(
+        routers_http
+            .clone()
+            .into_make_service_with_connect_info::<SocketAddr>(),
+    );
 
     // HTTPS
     #[cfg(feature = "tls")]
@@ -294,7 +298,11 @@ pub async fn main(cli: Cli) -> Result<(), Error> {
         cli.listen.https_port,
     ))
     .acceptor(tls_acceptor.clone())
-    .serve(routers_https.clone().into_make_service());
+    .serve(
+        routers_https
+            .clone()
+            .into_make_service_with_connect_info::<SocketAddr>(),
+    );
 
     // Metrics
     let metrics_cache = Arc::new(RwLock::new(MetricsCache::new(METRICS_CACHE_CAPACITY)));

diff --git a/rs/boundary_node/ic_boundary/src/main.rs b/rs/boundary_node/ic_boundary/src/main.rs
@@ -34,13 +34,15 @@ async fn main() -> Result<(), Error> {
     // This line has to be in `main` not in `core` because (to quote the docs):
     // `Libraries should NOT call set_global_default()! That will cause conflicts when executables try to set them later.`
 
+    let cli = Cli::parse();
+
     tracing::subscriber::set_global_default(
         tracing_subscriber::fmt()
+            .with_max_level(cli.monitoring.max_logging_level)
             .json()
             .flatten_event(true)
             .finish(),
     )?;
 
-    let cli = Cli::parse();
     core::main(cli).await
 }
diff --git a/rs/boundary_node/ic_boundary/src/metrics.rs b/rs/boundary_node/ic_boundary/src/metrics.rs
@@ -1,4 +1,5 @@
 use std::{
+    net::SocketAddr,
     pin::Pin,
     sync::{atomic::AtomicBool, Arc},
     time::Instant,
@@ -9,15 +10,17 @@ use arc_swap::ArcSwapOption;
 use async_trait::async_trait;
 use axum::{
     body::Body,
-    extract::State,
+    extract::{ConnectInfo, RawQuery, State},
     http::Request,
     middleware::Next,
     response::{IntoResponse, Response},
     Extension,
 };
 use bytes::Buf;
 use futures::task::{Context as FutContext, Poll};
-use http::header::{HeaderMap, HeaderValue, CONTENT_LENGTH, CONTENT_TYPE};
+use http::header::{
+    HeaderMap, HeaderValue, CONTENT_LENGTH, CONTENT_TYPE, HOST, ORIGIN, REFERER, USER_AGENT,
+};
 use http_body::Body as HttpBody;
 use ic_types::{messages::ReplicaHealthStatus, CanisterId};
 use jemalloc_ctl::{epoch, stats};
@@ -608,6 +611,9 @@ pub async fn metrics_middleware_status(
 // middleware to log and measure proxied requests
 pub async fn metrics_middleware(
     State(metric_params): State<HttpMetricParams>,
+    ConnectInfo(addr): ConnectInfo<SocketAddr>,
+    RawQuery(query_string): RawQuery,
+    headers: HeaderMap,
     Extension(request_id): Extension<RequestId>,
     request: Request<Body>,
     next: Next<Body>,
@@ -646,6 +652,13 @@ pub async fn metrics_middleware(
     let sender = ctx.sender.map(|x| x.to_string());
     let node_id = node.as_ref().map(|x| x.id.to_string());
     let subnet_id = node.as_ref().map(|x| x.subnet_id.to_string());
+    let ip_family = String::from({
+        if addr.is_ipv4() {
+            "IPv4"
+        } else {
+            "IPv6"
+        }
+    });
 
     let HttpMetricParams {
         action,
@@ -710,6 +723,19 @@ pub async fn metrics_middleware(
             .with_label_values(labels)
             .observe(response_size as f64);
 
+        let header_host = headers
+            .get(HOST)
+            .map(|v| v.to_str().unwrap_or("parsing_error"));
+        let header_origin = headers
+            .get(ORIGIN)
+            .map(|v| v.to_str().unwrap_or("parsing_error"));
+        let header_referer = headers
+            .get(REFERER)
+            .map(|v| v.to_str().unwrap_or("parsing_error"));
+        let header_user_agent = headers
+            .get(USER_AGENT)
+            .map(|v| v.to_str().unwrap_or("parsing_error"));
+
         info!(
             action,
             request_id,
@@ -734,6 +760,12 @@ pub async fn metrics_middleware(
             cache_bypass_reason = cache_bypass_reason.map(|x| x.to_string()),
             nonce_len = ctx.nonce.clone().map(|x| x.len()),
             arg_len = ctx.arg.clone().map(|x| x.len()),
+            ip_family,
+            query_string,
+            header_host,
+            header_origin,
+            header_referer,
+            header_user_agent,
         );
     };
 

diff --git a/rs/boundary_node/ic_boundary/src/routes/test.rs b/rs/boundary_node/ic_boundary/src/routes/test.rs
@@ -1,10 +1,14 @@
 use super::*;
 
-use std::sync::{Arc, Mutex};
+use std::{
+    net::SocketAddr,
+    sync::{Arc, Mutex},
+};
 
 use anyhow::Error;
 use axum::{
     body::Body,
+    extract::connect_info::MockConnectInfo,
     http::Request,
     middleware,
     response::IntoResponse,
@@ -350,6 +354,7 @@ async fn test_all_call_types() -> Result<(), Error> {
                 .layer(middleware::from_fn(pre_compression))
                 .set_x_request_id(MakeRequestUuid)
                 .propagate_x_request_id()
+                .layer(MockConnectInfo(SocketAddr::from(([0, 0, 0, 0], 1337))))
                 .layer(middleware::from_fn_with_state(
                     metric_params,
                     metrics_middleware,