feat: support customize http log format (#116)

README.md

@@ -64,9 +64,10 @@ OPTIONS:
         --render-index           Serve index.html when requesting a directory, returns 404 if not found index.html
         --render-try-index       Serve index.html when requesting a directory, returns directory listing if not found index.html
         --render-spa             Serve SPA(Single Page Application)
-        --completions <shell>    Print shell completion script for <shell> [possible values: bash, elvish, fish, powershell, zsh]
         --tls-cert <path>        Path to an SSL/TLS certificate to serve with HTTPS
         --tls-key <path>         Path to the SSL/TLS certificate's private key
+        --log-format <format>    Customize http log format
+        --completions <shell>    Print shell completion script for <shell> [possible values: bash, elvish, fish, powershell, zsh]
     -h, --help                   Print help information
     -V, --version                Print version information
 ```
@@ -187,6 +188,23 @@ dufs -a /@admin:pass1@* -a /ui@designer:pass2 -A
 - Account `admin:pass1` can upload/delete/view/download any files/folders.
 - Account `designer:pass2` can upload/delete/view/download any files/folders in the `ui` folder.
 
+## Log format
+
+dufs supports customize http log format via option `--log-format`.
+
+The default format is `$remote_addr "$request" $status`.
+
+All variables list below:
+
+| name         | description                                                               |
+| ------------ | ------------------------------------------------------------------------- |
+| $remote_addr | client address                                                            |
+| $remote_user | user name supplied with authentication                                    |
+| $request     | full original request line                                                |
+| $status      | response status                                                           |
+| $http_       | arbitrary request header field. examples: $http_user_agent, $http_referer |
+
+> use `dufs --log-format=''` to disable http log
 ## License
 
 Copyright (c) 2022 dufs-developers.

src/args.rs

@@ -8,6 +8,7 @@ use std::path::{Path, PathBuf};
 
 use crate::auth::AccessControl;
 use crate::auth::AuthMethod;
+use crate::log_http::{LogHttp, DEFAULT_LOG_FORMAT};
 #[cfg(feature = "tls")]
 use crate::tls::{load_certs, load_private_key};
 use crate::utils::encode_uri;
@@ -120,13 +121,6 @@ pub fn build_cli() -> Command<'static> {
             Arg::new("render-spa")
                 .long("render-spa")
                 .help("Serve SPA(Single Page Application)"),
-        )
-        .arg(
-            Arg::new("completions")
-                .long("completions")
-                .value_name("shell")
-                .value_parser(value_parser!(Shell))
-                .help("Print shell completion script for <shell>"),
         );
 
     #[cfg(feature = "tls")]
@@ -144,7 +138,19 @@ pub fn build_cli() -> Command<'static> {
                 .help("Path to the SSL/TLS certificate's private key"),
         );
 
-    app
+    app.arg(
+        Arg::new("log-format")
+            .long("log-format")
+            .value_name("format")
+            .help("Customize http log format"),
+    )
+    .arg(
+        Arg::new("completions")
+            .long("completions")
+            .value_name("shell")
+            .value_parser(value_parser!(Shell))
+            .help("Print shell completion script for <shell>"),
+    )
 }
 
 pub fn print_completions<G: Generator>(gen: G, cmd: &mut Command) {
@@ -170,6 +176,7 @@ pub struct Args {
     pub render_spa: bool,
     pub render_try_index: bool,
     pub enable_cors: bool,
+    pub log_http: LogHttp,
     #[cfg(feature = "tls")]
     pub tls: Option<(Vec<Certificate>, PrivateKey)>,
     #[cfg(not(feature = "tls"))]
@@ -231,6 +238,10 @@ impl Args {
         };
         #[cfg(not(feature = "tls"))]
         let tls = None;
+        let log_http: LogHttp = matches
+            .value_of("log-format")
+            .unwrap_or(DEFAULT_LOG_FORMAT)
+            .parse()?;
 
         Ok(Args {
             addrs,
@@ -251,6 +262,7 @@ impl Args {
             render_try_index,
             render_spa,
             tls,
+            log_http,
         })
     }
 

src/auth.rs

@@ -198,6 +198,24 @@ impl AuthMethod {
             }
         }
     }
+    pub fn get_user(&self, authorization: &HeaderValue) -> Option<String> {
+        match self {
+            AuthMethod::Basic => {
+                let value: Vec<u8> =
+                    base64::decode(strip_prefix(authorization.as_bytes(), b"Basic ")?).ok()?;
+                let parts: Vec<&str> = std::str::from_utf8(&value).ok()?.split(':').collect();
+                Some(parts[0].to_string())
+            }
+            AuthMethod::Digest => {
+                let digest_value = strip_prefix(authorization.as_bytes(), b"Digest ")?;
+                let digest_vals = to_headermap(digest_value).ok()?;
+                digest_vals
+                    .get(b"username".as_ref())
+                    .and_then(|b| std::str::from_utf8(*b).ok())
+                    .map(|v| v.to_string())
+            }
+        }
+    }
     pub fn validate(
         &self,
         authorization: &HeaderValue,
@@ -207,10 +225,9 @@ impl AuthMethod {
     ) -> Option<()> {
         match self {
             AuthMethod::Basic => {
-                let value: Vec<u8> =
+                let basic_value: Vec<u8> =
-                    base64::decode(strip_prefix(authorization.as_bytes(), b"Basic ").unwrap())
+                    base64::decode(strip_prefix(authorization.as_bytes(), b"Basic ")?).ok()?;
-                        .unwrap();
+                let parts: Vec<&str> = std::str::from_utf8(&basic_value).ok()?.split(':').collect();
-                let parts: Vec<&str> = std::str::from_utf8(&value).unwrap().split(':').collect();
 
                 if parts[0] != auth_user {
                     return None;
@@ -229,13 +246,13 @@ impl AuthMethod {
             }
             AuthMethod::Digest => {
                 let digest_value = strip_prefix(authorization.as_bytes(), b"Digest ")?;
-                let user_vals = to_headermap(digest_value).ok()?;
+                let digest_vals = to_headermap(digest_value).ok()?;
                 if let (Some(username), Some(nonce), Some(user_response)) = (
-                    user_vals
+                    digest_vals
                         .get(b"username".as_ref())
                         .and_then(|b| std::str::from_utf8(*b).ok()),
-                    user_vals.get(b"nonce".as_ref()),
+                    digest_vals.get(b"nonce".as_ref()),
-                    user_vals.get(b"response".as_ref()),
+                    digest_vals.get(b"response".as_ref()),
                 ) {
                     match validate_nonce(nonce) {
                         Ok(true) => {}
@@ -247,12 +264,12 @@ impl AuthMethod {
                     let mut ha = Context::new();
                     ha.consume(method);
                     ha.consume(b":");
-                    if let Some(uri) = user_vals.get(b"uri".as_ref()) {
+                    if let Some(uri) = digest_vals.get(b"uri".as_ref()) {
                         ha.consume(uri);
                     }
                     let ha = format!("{:x}", ha.compute());
                     let mut correct_response = None;
-                    if let Some(qop) = user_vals.get(b"qop".as_ref()) {
+                    if let Some(qop) = digest_vals.get(b"qop".as_ref()) {
                         if qop == &b"auth".as_ref() || qop == &b"auth-int".as_ref() {
                             correct_response = Some({
                                 let mut c = Context::new();
@@ -260,11 +277,11 @@ impl AuthMethod {
                                 c.consume(b":");
                                 c.consume(nonce);
                                 c.consume(b":");
-                                if let Some(nc) = user_vals.get(b"nc".as_ref()) {
+                                if let Some(nc) = digest_vals.get(b"nc".as_ref()) {
                                     c.consume(nc);
                                 }
                                 c.consume(b":");
-                                if let Some(cnonce) = user_vals.get(b"cnonce".as_ref()) {
+                                if let Some(cnonce) = digest_vals.get(b"cnonce".as_ref()) {
                                     c.consume(cnonce);
                                 }
                                 c.consume(b":");

src/log_http.rs

@@ -0,0 +1,99 @@
+use std::{collections::HashMap, str::FromStr, sync::Arc};
+
+use crate::{args::Args, server::Request};
+
+pub const DEFAULT_LOG_FORMAT: &str = r#"$remote_addr "$request" $status"#;
+
+#[derive(Debug)]
+pub struct LogHttp {
+    elems: Vec<LogElement>,
+}
+
+#[derive(Debug)]
+enum LogElement {
+    Variable(String),
+    Header(String),
+    Literal(String),
+}
+
+impl LogHttp {
+    pub fn data(&self, req: &Request, args: &Arc<Args>) -> HashMap<String, String> {
+        let mut data = HashMap::default();
+        for elem in self.elems.iter() {
+            match elem {
+                LogElement::Variable(name) => match name.as_str() {
+                    "request" => {
+                        data.insert(name.to_string(), format!("{} {}", req.method(), req.uri()));
+                    }
+                    "remote_user" => {
+                        if let Some(user) = req
+                            .headers()
+                            .get("authorization")
+                            .and_then(|v| args.auth_method.get_user(v))
+                        {
+                            data.insert(name.to_string(), user);
+                        }
+                    }
+                    _ => {}
+                },
+                LogElement::Header(name) => {
+                    if let Some(value) = req.headers().get(name).and_then(|v| v.to_str().ok()) {
+                        data.insert(name.to_string(), value.to_string());
+                    }
+                }
+                LogElement::Literal(_) => {}
+            }
+        }
+        data
+    }
+    pub fn log(&self, data: &HashMap<String, String>, err: Option<String>) {
+        if self.elems.is_empty() {
+            return;
+        }
+        let mut output = String::new();
+        for elem in self.elems.iter() {
+            match elem {
+                LogElement::Literal(value) => output.push_str(value.as_str()),
+                LogElement::Header(name) | LogElement::Variable(name) => {
+                    output.push_str(data.get(name).map(|v| v.as_str()).unwrap_or("-"))
+                }
+            }
+        }
+        match err {
+            Some(err) => error!("{} {}", output, err),
+            None => info!("{}", output),
+        }
+    }
+}
+
+impl FromStr for LogHttp {
+    type Err = Box<dyn std::error::Error>;
+    fn from_str(s: &str) -> Result<Self, Self::Err> {
+        let mut elems = vec![];
+        let mut is_var = false;
+        let mut cache = String::new();
+        for c in format!("{} ", s).chars() {
+            if c == '$' {
+                if !cache.is_empty() {
+                    elems.push(LogElement::Literal(cache.to_string()));
+                }
+                cache.clear();
+                is_var = true;
+            } else if is_var && !(c.is_alphanumeric() || c == '_') {
+                if let Some(value) = cache.strip_prefix("$http_") {
+                    elems.push(LogElement::Header(value.replace('_', "-").to_string()));
+                } else if let Some(value) = cache.strip_prefix('$') {
+                    elems.push(LogElement::Variable(value.to_string()));
+                }
+                cache.clear();
+                is_var = false;
+            }
+            cache.push(c);
+        }
+        let cache = cache.trim();
+        if !cache.is_empty() {
+            elems.push(LogElement::Literal(cache.to_string()));
+        }
+        Ok(Self { elems })
+    }
+}

src/main.rs

@@ -1,5 +1,6 @@
 mod args;
 mod auth;
+mod log_http;
 mod logger;
 mod server;
 mod streamer;

src/server.rs

@@ -78,16 +78,17 @@ impl Server {
         req: Request,
         addr: SocketAddr,
     ) -> Result<Response, hyper::Error> {
-        let method = req.method().clone();
         let uri = req.uri().clone();
         let assets_prefix = self.assets_prefix.clone();
         let enable_cors = self.args.enable_cors;
+        let mut http_log_data = self.args.log_http.data(&req, &self.args);
+        http_log_data.insert("remote_addr".to_string(), addr.ip().to_string());
 
-        let mut res = match self.handle(req).await {
+        let mut res = match self.clone().handle(req).await {
             Ok(res) => {
-                let status = res.status().as_u16();
+                http_log_data.insert("status".to_string(), res.status().as_u16().to_string());
                 if !uri.path().starts_with(&assets_prefix) {
-                    info!(r#"{} "{} {}" - {}"#, addr.ip(), method, uri, status,);
+                    self.args.log_http.log(&http_log_data, None);
                 }
                 res
             }
@@ -95,8 +96,10 @@ impl Server {
                 let mut res = Response::default();
                 let status = StatusCode::INTERNAL_SERVER_ERROR;
                 *res.status_mut() = status;
-                let status = status.as_u16();
+                http_log_data.insert("status".to_string(), status.as_u16().to_string());
-                error!(r#"{} "{} {}" - {} {}"#, addr.ip(), method, uri, status, err);
+                self.args
+                    .log_http
+                    .log(&http_log_data, Some(err.to_string()));
                 res
             }
         };

tests/log_http.rs

@@ -0,0 +1,78 @@
+mod fixtures;
+mod utils;
+
+use diqwest::blocking::WithDigestAuth;
+use fixtures::{port, tmpdir, wait_for_port, Error};
+
+use assert_cmd::prelude::*;
+use assert_fs::fixture::TempDir;
+use rstest::rstest;
+use std::io::Read;
+use std::process::{Command, Stdio};
+
+#[rstest]
+#[case(&["-a", "/@user:pass", "--log-format", "$remote_user"], false)]
+#[case(&["-a", "/@user:pass", "--log-format", "$remote_user", "--auth-method", "basic"], true)]
+fn log_remote_user(
+    tmpdir: TempDir,
+    port: u16,
+    #[case] args: &[&str],
+    #[case] is_basic: bool,
+) -> Result<(), Error> {
+    let mut child = Command::cargo_bin("dufs")?
+        .arg(tmpdir.path())
+        .arg("-p")
+        .arg(port.to_string())
+        .args(args)
+        .stdout(Stdio::piped())
+        .spawn()?;
+
+    wait_for_port(port);
+
+    let stdout = child.stdout.as_mut().expect("Failed to get stdout");
+
+    let req = fetch!(b"GET", &format!("http://localhost:{}", port));
+
+    let resp = if is_basic {
+        req.basic_auth("user", Some("pass")).send()?
+    } else {
+        req.send_with_digest_auth("user", "pass")?
+    };
+
+    assert_eq!(resp.status(), 200);
+
+    let mut buf = [0; 1000];
+    let buf_len = stdout.read(&mut buf)?;
+    let output = std::str::from_utf8(&buf[0..buf_len])?;
+
+    assert!(output.lines().last().unwrap().ends_with("user"));
+
+    child.kill()?;
+    Ok(())
+}
+
+#[rstest]
+#[case(&["--log-format", ""])]
+fn no_log(tmpdir: TempDir, port: u16, #[case] args: &[&str]) -> Result<(), Error> {
+    let mut child = Command::cargo_bin("dufs")?
+        .arg(tmpdir.path())
+        .arg("-p")
+        .arg(port.to_string())
+        .args(args)
+        .stdout(Stdio::piped())
+        .spawn()?;
+
+    wait_for_port(port);
+
+    let stdout = child.stdout.as_mut().expect("Failed to get stdout");
+
+    let resp = fetch!(b"GET", &format!("http://localhost:{}", port)).send()?;
+    assert_eq!(resp.status(), 200);
+
+    let mut buf = [0; 1000];
+    let buf_len = stdout.read(&mut buf)?;
+    let output = std::str::from_utf8(&buf[0..buf_len])?;
+
+    assert_eq!(output.lines().last().unwrap(), "");
+    Ok(())
+}