Improve error messages in logs (#18)

Currently, the messages that the proxy logs on errors are often not 
very useful. For example, when an error occurred that caused the proxy
to return HTTP 500, we log a message like this:

```
ERR! proxy={server=in listen=0.0.0.0:4143 remote=127.0.0.1:57416} linkerd2_proxy turning Error caused by underlying HTTP/2 error: protocol error: unexpected internal error encountered into 500
```

Note that:
+ Regardless of what the error actually was, the current log message
  *always* says protocol error: unexpected internal error encountered,
  which is both fairly unclear *and* often not actually the case.
+ Regardless of whether the error was encountered by an HTTP/1 or 
  HTTP/2 client, the error message always includes the string
  "underlying HTTP/2 error". This is probably fairly confusing for 
  users who are, say, only proxying HTTP/1 traffic.

This branch fixes several related issues around the clarity of the
proxy's error messages:

+ A couple cases in the `transparency` module that returned
  `io::Error::from(io::ErrorKind::Other)` have been replaced with
  more descriptive errors that propagate the underlying error. This
  necessitated adding bounds on some error types.
+ Introduced a new `transparency::client::Error` enum that can be 
  either a `h2::Error` or a `hyper::Error`, depending on whether
  the client is HTTP/1 or HTTP/2, and proxies its' `std::error::Error`
  impl to the wrapped error types. This way, we don't return a
  `tower_h2::client::Error` (with format output that includes the 
  string "HTTP/2") from everything, and discard significantly less
  error information.

Signed-off-by: Eliza Weisman <eliza@buoyant.io>
This commit is contained in:
Eliza Weisman 2018-07-19 16:38:31 -07:00 committed by GitHub
parent 04e4b4409b
commit 6a81e1f137
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
6 changed files with 109 additions and 49 deletions

View File

@ -7,10 +7,11 @@ use std::marker::PhantomData;
use std::sync::Arc;
use std::time::Instant;
use tower_service::{NewService, Service};
use tower_h2::{client, Body};
use tower_h2::Body;
use ctx;
use telemetry::event::{self, Event};
use transparency::ClientError;
const GRPC_STATUS: &str = "grpc-status";
@ -118,7 +119,7 @@ where
N: NewService<
Request = http::Request<RequestBody<A>>,
Response = http::Response<B>,
Error = client::Error,
Error = ClientError,
>
+ 'static,
{
@ -143,7 +144,7 @@ where
N: NewService<
Request = http::Request<RequestBody<A>>,
Response = http::Response<B>,
Error = client::Error,
Error = ClientError,
>
+ 'static,
{
@ -200,7 +201,7 @@ where
S: Service<
Request = http::Request<RequestBody<A>>,
Response = http::Response<B>,
Error = client::Error,
Error = ClientError,
>
+ 'static,
{
@ -281,7 +282,7 @@ where
impl<F, B> Future for Respond<F, B>
where
F: Future<Item = http::Response<B>, Error=client::Error>,
F: Future<Item = http::Response<B>, Error=ClientError>,
B: Body + 'static,
{
type Item = http::Response<ResponseBody<B>>;

View File

@ -6,11 +6,12 @@ use http::{Request, Response};
use tokio_connect;
use tokio::io::{AsyncRead, AsyncWrite};
use tower_service::NewService;
use tower_h2::{client, Body};
use tower_h2::Body;
use ctx;
use telemetry::event;
use transport::{Connection, tls};
use transparency::ClientError;
pub mod http;
mod transport;
@ -90,7 +91,7 @@ impl Sensors {
N: NewService<
Request = Request<http::RequestBody<A>>,
Response = Response<B>,
Error = client::Error
Error = ClientError
>
+ 'static,
{

View File

@ -14,9 +14,24 @@ use telemetry::sensor::http::RequestBody;
use super::glue::{BodyPayload, HttpBody, HyperConnect};
use super::upgrade::{HttpConnect, Http11Upgrade};
use std::{self, fmt};
type HyperClient<C, B> =
hyper::Client<HyperConnect<C>, BodyPayload<RequestBody<B>>>;
/// A wrapper around the error types produced by the HTTP/1 and HTTP/2 clients.
///
/// Note that the names of the variants of this type (`Error::Http1` and
/// `Error::Http2`) aren't intended to imply that the error was a protocol
/// error; instead, they refer simply to which client the error occurred in.
/// Values of either variant may ultimately be caused by IO errors or other
/// types of error which could effect either protocol client.
#[derive(Debug)]
pub enum Error {
Http1(hyper::Error),
Http2(tower_h2::client::Error),
}
/// A `NewService` that can speak either HTTP/1 or HTTP/2.
pub struct Client<C, E, B>
where
@ -91,6 +106,7 @@ impl<C, E, B> Client<C, E, B>
where
C: Connect + Clone + Send + Sync + 'static,
C::Future: Send + 'static,
<C::Future as Future>::Error: ::std::error::Error + Send + Sync,
C::Connected: Send,
E: Executor + Clone,
E: future::Executor<Box<Future<Item = (), Error = ()> + Send + 'static>> + Send + Sync + 'static,
@ -130,6 +146,7 @@ impl<C, E, B> NewService for Client<C, E, B>
where
C: Connect + Clone + Send + Sync + 'static,
C::Future: Send + 'static,
<C::Future as Future>::Error: ::std::error::Error + Send + Sync,
C::Connected: Send,
E: Executor + Clone,
E: future::Executor<Box<Future<Item = (), Error = ()> + Send + 'static>> + Send + Sync + 'static,
@ -138,7 +155,7 @@ where
{
type Request = bind::HttpRequest<B>;
type Response = http::Response<HttpBody>;
type Error = tower_h2::client::Error;
type Error = Error;
type InitError = tower_h2::client::ConnectError<C::Error>;
type Service = ClientService<C, E, B>;
type Future = ClientNewServiceFuture<C, E, B>;
@ -192,6 +209,7 @@ where
C: Connect + Send + Sync + 'static,
C::Connected: Send,
C::Future: Send + 'static,
<C::Future as Future>::Error: ::std::error::Error + Send + Sync,
E: Executor + Clone,
E: future::Executor<Box<Future<Item = (), Error = ()> + Send + 'static>> + Send + Sync + 'static,
B: tower_h2::Body + Send + 'static,
@ -199,13 +217,13 @@ where
{
type Request = bind::HttpRequest<B>;
type Response = http::Response<HttpBody>;
type Error = tower_h2::client::Error;
type Error = Error;
type Future = ClientServiceFuture;
fn poll_ready(&mut self) -> Poll<(), Self::Error> {
match self.inner {
ClientServiceInner::Http1(_) => Ok(Async::Ready(())),
ClientServiceInner::Http2(ref mut h2) => h2.poll_ready(),
ClientServiceInner::Http2(ref mut h2) => h2.poll_ready().map_err(Error::from),
}
}
@ -245,28 +263,25 @@ pub enum ClientServiceFuture {
impl Future for ClientServiceFuture {
type Item = http::Response<HttpBody>;
type Error = tower_h2::client::Error;
type Error = Error;
fn poll(&mut self) -> Poll<Self::Item, Self::Error> {
match self {
ClientServiceFuture::Http1 { future, upgrade, is_http_connect } => {
match future.poll() {
Ok(Async::Ready(res)) => {
let mut res = res.map(move |b| HttpBody::Http1 {
body: Some(b),
upgrade: upgrade.take(),
});
if *is_http_connect {
res.extensions_mut().insert(HttpConnect);
}
Ok(Async::Ready(res))
},
Ok(Async::NotReady) => Ok(Async::NotReady),
Err(e) => {
let poll = future.poll()
.map_err(|e| {
debug!("http/1 client error: {}", e);
Err(h2::Reason::INTERNAL_ERROR.into())
}
Error::from(e)
});
let mut res = try_ready!(poll)
.map(move |b| HttpBody::Http1 {
body: Some(b),
upgrade: upgrade.take(),
});
if *is_http_connect {
res.extensions_mut().insert(HttpConnect);
}
Ok(Async::Ready(res))
},
ClientServiceFuture::Http2(f) => {
let res = try_ready!(f.poll());
@ -277,3 +292,43 @@ impl Future for ClientServiceFuture {
}
}
impl From<tower_h2::client::Error> for Error {
fn from(e: tower_h2::client::Error) -> Self {
Error::Http2(e)
}
}
impl From<hyper::Error> for Error {
fn from(e: hyper::Error) -> Self {
Error::Http1(e)
}
}
impl fmt::Display for Error {
fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
match self {
Error::Http1(ref e) => fmt::Display::fmt(e, f),
Error::Http2(ref e) => fmt::Display::fmt(e, f),
}
}
}
impl std::error::Error for Error {
fn cause(&self) -> Option<&std::error::Error> {
match self {
Error::Http1(e) => e.cause(),
Error::Http2(e) => e.cause(),
}
}
}
impl Error {
pub fn reason(&self) -> Option<h2::Reason> {
match self {
// TODO: it would be good to provide better error
// details in metrics for HTTP/1...
Error::Http1(_) => Some(h2::Reason::INTERNAL_ERROR),
Error::Http2(e) => e.reason(),
}
}
}

View File

@ -1,6 +1,8 @@
use std::fmt;
use std::io;
use std::sync::Arc;
use std::{
error::Error,
fmt,
sync::Arc,
};
use bytes::{Bytes, IntoBuf};
use futures::{future, Async, Future, Poll};
@ -241,14 +243,14 @@ where
Request=http::Request<HttpBody>,
Response=http::Response<B>,
>,
S::Error: fmt::Debug,
S::Error: Error + Send + Sync + 'static,
B: tower_h2::Body + Default + Send + 'static,
<B::Data as ::bytes::IntoBuf>::Buf: Send,
E: Executor<BoxSendFuture> + Clone + Send + Sync + 'static,
{
type ReqBody = hyper::Body;
type ResBody = BodyPayload<B>;
type Error = h2::Error;
type Error = S::Error;
type Future = Either<
HyperServerSvcFuture<S::Future>,
future::FutureResult<http::Response<Self::ResBody>, Self::Error>,
@ -303,15 +305,15 @@ where
impl<F, B> Future for HyperServerSvcFuture<F>
where
F: Future<Item=http::Response<B>>,
F::Error: fmt::Debug,
F::Error: Error + fmt::Debug + Send + Sync + 'static,
{
type Item = http::Response<BodyPayload<B>>;
type Error = h2::Error;
type Error = F::Error;
fn poll(&mut self) -> Poll<Self::Item, Self::Error> {
let mut res = try_ready!(self.inner.poll().map_err(|e| {
debug!("h2 error: {:?}", e);
h2::Error::from(io::Error::from(io::ErrorKind::Other))
debug!("HTTP/1 error: {}", e);
e
}));
if h1::is_upgrade(&res) {
@ -409,10 +411,11 @@ impl<C> hyper_connect::Connect for HyperConnect<C>
where
C: Connect + Send + Sync,
C::Future: Send + 'static,
<C::Future as Future>::Error: Error + Send + Sync + 'static,
C::Connected: Send + 'static,
{
type Transport = C::Connected;
type Error = io::Error;
type Error = <C::Future as Future>::Error;
type Future = HyperConnectFuture<C::Future>;
fn connect(&self, _dst: hyper_connect::Destination) -> Self::Future {
@ -425,16 +428,14 @@ where
impl<F> Future for HyperConnectFuture<F>
where
F: Future,
F: Future + 'static,
F::Error: Error + Send + Sync,
{
type Item = (F::Item, hyper_connect::Connected);
type Error = io::Error;
type Error = F::Error;
fn poll(&mut self) -> Poll<Self::Item, Self::Error> {
let transport = try_ready!(
self.inner.poll()
.map_err(|_| io::Error::from(io::ErrorKind::Other))
);
let transport = try_ready!(self.inner.poll());
let connected = hyper_connect::Connected::new()
.proxy(self.absolute_form);
Ok(Async::Ready((transport, connected)))

View File

@ -6,6 +6,6 @@ mod protocol;
mod server;
mod tcp;
pub use self::client::Client;
pub use self::client::{Client, Error as ClientError};
pub use self::glue::HttpBody;
pub use self::server::Server;

View File

@ -1,7 +1,10 @@
use std::fmt;
use std::net::SocketAddr;
use std::sync::Arc;
use std::time::{Duration, Instant};
use std::{
error::Error,
fmt,
net::SocketAddr,
sync::Arc,
time::{Duration, Instant},
};
use futures::{future::Either, Future};
use http;
@ -57,12 +60,11 @@ where
> + Clone + Send + 'static,
S::Future: 'static,
<S as NewService>::Service: Send,
S::Error: fmt::Debug,
<<S as NewService>::Service as ::tower_service::Service>::Future: Send,
S::InitError: fmt::Debug,
S::Future: Send + 'static,
B: tower_h2::Body + 'static,
S::Error: Send + fmt::Debug,
S::Error: Error + Send + Sync + 'static,
S::InitError: Send + fmt::Debug,
B: tower_h2::Body + Send + Default + 'static,
B::Data: Send,