Merge pull request #495 from http-rs/logger

init default logger

Author: yoshuawuyts

Cargo.toml

@@ -34,6 +34,7 @@ async-h1 = { version = "1.1.2", optional = true }
 async-sse = "2.1.0"
 async-std = { version = "1.4.0", features = ["unstable"] }
 cookie = { version = "0.12.0", features = ["percent-encode"]}
+femme = "2.0.1"
 http-types = "1.0.1"
 kv-log-macro = "1.0.4"
 mime = "0.3.14"
@@ -42,7 +43,6 @@ route-recognizer = "0.1.13"
 serde = "1.0.102"
 serde_json = "1.0.41"
 serde_qs = "0.5.0"
-femme = "1.3.0"
 
 [dev-dependencies]
 async-std = { version = "1.4.0", features = ["unstable", "attributes"] }

examples/hello.rs

@@ -1,10 +1,8 @@
-use async_std::task;
-
-fn main() -> Result<(), std::io::Error> {
-    task::block_on(async {
-        let mut app = tide::new();
-        app.at("/").get(|_| async move { Ok("Hello, world!") });
-        app.listen("127.0.0.1:8080").await?;
-        Ok(())
-    })
+#[async_std::main]
+async fn main() -> Result<(), std::io::Error> {
+    tide::log::start();
+    let mut app = tide::new();
+    app.at("/").get(|_| async move { Ok("Hello, world!") });
+    app.listen("127.0.0.1:8080").await?;
+    Ok(())
 }

examples/static_file.rs

@@ -1,13 +1,9 @@
-use async_std::task;
-use tide::log;
-
-fn main() -> Result<(), std::io::Error> {
-    femme::start(log::Level::Info.to_level_filter()).unwrap();
-    task::block_on(async {
-        let mut app = tide::new();
-        app.at("/").get(|_| async move { Ok("visit /src/*") });
-        app.at("/src").serve_dir("src/")?;
-        app.listen("127.0.0.1:8080").await?;
-        Ok(())
-    })
+#[async_std::main]
+async fn main() -> Result<(), std::io::Error> {
+    tide::log::start();
+    let mut app = tide::new();
+    app.at("/").get(|_| async move { Ok("visit /src/*") });
+    app.at("/src").serve_dir("src/")?;
+    app.listen("127.0.0.1:8080").await?;
+    Ok(())
 }

src/log/middleware.rs

@@ -31,29 +31,45 @@ impl LogMiddleware {
     ) -> crate::Result {
         let path = ctx.uri().path().to_owned();
         let method = ctx.method().to_string();
-        log::trace!("IN => {} {}", method, path);
+        log::info!("<-- Request received", {
+            method: method,
+            path: path,
+        });
         let start = std::time::Instant::now();
         match next.run(ctx).await {
             Ok(res) => {
                 let status = res.status();
-                log::info!(
-                    "{} {} {} {}ms",
-                    method,
-                    path,
-                    status,
-                    start.elapsed().as_millis()
-                );
+                if status.is_server_error() {
+                    log::error!("--> Response sent", {
+                        method: method,
+                        path: path,
+                        status: status as u16,
+                        duration: format!("{}ms", start.elapsed().as_millis()),
+                    });
+                } else if status.is_client_error() {
+                    log::warn!("--> Response sent", {
+                        method: method,
+                        path: path,
+                        status: status as u16,
+                        duration: format!("{}ms", start.elapsed().as_millis()),
+                    });
+                } else {
+                    log::info!("--> Response sent", {
+                        method: method,
+                        path: path,
+                        status: status as u16,
+                        duration: format!("{}ms", start.elapsed().as_millis()),
+                    });
+                }
                 Ok(res)
             }
             Err(err) => {
-                let msg = err.to_string();
-                log::error!(
-                    "{} {} {} {}ms",
-                    msg,
-                    method,
-                    path,
-                    start.elapsed().as_millis()
-                );
+                log::error!("{}", err.to_string(), {
+                    method: method,
+                    path: path,
+                    status: err.status() as u16,
+                    duration: format!("{}ms", start.elapsed().as_millis()),
+                });
                 Err(err)
             }
         }

src/log/mod.rs

@@ -5,9 +5,7 @@
 //! ```no_run
 //! use tide::log;
 //!
-//! // `tide::log` requires starting a third-party logger such as `femme`. We may
-//! // ship such a logger as part of Tide in the future.
-//! femme::start(log::Level::Info.to_level_filter()).unwrap();
+//! log::start();
 //!
 //! log::info!("Hello cats");
 //! log::debug!("{} wants tuna", "Nori");
@@ -23,4 +21,17 @@ pub use kv_log_macro::{max_level, Level};
 
 mod middleware;
 
+pub use femme::LevelFilter;
 pub use middleware::LogMiddleware;
+
+/// Start logging.
+pub fn start() {
+    femme::start();
+    crate::log::info!("Logger started", { level: "Info" });
+}
+
+/// Start logging with a log level.
+pub fn with_level(level: LevelFilter) {
+    femme::with_level(level);
+    crate::log::info!("Logger started", { level: format!("{}", level) });
+}

src/server.rs

@@ -283,9 +283,15 @@ impl<State: Send + Sync + 'static> Server<State> {
         let listener = async_std::net::TcpListener::bind(addr).await?;
 
         let addr = format!("http://{}", listener.local_addr()?);
-        log::info!("Server is listening on: {}", addr);
-        let mut incoming = listener.incoming();
+        let tls = false;
+        let target = if cfg!(debug_assertions) {
+            "dev"
+        } else {
+            "release"
+        };
+        log::info!("Server listening", { address: addr, target: target, tls: tls });
 
+        let mut incoming = listener.incoming();
         while let Some(stream) = incoming.next().await {
             let stream = stream?;
             let addr = addr.clone();