1
  2
  3
  4
  5
  6
  7
  8
  9
 10
 11
 12
 13
 14
 15
 16
 17
 18
 19
 20
 21
 22
 23
 24
 25
 26
 27
 28
 29
 30
 31
 32
 33
 34
 35
 36
 37
 38
 39
 40
 41
 42
 43
 44
 45
 46
 47
 48
 49
 50
 51
 52
 53
 54
 55
 56
 57
 58
 59
 60
 61
 62
 63
 64
 65
 66
 67
 68
 69
 70
 71
 72
 73
 74
 75
 76
 77
 78
 79
 80
 81
 82
 83
 84
 85
 86
 87
 88
 89
 90
 91
 92
 93
 94
 95
 96
 97
 98
 99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128

use futures::{Future, Poll};
use http;
use log::{logger, Level, Record};
use tower_service::Service;

use std::time::Instant;

/// Decorates a service by logging all received requests
#[derive(Debug)]
pub struct LogService<S> {
    inner: S,
    target: &'static str,
}

/// Log the received request once the response has been processed.
#[derive(Debug)]
pub struct ResponseFuture<T> {
    inner: T,
    context: Option<LogContext>,
}

#[derive(Debug)]
struct LogContext {
    method: http::Method,
    path: Option<http::uri::PathAndQuery>,
    version: http::Version,
    start: Instant,
    target: &'static str,
}

impl<S> LogService<S> {
    pub(super) fn new(inner: S, target: &'static str) -> LogService<S> {
        LogService {
            inner,
            target,
        }
    }
}

impl<S, RequestBody, ResponseBody> Service for LogService<S>
where S: Service<Request = http::Request<RequestBody>,
                Response = http::Response<ResponseBody>>,
      S::Error: ::std::error::Error,
{
    type Request = S::Request;
    type Response = S::Response;
    type Error = S::Error;
    type Future = ResponseFuture<S::Future>;

    fn poll_ready(&mut self) -> Poll<(), Self::Error> {
        self.inner.poll_ready()
    }

    fn call(&mut self, request: Self::Request) -> Self::Future {
        let context = if log_enabled!(target: self.target, Level::Info) {
            Some(LogContext {
                method: request.method().clone(),
                path: request.uri().path_and_query().map(|p| p.clone()),
                version: request.version(),
                start: Instant::now(),
                target: self.target,
            })
        } else {
            None
        };

        let inner = self.inner.call(request);

        ResponseFuture {
            inner,
            context,
        }
    }
}

impl<T, B> Future for ResponseFuture<T>
where
    T: Future<Item = http::Response<B>>,
    T::Error: ::std::error::Error,
{
    type Item = T::Item;
    type Error = T::Error;

    fn poll(&mut self) -> Poll<Self::Item, Self::Error> {
        use futures::Async::*;

        let res = self.inner.poll();

        match (&res, &self.context) {
            (Ok(Ready(ref response)), Some(ref context)) => {
                let full_path = context.path.as_ref()
                    .map(|p| p.as_str())
                    .unwrap_or("/");

                // TODO:
                // - remote_addr
                // - response content length
                // - date
                let status_code = response.status().as_u16();
                let level = match status_code {
                    400...599 => Level::Error,
                    _ => Level::Info,
                };
                logger().log(&Record::builder()
                    .args(format_args!(
                        "\"{} {} {:?}\" {} {:?}",
                        context.method,
                        full_path,
                        context.version,
                        status_code,
                        context.start.elapsed(),
                    ))
                    .level(level)
                    .target(context.target)
                    .module_path(Some(module_path!()))
                    .file(Some(file!()))
                    .line(Some(line!()))
                    .build());
            }
            (Err(ref err), ..) => {
                warn!("ERROR: {}", err);
            }
            _ => {}
        }

        res
    }
}