From c3ad9e5f2f9260421ef70cfacf81bf085ab0d6bc Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Fri, 2 Mar 2018 12:44:18 -0800 Subject: [PATCH] Use fmt::Display to format error messages in logs (#477) This PR changes the proxy to log error messages using `fmt::Display` whenever possible, which should lead to much more readable and meaningful error messages This is part of the work I started last week on issue #442. While I haven't finished everything for that issue (all errors still are mapped to HTTP 500 error codes), I wanted to go ahead and open a PR for the more readable error messages. This is partially because I found myself merging these changes into other branches to aid in debugging, and because I figured we may as well have the nicer logging on master. --- proxy/router/src/lib.rs | 41 +++++++++++++++++++++++++++++++++++++- proxy/src/bind.rs | 29 +++++++++++++++++++++++++++ proxy/src/inbound.rs | 4 ++-- proxy/src/lib.rs | 26 +++++++++++++++++++----- proxy/src/map_err.rs | 31 +++++++++++++++++------------ proxy/src/outbound.rs | 44 +++++++++++++++++++++++++++++++++++------ 6 files changed, 148 insertions(+), 27 deletions(-) diff --git a/proxy/router/src/lib.rs b/proxy/router/src/lib.rs index 1ebad9250..188617d8c 100644 --- a/proxy/router/src/lib.rs +++ b/proxy/router/src/lib.rs @@ -6,8 +6,8 @@ use futures::{Future, Poll}; use indexmap::IndexMap; use tower::Service; +use std::{error, fmt, mem}; use std::hash::Hash; -use std::mem; use std::sync::{Arc, Mutex}; /// Route requests based on the request authority @@ -223,3 +223,42 @@ where T: Recognize, } } } + +// ===== impl RouteError ===== + +impl fmt::Display for Error +where + T: fmt::Display, + U: fmt::Display, +{ + fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result { + match *self { + Error::Inner(ref why) => fmt::Display::fmt(why, f), + Error::Route(ref why) => + write!(f, "route recognition failed: {}", why), + Error::NotRecognized => f.pad("route not recognized"), + } + } +} + +impl error::Error for Error +where + T: error::Error, + U: error::Error, +{ + fn cause(&self) -> Option<&error::Error> { + match *self { + Error::Inner(ref why) => Some(why), + Error::Route(ref why) => Some(why), + _ => None, + } + } + + fn description(&self) -> &str { + match *self { + Error::Inner(_) => "inner service error", + Error::Route(_) => "route recognition failed", + Error::NotRecognized => "route not recognized", + } + } +} diff --git a/proxy/src/bind.rs b/proxy/src/bind.rs index f601e43fa..e0bc2e940 100644 --- a/proxy/src/bind.rs +++ b/proxy/src/bind.rs @@ -1,3 +1,5 @@ +use std::error::Error; +use std::fmt; use std::marker::PhantomData; use std::net::SocketAddr; use std::sync::Arc; @@ -60,6 +62,33 @@ pub type Client = transparency::Client< B, >; +#[derive(Copy, Clone, Debug)] +pub enum BufferSpawnError { + Inbound, + Outbound, +} + +impl fmt::Display for BufferSpawnError { + fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result { + f.pad(self.description()) + } +} + +impl Error for BufferSpawnError { + + fn description(&self) -> &str { + match *self { + BufferSpawnError::Inbound => + "error spawning inbound buffer task", + BufferSpawnError::Outbound => + "error spawning outbound buffer task", + } + } + + fn cause(&self) -> Option<&Error> { None } +} + + impl Bind<(), B> { pub fn new(executor: Handle) -> Self { Self { diff --git a/proxy/src/inbound.rs b/proxy/src/inbound.rs index f51bd8ef3..50219abef 100644 --- a/proxy/src/inbound.rs +++ b/proxy/src/inbound.rs @@ -43,7 +43,7 @@ where > >; type Key = (SocketAddr, bind::Protocol); - type RouteError = (); + type RouteError = bind::BufferSpawnError; type Service = InFlightLimit>>; fn recognize(&self, req: &Self::Request) -> Option { @@ -81,7 +81,7 @@ where .map(|buffer| { InFlightLimit::new(buffer, MAX_IN_FLIGHT) }) - .map_err(|_| {}) + .map_err(|_| bind::BufferSpawnError::Inbound) } } diff --git a/proxy/src/lib.rs b/proxy/src/lib.rs index 39f0b0bd8..8efe4c376 100644 --- a/proxy/src/lib.rs +++ b/proxy/src/lib.rs @@ -44,6 +44,7 @@ extern crate tower_in_flight_limit; use futures::*; +use std::error::Error; use std::io; use std::net::SocketAddr; use std::sync::Arc; @@ -53,7 +54,7 @@ use std::time::Duration; use tokio_core::reactor::{Core, Handle}; use tower::NewService; use tower_fn::*; -use conduit_proxy_router::{Recognize, Router}; +use conduit_proxy_router::{Recognize, Router, Error as RouteError}; pub mod app; mod bind; @@ -301,8 +302,8 @@ fn serve( ) -> Box + 'static> where B: tower_h2::Body + Default + 'static, - E: ::std::fmt::Debug + 'static, - F: ::std::fmt::Debug + 'static, + E: Error + 'static, + F: Error + 'static, R: Recognize< Request = http::Request, Response = http::Response>, @@ -317,8 +318,23 @@ where // Clone the router handle let router = router.clone(); - // Map errors to 500 responses - MapErr::new(router) + // Map errors to appropriate response error codes. + MapErr::new(router, |e| { + match e { + RouteError::Route(r) => { + error!(" turning route error: {} into 500", r); + http::StatusCode::INTERNAL_SERVER_ERROR + } + RouteError::Inner(i) => { + error!("turning {} into 500", i); + http::StatusCode::INTERNAL_SERVER_ERROR + } + RouteError::NotRecognized => { + error!("turning route not recognized error into 500"); + http::StatusCode::INTERNAL_SERVER_ERROR + } + } + }) })); let listen_addr = bound_port.local_addr(); diff --git a/proxy/src/map_err.rs b/proxy/src/map_err.rs index 8d4e879f2..dd94dbbd4 100644 --- a/proxy/src/map_err.rs +++ b/proxy/src/map_err.rs @@ -1,5 +1,5 @@ -use std::fmt::Debug; use std::marker::PhantomData; +use std::sync::Arc; use futures::{Future, Poll}; use h2; @@ -8,43 +8,47 @@ use http::header::CONTENT_LENGTH; use tower::Service; /// Map an HTTP service's error to an appropriate 500 response. -pub struct MapErr { +pub struct MapErr { inner: T, + f: Arc, _p: PhantomData, } /// Catches errors from the inner future and maps them to 500 responses. -pub struct ResponseFuture { +pub struct ResponseFuture { inner: T, + f: Arc, _p: PhantomData, } + // ===== impl MapErr ===== -impl MapErr +impl MapErr where T: Service, - E: Debug, + F: Fn(E) -> http::StatusCode, { /// Crete a new `MapErr` - pub fn new(inner: T) -> Self { + pub fn new(inner: T, f: F) -> Self { MapErr { inner, + f: Arc::new(f), _p: PhantomData, } } } -impl Service for MapErr +impl Service for MapErr where T: Service, Error = E>, B: Default, - E: Debug, + F: Fn(E) -> http::StatusCode, { type Request = T::Request; type Response = T::Response; type Error = h2::Error; - type Future = ResponseFuture; + type Future = ResponseFuture; fn poll_ready(&mut self) -> Poll<(), Self::Error> { self.inner.poll_ready() @@ -56,6 +60,7 @@ where let inner = self.inner.call(request); ResponseFuture { inner, + f: self.f.clone(), _p: PhantomData, } } @@ -63,20 +68,20 @@ where // ===== impl ResponseFuture ===== -impl Future for ResponseFuture +impl Future for ResponseFuture where T: Future, Error = E>, B: Default, - E: Debug, + F: Fn(E) -> http::StatusCode, { type Item = T::Item; type Error = h2::Error; fn poll(&mut self) -> Poll { self.inner.poll().or_else(|e| { - error!("turning service error into 500: {:?}", e); + let status = (self.f)(e); let response = http::Response::builder() - .status(500) + .status(status) .header(CONTENT_LENGTH, "0") .body(Default::default()) .unwrap(); diff --git a/proxy/src/outbound.rs b/proxy/src/outbound.rs index cce9cf4ea..986dfa9a3 100644 --- a/proxy/src/outbound.rs +++ b/proxy/src/outbound.rs @@ -1,10 +1,11 @@ +use std::{error, fmt}; use std::net::SocketAddr; use std::time::Duration; +use std::sync::Arc; use futures::{Async, Poll}; use http; use rand; -use std::sync::Arc; use tower; use tower_balance::{self, choose, load, Balance}; use tower_buffer::Buffer; @@ -65,7 +66,7 @@ where type Response = bind::HttpResponse; type Error = ::Error; type Key = (Destination, Protocol); - type RouteError = (); + type RouteError = bind::BufferSpawnError; type Service = InFlightLimit>, choose::PowerOfTwoChoices @@ -145,7 +146,8 @@ where // `Timeout`. let handle = self.bind.executor(); - let buffer = Buffer::new(balance, handle).map_err(|_| {})?; + let buffer = Buffer::new(balance, handle) + .map_err(|_| bind::BufferSpawnError::Outbound)?; let timeout = Timeout::new(buffer, self.bind_timeout, handle); @@ -168,11 +170,12 @@ where type Response = bind::HttpResponse; type Error = as tower::Service>::Error; type Service = bind::Service; - type DiscoverError = (); + type DiscoverError = BindError; fn poll(&mut self) -> Poll, Self::DiscoverError> { match *self { - Discovery::LocalSvc(ref mut w) => w.poll(), + Discovery::LocalSvc(ref mut w) => w.poll() + .map_err(|_| BindError::Internal), Discovery::External(ref mut opt) => { // This "discovers" a single address for an external service // that never has another change. This can mean it floats @@ -180,7 +183,8 @@ where // circuit-breaking, this should be able to take care of itself, // closing down when the connection is no longer usable. if let Some((addr, bind)) = opt.take() { - let svc = bind.bind(&addr)?; + let svc = bind.bind(&addr) + .map_err(|_| BindError::External{ addr })?; Ok(Async::Ready(Change::Insert(addr, svc))) } else { Ok(Async::NotReady) @@ -189,3 +193,31 @@ where } } } +#[derive(Copy, Clone, Debug)] +pub enum BindError { + External { addr: SocketAddr }, + Internal, +} + +impl fmt::Display for BindError { + fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result { + match *self { + BindError::External { addr } => + write!(f, "binding external service for {:?} failed", addr), + BindError::Internal => + write!(f, "binding internal service failed"), + } + } + +} + +impl error::Error for BindError { + fn description(&self) -> &str { + match *self { + BindError::External { .. } => "binding external service failed", + BindError::Internal => "binding internal service failed", + } + } + + fn cause(&self) -> Option<&error::Error> { None } +}