Size limit on gRPC-JSON transcoder with google.api.HttpBody as output? #6441

npuichigo · 2019-03-31T06:25:04Z

Hi, I have been using gRPC-JSON transcoder with google.api.HttpBody to send media resources like mp3 and so on.

Everything is okay until the body size of HttpBody grows to more than 1MB, and the response header has Internal Server Error in Grpc-Message field.

Here is my configuration:

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

static_resources:
  listeners:
  - name: listener_0
    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: texttospeech_service
                  max_grpc_timeout: 0s
              cors:
                allow_origin:
                - "*"
                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-web,grpc-timeout
                max_age: "1728000"
                expose_headers: custom-header-1,grpc-status,grpc-message
                enabled: true
          http_filters:
          - name: envoy.grpc_json_transcoder
            config:
              proto_descriptor: "/data/texttospeech_service_definition.pb"
              services: ["tts_system.serving.TextToSpeech"]
              print_options:
                add_whitespace: true
                always_print_primitive_fields: true
                always_print_enums_as_ints: false
                preserve_proto_field_names: false
          - name: envoy.cors
          - name: envoy.router
  clusters:
  - name: texttospeech_service
    connect_timeout: 1.25s
    type: logical_dns
    http2_protocol_options: {}
    lb_policy: round_robin
    dns_lookup_family: V4_ONLY
    hosts: [{ socket_address: { address: tts-server, port_value: 9090 }}]
    upstream_connection_options:
      tcp_keepalive:
        keepalive_time: 300
        keepalive_interval: 30
        keepalive_probes: 10

So is there any option to configure the size limit of the transcoded message?

mattklein123 · 2019-03-31T23:56:33Z

@lizan

lizan · 2019-04-01T09:12:59Z

@npuichigo Did you confirm the error wasn't from upstream gRPC server? The default gRPC message size limit is 4MB.

npuichigo · 2019-04-01T10:05:13Z

I used a grpc client to test my server and it's just okay for messages with large size. So I think maybe it's related to envoy.

npuichigo · 2019-04-01T16:39:12Z

@lizan By the way, I have already set the maximum grpc message size to kint32max.

lizan · 2019-04-02T08:05:20Z

Do you have a sample setup for this? it might be due to envoy flow control too so I’d like to verify.

…

On Tue, Apr 2, 2019 at 1:39 AM Yuchao Zhang ***@***.***> wrote: @lizan <https://github.com/lizan> By the way, I have already set the maximum grpc message size to kint32max. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#6441 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AA-A7zrFDnLOQOExGsT7yt2lTmc74P4Mks5vcjY0gaJpZM4cUJQM> .

npuichigo · 2019-04-02T16:40:03Z

@lizan Hi, I have uploaded a sample to reproduce my problem. Here is the repository (https://github.com/npuichigo/grpc_with_envoy), and you can test it with the provided dockerfiles.

alexandrecp-b · 2019-04-11T18:11:48Z

I'm observing something that looks similar and might be related:

When the resulting response body (after transcoding to JSON) is larger than 1MB, then I get the exact same behavior as @npuichigo :

$ curl -v -X POST "http://127.0.0.1:9000/test?api_key=123"
*   Trying 127.0.0.1...
* Connected to 127.0.0.1 (127.0.0.1) port 9000 (#0)
> POST /test?api_key=123 HTTP/1.1
> Host: 127.0.0.1:9000
> User-Agent: curl/7.47.0
> Accept: */*
> 
< HTTP/1.1 200 OK
< content-type: application/grpc
< grpc-status: 2
< grpc-message: Internal Server Error
< content-length: 0
< 
* Connection #0 to host 127.0.0.1 left intact

Here's an excerpt of the logs with a resulting (good) JSON response that's smaller than 1MB:

[2019-04-11 17:38:24.597][19][trace][http] [source/common/http/conn_manager_impl.cc:1394] [C14][S15922156444879263414] encode data called: filter=0x284f1c0 status=1
[2019-04-11 17:38:24.597][19][trace][http2] [source/common/http/http2/codec_impl.cc:411] [C5] recv frame type=0
[2019-04-11 17:38:24.603][19][trace][http] [source/common/http/conn_manager_impl.cc:1394] [C14][S15922156444879263414] encode data called: filter=0x284f1c0 status=1
[2019-04-11 17:38:24.603][19][trace][http2] [source/common/http/http2/codec_impl.cc:411] [C5] recv frame type=1
[2019-04-11 17:38:24.603][19][debug][client] [source/common/http/codec_client.cc:95] [C5] response complete
[2019-04-11 17:38:24.603][19][trace][main] [source/common/event/dispatcher_impl.cc:133] item added to deferred deletion list (size=1)
[2019-04-11 17:38:24.603][19][debug][pool] [source/common/http/http2/conn_pool.cc:237] [C5] destroying stream: 0 remaining
[2019-04-11 17:38:24.603][19][trace][http] [source/common/http/conn_manager_impl.cc:1440] [C14][S15922156444879263414] encode trailers called: filter=0x284f1c0 status=0
[2019-04-11 17:38:24.603][19][trace][http] [source/common/http/conn_manager_impl.cc:1561] [C14][S15922156444879263414] continuing filter chain: filter=0x284f1c0
[2019-04-11 17:38:24.603][19][debug][http] [source/common/http/conn_manager_impl.cc:1278] [C14][S15922156444879263414] encoding headers via codec (end_stream=false):
':status', '200'
'content-type', 'application/json'
'grpc-accept-encoding', 'identity,deflate,gzip'
'accept-encoding', 'identity,gzip'
'x-envoy-upstream-service-time', '381'
'grpc-status', '0'
'content-length', '901270'
'date', 'Thu, 11 Apr 2019 17:38:24 GMT'
'server', 'envoy'

[2019-04-11 17:38:24.603][19][trace][connection] [source/common/network/connection_impl.cc:376] [C14] writing 256 bytes, end_stream false
[2019-04-11 17:38:24.603][19][trace][http] [source/common/http/conn_manager_impl.cc:1407] [C14][S15922156444879263414] encoding data via codec (size=901270 end_stream=false)

Here's an excerpt of the logs with a resulting (bad) JSON response that's slightly larger than 1MB:

[2019-04-11 17:39:32.620][24][trace][http2] [source/common/http/http2/codec_impl.cc:411] [C9] recv frame type=0
[2019-04-11 17:39:32.620][24][trace][http] [source/common/http/conn_manager_impl.cc:1394] [C15][S909030969909257382] encode data called: filter=0x284fec0 status=1
[2019-04-11 17:39:32.620][24][trace][http2] [source/common/http/http2/codec_impl.cc:411] [C9] recv frame type=0
[2019-04-11 17:39:32.626][24][trace][http] [source/common/http/conn_manager_impl.cc:1394] [C15][S909030969909257382] encode data called: filter=0x284fec0 status=1
[2019-04-11 17:39:32.627][24][trace][connection] [source/common/network/connection_impl.cc:376] [C15] writing 123 bytes, end_stream false
[2019-04-11 17:39:32.627][24][debug][router] [source/common/router/router.cc:1111] [C15][S909030969909257382] resetting pool request
[2019-04-11 17:39:32.627][24][debug][client] [source/common/http/codec_client.cc:105] [C9] request reset
[2019-04-11 17:39:32.627][24][trace][main] [source/common/event/dispatcher_impl.cc:133] item added to deferred deletion list (size=1)
[2019-04-11 17:39:32.627][24][debug][pool] [source/common/http/http2/conn_pool.cc:237] [C9] destroying stream: 0 remaining
[2019-04-11 17:39:32.627][24][trace][main] [source/common/event/dispatcher_impl.cc:133] item added to deferred deletion list (size=2)
[2019-04-11 17:39:32.627][24][trace][connection] [source/common/network/connection_impl.cc:282] [C15] readDisable: enabled=false disable=false
[2019-04-11 17:39:32.627][24][trace][http2] [source/common/http/http2/codec_impl.cc:411] [C9] recv frame type=8
[2019-04-11 17:39:32.627][24][trace][http2] [source/common/http/http2/codec_impl.cc:411] [C9] recv frame type=6
[2019-04-11 17:39:32.627][24][trace][http2] [source/common/http/http2/codec_impl.cc:368] [C9] dispatched 948581 bytes
[2019-04-11 17:39:32.627][24][trace][http2] [source/common/http/http2/codec_impl.cc:568] [C9] send data: bytes=17
[2019-04-11 17:39:32.627][24][trace][connection] [source/common/network/connection_impl.cc:376] [C9] writing 17 bytes, end_stream false
[2019-04-11 17:39:32.627][24][trace][http2] [source/common/http/http2/codec_impl.cc:521] [C9] sent frame type=6
[2019-04-11 17:39:32.627][24][trace][http2] [source/common/http/http2/codec_impl.cc:568] [C9] send data: bytes=13
[2019-04-11 17:39:32.627][24][trace][connection] [source/common/network/connection_impl.cc:376] [C9] writing 13 bytes, end_stream false
[2019-04-11 17:39:32.627][24][trace][http2] [source/common/http/http2/codec_impl.cc:521] [C9] sent frame type=3
[2019-04-11 17:39:32.627][24][debug][http2] [source/common/http/http2/codec_impl.cc:531] [C9] sent reset code=0
[2019-04-11 17:39:32.627][24][debug][http2] [source/common/http/http2/codec_impl.cc:577] [C9] stream closed: 0
[2019-04-11 17:39:32.627][24][trace][main] [source/common/event/dispatcher_impl.cc:133] item added to deferred deletion list (size=3)
[2019-04-11 17:39:32.627][24][trace][main] [source/common/event/dispatcher_impl.cc:53] clearing deferred deletion list (size=3)
[2019-04-11 17:39:32.627][24][trace][connection] [source/common/network/connection_impl.cc:440] [C9] socket event: 2

Going directly to the gRPC service or proxying with Envoy over HTTP2 works just fine. This is specifically failing with the grpc_json_transcoder.

lizan · 2019-04-12T06:20:15Z

@alexandrecp-b Thanks for the trace log, it is very helpful. I think it might be a bug, which specific version of Envoy are you running? v1.10.0?

alexandrecp-b · 2019-05-03T12:51:10Z

@lizan : Sorry about my late reply, I missed the notification. IIRC this particular trace came from v1.10.0.

In all cases, I reproduced the exact same behavior on v1.8.0, v1.9.0 and v1.10.0

lizan · 2019-05-06T18:56:33Z

@alexandrecp-b Can you try to adjust your cluster's per_connection_buffer_limit_bytes to a larger value? I think the upstream connection is hitting this limit when it sends a larger HttpBody.

alexandrecp-b · 2019-05-06T20:12:21Z

@lizan That did the trick! Thanks a lot!

lizan · 2019-05-06T22:42:24Z

@npuichigo closing this as answered, feel free to re-open if you still have the issue.

npuichigo · 2019-05-07T03:31:12Z

@lizan Wow, it's cool. Thanks.

piaw · 2020-01-17T20:00:57Z

Hi, I'm trying to increase the limit on envoy 1.10, and it doesn't seem to have any effect. Here's what I have (the jinja templates get expanded to reasonable values):
admin:
access_log_path: {{ logging_prefix }}_envoy_rest_proxy_admin.{{ logging_suffix }}
address:
socket_address: { address: 0.0.0.0, port_value: {{ admin_port }} }

static_resources:
listeners:

name: listener
address:
socket_address: { address: 0.0.0.0, port_value: {{ rest_port }} }
per_connection_buffer_limit_bytes: 5048576
filter_chains:
- filters:
  - name: envoy.http_connection_manager
    config:
    access_log:
    - name: envoy.file_access_log
    config:
    path: {{ logging_prefix }}_envoy_rest_proxy.{{ logging_suffix }}
    stat_prefix: grpc_json
    codec_type: AUTO
    route_config:
    name: local_route
    virtual_hosts:
    - name: local_service
    domains: ["*"]
    routes:
    - match: { prefix: "/" }
    route: { cluster: grpc, timeout: { seconds: 60 } }
    http_filters:
    {% for service in service_list %}
    - name: envoy.grpc_json_transcoder
      config:
      proto_descriptor: "{{ service.proto_descriptor }}"
      services: {{ service.services }}
      print_options:
      add_whitespace: true
      always_print_primitive_fields: true
      always_print_enums_as_ints: false
      preserve_proto_field_names: false
      {% endfor %}
    - name: envoy.router

clusters:

name: grpc
connect_timeout: 1.25s
type: logical_dns
lb_policy: round_robin
dns_lookup_family: V4_ONLY
http2_protocol_options: {}
per_connection_buffer_limit_bytes: 5048576
hosts:
- socket_address:
  address: localhost
  port_value: {{ grpc_port }}

Is there an example on how to do this?

mattklein123 added the question Questions that are neither investigations, bugs, nor enhancements label Mar 31, 2019

lizan self-assigned this Apr 1, 2019

lizan added bug help wanted Needs help! and removed question Questions that are neither investigations, bugs, nor enhancements labels Apr 12, 2019

lizan added question Questions that are neither investigations, bugs, nor enhancements and removed bug help wanted Needs help! labels May 6, 2019

lizan closed this as completed May 6, 2019

mscno mentioned this issue Sep 21, 2020

Add start-up flag to set per_connection_buffer_limit_bytes setting in envoy GoogleCloudPlatform/esp-v2#341

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Size limit on gRPC-JSON transcoder with google.api.HttpBody as output? #6441

Size limit on gRPC-JSON transcoder with google.api.HttpBody as output? #6441

npuichigo commented Mar 31, 2019

mattklein123 commented Mar 31, 2019

lizan commented Apr 1, 2019

npuichigo commented Apr 1, 2019

npuichigo commented Apr 1, 2019

lizan commented Apr 2, 2019 via email

npuichigo commented Apr 2, 2019

alexandrecp-b commented Apr 11, 2019

lizan commented Apr 12, 2019

alexandrecp-b commented May 3, 2019

lizan commented May 6, 2019

alexandrecp-b commented May 6, 2019

lizan commented May 6, 2019

npuichigo commented May 7, 2019

piaw commented Jan 17, 2020

Size limit on gRPC-JSON transcoder with google.api.HttpBody as output? #6441

Size limit on gRPC-JSON transcoder with google.api.HttpBody as output? #6441

Comments

npuichigo commented Mar 31, 2019

mattklein123 commented Mar 31, 2019

lizan commented Apr 1, 2019

npuichigo commented Apr 1, 2019

npuichigo commented Apr 1, 2019

lizan commented Apr 2, 2019 via email

npuichigo commented Apr 2, 2019

alexandrecp-b commented Apr 11, 2019

lizan commented Apr 12, 2019

alexandrecp-b commented May 3, 2019

lizan commented May 6, 2019

alexandrecp-b commented May 6, 2019

lizan commented May 6, 2019

npuichigo commented May 7, 2019

piaw commented Jan 17, 2020