http: per-stream idle timeout. (#3841)

htuch · web-flow · commit 45fe83e4eb53 · 2018-07-16T12:35:40.000-04:00
Fixes #1778. Risk level: Medium. A very conservative 5 minute default idle timeout has been set, which should not affect most deployments with default timeout already kicking in for connection idle or upstream idle. This will however affect things like hanging POSTs. Testing: Integration and unit tests added for various timeout scenarios. Signed-off-by: Harvey Tuch <htuch@google.com>
diff --git a/api/envoy/api/v2/route/route.proto b/api/envoy/api/v2/route/route.proto
@@ -313,7 +313,7 @@ message CorsPolicy {
   google.protobuf.BoolValue enabled = 7;
 }
 
-// [#comment:next free field: 24]
+// [#comment:next free field: 25]
 message RouteAction {
   oneof cluster_specifier {
     option (validate.required) = true;
@@ -401,7 +401,9 @@ message RouteAction {
     google.protobuf.BoolValue auto_host_rewrite = 7;
   }
 
-  // Specifies the timeout for the route. If not specified, the default is 15s.
+  // Specifies the upstream timeout for the route. If not specified, the default is 15s. This
+  // spans between the point at which the entire downstream request (i.e. end-of-stream) has been
+  // processed and when the upstream response has been completely processed.
   //
   // .. note::
   //
@@ -423,8 +425,8 @@ message RouteAction {
     // :ref:`config_http_filters_router_x-envoy-max-retries`.
     google.protobuf.UInt32Value num_retries = 2;
 
-    // Specifies a non-zero timeout per retry attempt. This parameter is optional.
-    // The same conditions documented for
+    // Specifies a non-zero upstream timeout per retry attempt. This parameter is optional. The
+    // same conditions documented for
     // :ref:`config_http_filters_router_x-envoy-upstream-rq-per-try-timeout-ms` apply.
     //
     // .. note::
@@ -437,6 +439,28 @@ message RouteAction {
     google.protobuf.Duration per_try_timeout = 3 [(gogoproto.stdduration) = true];
   }
 
+  // Specifies the idle timeout for the route. If not specified, this defaults
+  // to 5 minutes. The default value was select so as not to interfere with any
+  // smaller configured timeouts that may have existed in configurations prior
+  // to the introduction of this feature, while introducing robustness to TCP
+  // connections that terminate without FIN. A value of 0 will completely
+  // disable the idle timeout.
+  //
+  // The idle timeout is distinct to :ref:`timeout
+  // <envoy_api_field_route.RouteAction.timeout>`, which provides an upper bound
+  // on the upstream response time; :ref:`idle_timeout
+  // <envoy_api_field_route.RouteAction.idle_timeout>` instead bounds the amount
+  // of time the request's stream may be idle.
+  //
+  // After header decoding, the idle timeout will apply on downstream and
+  // upstream request events. Each time an encode/decode event for headers or
+  // data is processed for the stream, the timer will be reset. If the timeout
+  // fires, the stream is terminated with a 408 Request Timeout error code if no
+  // upstream response header has been received, otherwise a stream reset
+  // occurs.
+  google.protobuf.Duration idle_timeout = 24
+      [(validate.rules).duration.gt = {}, (gogoproto.stdduration) = true];
+
   // Indicates that the route has a retry policy.
   RetryPolicy retry_policy = 9;
 
diff --git a/docs/root/configuration/http_conn_man/stats.rst b/docs/root/configuration/http_conn_man/stats.rst
@@ -52,6 +52,7 @@ statistics:
    downstream_rq_5xx, Counter, Total 5xx responses
    downstream_rq_ws_on_non_ws_route, Counter, Total WebSocket upgrade requests rejected by non WebSocket routes
    downstream_rq_time, Histogram, Request time milliseconds
+   downstream_rq_idle_timeout, Counter, Total requests closed due to idle timeout
    rs_too_large, Counter, Total response errors due to buffering an overly large body
 
 Per user agent statistics
diff --git a/docs/root/intro/version_history.rst b/docs/root/intro/version_history.rst
@@ -14,6 +14,10 @@ Version history
 * health check: added support for :ref:`custom health check <envoy_api_field_core.HealthCheck.custom_health_check>`.
 * health check: added support for :ref:`specifying jitter as a percentage <envoy_api_field_core.HealthCheck.interval_jitter_percent>`.
 * health_check: added support for :ref:`health check event logging <arch_overview_health_check_logging>`.
+* http: added support for a :ref:`per-stream idle timeout
+  <envoy_api_field_route.RouteAction.idle_timeout>`. This defaults to 5 minutes; if you have
+  other timeouts (e.g. connection idle timeout, upstream response per-retry) that are longer than
+  this in duration, you may want to consider setting a non-default per-stream idle timeout.
 * http: better handling of HEAD requests. Now sending transfer-encoding: chunked rather than content-length: 0.
 * http: response filters not applied to early error paths such as http_parser generated 400s.
 * proxy_protocol: added support for HAProxy Proxy Protocol v2 (AF_INET/AF_INET6 only).
diff --git a/include/envoy/router/router.h b/include/envoy/router/router.h
@@ -472,6 +472,11 @@ class RouteEntry : public ResponseEntry {
    */
   virtual std::chrono::milliseconds timeout() const PURE;
 
+  /**
+   * @return absl::optional<std::chrono::milliseconds> the route's idle timeout.
+   */
+  virtual absl::optional<std::chrono::milliseconds> idleTimeout() const PURE;
+
   /**
    * @return absl::optional<std::chrono::milliseconds> the maximum allowed timeout value derived
    * from 'grpc-timeout' header of a gRPC request. Non-present value disables use of 'grpc-timeout'
diff --git a/source/common/http/async_client_impl.h b/source/common/http/async_client_impl.h
@@ -195,6 +195,7 @@ class AsyncStreamImpl : public AsyncClient::Stream,
         return std::chrono::milliseconds(0);
       }
     }
+    absl::optional<std::chrono::milliseconds> idleTimeout() const override { return absl::nullopt; }
     absl::optional<std::chrono::milliseconds> maxGrpcTimeout() const override {
       return absl::nullopt;
     }
diff --git a/source/common/http/conn_manager_config.h b/source/common/http/conn_manager_config.h
@@ -54,6 +54,7 @@ namespace Http {
   COUNTER  (downstream_rq_4xx)                                                                     \
   COUNTER  (downstream_rq_5xx)                                                                     \
   HISTOGRAM(downstream_rq_time)                                                                    \
+  COUNTER  (downstream_rq_idle_timeout)                                                            \
   COUNTER  (rs_too_large)
 // clang-format on
 
diff --git a/source/common/http/conn_manager_impl.cc b/source/common/http/conn_manager_impl.cc
@@ -396,6 +396,28 @@ ConnectionManagerImpl::ActiveStream::~ActiveStream() {
   ASSERT(state_.filter_call_state_ == 0);
 }
 
+void ConnectionManagerImpl::ActiveStream::resetIdleTimer() {
+  if (idle_timer_ != nullptr) {
+    // TODO(htuch): If this shows up in performance profiles, optimize by only
+    // updating a timestamp here and doing periodic checks for idle timeouts
+    // instead, or reducing the accuracy of timers.
+    idle_timer_->enableTimer(idle_timeout_ms_);
+  }
+}
+
+void ConnectionManagerImpl::ActiveStream::onIdleTimeout() {
+  connection_manager_.stats_.named_.downstream_rq_idle_timeout_.inc();
+  // If headers have not been sent to the user, send a 408.
+  if (response_headers_ != nullptr) {
+    // TODO(htuch): We could send trailers here with an x-envoy timeout header
+    // or gRPC status code, and/or set H2 RST_STREAM error.
+    connection_manager_.doEndStream(*this);
+  } else {
+    sendLocalReply(Grpc::Common::hasGrpcContentType(*request_headers_), Http::Code::RequestTimeout,
+                   "stream timeout", nullptr);
+  }
+}
+
 void ConnectionManagerImpl::ActiveStream::addStreamDecoderFilterWorker(
     StreamDecoderFilterSharedPtr filter, bool dual_filter) {
   ActiveStreamDecoderFilterPtr wrapper(new ActiveStreamDecoderFilter(*this, filter, dual_filter));
@@ -579,6 +601,16 @@ void ConnectionManagerImpl::ActiveStream::decodeHeaders(HeaderMapPtr&& headers,
     // Allow non websocket requests to go through websocket enabled routes.
   }
 
+  if (cached_route_.value()) {
+    const Router::RouteEntry* route_entry = cached_route_.value()->routeEntry();
+    if (route_entry != nullptr && route_entry->idleTimeout()) {
+      idle_timeout_ms_ = route_entry->idleTimeout().value();
+      idle_timer_ = connection_manager_.read_callbacks_->connection().dispatcher().createTimer(
+          [this]() -> void { onIdleTimeout(); });
+      resetIdleTimer();
+    }
+  }
+
   // Check if tracing is enabled at all.
   if (connection_manager_.config_.tracingConfig()) {
     traceRequest();
@@ -702,6 +734,8 @@ void ConnectionManagerImpl::ActiveStream::decodeData(Buffer::Instance& data, boo
 
 void ConnectionManagerImpl::ActiveStream::decodeData(ActiveStreamDecoderFilter* filter,
                                                      Buffer::Instance& data, bool end_stream) {
+  resetIdleTimer();
+
   // If a response is complete or a reset has been sent, filters do not care about further body
   // data. Just drop it.
   if (state_.local_complete_) {
@@ -750,6 +784,7 @@ void ConnectionManagerImpl::ActiveStream::addDecodedData(ActiveStreamDecoderFilt
 }
 
 void ConnectionManagerImpl::ActiveStream::decodeTrailers(HeaderMapPtr&& trailers) {
+  resetIdleTimer();
   maybeEndDecode(true);
   request_trailers_ = std::move(trailers);
   decodeTrailers(nullptr, *request_trailers_);
@@ -846,6 +881,7 @@ void ConnectionManagerImpl::ActiveStream::sendLocalReply(
 
 void ConnectionManagerImpl::ActiveStream::encode100ContinueHeaders(
     ActiveStreamEncoderFilter* filter, HeaderMap& headers) {
+  resetIdleTimer();
   ASSERT(connection_manager_.config_.proxy100Continue());
   // Make sure commonContinue continues encode100ContinueHeaders.
   has_continue_headers_ = true;
@@ -882,6 +918,8 @@ void ConnectionManagerImpl::ActiveStream::encode100ContinueHeaders(
 
 void ConnectionManagerImpl::ActiveStream::encodeHeaders(ActiveStreamEncoderFilter* filter,
                                                         HeaderMap& headers, bool end_stream) {
+  resetIdleTimer();
+
   std::list<ActiveStreamEncoderFilterPtr>::iterator entry = commonEncodePrefix(filter, end_stream);
   std::list<ActiveStreamEncoderFilterPtr>::iterator continue_data_entry = encoder_filters_.end();
 
@@ -1019,6 +1057,7 @@ void ConnectionManagerImpl::ActiveStream::addEncodedData(ActiveStreamEncoderFilt
 
 void ConnectionManagerImpl::ActiveStream::encodeData(ActiveStreamEncoderFilter* filter,
                                                      Buffer::Instance& data, bool end_stream) {
+  resetIdleTimer();
   std::list<ActiveStreamEncoderFilterPtr>::iterator entry = commonEncodePrefix(filter, end_stream);
   for (; entry != encoder_filters_.end(); entry++) {
     ASSERT(!(state_.filter_call_state_ & FilterCallState::EncodeData));
@@ -1042,6 +1081,7 @@ void ConnectionManagerImpl::ActiveStream::encodeData(ActiveStreamEncoderFilter*
 
 void ConnectionManagerImpl::ActiveStream::encodeTrailers(ActiveStreamEncoderFilter* filter,
                                                          HeaderMap& trailers) {
+  resetIdleTimer();
   std::list<ActiveStreamEncoderFilterPtr>::iterator entry = commonEncodePrefix(filter, true);
   for (; entry != encoder_filters_.end(); entry++) {
     ASSERT(!(state_.filter_call_state_ & FilterCallState::EncodeTrailers));
diff --git a/source/common/http/conn_manager_impl.h b/source/common/http/conn_manager_impl.h
@@ -362,6 +362,10 @@ class ConnectionManagerImpl : Logger::Loggable<Logger::Id::http>,
     void setBufferLimit(uint32_t limit);
     // Set up the Encoder/Decoder filter chain.
     bool createFilterChain();
+    // Per-stream idle timeout callback.
+    void onIdleTimeout();
+    // Reset per-stream idle timer.
+    void resetIdleTimer();
 
     ConnectionManagerImpl& connection_manager_;
     Router::ConfigConstSharedPtr snapped_route_config_;
@@ -379,6 +383,9 @@ class ConnectionManagerImpl : Logger::Loggable<Logger::Id::http>,
     std::list<ActiveStreamEncoderFilterPtr> encoder_filters_;
     std::list<AccessLog::InstanceSharedPtr> access_log_handlers_;
     Stats::TimespanPtr request_timer_;
+    // Per-stream idle timeout.
+    Event::TimerPtr idle_timer_;
+    std::chrono::milliseconds idle_timeout_ms_{};
     State state_;
     RequestInfo::RequestInfoImpl request_info_;
     absl::optional<Router::RouteConstSharedPtr> cached_route_;
diff --git a/source/common/router/config_impl.cc b/source/common/router/config_impl.cc
@@ -258,6 +258,8 @@ RouteEntryImplBase::RouteEntryImplBase(const VirtualHostImpl& vhost,
       cluster_not_found_response_code_(ConfigUtility::parseClusterNotFoundResponseCode(
           route.route().cluster_not_found_response_code())),
       timeout_(PROTOBUF_GET_MS_OR_DEFAULT(route.route(), timeout, DEFAULT_ROUTE_TIMEOUT_MS)),
+      idle_timeout_(
+          PROTOBUF_GET_MS_OR_DEFAULT(route.route(), idle_timeout, DEFAULT_ROUTE_IDLE_TIMEOUT_MS)),
       max_grpc_timeout_(PROTOBUF_GET_OPTIONAL_MS(route.route(), max_grpc_timeout)),
       runtime_(loadRuntimeData(route.match())), loader_(factory_context.runtime()),
       host_redirect_(route.redirect().host_redirect()),
diff --git a/source/common/router/config_impl.h b/source/common/router/config_impl.h
@@ -311,6 +311,10 @@ class RouteEntryImplBase : public RouteEntry,
     return vhost_.virtualClusterFromEntries(headers);
   }
   std::chrono::milliseconds timeout() const override { return timeout_; }
+  absl::optional<std::chrono::milliseconds> idleTimeout() const override {
+    return idle_timeout_.count() == 0 ? absl::nullopt
+                                      : absl::optional<std::chrono::milliseconds>(idle_timeout_);
+  }
   absl::optional<std::chrono::milliseconds> maxGrpcTimeout() const override {
     return max_grpc_timeout_;
   }
@@ -395,6 +399,9 @@ class RouteEntryImplBase : public RouteEntry,
     const RetryPolicy& retryPolicy() const override { return parent_->retryPolicy(); }
     const ShadowPolicy& shadowPolicy() const override { return parent_->shadowPolicy(); }
     std::chrono::milliseconds timeout() const override { return parent_->timeout(); }
+    absl::optional<std::chrono::milliseconds> idleTimeout() const override {
+      return parent_->idleTimeout();
+    }
     absl::optional<std::chrono::milliseconds> maxGrpcTimeout() const override {
       return parent_->maxGrpcTimeout();
     }
@@ -503,6 +510,9 @@ class RouteEntryImplBase : public RouteEntry,
   // Default timeout is 15s if nothing is specified in the route config.
   static const uint64_t DEFAULT_ROUTE_TIMEOUT_MS = 15000;
 
+  // Default idle timeout is 5 minutes if nothing is specified in the route config.
+  static const uint64_t DEFAULT_ROUTE_IDLE_TIMEOUT_MS = 5 * 60 * 1000;
+
   std::unique_ptr<const CorsPolicyImpl> cors_policy_;
   const VirtualHostImpl& vhost_; // See note in RouteEntryImplBase::clusterEntry() on why raw ref
                                  // to virtual host is currently safe.
@@ -512,6 +522,7 @@ class RouteEntryImplBase : public RouteEntry,
   const Http::LowerCaseString cluster_header_name_;
   const Http::Code cluster_not_found_response_code_;
   const std::chrono::milliseconds timeout_;
+  const std::chrono::milliseconds idle_timeout_;
   const absl::optional<std::chrono::milliseconds> max_grpc_timeout_;
   const absl::optional<RuntimeData> runtime_;
   Runtime::Loader& loader_;
diff --git a/test/common/http/conn_manager_impl_test.cc b/test/common/http/conn_manager_impl_test.cc
diff --git a/test/common/router/config_impl_test.cc b/test/common/router/config_impl_test.cc
diff --git a/test/integration/BUILD b/test/integration/BUILD
diff --git a/test/integration/idle_timeout_integration_test.cc b/test/integration/idle_timeout_integration_test.cc
diff --git a/test/mocks/router/mocks.h b/test/mocks/router/mocks.h

Original file line number	Diff line number	Diff line change
`@@ -195,6 +195,7 @@ class AsyncStreamImpl : public AsyncClient::Stream,`
`195`	`195`	`return std::chrono::milliseconds(0);`
`196`	`196`	`}`
`197`	`197`	`}`
	`198`	`+ absl::optional<std::chrono::milliseconds> idleTimeout() const override { return absl::nullopt; }`
`198`	`199`	`absl::optional<std::chrono::milliseconds> maxGrpcTimeout() const override {`
`199`	`200`	`return absl::nullopt;`
`200`	`201`	`}`