add logs to middleware (#1263)

nuclia · Aug 28, 2023 · 1d28524 · 1d28524 · github-actions · Aug 28, 2023
1 parent b0d041e
commit 1d28524
Show file tree

Hide file tree

Showing 2 changed files with 8 additions and 3 deletions.
diff --git a/nucliadb_node/src/grpc/middleware/debug.rs b/nucliadb_node/src/grpc/middleware/debug.rs
@@ -56,6 +56,7 @@ where
     }
 
     fn call(&mut self, req: hyper::Request<Body>) -> Self::Future {
+        debug!("debug middleware starts");
         // This is necessary because tonic internally uses `tower::buffer::Buffer`.
         // See https://github.com/tower-rs/tower/issues/547#issuecomment-767629149
         // for details on why this is necessary
@@ -69,7 +70,7 @@ where
         let name = req.uri().path();
         let method = name.split('/').last().unwrap_or(name).to_string();
 
-        Box::pin(async move {
+        let pin = Box::pin(async move {
             debug!("gRPC call {method} starts");
             let response = inner.call(req).await;
             match response {
@@ -82,6 +83,8 @@ where
                     Err(error)
                 }
             }
-        })
+        });
+        debug!("debug middleware ends");
+        pin
     }
 }
diff --git a/nucliadb_node/src/grpc/middleware/telemetry.rs b/nucliadb_node/src/grpc/middleware/telemetry.rs
@@ -22,7 +22,7 @@ use std::task::{Context, Poll};
 use futures::future::BoxFuture;
 use hyper::Body;
 use nucliadb_core::tracing::instrument::Instrument;
-use nucliadb_core::tracing::{info_span, warn};
+use nucliadb_core::tracing::{debug, info_span, warn};
 use opentelemetry::propagation::Extractor;
 use tonic::body::BoxBody;
 use tower::{Layer, Service};
@@ -60,6 +60,7 @@ where
     }
 
     fn call(&mut self, req: hyper::Request<Body>) -> Self::Future {
+        debug!("telemetry middleware starts");
         // This is necessary because tonic internally uses `tower::buffer::Buffer`.
         // See https://github.com/tower-rs/tower/issues/547#issuecomment-767629149
         // for details on why this is necessary
@@ -96,6 +97,7 @@ where
         span.set_parent(parent_context);
 
         let fut = inner.call(req).instrument(span);
+        debug!("telemetry middleware ends");
         Box::pin(fut)
     }
 }
Benchmark suite	Current: `1d28524`	Previous: `a40981d`	Ratio
`nucliadb/tests/benchmarks/test_search.py::test_search_returns_labels`	`82.44085876942842` iter/sec (`stddev: 0.00018207693262379144`)	`60.779932309336715` iter/sec (`stddev: 0.0019119907918232523`)	`0.74`
`nucliadb/tests/benchmarks/test_search.py::test_search_relations`	`202.7620434534844` iter/sec (`stddev: 0.00014240491499395615`)	`182.57436721258293` iter/sec (`stddev: 0.0002220745559283828`)	`0.90`