nghttpx: Robust backend read timeout

src/shrpx_connection.cc

@@ -67,7 +67,9 @@ Connection::Connection(struct ev_loop *loop, int fd, SSL *ssl,
       fd(fd),
       tls_dyn_rec_warmup_threshold(tls_dyn_rec_warmup_threshold),
       tls_dyn_rec_idle_timeout(tls_dyn_rec_idle_timeout),
-      proto(proto) {
+      proto(proto),
+      last_read(0.),
+      read_timeout(read_timeout) {
 
   ev_io_init(&wev, writecb, fd, EV_WRITE);
   ev_io_init(&rev, readcb, fd, EV_READ);
@@ -809,4 +811,27 @@ int Connection::get_tcp_hint(TCPHint *hint) const {
 #endif // !defined(TCP_INFO) || !defined(TCP_NOTSENT_LOWAT)
 }
 
+void Connection::again_rt(ev_tstamp t) {
+  read_timeout = t;
+  rt.repeat = t;
+  ev_timer_again(loop, &rt);
+  last_read = ev_now(loop);
+}
+
+void Connection::again_rt() {
+  rt.repeat = read_timeout;
+  ev_timer_again(loop, &rt);
+  last_read = ev_now(loop);
+}
+
+bool Connection::expired_rt() {
+  auto delta = read_timeout - (ev_now(loop) - last_read);
+  if (delta < 1e-9) {
+    return true;
+  }
+  rt.repeat = delta;
+  ev_timer_again(loop, &rt);
+  return false;
+}
+
 } // namespace shrpx

src/shrpx_connection.h

@@ -125,6 +125,17 @@ struct Connection {
 
   int get_tcp_hint(TCPHint *hint) const;
 
+  // These functions are provided for read timer which is frequently
+  // restarted.  We do a trick to make a bit more efficient than just
+  // calling ev_timer_again().
+
+  // Restarts read timer with timeout value |t|.
+  void again_rt(ev_tstamp t);
+  // Restarts read timer without chainging timeout.
+  void again_rt();
+  // Returns true if read timer expired.
+  bool expired_rt();
+
   TLSConnection tls;
   ev_io wev;
   ev_io rev;
@@ -141,6 +152,11 @@ struct Connection {
   // used in this object at the moment.  The rest of the program may
   // use this value when it is useful.
   shrpx_proto proto;
+  // The point of time when last read is observed.  Note: sinde we use
+  // |rt| as idle timer, the activity is not limited to read.
+  ev_tstamp last_read;
+  // Timeout for read timer |rt|.
+  ev_tstamp read_timeout;
 };
 
 // Creates BIO_method shared by all SSL objects.  If nghttp2 is built

src/shrpx_http2_session.cc

@@ -111,6 +111,10 @@ void timeoutcb(struct ev_loop *loop, ev_timer *w, int revents) {
   auto conn = static_cast<Connection *>(w->data);
   auto http2session = static_cast<Http2Session *>(conn->data);
 
+  if (w == &conn->rt && !conn->expired_rt()) {
+    return;
+  }
+
   if (LOG_ENABLED(INFO)) {
     SSLOG(INFO, http2session) << "Timeout";
   }
@@ -491,10 +495,7 @@ int Http2Session::initiate_connection() {
       ev_timer_again(conn_.loop, &conn_.wt);
     } else {
       conn_.rlimit.startw();
-
+      conn_.again_rt();
-      if (addr_->num_dconn == 0) {
-        ev_timer_again(conn_.loop, &conn_.rt);
-      }
     }
 
     return 0;
@@ -615,8 +616,6 @@ int Http2Session::downstream_connect_proxy() {
 void Http2Session::add_downstream_connection(Http2DownstreamConnection *dconn) {
   dconns_.append(dconn);
   ++addr_->num_dconn;
-
-  stop_read_timer();
 }
 
 void Http2Session::remove_downstream_connection(
@@ -625,10 +624,6 @@ void Http2Session::remove_downstream_connection(
   dconns_.remove(dconn);
   dconn->detach_stream_data();
 
-  if (addr_->num_dconn == 0) {
-    repeat_read_timer();
-  }
-
   if (LOG_ENABLED(INFO)) {
     SSLOG(INFO, this) << "Remove downstream";
   }
@@ -1867,6 +1862,7 @@ int Http2Session::connected() {
   ev_timer_again(conn_.loop, &conn_.wt);
 
   conn_.rlimit.startw();
+  conn_.again_rt();
 
   read_ = &Http2Session::read_clear;
   write_ = &Http2Session::write_clear;
@@ -1891,6 +1887,8 @@ int Http2Session::connected() {
 }
 
 int Http2Session::read_clear() {
+  conn_.last_read = ev_now(conn_.loop);
+
   std::array<uint8_t, 16_k> buf;
 
   for (;;) {
@@ -1911,6 +1909,8 @@ int Http2Session::read_clear() {
 }
 
 int Http2Session::write_clear() {
+  conn_.last_read = ev_now(conn_.loop);
+
   std::array<struct iovec, MAX_WR_IOVCNT> iov;
 
   for (;;) {
@@ -1945,7 +1945,7 @@ int Http2Session::write_clear() {
 }
 
 int Http2Session::tls_handshake() {
-  ev_timer_again(conn_.loop, &conn_.rt);
+  conn_.last_read = ev_now(conn_.loop);
 
   ERR_clear_error();
 
@@ -1992,6 +1992,8 @@ int Http2Session::tls_handshake() {
 }
 
 int Http2Session::read_tls() {
+  conn_.last_read = ev_now(conn_.loop);
+
   std::array<uint8_t, 16_k> buf;
 
   ERR_clear_error();
@@ -2014,6 +2016,8 @@ int Http2Session::read_tls() {
 }
 
 int Http2Session::write_tls() {
+  conn_.last_read = ev_now(conn_.loop);
+
   ERR_clear_error();
 
   struct iovec iov;
@@ -2281,10 +2285,4 @@ void Http2Session::check_retire() {
   signal_write();
 }
 
-void Http2Session::repeat_read_timer() {
-  ev_timer_again(conn_.loop, &conn_.rt);
-}
-
-void Http2Session::stop_read_timer() { ev_timer_stop(conn_.loop, &conn_.rt); }
-
 } // namespace shrpx

src/shrpx_http2_session.h

@@ -203,9 +203,6 @@ public:
   // shutdown the connection.
   void check_retire();
 
-  void repeat_read_timer();
-  void stop_read_timer();
-
   enum {
     // Disconnected
     DISCONNECTED,

src/shrpx_http_downstream_connection.cc

@@ -48,6 +48,10 @@ void timeoutcb(struct ev_loop *loop, ev_timer *w, int revents) {
   auto conn = static_cast<Connection *>(w->data);
   auto dconn = static_cast<HttpDownstreamConnection *>(conn->data);
 
+  if (w == &conn->rt && !conn->expired_rt()) {
+    return;
+  }
+
   if (LOG_ENABLED(INFO)) {
     DCLOG(INFO, dconn) << "Time out";
   }
@@ -319,9 +323,13 @@ int HttpDownstreamConnection::attach_downstream(Downstream *downstream) {
     ev_timer_again(conn_.loop, &conn_.wt);
   } else {
     // we may set read timer cb to idle_timeoutcb.  Reset again.
-    conn_.rt.repeat = downstreamconf.timeout.read;
     ev_set_cb(&conn_.rt, timeoutcb);
-    ev_timer_stop(conn_.loop, &conn_.rt);
+    if (conn_.read_timeout < downstreamconf.timeout.read) {
+      conn_.read_timeout = downstreamconf.timeout.read;
+      conn_.last_read = ev_now(conn_.loop);
+    } else {
+      conn_.again_rt(downstreamconf.timeout.read);
+    }
 
     ev_set_cb(&conn_.rev, readcb);
   }
@@ -617,6 +625,9 @@ namespace {
 void idle_timeoutcb(struct ev_loop *loop, ev_timer *w, int revents) {
   auto conn = static_cast<Connection *>(w->data);
   auto dconn = static_cast<HttpDownstreamConnection *>(conn->data);
+
+  // We don't have to check conn->expired_rt() since we restart timer
+  // when connection gets idle.
   if (LOG_ENABLED(INFO)) {
     DCLOG(INFO, dconn) << "Idle connection timeout";
   }
@@ -637,9 +648,13 @@ void HttpDownstreamConnection::detach_downstream(Downstream *downstream) {
 
   auto &downstreamconf = *worker_->get_downstream_config();
 
-  conn_.rt.repeat = downstreamconf.timeout.idle_read;
   ev_set_cb(&conn_.rt, idle_timeoutcb);
-  ev_timer_again(conn_.loop, &conn_.rt);
+  if (conn_.read_timeout < downstreamconf.timeout.idle_read) {
+    conn_.read_timeout = downstreamconf.timeout.idle_read;
+    conn_.last_read = ev_now(conn_.loop);
+  } else {
+    conn_.again_rt(downstreamconf.timeout.idle_read);
+  }
 
   conn_.wlimit.stopw();
   ev_timer_stop(conn_.loop, &conn_.wt);
@@ -924,6 +939,8 @@ http_parser_settings htp_hooks = {
 } // namespace
 
 int HttpDownstreamConnection::read_clear() {
+  conn_.last_read = ev_now(conn_.loop);
+
   std::array<uint8_t, 16_k> buf;
   int rv;
 
@@ -949,6 +966,8 @@ int HttpDownstreamConnection::read_clear() {
 }
 
 int HttpDownstreamConnection::write_clear() {
+  conn_.last_read = ev_now(conn_.loop);
+
   auto upstream = downstream_->get_upstream();
   auto input = downstream_->get_request_buf();
 
@@ -986,7 +1005,7 @@ int HttpDownstreamConnection::write_clear() {
 int HttpDownstreamConnection::tls_handshake() {
   ERR_clear_error();
 
-  ev_timer_again(conn_.loop, &conn_.rt);
+  conn_.last_read = ev_now(conn_.loop);
 
   auto rv = conn_.tls_handshake();
   if (rv == SHRPX_ERR_INPROGRESS) {
@@ -1036,6 +1055,8 @@ int HttpDownstreamConnection::tls_handshake() {
 }
 
 int HttpDownstreamConnection::read_tls() {
+  conn_.last_read = ev_now(conn_.loop);
+
   ERR_clear_error();
 
   std::array<uint8_t, 16_k> buf;
@@ -1063,6 +1084,8 @@ int HttpDownstreamConnection::read_tls() {
 }
 
 int HttpDownstreamConnection::write_tls() {
+  conn_.last_read = ev_now(conn_.loop);
+
   ERR_clear_error();
 
   auto upstream = downstream_->get_upstream();
@@ -1193,6 +1216,7 @@ int HttpDownstreamConnection::connected() {
   ev_timer_again(conn_.loop, &conn_.wt);
 
   conn_.rlimit.startw();
+  conn_.again_rt();
 
   ev_set_cb(&conn_.wev, writecb);