" server closed the stream without sending trailers" error when calling grpc endpoints over ambassador with TLS

1.8k views Asked by At

I'm getting the error "server closed the stream without sending trailers" on the GRPC client side, when calling the GRPC endpoint exposed in Ambassador.

So my stack is : Client GRPC code -> Ambassador -> grpc-service-envoy -> grpc-service

I can see the request going all the way to grpc-service, and they seem to reach the grpc-service-envoy too.

Note that http transcoded calls are working fine. Just the grpc calls are causing issues.

Any idea what could be wrong here?

envoy conf file:

admin:
  access_log_path: /tmp/admin_access.log
  address:
    socket_address: { address: 0.0.0.0, port_value: 9901 }

static_resources:
  listeners:
  - name: mix-api-listener
    address:
      socket_address: { address: 0.0.0.0, port_value: 51051 }
    filter_chains:
    - filters:
      - name: envoy.http_connection_manager
        config:
          stat_prefix: grpc_json
          codec_type: AUTO
          route_config:
            name: local_route
            virtual_hosts:
            - name: local_service
              domains: ["*"]
              routes:
              - match: { prefix: "/swagger-ui"}
                route: { cluster: swagger-backend-services, timeout: { seconds: 1500 } }
              - match: { prefix: "/swagger-resources"}
                route: { cluster: swagger-backend-services, timeout: { seconds: 1500 } }
              - match: { prefix: "/v2"}
                route: { cluster: swagger-backend-services, timeout: { seconds: 1500 } }
              - match: { prefix: "/", grpc: {} }
                route: { cluster: grpc-backend-services, timeout: { seconds: 120 } }
          http_filters:
          - name: envoy.grpc_json_transcoder
            config:
              proto_descriptor: "/data/mix-api.pb"
              services: ["mix.api.MixAPI"]
              print_options:
                add_whitespace: true
                always_print_primitive_fields: true
                always_print_enums_as_ints: false
                preserve_proto_field_names: false
          - name: envoy.router

  clusters:
  - name: grpc-backend-services
    connect_timeout: 150s
    type: logical_dns
    lb_policy: round_robin
    dns_lookup_family: V4_ONLY
    http2_protocol_options: {}
    hosts:
    - socket_address:
        address: ${GRPC_HOST}
        port_value: 9090
  - name: swagger-backend-services
    connect_timeout: 150s
    type: logical_dns
    lb_policy: round_robin
    dns_lookup_family: V4_ONLY
    hosts:
    - socket_address:
        address: ${GRPC_HOST}
        port_value: 8080

envoy logs:

[2020-12-10 19:11:11.616][36][trace][connection] [source/common/network/connection_impl.cc:508] [C6] socket event: 3
[2020-12-10 19:11:11.616][36][trace][connection] [source/common/network/connection_impl.cc:616] [C6] write ready
[2020-12-10 19:11:11.616][36][trace][connection] [source/common/network/connection_impl.cc:546] [C6] read ready. dispatch_buffered_data=false
[2020-12-10 19:11:11.616][36][trace][connection] [source/common/network/raw_buffer_socket.cc:25] [C6] read returns: 2070
[2020-12-10 19:11:11.616][36][trace][connection] [source/common/network/raw_buffer_socket.cc:39] [C6] read error: Resource temporarily unavailable
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:535] [C6] parsing 2070 bytes
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:768] [C6] message begin
[2020-12-10 19:11:11.616][36][debug][http] [source/common/http/conn_manager_impl.cc:225] [C6] new stream
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=host value=mix-api.dev.cd4.crt.nuance.com:443
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=content-type value=application/grpc
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=user-agent value=grpc-go/1.31.1
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=te value=trailers
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=grpc-client value=evans
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=authorization value=Bearer eyJhbGciOiJSUzI1NiIsImtpZCI6InB1YmxpYzoxYWI2YzUxMC00OGEwLTRiZDUtYmZiNy1mOTY2YzFmMDc1MGQiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOltdLCJjbGllbnRfaWQiOiJtaXgtcG9ydGFsLWNsaWVudCIsImV4cCI6MTYwNzYyNzkyOCwiZXh0Ijp7InN1Yl9pc3MiOiJodHRwczovL2Rldi5jZDQuY3J0Lm51YW5jZS5jb20vYXV0aC9yZWFsbXMvbWl4IiwidGVuYW50IjoibWl4In0sImlhdCI6MTYwNzYyNzAyOCwiaXNzIjoiaHR0cHM6Ly9hdXRoLWRldi5jZDQuY3J0Lm51YW5jZS5jb20vIiwianRpIjoiYmU5YzJkZDYtZDQzOS00Y2E2LWIzNTUtYzMwMzRlMjg3MjVhIiwibmJmIjoxNjA3NjI3MDI4LCJzY3AiOlsibWl4LWFwaSJdLCJzdWIiOiJkNjE4ZTFmMC0zODA4LTQ4OTItYWUyYi03YmZiNDQ4YmQ5MWUifQ.bi6p0r0Zb6ERCo4SXYnj6g6GjK0ZhCMdhqqorbfGE9bgnU4spo0hlGGnGJ8lNY6jhO7qYkPqhvZBX2UmvFeTCfufzIFvYKF2ZQ4j8ONte8LEtAM8RghuQ_WrvMvjF26NhsrCpELkhh2xzvCFt3WbbS6v5w1CyNi-FsB3PJhOgY1UgP0_Iw6quzPz_HHUs6uX3W9J4zUYlKhfqztuAHp01Pzo5DreYX5xjh5ogueye5IlKFDQFZE8FxZMNnXUGJR7nH_s5GkbMS-b-GNheHlNBBQ8QoXiMLUgq6MixcmdK_jvjAnJe8pr3GEDgo71lEvUq7bzL40_Px7kXnJmxg2hgHk7KMrMqyz0009hN0phyPRNF9OtJ-DUxFSvckhUQjddPAx55YQdCJf8AeK3wTwajDNppSZV_Ncbd-GHzf6J4dGNEZBdPDaerhG7Zmu_WF66DJ95luwC8dR0Rh2HYbbURCME0GcbOIxEr7jHnlEBgFbfFUrmuN5qO5y1oqNpe5i1r_9SsvWLZHQYCtlWi1K89zcsN4UOGZbXXy0-AgSAFvU4h3lV73EVJRzgPXoyZQEnHmGAEfUsvfez-JZvOZWsJ86PbK_OQXoxfxLwU5nwAwlspD4JqFgYVSbQUEZ7Tp4TmOqoEnO3QZkY4j49TN70Ip4GrDpOauFNnH_53U5Z05I
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=x-forwarded-for value=10.3.195.67
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=x-forwarded-proto value=https
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=x-envoy-internal value=true
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=x-request-id value=e31b694f-c0d6-9d40-a9ef-01517b1184d3
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=x-nuance-client-id value=mix-portal-client
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=x-nuance-client-id-iss value=https://auth-dev.cd4.crt.nuance.com/
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=x-nuance-client-scopes value=[mix-api]
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=x-nuance-tenant-id value=mix
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=x-nuance-user-id value=d618e1f0-3808-4892-ae2b-7bfb448bd91e
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=x-nuance-user-id-iss value=https://dev.cd4.crt.nuance.com/auth/realms/mix
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=x-envoy-expected-rq-timeout-ms value=120000
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=x-b3-traceid value=6dc62f223a5d9a9a4a0a25f9e2ed22bf
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=x-b3-spanid value=8778e830a199e676
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=x-b3-parentspanid value=4a0a25f9e2ed22bf
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=x-b3-sampled value=1
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:632] [C6] onHeadersCompleteBase
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:470] [C6] completed header: key=transfer-encoding value=chunked
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:874] [C6] Server: onHeadersComplete size=22
[2020-12-10 19:11:11.616][36][debug][http] [source/common/http/conn_manager_impl.cc:837] [C6][S7575434646215072185] request headers complete (end_stream=false):
':authority', 'mix-api.dev.cd4.crt.nuance.com:443'
':path', '/mix.api.MixAPI/GetVersion'
':method', 'POST'
'content-type', 'application/grpc'
'user-agent', 'grpc-go/1.31.1'
'te', 'trailers'
'grpc-client', 'evans'
'authorization', 'Bearer eyJhbGciOiJSUzI1NiIsImtpZCI6InB1YmxpYzoxYWI2YzUxMC00OGEwLTRiZDUtYmZiNy1mOTY2YzFmMDc1MGQiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOltdLCJjbGllbnRfaWQiOiJtaXgtcG9ydGFsLWNsaWVudCIsImV4cCI6MTYwNzYyNzkyOCwiZXh0Ijp7InN1Yl9pc3MiOiJodHRwczovL2Rldi5jZDQuY3J0Lm51YW5jZS5jb20vYXV0aC9yZWFsbXMvbWl4IiwidGVuYW50IjoibWl4In0sImlhdCI6MTYwNzYyNzAyOCwiaXNzIjoiaHR0cHM6Ly9hdXRoLWRldi5jZDQuY3J0Lm51YW5jZS5jb20vIiwianRpIjoiYmU5YzJkZDYtZDQzOS00Y2E2LWIzNTUtYzMwMzRlMjg3MjVhIiwibmJmIjoxNjA3NjI3MDI4LCJzY3AiOlsibWl4LWFwaSJdLCJzdWIiOiJkNjE4ZTFmMC0zODA4LTQ4OTItYWUyYi03YmZiNDQ4YmQ5MWUifQ.bi6p0r0Zb6ERCo4SXYnj6g6GjK0ZhCMdhqqorbfGE9bgnU4spo0hlGGnGJ8lNY6jhO7qYkPqhvZBX2UmvFeTCfufzIFvYKF2ZQ4j8ONte8LEtAM8RghuQ_WrvMvjF26NhsrCpELkhh2xzvCFt3WbbS6v5w1CyNi-FsB3PJhOgY1UgP0_Iw6quzPz_HHUs6uX3W9J4zUYlKhfqztuAHp01Pzo5DreYX5xjh5ogueye5IlKFDQFZE8FxZMNnXUGJR7nH_s5GkbMS-b-GNheHlNBBQ8QoXiMLUgq6MixcmdK_jvjAnJe8pr3GEDgo71lEvUq7bzL40_Px7kXnJmxg2hgHk7KMrMqyz0009hN0phyPRNF9OtJ-DUxFSvckhUQjddPAx55YQdCJf8AeK3wTwajDNppSZV_Ncbd-GHzf6J4dGNEZBdPDaerhG7Zmu_WF66DJ95luwC8dR0Rh2HYbbURCME0GcbOIxEr7jHnlEBgFbfFUrmuN5qO5y1oqNpe5i1r_9SsvWLZHQYCtlWi1K89zcsN4UOGZbXXy0-AgSAFvU4h3lV73EVJRzgPXoyZQEnHmGAEfUsvfez-JZvOZWsJ86PbK_OQXoxfxLwU5nwAwlspD4JqFgYVSbQUEZ7Tp4TmOqoEnO3QZkY4j49TN70Ip4GrDpOauFNnH_53U5Z05I'
'x-forwarded-for', '10.3.195.67'
'x-forwarded-proto', 'https'
'x-envoy-internal', 'true'
'x-request-id', 'e31b694f-c0d6-9d40-a9ef-01517b1184d3'
'x-nuance-client-id', 'mix-portal-client'
'x-nuance-client-id-iss', 'https://auth-dev.cd4.crt.nuance.com/'
'x-nuance-client-scopes', '[mix-api]'
'x-nuance-tenant-id', 'mix'
'x-nuance-user-id', 'd618e1f0-3808-4892-ae2b-7bfb448bd91e'
'x-nuance-user-id-iss', 'https://dev.cd4.crt.nuance.com/auth/realms/mix'
'x-envoy-expected-rq-timeout-ms', '120000'
'x-b3-traceid', '6dc62f223a5d9a9a4a0a25f9e2ed22bf'
'x-b3-spanid', '8778e830a199e676'
'x-b3-parentspanid', '4a0a25f9e2ed22bf'
'x-b3-sampled', '1'
'transfer-encoding', 'chunked'

[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/filter_manager.cc:463] [C6][S7575434646215072185] decode headers called: filter=0x36433e962240 status=0
[2020-12-10 19:11:11.616][36][debug][router] [source/common/router/router.cc:429] [C6][S7575434646215072185] cluster 'grpc-backend-services' match for URL '/mix.api.MixAPI/GetVersion'
[2020-12-10 19:11:11.616][36][debug][router] [source/common/router/router.cc:586] [C6][S7575434646215072185] router decoding headers:
':authority', 'mix-api.dev.cd4.crt.nuance.com:443'
':path', '/mix.api.MixAPI/GetVersion'
':method', 'POST'
':scheme', 'http'
'content-type', 'application/grpc'
'user-agent', 'grpc-go/1.31.1'
'te', 'trailers'
'grpc-client', 'evans'
'authorization', 'Bearer eyJhbGciOiJSUzI1NiIsImtpZCI6InB1YmxpYzoxYWI2YzUxMC00OGEwLTRiZDUtYmZiNy1mOTY2YzFmMDc1MGQiLCJ0eXAiOiJKV1QifQ.eyJhdWQiOltdLCJjbGllbnRfaWQiOiJtaXgtcG9ydGFsLWNsaWVudCIsImV4cCI6MTYwNzYyNzkyOCwiZXh0Ijp7InN1Yl9pc3MiOiJodHRwczovL2Rldi5jZDQuY3J0Lm51YW5jZS5jb20vYXV0aC9yZWFsbXMvbWl4IiwidGVuYW50IjoibWl4In0sImlhdCI6MTYwNzYyNzAyOCwiaXNzIjoiaHR0cHM6Ly9hdXRoLWRldi5jZDQuY3J0Lm51YW5jZS5jb20vIiwianRpIjoiYmU5YzJkZDYtZDQzOS00Y2E2LWIzNTUtYzMwMzRlMjg3MjVhIiwibmJmIjoxNjA3NjI3MDI4LCJzY3AiOlsibWl4LWFwaSJdLCJzdWIiOiJkNjE4ZTFmMC0zODA4LTQ4OTItYWUyYi03YmZiNDQ4YmQ5MWUifQ.bi6p0r0Zb6ERCo4SXYnj6g6GjK0ZhCMdhqqorbfGE9bgnU4spo0hlGGnGJ8lNY6jhO7qYkPqhvZBX2UmvFeTCfufzIFvYKF2ZQ4j8ONte8LEtAM8RghuQ_WrvMvjF26NhsrCpELkhh2xzvCFt3WbbS6v5w1CyNi-FsB3PJhOgY1UgP0_Iw6quzPz_HHUs6uX3W9J4zUYlKhfqztuAHp01Pzo5DreYX5xjh5ogueye5IlKFDQFZE8FxZMNnXUGJR7nH_s5GkbMS-b-GNheHlNBBQ8QoXiMLUgq6MixcmdK_jvjAnJe8pr3GEDgo71lEvUq7bzL40_Px7kXnJmxg2hgHk7KMrMqyz0009hN0phyPRNF9OtJ-DUxFSvckhUQjddPAx55YQdCJf8AeK3wTwajDNppSZV_Ncbd-GHzf6J4dGNEZBdPDaerhG7Zmu_WF66DJ95luwC8dR0Rh2HYbbURCME0GcbOIxEr7jHnlEBgFbfFUrmuN5qO5y1oqNpe5i1r_9SsvWLZHQYCtlWi1K89zcsN4UOGZbXXy0-AgSAFvU4h3lV73EVJRzgPXoyZQEnHmGAEfUsvfez-JZvOZWsJ86PbK_OQXoxfxLwU5nwAwlspD4JqFgYVSbQUEZ7Tp4TmOqoEnO3QZkY4j49TN70Ip4GrDpOauFNnH_53U5Z05I'
'x-forwarded-for', '10.3.195.67'
'x-forwarded-proto', 'https'
'x-request-id', 'e31b694f-c0d6-9d40-a9ef-01517b1184d3'
'x-nuance-client-id', 'mix-portal-client'
'x-nuance-client-id-iss', 'https://auth-dev.cd4.crt.nuance.com/'
'x-nuance-client-scopes', '[mix-api]'
'x-nuance-tenant-id', 'mix'
'x-nuance-user-id', 'd618e1f0-3808-4892-ae2b-7bfb448bd91e'
'x-nuance-user-id-iss', 'https://dev.cd4.crt.nuance.com/auth/realms/mix'
'x-envoy-expected-rq-timeout-ms', '120000'
'x-b3-traceid', '6dc62f223a5d9a9a4a0a25f9e2ed22bf'
'x-b3-spanid', '8778e830a199e676'
'x-b3-parentspanid', '4a0a25f9e2ed22bf'
'x-b3-sampled', '1'
'x-envoy-internal', 'true'

[2020-12-10 19:11:11.616][36][debug][pool] [source/common/conn_pool/conn_pool_base.cc:174] [C7] using existing connection
[2020-12-10 19:11:11.616][36][debug][pool] [source/common/conn_pool/conn_pool_base.cc:126] [C7] creating stream
[2020-12-10 19:11:11.616][36][debug][router] [source/common/router/upstream_request.cc:357] [C6][S7575434646215072185] pool ready
[2020-12-10 19:11:11.616][36][trace][http2] [source/common/http/http2/codec_impl.cc:914] [C7] about to send frame type=1, flags=4
[2020-12-10 19:11:11.616][36][trace][http2] [source/common/http/http2/codec_impl.cc:941] [C7] send data: bytes=1132
[2020-12-10 19:11:11.616][36][trace][connection] [source/common/network/connection_impl.cc:429] [C7] writing 1132 bytes, end_stream false
[2020-12-10 19:11:11.616][36][trace][http2] [source/common/http/http2/codec_impl.cc:843] [C7] sent frame type=1
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/filter_manager.cc:463] [C6][S7575434646215072185] decode headers called: filter=0x36433e909800 status=1
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:955] [C6] body size=7
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/filter_manager.cc:594] [C6][S7575434646215072185] decode data called: filter=0x36433e962240 status=0
[2020-12-10 19:11:11.616][36][trace][router] [source/common/router/upstream_request.cc:224] [C6][S7575434646215072185] proxying 7 bytes
[2020-12-10 19:11:11.616][36][trace][connection] [source/common/network/connection_impl.cc:429] [C7] writing 16 bytes, end_stream false
[2020-12-10 19:11:11.616][36][trace][http2] [source/common/http/http2/codec_impl.cc:843] [C7] sent frame type=0
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/filter_manager.cc:594] [C6][S7575434646215072185] decode data called: filter=0x36433e909800 status=3
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:745] [C6] message complete
[2020-12-10 19:11:11.616][36][trace][connection] [source/common/network/connection_impl.cc:311] [C6] readDisable: disable=true disable_count=0 state=0 buffer_length=2070
[2020-12-10 19:11:11.616][36][debug][http] [source/common/http/filter_manager.cc:721] [C6][S7575434646215072185] request end stream
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/filter_manager.cc:594] [C6][S7575434646215072185] decode data called: filter=0x36433e962240 status=0
[2020-12-10 19:11:11.616][36][trace][router] [source/common/router/upstream_request.cc:224] [C6][S7575434646215072185] proxying 0 bytes
[2020-12-10 19:11:11.616][36][trace][connection] [source/common/network/connection_impl.cc:429] [C7] writing 9 bytes, end_stream false
[2020-12-10 19:11:11.616][36][trace][http2] [source/common/http/http2/codec_impl.cc:843] [C7] sent frame type=0
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/filter_manager.cc:594] [C6][S7575434646215072185] decode data called: filter=0x36433e909800 status=3
[2020-12-10 19:11:11.616][36][trace][http] [source/common/http/http1/codec_impl_legacy.cc:562] [C6] parsed 2070 bytes
[2020-12-10 19:11:11.616][36][trace][connection] [source/common/network/connection_impl.cc:508] [C6] socket event: 2
[2020-12-10 19:11:11.616][36][trace][connection] [source/common/network/connection_impl.cc:616] [C6] write ready
[2020-12-10 19:11:11.616][36][trace][connection] [source/common/network/connection_impl.cc:508] [C7] socket event: 2
[2020-12-10 19:11:11.616][36][trace][connection] [source/common/network/connection_impl.cc:616] [C7] write ready
[2020-12-10 19:11:11.616][36][trace][connection] [source/common/network/raw_buffer_socket.cc:68] [C7] write returns: 1157
[2020-12-10 19:11:11.647][36][trace][connection] [source/common/network/connection_impl.cc:508] [C7] socket event: 3
[2020-12-10 19:11:11.647][36][trace][connection] [source/common/network/connection_impl.cc:616] [C7] write ready
[2020-12-10 19:11:11.647][36][trace][connection] [source/common/network/connection_impl.cc:546] [C7] read ready. dispatch_buffered_data=false
[2020-12-10 19:11:11.647][36][trace][connection] [source/common/network/raw_buffer_socket.cc:25] [C7] read returns: 126
[2020-12-10 19:11:11.647][36][trace][connection] [source/common/network/raw_buffer_socket.cc:39] [C7] read error: Resource temporarily unavailable
[2020-12-10 19:11:11.647][36][trace][http2] [source/common/http/http2/codec_impl.cc:636] [C7] dispatching 126 bytes
[2020-12-10 19:11:11.647][36][trace][http2] [source/common/http/http2/codec_impl.cc:711] [C7] about to recv frame type=1, flags=4
[2020-12-10 19:11:11.647][36][trace][http2] [source/common/http/http2/codec_impl.cc:735] [C7] recv frame type=1
[2020-12-10 19:11:11.647][36][debug][router] [source/common/router/router.cc:1178] [C6]grpc-service-envoy[S7575434646215072185] upstream headers complete: end_stream=false
[2020-12-10 19:11:11.647][36][trace][http] [source/common/http/filter_manager.cc:966] [C6][S7575434646215072185] encode headers called: filter=0x36433ea3f630 status=0
[2020-12-10 19:11:11.647][36][debug][http] [source/common/http/conn_manager_impl.cc:1435] [C6][S7575434646215072185] encoding headers via codec (end_stream=false):
':status', '200'
'content-type', 'application/grpc'
'grpc-encoding', 'identity'
'grpc-accept-encoding', 'gzip'
'x-envoy-upstream-service-time', '30'
'date', 'Thu, 10 Dec 2020 19:11:11 GMT'
'server', 'envoy'

[2020-12-10 19:11:11.647][36][trace][connection] [source/common/network/connection_impl.cc:429] [C6] writing 219 bytes, end_stream false
[2020-12-10 19:11:11.647][36][trace][http2] [source/common/http/http2/codec_impl.cc:711] [C7] about to recv frame type=0, flags=0
[2020-12-10 19:11:11.647][36][trace][http2] [source/common/http/http2/codec_impl.cc:735] [C7] recv frame type=0
[2020-12-10 19:11:11.647][36][trace][http] [source/common/http/filter_manager.cc:1122] [C6][S7575434646215072185] encode data called: filter=0x36433ea3f630 status=0
[2020-12-10 19:11:11.647][36][trace][http] [source/common/http/conn_manager_impl.cc:1444] [C6][S7575434646215072185] encoding data via codec (size=94 end_stream=false)
[2020-12-10 19:11:11.647][36][trace][connection] [source/common/network/connection_impl.cc:429] [C6] writing 100 bytes, end_stream false
[2020-12-10 19:11:11.647][36][trace][http2] [source/common/http/http2/codec_impl.cc:711] [C7] about to recv frame type=1, flags=5
[2020-12-10 19:11:11.647][36][trace][http2] [source/common/http/http2/codec_impl.cc:735] [C7] recv frame type=1
[2020-12-10 19:11:11.647][36][debug][client] [source/common/http/codec_client.cc:109] [C7] response complete
[2020-12-10 19:11:11.647][36][trace][main] [source/common/event/dispatcher_impl.cc:192] item added to deferred deletion list (size=1)
[2020-12-10 19:11:11.647][36][debug][pool] [source/common/conn_pool/conn_pool_base.cc:151] [C7] destroying stream: 0 remaining
[2020-12-10 19:11:11.647][36][trace][http] [source/common/http/filter_manager.cc:1170] [C6][S7575434646215072185] encode trailers called: filter=0x36433ea3f630 status=0
[2020-12-10 19:11:11.647][36][debug][http] [source/common/http/conn_manager_impl.cc:1451] [C6][S7575434646215072185] encoding trailers via codec:
'grpc-status', '0'

[2020-12-10 19:11:11.647][36][trace][connection] [source/common/network/connection_impl.cc:429] [C6] writing 5 bytes, end_stream false
[2020-12-10 19:11:11.647][36][trace][connection] [source/common/network/connection_impl.cc:311] [C6] readDisable: disable=false disable_count=1 state=0 buffer_length=0
[2020-12-10 19:11:11.647][36][trace][main] [source/common/event/dispatcher_impl.cc:192] item added to deferred deletion list (size=2)
[2020-12-10 19:11:11.647][36][debug][http2] [source/common/http/http2/codec_impl.cc:964] [C7] stream closed: 0
[2020-12-10 19:11:11.647][36][trace][main] [source/common/event/dispatcher_impl.cc:192] item added to deferred deletion list (size=3)
[2020-12-10 19:11:11.647][36][trace][http2] [source/common/http/http2/codec_impl.cc:663] [C7] dispatched 126 bytes
[2020-12-10 19:11:11.647][36][trace][main] [source/common/event/dispatcher_impl.cc:83] clearing deferred deletion list (size=3)
[2020-12-10 19:11:11.647][36][trace][connection] [source/common/network/connection_impl.cc:508] [C7] socket event: 2
[2020-12-10 19:11:11.647][36][trace][connection] [source/common/network/connection_impl.cc:616] [C7] write ready
[2020-12-10 19:11:11.647][36][trace][connection] [source/common/network/connection_impl.cc:508] [C6] socket event: 2
[2020-12-10 19:11:11.647][36][trace][connection] [source/common/network/connection_impl.cc:616] [C6] write ready
[2020-12-10 19:11:11.647][36][trace][connection] [source/common/network/raw_buffer_socket.cc:68] [C6] write returns: 324
1

There are 1 answers

0
Yonoss On

It seems the problem was actually caused by an Ambassador glitch. Details on the ambassador issue can be found here: https://github.com/datawire/ambassador/issues/3112