DispatchHttpCall from OnTick() results in runtime.nilPanic

[abhide]

PLEASE FILL IN THE FOLLOWINGS for EVERY ISSUE you make.

Describe the bug / error

I have a filter that processes HTTP requests and caches data about the request/response OnHttpStreamDone(). Then OnTick(); we process the data and POST it to an external endpoint.

func (ctx *rootContext) OnTick() {
	length := len(buffer)
	if length == 0 {
		return
	}

	gatewayLoggerReqHeaders := [][2]string{
		{":method", "POST"}, {":path", "/foobar"}, {":authority", cfg.GetExternalEndpointDNSName()}, {":scheme", "https"},
	}
	for i:=0; i < length; i++ {
		if _, err := proxywasm.DispatchHttpCall(
			cfg.GetUpstreamClusterName(), ReqHeaders, buffer[i], [][2]string{}, 5000, httpCallResponseCallback);
		err != nil {
			proxywasm.LogCriticalf("Failed to dispatch http call", err)
		} else {
			proxywasm.LogInfo("Successfully dispatched HTTP POST")
		}
	}
	// Remove elements we have consumed
	buffer = buffer[length:]
}

This results in the following error

2021-07-20T06:31:38.974139Z	error	envoy wasm	Function: proxy_on_tick failed: Uncaught RuntimeError: unreachable
Proxy-Wasm plugin in-VM backtrace:
  0:  0x3fe9 - runtime.runtimePanic
  1:  0x19ba - runtime.nilPanic
  2:  0x16676 - proxy_on_tick

What is your Envoy/Istio version?

$ istioctl version
istiod version: 1.9.5
data plane version: 1.9.5

What is the SDK version?

0.3.0

What is your TinyGo version?

$ tinygo version
tinygo version 0.18.0 darwin/amd64 (using go version go1.16.5 and LLVM version 11.0.0)

URL or snippet of your code including Envoy configuration

Additional context (Optional)

[mathetake]

@abhide thanks for reporting this, and this looks like a bug of SDK. Do you have any small reproducer I can use to investigate?

[abhide]

@mathetake Thanks for getting back promptly.
I don't have a small repro. You could modify the examples to actually make a POST call
https://github.com/tetratelabs/proxy-wasm-go-sdk/blob/v0.13.0/examples/dispatch_call_on_tick/main.go

[abhide]

Another data point; I can see the first POST HTTP request from OnTick() is making to the external endpoint but then its failing in the plugin. Something that's evident from trace level logs.

2021-07-20T07:13:19.044286Z     trace   envoy wasm      [vm<-host] env.proxy_log return: 0
2021-07-20T07:13:19.044296Z     trace   envoy wasm      [vm->host] env.proxy_http_call(79600, 73, 99844, 176, 94436, 434, 100020, 4, 5000, 65348)
2021-07-20T07:13:19.044580Z     trace   envoy wasm      [vm<-host] env.proxy_http_call return: 0
2021-07-20T07:13:19.044603Z     trace   envoy wasm      [vm->host] wasi_snapshot_preview1.fd_write(1, 74060, 1, 78400)
2021-07-20T07:13:19.044608Z     info    envoy wasm      wasm log filter-root-id: panic: runtime error: nil pointer dereference
2021-07-20T07:13:19.044612Z     trace   envoy wasm      [vm<-host] wasi_snapshot_preview1.fd_write return: 0
2021-07-20T07:13:19.044763Z     error   envoy wasm      Function: proxy_on_tick failed: Uncaught RuntimeError: unreachable
Proxy-Wasm plugin in-VM backtrace:
  0:  0x3fe7 - runtime.runtimePanic
  1:  0x19b8 - runtime.nilPanic
  2:  0x16416 - proxy_on_tick

[mathetake]

I found a bug around on_tick and fixed in #202 but not sure this fixes your crash. Could you try this out by the followings? (the API has changed since your version but I hope the necessary change to your code is not big).

$ go mod edit -require=github.com/tetratelabs/proxy-wasm-go-sdk@main
$ go mod download github.com/tetratelabs/proxy-wasm-go-sdk

[abhide]

Thanks @mathetake. Your fix is working and I don't see nilPanic as before.
When do we expect this to be part of an official release?

Adding my teammate @bvandewalle

[mathetake]

OK just released v0.14.0 https://github.com/tetratelabs/proxy-wasm-go-sdk/releases/tag/v0.14.0 - thanks for reporting and testing the patch! Now closing issue.

[abhide]

Amazing! Thanks for your fix @mathetake.
👍 💯