envoyproxy/envoy

Lua filter: httpCall() terminates abruptly in envoy_on_response() when used after bodyChunks()

Open

#8,785 opened on 2019年10月28日

GitHub で見る
 (8 comments) (0 reactions) (0 assignees)C++ (5,373 forks)batch import
bughelp wanted

Repository metrics

Stars
 (27,997 stars)
PR merge metrics
 (平均マージ 8d) (30d で 378 merged PRs)

説明

Title: Lua filter: httpCall() terminates abruptly in envoy_on_response() when used after bodyChunks()

Description: In an attempt to shadow an upstream response using a Lua filter, I use envoy_on_response() to collect the response data using either body() or bodyChunks(), then use httpCall() to send the data to a special logging cluster. Buffering the response with body() and sending with httpCall() works as expected, but using bodyChunks() followed by httpCall() does not; the connection to the logging cluster terminates from the Lua side before it is able to finish sending the data.

Envoy Version: v1.11.1 (alpine docker image)

Repro steps:

  1. Using the config below, start Envoy as a reverse proxy for a service that responds with ~2 MiB payloads. (e.g. GET /xxlarge); I run Envoy and the services on a separate server from my tests. The logging cluster simply responds with status code 204.
  2. Run curl -s -o /dev/null -D - envoy-host:8080/log/buffer/xxlarge to observe expected behaviour with buffered responses. Logs are provided in buffered_output below.
  3. Run curl -s -o /dev/null -D - envoy-host:8080/log/xxlarge to see that envoy_on_response() does not complete execution. Note that the output of logDebug() calls after httpCall() do not appear. Logs provided in streamed_output below.

Notes: If the response payload is small enough and txn_logger is fast enough to receive the data from httpCall(), then I am able to see the final logDebug() call in the streamed response example.

Config: lds.yaml

version_info: "0"
resources:
- "@type": type.googleapis.com/envoy.api.v2.Listener
  name: vip_listener
  address:
    socket_address:
      address: 0.0.0.0
      port_value: 8080
  per_connection_buffer_limit_bytes: 10000000
  filter_chains:
  - filters:
    - name: envoy.http_connection_manager
      typed_config:
        "@type": type.googleapis.com/envoy.config.filter.network.http_connection_manager.v2.HttpConnectionManager
        stat_prefix: vip_http
        codec_type: auto
        rds:
          route_config_name: vip_routes
          config_source:
            path: /envoy/conf/rds.yaml
        http_filters:
          - name: envoy.health_check
            typed_config:
              "@type": type.googleapis.com/envoy.config.filter.http.health_check.v2.HealthCheck
              pass_through_mode: false
              headers:
                - name: ":path"
                  exact_match: "/healthcheck"
          - name: envoy.lua
            typed_config:
              "@type": type.googleapis.com/envoy.config.filter.http.lua.v2.Lua
              inline_code: |
                function envoy_on_request(handle)
                  local metadata = handle:streamInfo():dynamicMetadata()
                  local headers = handle:headers()
                  local rid = headers:get("x-request-id")
                  if rid ~= nil then
                    metadata:set("envoy.lua", "req.x-request-id", rid)
                  end
                end

                function envoy_on_response(handle)
                  local cluster = handle:metadata():get("mirror_response_cluster")
                  if cluster == nil then return end
                  local headers = {
                    [":method"] = "POST",
                    [":path"] = "/response",
                    [":authority"] = cluster,
                  }
                  local metadata = handle:streamInfo():dynamicMetadata():get("envoy.lua")
                  for key, value in pairs(metadata) do
                    if key == "req.x-request-id" then headers[":path"] = "/response/for/" .. value end
                  end
                  handle:logDebug("vvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvv")
                  if (handle:metadata():get("buffer_response") == "buffered") then
                    local res = handle:body()
                    local body = res:getBytes(0, res:length())
                    handle:logDebug("!!!! Body buffered! Can we at least fire off a log?")
                    local h, b = handle:httpCall(cluster, headers, body, 0)
                  else
                    local t = {}
                    for chunk in handle:bodyChunks() do
                      local body = chunk:getBytes(0, chunk:length())
                      table.insert(t, body)
                    end
                    handle:logDebug("!!!! Last chunk buffered! Can we at least fire off a log?")
                    local h, b = handle:httpCall(cluster, headers, table.concat(t, ""), 0)
                  end
                  handle:logDebug("^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^")
                end
          - name: envoy.router
            config: {}
        access_log:
          - name: envoy.file_access_log
            typed_config:
              "@type": type.googleapis.com/envoy.config.accesslog.v2.FileAccessLog
              format: '[%START_TIME%] "%REQ(:METHOD)% %REQ(X-ENVOY-ORIGINAL-PATH?:PATH)% %PROTOCOL%"
                %RESPONSE_CODE% %RESPONSE_FLAGS% %BYTES_RECEIVED% %BYTES_SENT% %DURATION% %RESP(X-ENVOY-UPSTREAM-SERVICE-TIME)%
                "%REQ(X-FORWARDED-FOR)%" "%REQ(USER-AGENT)%" "%REQ(X-REQUEST-ID)%" "%REQ(:AUTHORITY)%" "%UPSTREAM_HOST%"
                '
              path: /dev/stdout

rds.yaml

version_info: "0"
resources:
  - "@type": type.googleapis.com/envoy.api.v2.RouteConfiguration
    name: vip_routes
    virtual_hosts:
      - name: incoming
        domains:
          - "*"
        retry_policy:
          per_try_timeout: 120s
        routes:
          - match:
              prefix: /log/buffer/
            route:
              prefix_rewrite: /
              cluster: test
            metadata:
              filter_metadata:
                envoy.lua:
                  mirror_response_cluster: txn_logger
                  buffer_response: buffered
          - match:
              prefix: /log/
            route:
              prefix_rewrite: /
              cluster: test
            metadata:
              filter_metadata:
                envoy.lua:
                  mirror_response_cluster: txn_logger
          - match:
              prefix: /
            route:
              cluster: test

cds.yaml

version_info: "0"
resources:
  - "@type": type.googleapis.com/envoy.api.v2.Cluster
    name: test
    connect_timeout: 0.25s
    type: strict_dns
    lb_policy: round_robin
    load_assignment:
      cluster_name: test
      endpoints:
        - lb_endpoints:
            - endpoint:
                address:
                  socket_address:
                    address: app
                    port_value: 8080
    drain_connections_on_host_removal: true
    circuit_breakers:
      thresholds:
        - max_connections: 10000
          max_pending_requests: 10000
          max_requests: 10000
          max_retries: 0
          priority: DEFAULT
  - "@type": type.googleapis.com/envoy.api.v2.Cluster
    name: txn_logger
    connect_timeout: 0.25s
    type: strict_dns
    lb_policy: round_robin
    load_assignment:
      cluster_name: txn_logger
      endpoints:
        - lb_endpoints:
            - endpoint:
                address:
                  socket_address:
                    address: logger
                    port_value: 5000
    drain_connections_on_host_removal: true
    circuit_breakers:
      thresholds:
        - max_connections: 10000
          max_pending_requests: 10000
          max_requests: 10000
          max_retries: 0
          priority: DEFAULT

envoy.yaml

admin:
  access_log_path: /dev/null
  address:
    socket_address:
      address: 0.0.0.0
      port_value: 8001
dynamic_resources:
  cds_config:
    path: '/envoy/conf/cds.yaml'
  lds_config:
    path: '/envoy/conf/lds.yaml'

Logs: buffered_output

[2019-10-28 14:26:58.270][20][debug][main] [source/server/connection_handler_impl.cc:280] [C0] new connection
[2019-10-28 14:26:58.271][20][debug][http] [source/common/http/conn_manager_impl.cc:246] [C0] new stream
[2019-10-28 14:26:58.272][20][debug][http] [source/common/http/conn_manager_impl.cc:619] [C0][S4761526198635461934] request headers complete (end_stream=true):
':authority', '10.5.130.68:9999'
':path', '/log/buffer/xxlarge'
':method', 'GET'
'user-agent', 'curl/7.29.0'
'accept', '*/*'

[2019-10-28 14:26:58.272][20][debug][http] [source/common/http/conn_manager_impl.cc:1111] [C0][S4761526198635461934] request end stream
[2019-10-28 14:26:58.273][20][debug][lua] [source/extensions/filters/common/lua/lua.cc:37] coroutine finished
[2019-10-28 14:26:58.273][20][debug][router] [source/common/router/router.cc:401] [C0][S4761526198635461934] cluster 'test' match for URL '/log/buffer/xxlarge'
[2019-10-28 14:26:58.273][20][debug][router] [source/common/router/router.cc:514] [C0][S4761526198635461934] router decoding headers:
':authority', '10.5.130.68:9999'
':path', '/xxlarge'
':method', 'GET'
':scheme', 'http'
'user-agent', 'curl/7.29.0'
'accept', '*/*'
'x-forwarded-proto', 'http'
'x-request-id', '2e329727-a93e-4ec3-9a57-2254747ae2cc'
'x-envoy-expected-rq-timeout-ms', '15000'
'x-envoy-original-path', '/log/buffer/xxlarge'

[2019-10-28 14:26:58.273][20][debug][pool] [source/common/http/http1/conn_pool.cc:88] creating a new connection
[2019-10-28 14:26:58.273][20][debug][client] [source/common/http/codec_client.cc:26] [C1] connecting
[2019-10-28 14:26:58.273][20][debug][connection] [source/common/network/connection_impl.cc:704] [C1] connecting to 10.200.1.101:8080
[2019-10-28 14:26:58.273][20][debug][connection] [source/common/network/connection_impl.cc:713] [C1] connection in progress
[2019-10-28 14:26:58.273][20][debug][pool] [source/common/http/conn_pool_base.cc:20] queueing request due to no available connections
[2019-10-28 14:26:58.273][20][debug][connection] [source/common/network/connection_impl.cc:552] [C1] connected
[2019-10-28 14:26:58.273][20][debug][client] [source/common/http/codec_client.cc:64] [C1] connected
[2019-10-28 14:26:58.273][20][debug][pool] [source/common/http/http1/conn_pool.cc:241] [C1] attaching to next request
[2019-10-28 14:26:58.273][20][debug][router] [source/common/router/router.cc:1503] [C0][S4761526198635461934] pool ready
[2019-10-28 14:26:58.280][20][debug][router] [source/common/router/router.cc:994] [C0][S4761526198635461934] upstream headers complete: end_stream=false
[2019-10-28 14:26:58.281][20][debug][lua] [source/extensions/filters/http/lua/lua_filter.cc:582] script log: vvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvv
[2019-10-28 14:26:58.281][20][debug][lua] [source/extensions/filters/http/lua/lua_filter.cc:311] yielding for full body
[2019-10-28 14:26:58.281][20][debug][lua] [source/extensions/filters/common/lua/lua.cc:40] coroutine yielded
[2019-10-28 14:26:58.288][20][debug][client] [source/common/http/codec_client.cc:95] [C1] response complete
[2019-10-28 14:26:58.289][20][debug][lua] [source/extensions/filters/http/lua/lua_filter.cc:55] resuming body due to end stream
[2019-10-28 14:26:58.295][20][debug][lua] [source/extensions/filters/http/lua/lua_filter.cc:582] script log: !!!! Body buffered! Can we at least fire off a log?
[2019-10-28 14:26:58.295][20][debug][router] [source/common/router/router.cc:401] [C0][S6278964145888681587] cluster 'txn_logger' match for URL '/response/for/2e329727-a93e-4ec3-9a57-2254747ae2cc'
[2019-10-28 14:26:58.295][20][debug][router] [source/common/router/router.cc:514] [C0][S6278964145888681587] router decoding headers:
':path', '/response/for/2e329727-a93e-4ec3-9a57-2254747ae2cc'
':method', 'POST'
':authority', 'txn_logger'
':scheme', 'http'
'content-length', '4000000'
'x-envoy-internal', 'true'
'x-forwarded-for', '10.200.1.98'

[2019-10-28 14:26:58.295][20][debug][pool] [source/common/http/http1/conn_pool.cc:88] creating a new connection
[2019-10-28 14:26:58.296][20][debug][client] [source/common/http/codec_client.cc:26] [C2] connecting
[2019-10-28 14:26:58.296][20][debug][connection] [source/common/network/connection_impl.cc:704] [C2] connecting to 10.200.1.103:5000
[2019-10-28 14:26:58.296][20][debug][connection] [source/common/network/connection_impl.cc:713] [C2] connection in progress
[2019-10-28 14:26:58.296][20][debug][pool] [source/common/http/conn_pool_base.cc:20] queueing request due to no available connections
[2019-10-28 14:26:58.296][20][debug][lua] [source/extensions/filters/common/lua/lua.cc:40] coroutine yielded
[2019-10-28 14:26:58.296][20][debug][pool] [source/common/http/http1/conn_pool.cc:198] [C1] response complete
[2019-10-28 14:26:58.296][20][debug][pool] [source/common/http/http1/conn_pool.cc:203] [C1] saw upstream close connection
[2019-10-28 14:26:58.296][20][debug][connection] [source/common/network/connection_impl.cc:101] [C1] closing data_to_write=0 type=1
[2019-10-28 14:26:58.296][20][debug][connection] [source/common/network/connection_impl.cc:190] [C1] closing socket: 1
[2019-10-28 14:26:58.296][20][debug][client] [source/common/http/codec_client.cc:82] [C1] disconnect. resetting 0 pending requests
[2019-10-28 14:26:58.296][20][debug][pool] [source/common/http/http1/conn_pool.cc:129] [C1] client disconnected, failure reason:
[2019-10-28 14:26:58.296][20][debug][connection] [source/common/network/connection_impl.cc:520] [C1] remote close
[2019-10-28 14:26:58.296][20][debug][connection] [source/common/network/connection_impl.cc:552] [C2] connected
[2019-10-28 14:26:58.296][20][debug][client] [source/common/http/codec_client.cc:64] [C2] connected
[2019-10-28 14:26:58.296][20][debug][pool] [source/common/http/http1/conn_pool.cc:241] [C2] attaching to next request
[2019-10-28 14:26:58.296][20][debug][router] [source/common/router/router.cc:1503] [C0][S6278964145888681587] pool ready
[2019-10-28 14:26:58.296][20][debug][connection] [source/common/network/connection_impl.cc:449] [C2] onAboveWriteBufferHighWatermark
[2019-10-28 14:26:58.336][20][debug][connection] [source/common/network/connection_impl.cc:440] [C2] onBelowWriteBufferLowWatermark
[2019-10-28 14:26:58.593][20][debug][client] [source/common/http/codec_client.cc:95] [C2] response complete
[2019-10-28 14:26:58.593][20][debug][router] [source/common/router/router.cc:994] [C0][S6278964145888681587] upstream headers complete: end_stream=true
[2019-10-28 14:26:58.593][20][debug][http] [source/common/http/async_client_impl.cc:91] async http request response headers (end_stream=true):
':status', '204'
'date', 'Mon, 28 Oct 2019 14:26:57 GMT'
'server', 'Kestrel'
'x-envoy-upstream-service-time', '297'

[2019-10-28 14:26:58.593][20][debug][lua] [source/extensions/filters/http/lua/lua_filter.cc:208] async HTTP response complete
[2019-10-28 14:26:58.593][20][debug][lua] [source/extensions/filters/http/lua/lua_filter.cc:582] script log: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
[2019-10-28 14:26:58.593][20][debug][lua] [source/extensions/filters/common/lua/lua.cc:37] coroutine finished
[2019-10-28 14:26:58.593][20][debug][http] [source/common/http/conn_manager_impl.cc:1378] [C0][S4761526198635461934] encoding headers via codec (end_stream=false):
':status', '200'
'content-type', 'text/html; charset=utf-8'
'content-length', '4000000'
'server', 'envoy'
'date', 'Mon, 28 Oct 2019 14:26:58 GMT'
'x-envoy-upstream-service-time', '7'

[2019-10-28T14:26:58.271Z] "GET /log/buffer/xxlarge HTTP/1.1" 200 - 0 4000000 323 7 "-" "curl/7.29.0" "-" "-" "-" "-" "2e329727-a93e-4ec3-9a57-2254747ae2cc" "-" "10.5.130.68:9999" "10.200.1.101:8080"
[2019-10-28 14:26:58.594][20][debug][pool] [source/common/http/http1/conn_pool.cc:198] [C2] response complete
[2019-10-28 14:26:58.594][20][debug][pool] [source/common/http/http1/conn_pool.cc:236] [C2] moving to ready
[2019-10-28 14:26:58.609][20][debug][connection] [source/common/network/connection_impl.cc:520] [C0] remote close
[2019-10-28 14:26:58.609][20][debug][connection] [source/common/network/connection_impl.cc:190] [C0] closing socket: 0
[2019-10-28 14:26:58.609][20][debug][main] [source/server/connection_handler_impl.cc:80] [C0] adding to cleanup list
[2019-10-28 14:26:59.027][12][debug][main] [source/server/server.cc:170] flushing stats

streamed_output

[2019-10-28 14:34:56.694][19][debug][main] [source/server/connection_handler_impl.cc:280] [C0] new connection
[2019-10-28 14:34:56.694][19][debug][http] [source/common/http/conn_manager_impl.cc:246] [C0] new stream
[2019-10-28 14:34:56.696][19][debug][http] [source/common/http/conn_manager_impl.cc:619] [C0][S12691433455413425278] request headers complete (end_stream=true):
':authority', '10.5.130.68:9999'
':path', '/log/xxlarge'
':method', 'GET'
'user-agent', 'curl/7.29.0'
'accept', '*/*'

[2019-10-28 14:34:56.696][19][debug][http] [source/common/http/conn_manager_impl.cc:1111] [C0][S12691433455413425278] request end stream
[2019-10-28 14:34:56.696][19][debug][lua] [source/extensions/filters/common/lua/lua.cc:37] coroutine finished
[2019-10-28 14:34:56.696][19][debug][router] [source/common/router/router.cc:401] [C0][S12691433455413425278] cluster 'test' match for URL '/log/xxlarge'
[2019-10-28 14:34:56.696][19][debug][router] [source/common/router/router.cc:514] [C0][S12691433455413425278] router decoding headers:
':authority', '10.5.130.68:9999'
':path', '/xxlarge'
':method', 'GET'
':scheme', 'http'
'user-agent', 'curl/7.29.0'
'accept', '*/*'
'x-forwarded-proto', 'http'
'x-request-id', '02bf15f6-d67f-41b5-a9c8-0fe67309426a'
'x-envoy-expected-rq-timeout-ms', '15000'
'x-envoy-original-path', '/log/xxlarge'

[2019-10-28 14:34:56.696][19][debug][pool] [source/common/http/http1/conn_pool.cc:88] creating a new connection
[2019-10-28 14:34:56.697][19][debug][client] [source/common/http/codec_client.cc:26] [C1] connecting
[2019-10-28 14:34:56.697][19][debug][connection] [source/common/network/connection_impl.cc:704] [C1] connecting to 10.200.1.130:8080
[2019-10-28 14:34:56.697][19][debug][connection] [source/common/network/connection_impl.cc:713] [C1] connection in progress
[2019-10-28 14:34:56.697][19][debug][pool] [source/common/http/conn_pool_base.cc:20] queueing request due to no available connections
[2019-10-28 14:34:56.697][19][debug][connection] [source/common/network/connection_impl.cc:552] [C1] connected
[2019-10-28 14:34:56.697][19][debug][client] [source/common/http/codec_client.cc:64] [C1] connected
[2019-10-28 14:34:56.697][19][debug][pool] [source/common/http/http1/conn_pool.cc:241] [C1] attaching to next request
[2019-10-28 14:34:56.697][19][debug][router] [source/common/router/router.cc:1503] [C0][S12691433455413425278] pool ready
[2019-10-28 14:34:56.704][19][debug][router] [source/common/router/router.cc:994] [C0][S12691433455413425278] upstream headers complete: end_stream=false
[2019-10-28 14:34:56.704][19][debug][lua] [source/extensions/filters/http/lua/lua_filter.cc:582] script log: vvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvv
[2019-10-28 14:34:56.704][19][debug][lua] [source/extensions/filters/http/lua/lua_filter.cc:337] yielding for next body chunk
[2019-10-28 14:34:56.704][19][debug][lua] [source/extensions/filters/common/lua/lua.cc:40] coroutine yielded
[2019-10-28 14:34:56.704][19][debug][http] [source/common/http/conn_manager_impl.cc:1378] [C0][S12691433455413425278] encoding headers via codec (end_stream=false):
':status', '200'
'content-type', 'text/html; charset=utf-8'
'content-length', '4000000'
'server', 'envoy'
'date', 'Mon, 28 Oct 2019 14:34:56 GMT'
'x-envoy-upstream-service-time', '7'

[2019-10-28 14:34:56.707][19][debug][lua] [source/extensions/filters/http/lua/lua_filter.cc:337] yielding for next body chunk
[2019-10-28 14:34:56.707][19][debug][lua] [source/extensions/filters/common/lua/lua.cc:40] coroutine yielded
[2019-10-28 14:34:56.707][19][debug][lua] [source/extensions/filters/http/lua/lua_filter.cc:337] yielding for next body chunk
[2019-10-28 14:34:56.707][19][debug][lua] [source/extensions/filters/common/lua/lua.cc:40] coroutine yielded
[2019-10-28 14:34:56.708][19][debug][lua] [source/extensions/filters/http/lua/lua_filter.cc:337] yielding for next body chunk
[2019-10-28 14:34:56.708][19][debug][lua] [source/extensions/filters/common/lua/lua.cc:40] coroutine yielded
...
[2019-10-28 14:34:56.723][19][debug][lua] [source/extensions/filters/http/lua/lua_filter.cc:337] yielding for next body chunk
[2019-10-28 14:34:56.723][19][debug][lua] [source/extensions/filters/common/lua/lua.cc:40] coroutine yielded
[2019-10-28 14:34:56.724][19][debug][lua] [source/extensions/filters/http/lua/lua_filter.cc:337] yielding for next body chunk
[2019-10-28 14:34:56.724][19][debug][lua] [source/extensions/filters/common/lua/lua.cc:40] coroutine yielded
[2019-10-28 14:34:56.724][19][debug][client] [source/common/http/codec_client.cc:95] [C1] response complete
[2019-10-28 14:34:56.724][19][debug][lua] [source/extensions/filters/http/lua/lua_filter.cc:334] body complete. no more body chunks
[2019-10-28 14:34:56.724][19][debug][lua] [source/extensions/filters/http/lua/lua_filter.cc:582] script log: !!!! Last chunk buffered! Can we at least fire off a log?
[2019-10-28 14:34:56.734][19][debug][router] [source/common/router/router.cc:401] [C0][S14559515594191298660] cluster 'txn_logger' match for URL '/response/for/02bf15f6-d67f-41b5-a9c8-0fe67309426a'
[2019-10-28 14:34:56.734][19][debug][router] [source/common/router/router.cc:514] [C0][S14559515594191298660] router decoding headers:
':path', '/response/for/02bf15f6-d67f-41b5-a9c8-0fe67309426a'
':method', 'POST'
':authority', 'txn_logger'
':scheme', 'http'
'content-length', '4000000'
'x-envoy-internal', 'true'
'x-forwarded-for', '10.200.1.132'

[2019-10-28 14:34:56.734][19][debug][pool] [source/common/http/http1/conn_pool.cc:88] creating a new connection
[2019-10-28 14:34:56.734][19][debug][client] [source/common/http/codec_client.cc:26] [C2] connecting
[2019-10-28 14:34:56.734][19][debug][connection] [source/common/network/connection_impl.cc:704] [C2] connecting to 10.200.1.134:5000
[2019-10-28 14:34:56.735][19][debug][connection] [source/common/network/connection_impl.cc:713] [C2] connection in progress
[2019-10-28 14:34:56.735][19][debug][pool] [source/common/http/conn_pool_base.cc:20] queueing request due to no available connections
[2019-10-28 14:34:56.735][19][debug][lua] [source/extensions/filters/common/lua/lua.cc:40] coroutine yielded
[2019-10-28 14:34:56.735][19][debug][pool] [source/common/http/http1/conn_pool.cc:198] [C1] response complete
[2019-10-28 14:34:56.735][19][debug][pool] [source/common/http/http1/conn_pool.cc:203] [C1] saw upstream close connection
[2019-10-28 14:34:56.735][19][debug][connection] [source/common/network/connection_impl.cc:101] [C1] closing data_to_write=0 type=1
[2019-10-28 14:34:56.735][19][debug][connection] [source/common/network/connection_impl.cc:190] [C1] closing socket: 1
[2019-10-28 14:34:56.735][19][debug][client] [source/common/http/codec_client.cc:82] [C1] disconnect. resetting 0 pending requests
[2019-10-28 14:34:56.735][19][debug][pool] [source/common/http/http1/conn_pool.cc:129] [C1] client disconnected, failure reason:
[2019-10-28 14:34:56.735][19][debug][connection] [source/common/network/connection_impl.cc:520] [C1] remote close
[2019-10-28 14:34:56.735][19][debug][connection] [source/common/network/connection_impl.cc:552] [C2] connected
[2019-10-28 14:34:56.735][19][debug][client] [source/common/http/codec_client.cc:64] [C2] connected
[2019-10-28 14:34:56.735][19][debug][pool] [source/common/http/http1/conn_pool.cc:241] [C2] attaching to next request
[2019-10-28 14:34:56.735][19][debug][router] [source/common/router/router.cc:1503] [C0][S14559515594191298660] pool ready
[2019-10-28 14:34:56.735][19][debug][connection] [source/common/network/connection_impl.cc:449] [C2] onAboveWriteBufferHighWatermark
[2019-10-28 14:34:56.744][19][debug][connection] [source/common/network/connection_impl.cc:479] [C0] remote early close
[2019-10-28 14:34:56.744][19][debug][connection] [source/common/network/connection_impl.cc:190] [C0] closing socket: 0
[2019-10-28 14:34:56.744][19][debug][http] [source/common/http/conn_manager_impl.cc:1596] [C0][S12691433455413425278] stream reset
[2019-10-28 14:34:56.744][19][debug][router] [source/common/router/router.cc:1452] [C0][S14559515594191298660] resetting pool request
[2019-10-28 14:34:56.744][19][debug][client] [source/common/http/codec_client.cc:105] [C2] request reset
[2019-10-28 14:34:56.744][19][debug][connection] [source/common/network/connection_impl.cc:101] [C2] closing data_to_write=3044753 type=1
[2019-10-28 14:34:56.744][19][debug][connection] [source/common/network/connection_impl.cc:190] [C2] closing socket: 1
[2019-10-28 14:34:56.744][19][debug][client] [source/common/http/codec_client.cc:82] [C2] disconnect. resetting 0 pending requests
[2019-10-28 14:34:56.745][19][debug][pool] [source/common/http/http1/conn_pool.cc:129] [C2] client disconnected, failure reason:
[2019-10-28 14:34:56.745][19][debug][main] [source/server/connection_handler_impl.cc:80] [C0] adding to cleanup list
[2019-10-28T14:34:56.694Z] "GET /log/xxlarge HTTP/1.1" 200 - 0 4000000 50 7 "-" "curl/7.29.0" "-" "-" "-" "-" "02bf15f6-d67f-41b5-a9c8-0fe67309426a" "-" "10.5.130.68:9999" "10.200.1.130:8080"
[2019-10-28 14:34:58.029][12][debug][main] [source/server/server.cc:170] flushing stats

コントリビューターガイド

調査方針
Envoy Luaフィルターのenvoy on response()におけるbodyChunks()とhttpCall()の相互作用を調査する。問題は、bodyChunks()を使用するとhttpCall()が早期に終了することを示している。Luaフィルターのコルーチンライフサイクルとボディチャンクの配信方法に焦点を当てる。httpCallが非同期に完了するかどうか、および応答ボディが完全にストリーミングされた後にコルーチンが再開されるかどうかを確認する。Envoy Luaフィルターのソースコード（source/extensions/filters/http/lua）を調べて、yieldとresumeのメカニズムを理解する。大きなペイロードで再現し、デバッグログをトレースする。bodyChunksループ後にレースコンディションやyieldの欠如がないか検討する。
技術スタック
cpp
領域
backendnetworking
Issue 種別
バグ
難度新しい貢献者にとっての実装難度です。1 は非常に小さな変更、5 は専門的な作業です。
3
推定時間経験ある貢献者が調査、実装、テスト、pull request 準備にかけるおおよその時間範囲です。
半日
活動状況Issue が今どれだけ取り組みやすいかを示します。新しい、活発、古い、ブロック中、またはメンテナー入力待ちなどです。
アクティブ
明確さ期待される変更、受け入れ条件、次の手順がどれだけ明確かを示します。
明確
前提条件
EnvoyLua
初心者向け度初回貢献者にどれだけ取り組みやすいかを 1-100 で推定したスコアです。
40