Random connection issues HTTP/1.1" 0 DC "-" "-"

Hi. Hoping to get some clarity.

We are doing some performance testing to try and pin down a cause of random disconnects with our setup.

We have an elasticsearch running in GKE and are loading data via an Ingress GW from a Dataproc Cluster.

The direction is:
Dataproc > Loadbalancer > Ingress GW > istio-proxy sidecar > Elasticsearch

What we see is that randomly the requests get dropped and our loading tasks would fail.

We’ve done a lot of tests to try and pinpoint the cause, but no luck so far.

Some of the tests we tried were

  1. Direct to Pod access (no istio sidecar) without SSL. Result: No drops
  2. Direct to Pod access (no istio sidecar) with SSL. Result: No drops
  3. Via the Ingress GW, but mTLS and RBAC Disabled between Ingress GW and Sidecar. Result: No drops
  4. Via the Ingress GW, mTLS on by default. Result: Multiple drops

We don’t want to disable mTLS, but still interesting as to why it is more stable without mTLS/RBAC in place.

Everytime there is a failure, in the sidecar logs I get pretty much the same output:

[Envoy (Epoch 0)] [2020-11-30 17:24:58.611][28][debug][pool] [external/envoy/source/common/http/http1/conn_pool.cc:201] [C99] response complete
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.611][28][debug][pool] [external/envoy/source/common/http/http1/conn_pool.cc:239] [C99] moving to ready
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.611][28][debug][filter] [src/envoy/http/mixer/filter.cc:222] Called Mixer::Filter : log
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.611][28][debug][filter] [./src/envoy/http/mixer/report_data.h:144] No dynamic_metadata found for filter envoy.filters.http.rbac
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.612][28][debug][filter] [src/istio/control/client_context_base.cc:139] Report attributes: attributes {
      key: "connection.mtls"
      value {
    bool_value: true
      }
    }
    attributes {
      key: "connection.requested_server_name"
      value {
    string_value: "outbound_.9200_._.elasticsearc
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.613][28][debug][connection] [external/envoy/source/common/network/connection_impl.cc:455] [C98] onBelowWriteBufferLowWatermark
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.872][28][debug][filter] [src/envoy/http/mixer/filter.cc:96] Called Mixer::Filter : decodeData (740, false)
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.877][28][debug][http] [external/envoy/source/common/http/conn_manager_impl.cc:1276] [C79][S14371904417471549645] request end stream
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.879][28][debug][filter] [src/envoy/http/mixer/filter.cc:96] Called Mixer::Filter : decodeData (0, true)
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.879][28][debug][connection] [external/envoy/source/common/network/connection_impl.cc:538] [C79] remote close
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.879][28][debug][connection] [external/envoy/source/common/network/connection_impl.cc:192] [C79] closing socket: 0
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.879][28][debug][connection] [external/envoy/source/extensions/transport_sockets/tls/ssl_socket.cc:298] [C79] SSL shutdown: rc=1
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.879][28][debug][connection] [external/envoy/source/extensions/transport_sockets/tls/ssl_socket.cc:226] [C79] 
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.879][28][debug][http] [external/envoy/source/common/http/conn_manager_impl.cc:1855] [C79][S14371904417471549645] stream reset
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.879][28][debug][filter] [src/envoy/http/authn/http_filter.cc:49] Called AuthenticationFilter : onDestroy
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.879][28][debug][filter] [src/envoy/http/mixer/filter.cc:208] Called Mixer::Filter : onDestroy state: 2
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.879][28][debug][router] [external/envoy/source/common/router/router.cc:1657] [C79][S14371904417471549645] resetting pool request
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.879][28][debug][client] [external/envoy/source/common/http/codec_client.cc:114] [C103] request reset
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.879][28][debug][connection] [external/envoy/source/common/network/connection_impl.cc:101] [C103] closing data_to_write=740 type=1
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.879][28][debug][connection] [external/envoy/source/common/network/connection_impl.cc:192] [C103] closing socket: 1
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.879][28][debug][client] [external/envoy/source/common/http/codec_client.cc:91] [C103] disconnect. resetting 0 pending requests
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.879][28][debug][pool] [external/envoy/source/common/http/http1/conn_pool.cc:136] [C103] client disconnected, failure reason: 
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.879][28][debug][conn_handler] [external/envoy/source/server/connection_handler_impl.cc:86] [C79] adding to cleanup list
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.879][28][debug][filter] [src/envoy/http/mixer/filter.cc:222] Called Mixer::Filter : log
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.879][28][debug][filter] [./src/envoy/http/mixer/report_data.h:144] No dynamic_metadata found for filter envoy.filters.http.rbac
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.880][28][debug][filter] [src/istio/control/client_context_base.cc:139] Report attributes: attributes {
      key: "connection.mtls"
      value {
    bool_value: true
      }
    }
    attributes {
      key: "connection.requested_server_name"
      value {
    string_value: "outbound_.9200_._.elasticsearc
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.882][28][debug][http] [external/envoy/source/common/http/conn_manager_impl.cc:263] [C98] new stream
    [Envoy (Epoch 0)] [2020-11-30 17:24:58.882][28][debug][http] [external/envoy/source/common/http/conn_manager_impl.cc:731] [C98][S1048916221831723008] request headers complete (end_stream=false):

Any suggestions on how to pin point what the cause is?

Did you get this fixed?

No. No idea what is happening. We did a lot of tests, and there are always some of these DC 0 calls which cause Elastic Loader failures