Merge pull request #662 from jbr/only-log-once

Only run the log middleware once per request

src/log/middleware.rs

@@ -3,7 +3,9 @@ use crate::{Middleware, Next, Request};
 
 /// Log all incoming requests and responses.
 ///
-/// This middleware is enabled by default in Tide.
+/// This middleware is enabled by default in Tide. In the case of
+/// nested applications, this middleware will only run once for each
+/// request.
 ///
 /// # Examples
 ///
@@ -16,6 +18,8 @@ pub struct LogMiddleware {
  _priv: (),
 }
 
+struct LogMiddlewareHasBeenRun;
+
 impl LogMiddleware {
  /// Create a new instance of `LogMiddleware`.
  #[must_use]
@@ -26,17 +30,22 @@ impl LogMiddleware {
  /// Log a request and a response.
  async fn log<'a, State: Clone + Send + Sync + 'static>(
  &'a self,
- ctx: Request<State>,
+ mut req: Request<State>,
  next: Next<'a, State>,
  ) -> crate::Result {
- let path = ctx.url().path().to_owned();
- let method = ctx.method().to_string();
+ if req.ext::<LogMiddlewareHasBeenRun>().is_some() {
+ return Ok(next.run(req).await);
+ }
+ req.set_ext(LogMiddlewareHasBeenRun);
+
+ let path = req.url().path().to_owned();
+ let method = req.method().to_string();
  log::info!("<-- Request received", {
  method: method,
  path: path,
  });
  let start = std::time::Instant::now();
- let response = next.run(ctx).await;
+ let response = next.run(req).await;
  let status = response.status();
  if status.is_server_error() {
  if let Some(error) = response.error() {

tests/log.rs

@@ -2,11 +2,16 @@ use async_std::prelude::*;
 use std::time::Duration;
 
 mod test_utils;
+use test_utils::ServerTestingExt;
 
 #[async_std::test]
-async fn start_server_log() {
+async fn log_tests() {
  let mut logger = logtest::start();
+ test_server_listen(&mut logger).await;
+ test_only_log_once(&mut logger).await;
+}
 
+async fn test_server_listen(logger: &mut logtest::Logger) {
  let port = test_utils::find_port().await;
  let app = tide::new();
  let res = app
@@ -23,3 +28,31 @@ async fn start_server_log() {
  format!("Server listening on http://[::1]:{}", port)
  );
 }
+
+async fn test_only_log_once(logger: &mut logtest::Logger) {
+ let mut app = tide::new();
+ app.at("/").nest({
+ let mut app = tide::new();
+ app.at("/").get(|_| async { Ok("nested") });
+ app
+ });
+ app.get("/").await;
+
+ let entries: Vec<_> = logger.collect();
+
+ assert_eq!(
+ 1,
+ entries
+ .iter()
+ .filter(|entry| entry.args() == "<-- Request received")
+ .count()
+ );
+
+ assert_eq!(
+ 1,
+ entries
+ .iter()
+ .filter(|entry| entry.args() == "--> Response sent")
+ .count()
+ );
+}