GetHttpResponseBody with large file

[RoeiGanor]

Describe the bug / error

Issue with the wasm plugin while envoy serving relatively large file (approximately larger than 1mb).
When there is a large file, the request is being drop and the client fail to download the file.
The code is very similar to an example in this repository:

proxy-wasm-go-sdk/examples/http_body/main.go

Line 158 in 4abbb63

func (ctx *setBodyContext) OnHttpResponseBody(bodySize int, endOfStream bool) types.Action {

Our code:

func (ctx *httpContext) OnHttpResponseBody(bodySize int, endOfStream bool) types.Action {
	proxywasm.LogErrorf("Enter OnHttpResponseBody %d %t %d %d", bodySize, endOfStream, ctx.totalResponseBodySize, ctx.maxResponseBodySize)
	
	if !endOfStream {
		return types.ActionPause
	}

	if ctx.totalResponseBodySize > ctx.maxResponseBodySize {
		ctx.responseBodyTooLarge = true
	} else {
		reqBody, err := proxywasm.GetHttpResponseBody(0, ctx.totalResponseBodySize)
		if err != nil {
			proxywasm.LogErrorf("Failed to get response body: %v", err)
			return types.ActionContinue
		}

		// Saving the body for later
		ctx.responseBody = reqBody
	}

	return types.ActionContinue
}

The issue occurs when the envoy is serving a large file, but the endofstream is never true.
This is a small file (4064 bytes) example:

wasm log: Enter OnHttpResponseBody 4064 false 0 2147483647
wasm log: Enter OnHttpResponseBody 4064 true 4064 2147483647

This is a large file (2698669 bytes) example, the file is being dropped before the endofstream result in true

wasm log: Enter OnHttpResponseBody 114532 false 0 2147483647
wasm log: Enter OnHttpResponseBody 114532 false 114532 2147483647
wasm log: Enter OnHttpResponseBody 1047900 false 229064 2147483647

When the changing the types.ActionPause in !endOfStream to types.ActionContinue, the file is not being dropped:

func (ctx *httpContext) OnHttpResponseBody(bodySize int, endOfStream bool) types.Action {
	proxywasm.LogErrorf("Enter OnHttpResponseBody %d %t %d %d", bodySize, endOfStream, ctx.totalResponseBodySize, ctx.maxResponseBodySize)

	if !endOfStream {
		return types.ActionContinue
	}

	if ctx.totalResponseBodySize > ctx.maxResponseBodySize {
		ctx.responseBodyTooLarge = true
	} else {
		reqBody, err := proxywasm.GetHttpResponseBody(0, ctx.totalResponseBodySize)
		if err != nil {
			proxywasm.LogErrorf("Failed to get response body: %v", err)
			return types.ActionContinue
		}

		// Saving the body for later
		ctx.responseBody = reqBody
	}

	return types.ActionContinue
}

But another issue arise from this case, the GetHttpResponseBody being failed after 2 executions, which means you cant really retrieve the whole response body.
This is a large file (2698669 bytes) example:

wasm log: Enter OnHttpResponseBody 65536 false 0 2147483647
wasm log: Enter OnHttpResponseBody 1048576 false 0 2147483647
wasm log: Enter OnHttpResponseBody 1048576 false 0 2147483647
wasm log: Enter OnHttpResponseBody 535981 false 0 2147483647
wasm log: Enter OnHttpResponseBody 0 true 0 2147483647

What is your Envoy/Istio version?

envoy version 1.24.0

What is the SDK version?

v0.19.0

What is your TinyGo version?

tinygo version 0.25.0 darwin/amd64 (using go version go1.18.3 and LLVM version 14.0.0)

URL or snippet of your code including Envoy configuration

static_resources:

  listeners:
  - address:
      socket_address:
        address: 127.0.0.1
        port_value: 8086
    filter_chains:
    - filters:
      - name: envoy.filters.network.http_connection_manager
        typed_config:
          "@type": type.googleapis.com/envoy.extensions.filters.network.http_connection_manager.v3.HttpConnectionManager
          use_remote_address: true
          codec_type: AUTO
          stat_prefix: ingress_https
          access_log:
            - name: envoy.access_loggers.file
              typed_config:
                "@type": type.googleapis.com/envoy.extensions.access_loggers.file.v3.FileAccessLog
                path: "./access.log"
          http_filters:
            - name: envoy.filters.http.wasm
              typed_config:
                "@type": type.googleapis.com/udpa.type.v1.TypedStruct
                type_url: type.googleapis.com/envoy.extensions.filters.http.wasm.v3.Wasm
                value:
                  config:
                    fail_open: true
                    configuration:
                      "@type": type.googleapis.com/google.protobuf.StringValue
                      value: <plugin-configuration>
                    vm_config:
                      runtime: "envoy.wasm.runtime.v8"
                      code:
                        local:
                          filename: "./wib-proxy-wasm-tap.wasm"
            - name: envoy.filters.http.router
              typed_config:
                "@type": type.googleapis.com/envoy.extensions.filters.http.router.v3.Router
          route_config:
            name: local_route
            virtual_hosts:
            - name: passthrough
              domains: ["*"]
              routes:
              - match:
                  prefix: "/"
                route:
                  cluster: service-http

  clusters:
  - name: service-http
    type: STRICT_DNS
    dns_lookup_family: V4_ONLY
    lb_policy: ROUND_ROBIN
    load_assignment:
      cluster_name: service-http
      endpoints:
      - lb_endpoints:
        - endpoint:
            address:
              socket_address:
                address: 127.0.0.1
                port_value: 8080
  - name: wib
    connect_timeout: 5000s
    type: STRICT_DNS
    dns_lookup_family: V4_ONLY
    lb_policy: round_robin
    load_assignment:
      cluster_name: wib
      endpoints:
        - lb_endpoints:
            - endpoint:   
                address:
                  socket_address:
                    address: 127.0.0.1
                    port_value: 9094

Additional context (Optional)

[mathetake]

cc @jcchavezs wanna take a look?

[RoeiGanor]

@jcchavezs @mathetake I have updated the issue description, the problem with action.ActionContinue is that the proxywasm.GetHttpResponseBody function call failed after 2 executions. Let's say the file is big and the OnHttpResponseBody function is called 5 times (like in the last example), the proxywasm.GetHttpResponseBody Is failed at the third time, which leads us to not being able actually to collect the whole request body.

[jcchavezs]

I will check.

…

On Tue, 28 Feb 2023, 22:21 RoeiGanor, ***@***.***> wrote: @jcchavezs <https://github.com/jcchavezs> @mathetake <https://github.com/mathetake> I have updated the issue description, the problem with action.ActionContinue is that the proxywasm.GetHttpResponseBody function call failed after 2 executions. Let's say the file is big and the OnHttpResponseBody function is called 5 times (like in the last example), the proxywasm.GetHttpResponseBody Is failed at the third time, which leads us to not being able actually to collect the whole request body. — Reply to this email directly, view it on GitHub <#359 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAXOYAUJPVNGVXKEULM6KF3WZZT6PANCNFSM6AAAAAAVFZBAO4> . You are receiving this because you were mentioned.Message ID: ***@***.***>

[jcchavezs]

I am sorry I did not come back before. I also noticed weird behaviours with endOfStream in the past, for example in https://github.com/corazawaf/coraza-proxy-wasm/blob/main/wasmplugin/plugin.go#L240-L247 where I couldn't reproduce the error with curl but could do it with a golang http client. I would ask you to describe how you do perform the request.

I will check it soon.

[RoeiGanor]

A lot of time has passed but as far as I remember this was my lab:

1. python simple HTTP server to serve files
2. envoy proxying to the python server
3. Had few files with different sizes in the file server
4. Curling to envoy with the file size needed, for example: curl localhost:808/1mb or curl localhost:808/2mb
5. The files were created using dd from /dev/urandom with base64 encoding.

[RoeiGanor]

Hey @jcchavezs !
Is there any news regarding this issue?

[xianyouQ]

same problem, anything update?

[mathetake]

#451