aws / aws-lambda-runtime-interface-emulator

Apache License 2.0
936 stars 99 forks source link

Go Panic When Calling the `/runtime/init/error` Endpoint #35

Open chrisguitarguy opened 3 years ago

chrisguitarguy commented 3 years ago
time="2021-04-28T14:07:35.625" level=panic msg="ReplyStream not available"
2021/04/28 14:07:35 http: panic serving 127.0.0.1:52492: &{0xc000164000 map[] 2021-04-28 14:07:35.62583 +0000 UTC m=+2.137851001 panic <nil> ReplyStream not available <nil> <nil> }
goroutine 21 [running]:
net/http.(*conn).serve.func1(0xc000130aa0)
    /usr/local/go/src/net/http/server.go:1800 +0x139
panic(0x866640, 0xc0001641c0)
    /usr/local/go/src/runtime/panic.go:975 +0x3e3
github.com/sirupsen/logrus.Entry.log(0xc000164000, 0xc000106f00, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
    /go/pkg/mod/github.com/sirupsen/logrus@v1.6.0/entry.go:259 +0x335
github.com/sirupsen/logrus.(*Entry).Log(0xc0001640e0, 0xc000000000, 0xc00008d588, 0x1, 0x1)
    /go/pkg/mod/github.com/sirupsen/logrus@v1.6.0/entry.go:287 +0xeb
github.com/sirupsen/logrus.(*Logger).Log(0xc000164000, 0xc000000000, 0xc00008d588, 0x1, 0x1)
    /go/pkg/mod/github.com/sirupsen/logrus@v1.6.0/logger.go:193 +0x7d
github.com/sirupsen/logrus.(*Logger).Panic(...)
    /go/pkg/mod/github.com/sirupsen/logrus@v1.6.0/logger.go:234
github.com/sirupsen/logrus.Panic(...)
    /go/pkg/mod/github.com/sirupsen/logrus@v1.6.0/exported.go:129
go.amzn.com/lambda/rapi/rendering.RenderInteropError(0x9097c0, 0xc00018c0e0, 0xc0001a8200, 0x902b60, 0xc0001050c0)
    /LambdaRuntimeLocal/lambda/rapi/rendering/rendering.go:292 +0x9a
go.amzn.com/lambda/rapi/handler.(*initErrorHandler).ServeHTTP(0xc0002140a0, 0x9097c0, 0xc00018c0e0, 0xc0001a8200)
    /LambdaRuntimeLocal/lambda/rapi/handler/initerror.go:52 +0x519
net/http.HandlerFunc.ServeHTTP(0xc000202380, 0x9097c0, 0xc00018c0e0, 0xc0001a8200)
    /usr/local/go/src/net/http/server.go:2041 +0x44
github.com/go-chi/chi.(*Mux).routeHTTP(0xc00021e0c0, 0x9097c0, 0xc00018c0e0, 0xc0001a8200)
    /go/pkg/mod/github.com/go-chi/chi@v4.1.2+incompatible/mux.go:431 +0x278
net/http.HandlerFunc.ServeHTTP(0xc000214030, 0x9097c0, 0xc00018c0e0, 0xc0001a8200)
    /usr/local/go/src/net/http/server.go:2041 +0x44
go.amzn.com/lambda/rapi/middleware.RuntimeReleaseMiddleware.func1.1(0x9097c0, 0xc00018c0e0, 0xc0001a8200)
    /LambdaRuntimeLocal/lambda/rapi/middleware/middleware.go:100 +0xea
net/http.HandlerFunc.ServeHTTP(0xc000202180, 0x9097c0, 0xc00018c0e0, 0xc0001a8200)
    /usr/local/go/src/net/http/server.go:2041 +0x44
go.amzn.com/lambda/rapi/middleware.AccessLogMiddleware.func1.1(0x9097c0, 0xc00018c0e0, 0xc0001a8200)
    /LambdaRuntimeLocal/lambda/rapi/middleware/middleware.go:77 +0x170
net/http.HandlerFunc.ServeHTTP(0xc0002021a0, 0x9097c0, 0xc00018c0e0, 0xc0001a8200)
    /usr/local/go/src/net/http/server.go:2041 +0x44
go.amzn.com/lambda/rapi/middleware.AppCtxMiddleware.func1.1(0x9097c0, 0xc00018c0e0, 0xc0001a8100)
    /LambdaRuntimeLocal/lambda/rapi/middleware/middleware.go:66 +0x77
net/http.HandlerFunc.ServeHTTP(0xc0002122d0, 0x9097c0, 0xc00018c0e0, 0xc0001a8100)
    /usr/local/go/src/net/http/server.go:2041 +0x44
github.com/go-chi/chi.(*Mux).ServeHTTP(0xc00021e0c0, 0x9097c0, 0xc00018c0e0, 0xc0001a8100)
    /go/pkg/mod/github.com/go-chi/chi@v4.1.2+incompatible/mux.go:70 +0x513
github.com/go-chi/chi.(*Mux).Mount.func1(0x9097c0, 0xc00018c0e0, 0xc0001a8100)
    /go/pkg/mod/github.com/go-chi/chi@v4.1.2+incompatible/mux.go:298 +0x118
net/http.HandlerFunc.ServeHTTP(0xc0002023e0, 0x9097c0, 0xc00018c0e0, 0xc0001a8100)
    /usr/local/go/src/net/http/server.go:2041 +0x44
github.com/go-chi/chi.(*Mux).routeHTTP(0xc00021e060, 0x9097c0, 0xc00018c0e0, 0xc0001a8100)
    /go/pkg/mod/github.com/go-chi/chi@v4.1.2+incompatible/mux.go:431 +0x278
net/http.HandlerFunc.ServeHTTP(0xc0002140c0, 0x9097c0, 0xc00018c0e0, 0xc0001a8100)
    /usr/local/go/src/net/http/server.go:2041 +0x44
github.com/go-chi/chi.(*Mux).ServeHTTP(0xc00021e060, 0x9097c0, 0xc00018c0e0, 0xc0001a8000)
    /go/pkg/mod/github.com/go-chi/chi@v4.1.2+incompatible/mux.go:86 +0x2b2
net/http.serverHandler.ServeHTTP(0xc000222000, 0x9097c0, 0xc00018c0e0, 0xc0001a8000)
    /usr/local/go/src/net/http/server.go:2836 +0xa3
net/http.(*conn).serve(0xc000130aa0, 0x90a800, 0xc00012e480)
    /usr/local/go/src/net/http/server.go:1924 +0x86c
created by net/http.(*Server).Serve
    /usr/local/go/src/net/http/server.go:2962 +0x35c

Here's a minimal example that reproduces this: https://github.com/chrisguitarguy/rie-init-error-example (./run_example there should do it).

Seems to originate from here: https://github.com/aws/aws-lambda-runtime-interface-emulator/blob/00d793b74124ebabf38da49fe3a34645e6168b5f/lambda/rapidcore/server.go#L223

There are some additional warnings that show up too:

time="2021-04-28T14:07:35.64" level=warning msg="Failed to send default error response: ErrInvalidInvokeID"
time="2021-04-28T14:07:35.64" level=error msg="INIT DONE failed: Runtime.ExitError"
time="2021-04-28T14:07:35.641" level=warning msg="Reset initiated: ReserveFail"

Looking at that server.go, it seems like it all depends on invokeCtx being set, but that wouldn't be set up for init errors given there is not invoke context yet -- something went wrong before it go to that point, right?