fix(client): detect connection closes as pool tries to use

Currently, if the remote closes the connection at the same time that the
pool selects it to use for a new request, the connection may actually
hang. This fix will now more allow the keep-alive read to check the
socket even when the `Conn` think it's busy.

If the connection was closed before the request write happened, returns
back an `Error::Cancel`, letting the user know they could safely retry
it.

Closes #1439
This commit is contained in:
Sean McArthur
2018-02-12 13:27:50 -08:00
parent a9413d7367
commit dc619a8fa0
6 changed files with 167 additions and 94 deletions

View File

@@ -85,7 +85,7 @@ impl<T, U> Drop for Receiver<T, U> {
// - Err: unreachable // - Err: unreachable
while let Ok(Async::Ready(Some((_val, cb)))) = self.inner.poll() { while let Ok(Async::Ready(Some((_val, cb)))) = self.inner.poll() {
// maybe in future, we pass the value along with the error? // maybe in future, we pass the value along with the error?
let _ = cb.send(Err(::Error::new_canceled())); let _ = cb.send(Err(::Error::new_canceled(None)));
} }
} }

View File

@@ -243,11 +243,7 @@ where C: Connect,
}, },
Err(_) => { Err(_) => {
error!("pooled connection was not ready, this is a hyper bug"); error!("pooled connection was not ready, this is a hyper bug");
let err = io::Error::new( Either::B(future::err(::Error::new_canceled(None)))
io::ErrorKind::BrokenPipe,
"pool selected dead connection",
);
Either::B(future::err(::Error::Io(err)))
} }
} }
}); });

View File

@@ -60,9 +60,9 @@ pub enum Error {
} }
impl Error { impl Error {
pub(crate) fn new_canceled() -> Error { pub(crate) fn new_canceled(cause: Option<Error>) -> Error {
Error::Cancel(Canceled { Error::Cancel(Canceled {
_inner: (), cause: cause.map(Box::new),
}) })
} }
} }
@@ -73,10 +73,9 @@ impl Error {
/// as the related connection gets closed by the remote. In that case, /// as the related connection gets closed by the remote. In that case,
/// when the connection drops, the pending response future will be /// when the connection drops, the pending response future will be
/// fulfilled with this error, signaling the `Request` was never started. /// fulfilled with this error, signaling the `Request` was never started.
#[derive(Debug)]
pub struct Canceled { pub struct Canceled {
// maybe in the future this contains an optional value of cause: Option<Box<Error>>,
// what was canceled?
_inner: (),
} }
impl Canceled { impl Canceled {
@@ -85,13 +84,6 @@ impl Canceled {
} }
} }
impl fmt::Debug for Canceled {
fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
f.debug_struct("Canceled")
.finish()
}
}
impl fmt::Display for Canceled { impl fmt::Display for Canceled {
fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result { fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
f.pad(self.description()) f.pad(self.description())
@@ -142,6 +134,7 @@ impl StdError for Error {
Io(ref error) => Some(error), Io(ref error) => Some(error),
Uri(ref error) => Some(error), Uri(ref error) => Some(error),
Utf8(ref error) => Some(error), Utf8(ref error) => Some(error),
Cancel(ref e) => e.cause.as_ref().map(|e| &**e as &StdError),
Error::__Nonexhaustive(..) => unreachable!(), Error::__Nonexhaustive(..) => unreachable!(),
_ => None, _ => None,
} }

View File

@@ -119,7 +119,7 @@ where I: AsyncRead + AsyncWrite,
} else { } else {
trace!("poll when on keep-alive"); trace!("poll when on keep-alive");
if !T::should_read_first() { if !T::should_read_first() {
self.try_empty_read()?; self.require_empty_read()?;
if self.is_read_closed() { if self.is_read_closed() {
return Ok(Async::Ready(None)); return Ok(Async::Ready(None));
} }
@@ -281,17 +281,23 @@ where I: AsyncRead + AsyncWrite,
pub fn read_keep_alive(&mut self) -> Result<(), ::Error> { pub fn read_keep_alive(&mut self) -> Result<(), ::Error> {
debug_assert!(!self.can_read_head() && !self.can_read_body()); debug_assert!(!self.can_read_head() && !self.can_read_body());
trace!("Conn::read_keep_alive"); trace!("read_keep_alive; is_mid_message={}", self.is_mid_message());
if T::should_read_first() || !self.state.is_idle() { if self.is_mid_message() {
self.maybe_park_read(); self.maybe_park_read();
} else { } else {
self.try_empty_read()?; self.require_empty_read()?;
} }
Ok(()) Ok(())
} }
fn is_mid_message(&self) -> bool {
match (&self.state.reading, &self.state.writing) {
(&Reading::Init, &Writing::Init) => false,
_ => true,
}
}
fn maybe_park_read(&mut self) { fn maybe_park_read(&mut self) {
if !self.io.is_read_blocked() { if !self.io.is_read_blocked() {
// the Io object is ready to read, which means it will never alert // the Io object is ready to read, which means it will never alert
@@ -312,40 +318,68 @@ where I: AsyncRead + AsyncWrite,
// //
// This should only be called for Clients wanting to enter the idle // This should only be called for Clients wanting to enter the idle
// state. // state.
fn try_empty_read(&mut self) -> io::Result<()> { fn require_empty_read(&mut self) -> io::Result<()> {
assert!(!self.can_read_head() && !self.can_read_body()); assert!(!self.can_read_head() && !self.can_read_body());
if !self.io.read_buf().is_empty() { if !self.io.read_buf().is_empty() {
debug!("received an unexpected {} bytes", self.io.read_buf().len()); debug!("received an unexpected {} bytes", self.io.read_buf().len());
Err(io::Error::new(io::ErrorKind::InvalidData, "unexpected bytes after message ended")) Err(io::Error::new(io::ErrorKind::InvalidData, "unexpected bytes after message ended"))
} else { } else {
match self.io.read_from_io() { match self.try_io_read()? {
Ok(Async::Ready(0)) => { Async::Ready(0) => {
trace!("try_empty_read; found EOF on connection: {:?}", self.state); // case handled in try_io_read
let must_error = self.should_error_on_eof(); Ok(())
// order is important: must_error needs state BEFORE close_read },
self.state.close_read(); Async::Ready(n) => {
if must_error { debug!("received {} bytes on an idle connection", n);
Err(io::Error::new(io::ErrorKind::UnexpectedEof, "unexpected EOF waiting for response")) let desc = if self.state.is_idle() {
} else { "unexpected bytes after message ended"
Ok(()) } else {
} "unexpected bytes before writing message"
}, };
Ok(Async::Ready(n)) => { Err(io::Error::new(io::ErrorKind::InvalidData, desc))
debug!("received {} bytes on an idle connection", n); },
Err(io::Error::new(io::ErrorKind::InvalidData, "unexpected bytes after message ended")) Async::NotReady => {
},
Ok(Async::NotReady) => {
Ok(()) Ok(())
}, },
Err(e) => {
self.state.close();
Err(e)
}
} }
} }
} }
fn try_io_read(&mut self) -> Poll<usize, io::Error> {
match self.io.read_from_io() {
Ok(Async::Ready(0)) => {
trace!("try_io_read; found EOF on connection: {:?}", self.state);
let must_error = self.should_error_on_eof();
let ret = if must_error {
let desc = if self.is_mid_message() {
"unexpected EOF waiting for response"
} else {
"unexpected EOF before writing message"
};
Err(io::Error::new(io::ErrorKind::UnexpectedEof, desc))
} else {
Ok(Async::Ready(0))
};
// order is important: must_error needs state BEFORE close_read
self.state.close_read();
ret
},
Ok(Async::Ready(n)) => {
Ok(Async::Ready(n))
},
Ok(Async::NotReady) => {
Ok(Async::NotReady)
},
Err(e) => {
self.state.close();
Err(e)
}
}
}
fn maybe_notify(&mut self) { fn maybe_notify(&mut self) {
// its possible that we returned NotReady from poll() without having // its possible that we returned NotReady from poll() without having
// exhausted the underlying Io. We would have done this when we // exhausted the underlying Io. We would have done this when we

View File

@@ -401,7 +401,9 @@ where
let _ = cb.send(Err(err)); let _ = cb.send(Err(err));
Ok(()) Ok(())
} else if let Ok(Async::Ready(Some((_, cb)))) = self.rx.poll() { } else if let Ok(Async::Ready(Some((_, cb)))) = self.rx.poll() {
let _ = cb.send(Err(err)); // in this case, the message was never even started, so it's safe to tell
// the user that the request was completely canceled
let _ = cb.send(Err(::Error::new_canceled(Some(err))));
Ok(()) Ok(())
} else { } else {
Err(err) Err(err)
@@ -431,13 +433,14 @@ where
#[cfg(test)] #[cfg(test)]
mod tests { mod tests {
extern crate pretty_env_logger;
use super::*; use super::*;
use mock::AsyncIo; use mock::AsyncIo;
use proto::ClientTransaction; use proto::ClientTransaction;
#[test] #[test]
fn client_read_response_before_writing_request() { fn client_read_bytes_before_writing_request() {
extern crate pretty_env_logger;
let _ = pretty_env_logger::try_init(); let _ = pretty_env_logger::try_init();
::futures::lazy(|| { ::futures::lazy(|| {
let io = AsyncIo::new_buf(b"HTTP/1.1 200 OK\r\n\r\n".to_vec(), 100); let io = AsyncIo::new_buf(b"HTTP/1.1 200 OK\r\n\r\n".to_vec(), 100);
@@ -452,11 +455,16 @@ mod tests {
}; };
let res_rx = tx.send((req, None::<::Body>)).unwrap(); let res_rx = tx.send((req, None::<::Body>)).unwrap();
dispatcher.poll().expect("dispatcher poll 1"); let a1 = dispatcher.poll().expect("error should be sent on channel");
dispatcher.poll().expect("dispatcher poll 2"); assert!(a1.is_ready(), "dispatcher should be closed");
let _res = res_rx.wait() let err = res_rx.wait()
.expect("callback poll") .expect("callback poll")
.expect("callback response"); .expect_err("callback response");
match err {
::Error::Cancel(_) => (),
other => panic!("expected Cancel(_), got {:?}", other),
}
Ok::<(), ()>(()) Ok::<(), ()>(())
}).wait().unwrap(); }).wait().unwrap();
} }

View File

@@ -14,9 +14,10 @@ use hyper::client::{Client, Request, HttpConnector};
use hyper::{Method, StatusCode}; use hyper::{Method, StatusCode};
use futures::{Future, Stream}; use futures::{Future, Stream};
use futures::future::Either;
use futures::sync::oneshot; use futures::sync::oneshot;
use tokio_core::reactor::{Core, Handle}; use tokio_core::reactor::{Core, Handle, Timeout};
fn client(handle: &Handle) -> Client<HttpConnector> { fn client(handle: &Handle) -> Client<HttpConnector> {
Client::new(handle) Client::new(handle)
@@ -523,7 +524,6 @@ test! {
} }
#[test] #[test]
fn client_keep_alive() { fn client_keep_alive() {
let server = TcpListener::bind("127.0.0.1:0").unwrap(); let server = TcpListener::bind("127.0.0.1:0").unwrap();
@@ -562,10 +562,72 @@ fn client_keep_alive() {
core.run(res.join(rx).map(|r| r.0)).unwrap(); core.run(res.join(rx).map(|r| r.0)).unwrap();
} }
/* TODO: re-enable once retry works, its currently a flaky test
#[test] #[test]
fn client_pooled_socket_disconnected() { fn client_keep_alive_connreset() {
use std::sync::mpsc;
extern crate pretty_env_logger;
let _ = pretty_env_logger::try_init();
let server = TcpListener::bind("127.0.0.1:0").unwrap();
let addr = server.local_addr().unwrap();
let mut core = Core::new().unwrap();
let handle = core.handle();
// This one seems to hang forever
let client = client(&handle);
let (tx1, rx1) = oneshot::channel();
let (tx2, rx2) = mpsc::channel();
thread::spawn(move || {
let mut sock = server.accept().unwrap().0;
sock.set_read_timeout(Some(Duration::from_secs(5))).unwrap();
sock.set_write_timeout(Some(Duration::from_secs(5))).unwrap();
let mut buf = [0; 4096];
sock.read(&mut buf).expect("read 1");
sock.write_all(b"HTTP/1.1 200 OK\r\nContent-Length: 0\r\n\r\n").expect("write 1");
// Wait for client to indicate it is done processing the first request
// This is what seem to trigger the race condition -- without it client notices
// connection is closed while processing the first request.
let _ = rx2.recv();
let _r = sock.shutdown(std::net::Shutdown::Both);
// Let client know it can try to reuse the connection
let _ = tx1.send(());
});
let res = client.get(format!("http://{}/a", addr).parse().unwrap());
core.run(res).unwrap();
let _ = tx2.send(());
let rx = rx1.map_err(|_| hyper::Error::Io(io::Error::new(io::ErrorKind::Other, "thread panicked")));
core.run(rx).unwrap();
let t = Timeout::new(Duration::from_millis(100), &handle).unwrap();
let res = client.get(format!("http://{}/b", addr).parse().unwrap());
let fut = res.select2(t).then(|result| match result {
Ok(Either::A((resp, _))) => Ok(resp),
Err(Either::A((err, _))) => Err(err),
Ok(Either::B(_)) |
Err(Either::B(_)) => Err(hyper::Error::Timeout),
});
// for now, the 2nd request is just canceled, since the connection is found to be dead
// at the same time the request is scheduled.
//
// in the future, it'd be nice to auto retry the request, but can't really be done yet
// as the `connector` isn't clone so we can't use it "later", when the future resolves.
let err = core.run(fut).unwrap_err();
match err {
hyper::Error::Cancel(..) => (),
other => panic!("expected Cancel error, got {:?}", other),
}
}
#[test]
fn client_keep_alive_extra_body() {
let _ = pretty_env_logger::try_init(); let _ = pretty_env_logger::try_init();
let server = TcpListener::bind("127.0.0.1:0").unwrap(); let server = TcpListener::bind("127.0.0.1:0").unwrap();
let addr = server.local_addr().unwrap(); let addr = server.local_addr().unwrap();
@@ -581,51 +643,31 @@ fn client_pooled_socket_disconnected() {
sock.set_write_timeout(Some(Duration::from_secs(5))).unwrap(); sock.set_write_timeout(Some(Duration::from_secs(5))).unwrap();
let mut buf = [0; 4096]; let mut buf = [0; 4096];
sock.read(&mut buf).expect("read 1"); sock.read(&mut buf).expect("read 1");
let remote_addr = sock.peer_addr().unwrap().to_string(); sock.write_all(b"HTTP/1.1 200 OK\r\nContent-Length: 5\r\n\r\nhello").expect("write 1");
let out = format!("HTTP/1.1 200 OK\r\nContent-Length: {}\r\n\r\n{}", remote_addr.len(), remote_addr); // the body "hello", while ignored because its a HEAD request, should mean the connection
sock.write_all(out.as_bytes()).expect("write 1"); // cannot be put back in the pool
drop(sock); let _ = tx1.send(());
tx1.send(());
let mut sock = server.accept().unwrap().0; let mut sock2 = server.accept().unwrap().0;
sock.read(&mut buf).expect("read 2"); let n2 = sock2.read(&mut buf).expect("read 2");
let second_get = b"GET /b HTTP/1.1\r\n"; assert_ne!(n2, 0);
assert_eq!(&buf[..second_get.len()], second_get); let second_get = "GET /b HTTP/1.1\r\n";
let remote_addr = sock.peer_addr().unwrap().to_string(); assert_eq!(s(&buf[..second_get.len()]), second_get);
let out = format!("HTTP/1.1 200 OK\r\nContent-Length: {}\r\n\r\n{}", remote_addr.len(), remote_addr); sock2.write_all(b"HTTP/1.1 200 OK\r\nContent-Length: 0\r\n\r\n").expect("write 2");
sock.write_all(out.as_bytes()).expect("write 2"); let _ = tx2.send(());
tx2.send(());
}); });
// spin shortly so we receive the hangup on the client socket
let sleep = Timeout::new(Duration::from_millis(500), &core.handle()).unwrap();
core.run(sleep).unwrap();
let rx = rx1.map_err(|_| hyper::Error::Io(io::Error::new(io::ErrorKind::Other, "thread panicked"))); let rx = rx1.map_err(|_| hyper::Error::Io(io::Error::new(io::ErrorKind::Other, "thread panicked")));
let res = client.get(format!("http://{}/a", addr).parse().unwrap()) let req = Request::new(Method::Head, format!("http://{}/a", addr).parse().unwrap());
.and_then(|res| { let res = client.request(req);
res.body() core.run(res.join(rx).map(|r| r.0)).unwrap();
.map(|chunk| chunk.to_vec())
.collect()
.map(|vec| vec.concat())
.map(|vec| String::from_utf8(vec).unwrap())
});
let addr1 = core.run(res.join(rx).map(|r| r.0)).unwrap();
let rx = rx2.map_err(|_| hyper::Error::Io(io::Error::new(io::ErrorKind::Other, "thread panicked"))); let rx = rx2.map_err(|_| hyper::Error::Io(io::Error::new(io::ErrorKind::Other, "thread panicked")));
let res = client.get(format!("http://{}/b", addr).parse().unwrap()) let res = client.get(format!("http://{}/b", addr).parse().unwrap());
.and_then(|res| { core.run(res.join(rx).map(|r| r.0)).unwrap();
res.body()
.map(|chunk| chunk.to_vec())
.collect()
.map(|vec| vec.concat())
.map(|vec| String::from_utf8(vec).unwrap())
});
let addr2 = core.run(res.join(rx).map(|r| r.0)).unwrap();
assert_ne!(addr1, addr2);
} }
*/
mod dispatch_impl { mod dispatch_impl {
use super::*; use super::*;