envoy: Cannot connect to gRPC service from envoy when using TLS, gets a response of 503

Title: Cannot connect to gRPC service from envoy when using TLS, get a response of 503

Description: I have a gRPC service that is called from envoy on behalf of a web-browser client. When I have a non-TLS based website everything works. However, when I switch the website and the proxy to use TLS via a self-signed certificate, the envoy proxy returns with a 503. Thanks for your help

Config:

  listeners:
  - address:
      socket_address:
        address: 0.0.0.0
        port_value: 8080
    filter_chains:
    - filters:
      - name: envoy.http_connection_manager
        config:
          codec_type: auto
          stat_prefix: ingress_http
          route_config:
            name: local_route
            virtual_hosts:
            - name: local_service
              domains:
              - "*"
              routes:
              - match:
                  prefix: "/"
                route:
                  cluster: AuctioneerService
                  max_grpc_timeout: 0s
              cors:
                allow_origin:
                - "yams.com"
                allow_methods: GET, PUT, DELETE, POST, OPTIONS
                allow_headers: keep-alive,user-agent,cache-control,content-type,content-transfer-encoding,custom-header-1,x-accept-content-transfer-encoding,x-accept-response-streaming,x-user-agent,x-grpc
                max_age: "1728000"
                expose_headers: custom-header-1,grpc-status,grpc-message
          http_filters:
          - name: envoy.router
          - name: envoy.grpc_web
          - name: envoy.cors
            config: {}
      tls_context:
        common_tls_context:
          alpn_protocols: "h2"
          tls_certificates:
            - certificate_chain:
                filename: "/etc/crt"
              private_key:
                filename: "/etc/key"
  clusters:
  - name: AuctioneerService
    connect_timeout: 0.25s
    type: strict_dns
    http2_protocol_options: {}
    lb_policy: round_robin
    hosts: [{ socket_address: { address: 0.0.0.0, port_value: 9090 }}]
admin:
  access_log_path: "/dev/null"
  address:
    socket_address:
      address: 0.0.0.0

Logs:

':method', 'OPTIONS'
':authority', 'yams.com:8080'
':scheme', 'https'
':path', '/auctioneer.Auctioneer/Sell'
'access-control-request-method', 'POST'
'origin', 'https://yams.com:4200'
'user-agent', 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/75.0.3770.100 Safari/537.36'
'access-control-request-headers', 'content-type,x-grpc-web,x-user-agent'
'accept', '*/*'
'referer', 'https://yams.com:4200/yams'
'accept-encoding', 'gzip, deflate, br'
'accept-language', 'en-US,en;q=0.9'

[2019-07-26 20:35:40.223][13][debug][http] [source/common/http/conn_manager_impl.cc:1092] [C0][S12928722490925780738] request end stream
[2019-07-26 20:35:40.224][13][debug][router] [source/common/router/router.cc:401] [C0][S12928722490925780738] cluster 'AuctioneerService' match for URL '/auctioneer.Auctioneer/Sell'
[2019-07-26 20:35:40.224][13][debug][router] [source/common/router/router.cc:514] [C0][S12928722490925780738] router decoding headers:
':method', 'OPTIONS'
':authority', 'yams.com:8080'
':scheme', 'http'
':path', '/auctioneer.Auctioneer/Sell'
'access-control-request-method', 'POST'
'origin', 'https://yams.com:4200'
'user-agent', 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/75.0.3770.100 Safari/537.36'
'access-control-request-headers', 'content-type,x-grpc-web,x-user-agent'
'accept', '*/*'
'referer', 'https://yams.com:4200/yams'
'accept-encoding', 'gzip, deflate, br'
'accept-language', 'en-US,en;q=0.9'
'x-forwarded-proto', 'https'
'x-request-id', 'aedda97a-27df-4d5d-9983-84eb95e24fe5'
'x-envoy-expected-rq-timeout-ms', '15000'

[2019-07-26 20:35:40.224][13][debug][pool] [source/common/http/http2/conn_pool.cc:96] [C1] creating stream
[2019-07-26 20:35:40.224][13][debug][router] [source/common/router/router.cc:1503] [C0][S12928722490925780738] pool ready
[2019-07-26 20:35:40.224][13][trace][http2] [source/common/http/http2/codec_impl.cc:559] [C1] send data: bytes=72
[2019-07-26 20:35:40.224][13][trace][connection] [source/common/network/connection_impl.cc:392] [C1] writing 72 bytes, end_stream false
[2019-07-26 20:35:40.224][13][trace][http2] [source/common/http/http2/codec_impl.cc:511] [C1] sent frame type=1
[2019-07-26 20:35:40.224][13][trace][http] [source/common/http/conn_manager_impl.cc:857] [C0][S12928722490925780738] decode headers called: filter=0x39fd450 status=1
[2019-07-26 20:35:40.224][13][trace][http2] [source/common/http/http2/codec_impl.cc:401] [C0] recv frame type=6
[2019-07-26 20:35:40.224][13][trace][http2] [source/common/http/http2/codec_impl.cc:358] [C0] dispatched 82 bytes
[2019-07-26 20:35:40.224][13][trace][http2] [source/common/http/http2/codec_impl.cc:559] [C0] send data: bytes=17
[2019-07-26 20:35:40.224][13][trace][connection] [source/common/network/connection_impl.cc:392] [C0] writing 17 bytes, end_stream false
[2019-07-26 20:35:40.224][13][trace][http2] [source/common/http/http2/codec_impl.cc:511] [C0] sent frame type=6
[2019-07-26 20:35:40.224][13][trace][connection] [source/common/network/connection_impl.cc:456] [C1] socket event: 2
[2019-07-26 20:35:40.224][13][trace][connection] [source/common/network/connection_impl.cc:541] [C1] write ready
[2019-07-26 20:35:40.224][13][trace][connection] [source/common/network/raw_buffer_socket.cc:66] [C1] write returns: 72
[2019-07-26 20:35:40.224][13][trace][connection] [source/common/network/connection_impl.cc:456] [C0] socket event: 2
[2019-07-26 20:35:40.224][13][trace][connection] [source/common/network/connection_impl.cc:541] [C0] write ready
[2019-07-26 20:35:40.224][13][trace][connection] [source/extensions/transport_sockets/tls/ssl_socket.cc:234] [C0] ssl write returns: 17
[2019-07-26 20:35:40.224][13][trace][connection] [source/common/network/connection_impl.cc:456] [C0] socket event: 2
[2019-07-26 20:35:40.224][13][trace][connection] [source/common/network/connection_impl.cc:541] [C0] write ready
[2019-07-26 20:35:40.224][13][trace][connection] [source/common/network/connection_impl.cc:456] [C1] socket event: 3
[2019-07-26 20:35:40.224][13][trace][connection] [source/common/network/connection_impl.cc:541] [C1] write ready
[2019-07-26 20:35:40.224][13][trace][connection] [source/common/network/connection_impl.cc:494] [C1] read ready
[2019-07-26 20:35:40.224][13][trace][connection] [source/common/network/raw_buffer_socket.cc:23] [C1] read returns: 30
[2019-07-26 20:35:40.224][13][trace][connection] [source/common/network/raw_buffer_socket.cc:37] [C1] read error: Resource temporarily unavailable
[2019-07-26 20:35:40.224][13][trace][http2] [source/common/http/http2/codec_impl.cc:343] [C1] dispatching 30 bytes
[2019-07-26 20:35:40.224][13][trace][http2] [source/common/http/http2/codec_impl.cc:401] [C1] recv frame type=3
[2019-07-26 20:35:40.224][13][trace][http2] [source/common/http/http2/codec_impl.cc:497] [C1] remote reset: 2
[2019-07-26 20:35:40.224][13][debug][http2] [source/common/http/http2/codec_impl.cc:568] [C1] stream closed: 2
[2019-07-26 20:35:40.224][13][debug][client] [source/common/http/codec_client.cc:105] [C1] request reset
[2019-07-26 20:35:40.224][13][trace][main] [source/common/event/dispatcher_impl.cc:158] item added to deferred deletion list (size=1)
[2019-07-26 20:35:40.224][13][debug][pool] [source/common/http/http2/conn_pool.cc:233] [C1] destroying stream: 0 remaining
[2019-07-26 20:35:40.224][13][debug][router] [source/common/router/router.cc:868] [C0][S12928722490925780738] upstream reset: reset reason remote reset
[2019-07-26 20:35:40.224][13][debug][http] [source/common/http/conn_manager_impl.cc:1167] [C0][S12928722490925780738] Sending local reply with details upstream_reset_before_response_started{remote reset}
[2019-07-26 20:35:40.224][13][trace][http] [source/common/http/conn_manager_impl.cc:1254] [C0][S12928722490925780738] encode headers called: filter=0x39f92c0 status=0
[2019-07-26 20:35:40.224][13][trace][http] [source/common/http/conn_manager_impl.cc:1254] [C0][S12928722490925780738] encode headers called: filter=0x39f9600 status=0
[2019-07-26 20:35:40.224][13][debug][http] [source/common/http/conn_manager_impl.cc:1359] [C0][S12928722490925780738] encoding headers via codec (end_stream=false):
':status', '503'
'content-length', '85'
'content-type', 'text/plain'
'date', 'Fri, 26 Jul 2019 20:35:39 GMT'
'server', 'envoy'

[2019-07-26 20:35:40.224][13][trace][http2] [source/common/http/http2/codec_impl.cc:559] [C0] send data: bytes=41
[2019-07-26 20:35:40.224][13][trace][connection] [source/common/network/connection_impl.cc:392] [C0] writing 41 bytes, end_stream false
[2019-07-26 20:35:40.224][13][trace][http2] [source/common/http/http2/codec_impl.cc:511] [C0] sent frame type=1
[2019-07-26 20:35:40.224][13][trace][http] [source/common/http/conn_manager_impl.cc:1484] [C0][S12928722490925780738] encode data called: filter=0x39f92c0 status=0
[2019-07-26 20:35:40.224][13][trace][http] [source/common/http/conn_manager_impl.cc:1484] [C0][S12928722490925780738] encode data called: filter=0x39f9600 status=0
[2019-07-26 20:35:40.224][13][trace][http] [source/common/http/conn_manager_impl.cc:1497] [C0][S12928722490925780738] encoding data via codec (size=85 end_stream=true)
[2019-07-26 20:35:40.224][13][trace][connection] [source/common/network/connection_impl.cc:392] [C0] writing 94 bytes, end_stream false
[2019-07-26 20:35:40.224][13][trace][http2] [source/common/http/http2/codec_impl.cc:511] [C0] sent frame type=0
[2019-07-26 20:35:40.224][13][debug][http2] [source/common/http/http2/codec_impl.cc:568] [C0] stream closed: 0
[2019-07-26 20:35:40.224][13][trace][main] [source/common/event/dispatcher_impl.cc:158] item added to deferred deletion list (size=2)
[2019-07-26 20:35:40.224][13][trace][main] [source/common/event/dispatcher_impl.cc:158] item added to deferred deletion list (size=3)
[2019-07-26 20:35:40.224][13][trace][main] [source/common/event/dispatcher_impl.cc:158] item added to deferred deletion list (size=4)
[2019-07-26 20:35:40.224][13][trace][http2] [source/common/http/http2/codec_impl.cc:401] [C1] recv frame type=6
[2019-07-26 20:35:40.224][13][trace][http2] [source/common/http/http2/codec_impl.cc:358] [C1] dispatched 30 bytes
[2019-07-26 20:35:40.224][13][trace][http2] [source/common/http/http2/codec_impl.cc:559] [C1] send data: bytes=17
[2019-07-26 20:35:40.224][13][trace][connection] [source/common/network/connection_impl.cc:392] [C1] writing 17 bytes, end_stream false

About this issue

Original URL
State: closed
Created 5 years ago
Comments: 24 (7 by maintainers)

Most upvoted comments

@bitsmaker Tried the above No success. On checking envoy logs i am getting following error. TLS error: 268435703:SSL routines:OPENSSL_internal:WRONG_VERSION_NUMBER but the same certificate is working when I am creating grpc client and using it without grpc-web.

kumaranshu72 on Jun 11, 2020

@bitsmaker After adding the following config in envoy.yaml

        common_tls_context:
          tls_certificates:
            - certificate_chain:
                filename: "/etc/server.crt"
              private_key:
                filename: "/etc/server.key"

I am getting the following error. {code: 2, message: "Http response at 400 or 500 level"}

Everything is working fine if I remove TLS from the server-side. But not working when TSL is required. You can also check the details code I have mentioned here. https://stackoverflow.com/questions/62303049/grpc-web-connectivity-issue-in-tls

kumaranshu72 on Jun 10, 2020