Envoy: HTTP Proxy Hangs: HTTP Connection Management Configuration

Created on 3 Aug 2018  路  1Comment  路  Source: envoyproxy/envoy

Title: Envoy is not proxying HTTP requests based on the domain. Curl cmd hang indefinitely

Description:

I've configure Envoy using ADS to proxy all HTTP connections and route the request based on the domain name. However, the HTTP connection seems to hang indefinitely when i test it with curl/httpie.

I should also note that for each "cluster", I have a TCP Listener and the HTTP Manager pointing to them.

Any suggestions?

Terminal

# curl -v video-scheduler.service.consul.westeros-master.uhana.io:5555     
* Rebuilt URL to: video-scheduler.service.consul.westeros-master.uhana.io:5555/
*   Trying 172.27.1.155...
* Connected to video-scheduler.service.consul.westeros-master.uhana.io (172.27.1.155) port 5555 (#0)
> GET / HTTP/1.1
> Host: video-scheduler.service.consul.westeros-master.uhana.io:5555
> User-Agent: curl/7.47.0
> Accept: */*
> 
[ hangs indefinitely... ]

Envoy trace Logs

[2018-08-03 18:21:41.922][46][debug][main] source/server/connection_handler_impl.cc:217] [C36] new connection
[2018-08-03 18:21:41.922][46][trace][connection] source/common/network/connection_impl.cc:389] [C36] socket event: 3
[2018-08-03 18:21:41.922][46][trace][connection] source/common/network/connection_impl.cc:457] [C36] write ready
[2018-08-03 18:21:41.922][46][trace][connection] source/common/network/connection_impl.cc:427] [C36] read ready
[2018-08-03 18:21:41.922][46][trace][connection] source/common/network/raw_buffer_socket.cc:23] [C36] read returns: 124
[2018-08-03 18:21:41.922][46][trace][connection] source/common/network/raw_buffer_socket.cc:23] [C36] read returns: -1
[2018-08-03 18:21:41.922][46][trace][connection] source/common/network/raw_buffer_socket.cc:31] [C36] read error: 11
[2018-08-03 18:21:41.922][46][trace][http] source/common/http/http1/codec_impl.cc:341] [C36] parsing 124 bytes
[2018-08-03 18:21:41.922][46][trace][http] source/common/http/http1/codec_impl.cc:439] [C36] message begin
[2018-08-03 18:21:41.922][46][debug][http] source/common/http/conn_manager_impl.cc:191] [C36] new stream
[2018-08-03 18:21:41.923][46][trace][http] source/common/http/http1/codec_impl.cc:309] [C36] completed header: key=Host value=video-scheduler.service.consul.westeros-master.uhana.io:5555
[2018-08-03 18:21:41.923][46][trace][http] source/common/http/http1/codec_impl.cc:309] [C36] completed header: key=User-Agent value=curl/7.54.0
[2018-08-03 18:21:41.923][46][trace][http] source/common/http/http1/codec_impl.cc:405] [C36] headers complete
[2018-08-03 18:21:41.923][46][trace][http] source/common/http/http1/codec_impl.cc:309] [C36] completed header: key=Accept value=*/*
[2018-08-03 18:21:41.923][46][trace][http] source/common/http/http1/codec_impl.cc:426] [C36] message complete
[2018-08-03 18:21:41.923][46][debug][http] source/common/http/conn_manager_impl.cc:848] [C36][S17487243197426659549] request end stream
[2018-08-03 18:21:41.923][46][debug][http] source/common/http/conn_manager_impl.cc:488] [C36][S17487243197426659549] request headers complete (end_stream=true):
':authority', 'video-scheduler.service.consul.westeros-master.uhana.io:5555'
':path', '/'
':method', 'GET'
'user-agent', 'curl/7.54.0'
'accept', '*/*'

[2018-08-03 18:21:41.923][46][trace][http] source/common/http/http1/codec_impl.cc:362] [C36] parsed 124 bytes
[2018-08-03 18:21:41.923][46][trace][connection] source/common/network/connection_impl.cc:232] [C36] readDisable: enabled=true disable=true
[2018-08-03 18:21:41.923][46][trace][connection] source/common/network/connection_impl.cc:389] [C36] socket event: 2
[2018-08-03 18:21:41.923][46][trace][connection] source/common/network/connection_impl.cc:457] [C36] write ready
[2018-08-03 18:21:43.329][30][debug][main] source/server/server.cc:119] flushing stats
[2018-08-03 18:21:44.899][46][trace][connection] source/common/network/connection_impl.cc:389] [C36] socket event: 6
[2018-08-03 18:21:44.899][46][debug][connection] source/common/network/connection_impl.cc:410] [C36] remote early close
[2018-08-03 18:21:44.899][46][debug][connection] source/common/network/connection_impl.cc:133] [C36] closing socket: 0
[2018-08-03 18:21:44.899][46][trace][main] source/common/event/dispatcher_impl.cc:126] item added to deferred deletion list (size=1)
[2018-08-03 18:21:44.899][46][debug][main] source/server/connection_handler_impl.cc:50] [C36] adding to cleanup list
[2018-08-03 18:21:44.899][46][trace][main] source/common/event/dispatcher_impl.cc:126] item added to deferred deletion list (size=2)
[2018-08-03 18:21:44.899][46][trace][main] source/common/event/dispatcher_impl.cc:52] clearing deferred deletion list (size=2)
[2018-08-03 18:21:45.678][51][debug][main] source/server/connection_handler_impl.cc:217] [C37] new connection
[2018-08-03 18:21:45.678][51][trace][connection] source/common/network/connection_impl.cc:389] [C37] socket event: 3
[2018-08-03 18:21:45.678][51][trace][connection] source/common/network/connection_impl.cc:457] [C37] write ready
[2018-08-03 18:21:45.678][51][trace][connection] source/common/network/connection_impl.cc:427] [C37] read ready
[2018-08-03 18:21:45.678][51][trace][connection] source/common/network/raw_buffer_socket.cc:23] [C37] read returns: 124
[2018-08-03 18:21:45.678][51][trace][connection] source/common/network/raw_buffer_socket.cc:23] [C37] read returns: -1
[2018-08-03 18:21:45.678][51][trace][connection] source/common/network/raw_buffer_socket.cc:31] [C37] read error: 11
[2018-08-03 18:21:45.678][51][trace][http] source/common/http/http1/codec_impl.cc:341] [C37] parsing 124 bytes
[2018-08-03 18:21:45.678][51][trace][http] source/common/http/http1/codec_impl.cc:439] [C37] message begin
[2018-08-03 18:21:45.678][51][debug][http] source/common/http/conn_manager_impl.cc:191] [C37] new stream
[2018-08-03 18:21:45.678][51][trace][http] source/common/http/http1/codec_impl.cc:309] [C37] completed header: key=Host value=video-scheduler.service.consul.westeros-master.uhana.io:5555
[2018-08-03 18:21:45.678][51][trace][http] source/common/http/http1/codec_impl.cc:309] [C37] completed header: key=User-Agent value=curl/7.54.0
[2018-08-03 18:21:45.678][51][trace][http] source/common/http/http1/codec_impl.cc:405] [C37] headers complete
[2018-08-03 18:21:45.678][51][trace][http] source/common/http/http1/codec_impl.cc:309] [C37] completed header: key=Accept value=*/*
[2018-08-03 18:21:45.678][51][trace][http] source/common/http/http1/codec_impl.cc:426] [C37] message complete
[2018-08-03 18:21:45.678][51][debug][http] source/common/http/conn_manager_impl.cc:848] [C37][S5820302744768221260] request end stream
[2018-08-03 18:21:45.678][51][debug][http] source/common/http/conn_manager_impl.cc:488] [C37][S5820302744768221260] request headers complete (end_stream=true):
':authority', 'video-scheduler.service.consul.westeros-master.uhana.io:5555'
':path', '/'
':method', 'GET'
'user-agent', 'curl/7.54.0'
'accept', '*/*'

[2018-08-03 18:21:45.678][51][trace][http] source/common/http/http1/codec_impl.cc:362] [C37] parsed 124 bytes

Envoy /config_dump summary

{
 "configs": {
  "listeners": {
   "@type": "type.googleapis.com/envoy.admin.v2alpha.ListenersConfigDump",
   "version_info": "version-172.27.1.56-108",
   "dynamic_active_listeners": [
    {
     "version_info": "version-172.27.1.56-104",
     "listener": {
      "name": "westeros-master-main-http-proxy",
      "address": {
       "socket_address": {
        "address": "0.0.0.0",
        "port_value": 5555
       }
      },
      "filter_chains": [
       {
        "filters": [
         {
          "name": "envoy.http_connection_manager",
          "config": {
           "stat_prefix": "main_http",
           "rds": {
            "route_config_name": "westeros-master",
            "config_source": {
             "ads": {}
            }
           },
           "filters": {},
           "codec_type": "HTTP1"
          }
         }
        ]
       }
      ]
     },
     "last_updated": "2018-08-03T18:21:26.564Z"
    },
...
  "routes": {
   "@type": "type.googleapis.com/envoy.admin.v2alpha.RoutesConfigDump",
   "dynamic_route_configs": [
    {
     "version_info": "version-172.27.1.56-109",
     "route_config": {
      "name": "westeros-master",
      "virtual_hosts": [
      ...
       {
        "name": "http-video-scheduler",
        "domains": [
         "video-scheduler:5555",
         "video-scheduler.service.consul:5555",
         "video-scheduler.service.consul.westeros-master.uhana.io:5555",
         "video-scheduler.westeros-master.uhana.io:5555",
         "video-scheduler",
         "video-scheduler.service.consul",
         "video-scheduler.service.consul.westeros-master.uhana.io",
         "video-scheduler.westeros-master.uhana.io"
        ],
        "routes": [
         {
          "match": {
           "prefix": "/"
          },
          "route": {
           "cluster": "video-scheduler-westeros-master"
          }
         }
        ]
       },
    ....
  "clusters": {
   "@type": "type.googleapis.com/envoy.admin.v2alpha.ClustersConfigDump",
   "version_info": "version-172.27.1.56-106",
   "dynamic_active_clusters": [
    {
     "version_info": "version-172.27.1.56-102",
     "cluster": {
      "name": "video-scheduler-westeros-master",
      "type": "EDS",
      "eds_cluster_config": {
       "eds_config": {
        "ads": {}
       }
      },
      "connect_timeout": "5s",
      "load_assignment": {
       "cluster_name": "video-scheduler-westeros-master",
       "endpoints": [
        {
         "lb_endpoints": [
          {
           "endpoint": {
            "address": {
             "socket_address": {
              "address": "172.27.1.56",
              "port_value": 29786
             }
            }
           }
          },
          {
           "endpoint": {
            "address": {
             "socket_address": {
              "address": "172.27.1.155",
              "port_value": 28249
             }
            }
           }
          }
         ]
        }
       ]
      }
     },
     "last_updated": "2018-08-03T18:21:26.361Z"
    },
...
question
Source
picture zanes2016

Most helpful comment

The issue was that the http_filters was not set in the http_connection_manager configuration:

"http_filters": {
            "name": "envoy.router",
            "config": {}
}

Thus, the envoy proxy seems to just hang on a connection (or is waiting for an ADS update - it's not exactly clear). It would be good to update the documentation to state that at least one http_filter is required.

The correct configuration:

...
"filters": [
         {
          "name": "envoy.http_connection_manager",
          "config": {
           "codec_type": "HTTP1",
           "http_protocol_options": {
            "allow_absolute_url": true
           },
           "rds": {
            "route_config_name": "westeros-master",
            "config_source": {
             "ads": {}
            }
           },
           "stat_prefix": "main_http",
           "filters": {},
           "http_filters": {
            "name": "envoy.router",
            "config": {}
           }
          }
         }
        ]
...
picture zanes2016 on 3 Aug 2018
👍3 ❤1

>All comments

The issue was that the http_filters was not set in the http_connection_manager configuration:

"http_filters": {
            "name": "envoy.router",
            "config": {}
}

Thus, the envoy proxy seems to just hang on a connection (or is waiting for an ADS update - it's not exactly clear). It would be good to update the documentation to state that at least one http_filter is required.

The correct configuration:

...
"filters": [
         {
          "name": "envoy.http_connection_manager",
          "config": {
           "codec_type": "HTTP1",
           "http_protocol_options": {
            "allow_absolute_url": true
           },
           "rds": {
            "route_config_name": "westeros-master",
            "config_source": {
             "ads": {}
            }
           },
           "stat_prefix": "main_http",
           "filters": {},
           "http_filters": {
            "name": "envoy.router",
            "config": {}
           }
          }
         }
        ]
...
zanes2016 picture zanes2016 on 3 Aug 2018
👍3 ❤1
Was this page helpful?
0 / 5 - 0 ratings

Related issues

lps0535 picture lps0535  路  3Comments
karthequian picture karthequian  路  3Comments
zanes2016 picture zanes2016  路  3Comments
roelfdutoit picture roelfdutoit  路  3Comments
boncheo picture boncheo  路  3Comments