Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Crash: panic: Write called after Handler finished #319

Closed
jlewi opened this issue Oct 23, 2024 · 2 comments · Fixed by #332
Closed

Crash: panic: Write called after Handler finished #319

jlewi opened this issue Oct 23, 2024 · 2 comments · Fixed by #332

Comments

@jlewi
Copy link
Owner

jlewi commented Oct 23, 2024

Here's the trace.

2024-10-23T06:33:47.780-0700	INFO	agent/agent.go:137	Agent.Generate returning response	{"traceId": "3524a2b15ce4b54d1f97fdd00d742f91", "streamTraceId": "942ee54bf5d6ea074112c1b79cfe6966", "contextId": "01JAWSAJK9WV5R0C3ZR4SDFNHA", "traceId": "3524a2b15ce4b54d1f97fdd00d742f91", "evalMode": false, "response": {"blocks": [{"kind": "CODE", "language": "bash", "contents": "# Fetch the logs for the rube app to identify any issues causing the CrashLoopBackOff status\nkubectl -n rube logs rube-8689fcbdb-nsglc\n\n# Fetch the logs via gcloud for additional insights\ngcloud logging read \"resource.type=\\\"k8s_container\\\" AND labels.k8s-pod/app=\\\"rube\\\" AND labels.k8s-pod/env=\\\"prod\\\"\" --limit=100 --freshness=1h --format=\"table(severity,timestamp,jsonPayload.traceId,textPayload,jsonPayload.message)\"", "outputs": [], "trace_ids": [], "id": "01JAWSARC2FK3E8DSMMJJ2PS1Z"}], "trace_id": "3524a2b15ce4b54d1f97fdd00d742f91"}}
panic: Write called after Handler finished
	panic: Header called after Handler finished

goroutine 83920 [running]:
golang.org/x/net/http2.(*responseWriter).FlushError(0x200?)
	/Users/jlewi/go/pkg/mod/golang.org/x/net@v0.27.0/http2/server.go:2865 +0x118
golang.org/x/net/http2.(*responseWriter).Flush(0x10565af60?)
	/Users/jlewi/go/pkg/mod/golang.org/x/net@v0.27.0/http2/server.go:2859 +0x1c
github.com/gin-gonic/gin.(*responseWriter).Flush(0x105654b00?)
	/Users/jlewi/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/response_writer.go:123 +0xb4
connectrpc.com/connect.flushResponseWriter(...)
	/Users/jlewi/go/pkg/mod/connectrpc.com/connect@v1.16.2/protocol.go:357
panic({0x104160de0?, 0x10458a660?})
	/opt/homebrew/Cellar/go/1.22.5/libexec/src/runtime/panic.go:770 +0x124
golang.org/x/net/http2.(*responseWriter).write(0x10?, 0x105a54f18?, {0x1400ad77610?, 0x14005274008?, 0x1400ad77610?}, {0x0?, 0x0?})
	/Users/jlewi/go/pkg/mod/golang.org/x/net@v0.27.0/http2/server.go:3010 +0x15c
golang.org/x/net/http2.(*responseWriter).Write(0x5?, {0x1400ad77610?, 0x14002813701?, 0x1027ef9b8?})
	/Users/jlewi/go/pkg/mod/golang.org/x/net@v0.27.0/http2/server.go:2999 +0x38
github.com/gin-gonic/gin.(*responseWriter).Write(0x14000738000, {0x1400ad77610?, 0x14002813878?, 0x1027f032c?})
	/Users/jlewi/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/response_writer.go:83 +0x7c
connectrpc.com/connect.(*envelope).WriteTo(0x14002942288, {0x105c35090, 0x14000738000})
	/Users/jlewi/go/pkg/mod/connectrpc.com/connect@v1.16.2/envelope.go:79 +0xc0
connectrpc.com/connect.writeSender.Send(...)
	/Users/jlewi/go/pkg/mod/connectrpc.com/connect@v1.16.2/duplex_http_call.go:391
connectrpc.com/connect.(*envelopeWriter).write(0x14000f0cb78, 0x1027f032c?)
	/Users/jlewi/go/pkg/mod/connectrpc.com/connect@v1.16.2/envelope.go:212 +0x3c
connectrpc.com/connect.(*envelopeWriter).Write(0x14000f0cb78, 0x14002942270)
	/Users/jlewi/go/pkg/mod/connectrpc.com/connect@v1.16.2/envelope.go:167 +0x1f8
connectrpc.com/connect.(*envelopeWriter).marshalAppend(0x14000f0cb78, {0x1044469e0, 0x14000827500}, {0x105c372a0, 0x105708ba0})
	/Users/jlewi/go/pkg/mod/connectrpc.com/connect@v1.16.2/envelope.go:195 +0x22c
connectrpc.com/connect.(*envelopeWriter).Marshal(0x5cb1a224356669fe?, {0x1044469e0?, 0x14000827500?})
	/Users/jlewi/go/pkg/mod/connectrpc.com/connect@v1.16.2/envelope.go:143 +0x120
connectrpc.com/connect.(*connectStreamingHandlerConn).Send(0x0?, {0x1044469e0?, 0x14000827500?})
	/Users/jlewi/go/pkg/mod/connectrpc.com/connect@v1.16.2/protocol_connect.go:809 +0x68
connectrpc.com/connect.(*errorTranslatingHandlerConnCloser).Send(0x14000326840, {0x1044469e0?, 0x14000827500?})
	/Users/jlewi/go/pkg/mod/connectrpc.com/connect@v1.16.2/protocol.go:176 +0x38
connectrpc.com/otelconnect.(*streamingState).send(0x14001c40a80, {0x1045ab870, 0x140021c20f0}, {0x1044469e0, 0x14000827500}, {0x105c35300?, 0x14000326840?})
	/Users/jlewi/go/pkg/mod/connectrpc.com/otelconnect@v0.7.1/streaming.go:102 +0x5c
connectrpc.com/otelconnect.(*Interceptor).WrapStreamingHandler.func1.2({0x1044469e0?, 0x14000827500?}, {0x105c350d0?, 0x14000326840?})
	/Users/jlewi/go/pkg/mod/connectrpc.com/otelconnect@v0.7.1/interceptor.go:321 +0x74
connectrpc.com/otelconnect.(*streamingHandlerInterceptor).Send(0x40?, {0x1044469e0?, 0x14000827500?})
	/Users/jlewi/go/pkg/mod/connectrpc.com/otelconnect@v0.7.1/payloadinterceptor.go:55 +0x40
connectrpc.com/connect.(*BidiStream[...]).Send(0x140021c2150?, 0x14002396a50?)
	/Users/jlewi/go/pkg/mod/connectrpc.com/connect@v1.16.2/handler_stream.go:191 +0x30
github.com/jlewi/foyle/app/pkg/agent.(*Agent).StreamGenerate.func1({0x1045ab8a8, 0x14002396a50})
	/Users/jlewi/git_foyle/app/pkg/agent/agent.go:289 +0x230
created by github.com/jlewi/foyle/app/pkg/agent.(*Agent).StreamGenerate in goroutine 83921
	/Users/jlewi/git_foyle/app/pkg/agent/agent.go:247 +0x3fc

Using commit
e0d65ed

@jlewi
Copy link
Owner Author

jlewi commented Nov 2, 2024

I think the error indicates we are trying to write after the handler has finished
So maybe we should check gin.Context.Done?

jlewi added a commit that referenced this issue Nov 4, 2024
I think we get this issue (#319) because we check whether the context is cancelled
before generating an AI response and then try to return the response.
However, in between the initial check and actually having the response
to send the context could have been cancelled.

So check if the context is done. before sending the response.

Fix #319
@jlewi
Copy link
Owner Author

jlewi commented Nov 4, 2024

Here's the most recent stacktrace.

2024-11-03T12:58:39.187-0800	INFO	agent/agent.go:253	Received trigger signal	{"agentName": "", "traceId": "e895ed02a921b0a4642f61d3a5a34b27", "evalMode": false}
panic: Write called after Handler finished
	panic: Header called after Handler finished

goroutine 10161 [running]:
golang.org/x/net/http2.(*responseWriter).FlushError(0x14002f79628?)
	/Users/jlewi/go/pkg/mod/golang.org/x/net@v0.27.0/http2/server.go:2865 +0x118
golang.org/x/net/http2.(*responseWriter).Flush(0x105c9b000?)
	/Users/jlewi/go/pkg/mod/golang.org/x/net@v0.27.0/http2/server.go:2859 +0x1c
github.com/gin-gonic/gin.(*responseWriter).Flush(0x105c94ba0?)
	/Users/jlewi/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/response_writer.go:123 +0xb4
connectrpc.com/connect.flushResponseWriter(...)
	/Users/jlewi/go/pkg/mod/connectrpc.com/connect@v1.16.2/protocol.go:357
panic({0x1047a0e20?, 0x104bca7a0?})
	/opt/homebrew/Cellar/go/1.22.5/libexec/src/runtime/panic.go:770 +0x124
golang.org/x/net/http2.(*responseWriter).write(0x14003200000?, 0x105f94108?, {0x14002b057f9?, 0x14000600008?, 0x18?}, {0x0?, 0x0?})
	/Users/jlewi/go/pkg/mod/golang.org/x/net@v0.27.0/http2/server.go:3010 +0x15c
golang.org/x/net/http2.(*responseWriter).Write(0x5?, {0x14002b057f9?, 0x14002f79701?, 0x102e2b9b8?})
	/Users/jlewi/go/pkg/mod/golang.org/x/net@v0.27.0/http2/server.go:2999 +0x38
github.com/gin-gonic/gin.(*responseWriter).Write(0x140019da100, {0x14002b057f9?, 0x14002f79878?, 0x102e2c32c?})
	/Users/jlewi/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/response_writer.go:83 +0x7c
connectrpc.com/connect.(*envelope).WriteTo(0x1400375d6c8, {0x12d4c8ea8, 0x140019da100})
	/Users/jlewi/go/pkg/mod/connectrpc.com/connect@v1.16.2/envelope.go:79 +0xc0
connectrpc.com/connect.writeSender.Send(...)
	/Users/jlewi/go/pkg/mod/connectrpc.com/connect@v1.16.2/duplex_http_call.go:391
connectrpc.com/connect.(*envelopeWriter).write(0x14001efd258, 0x102e2c32c?)
	/Users/jlewi/go/pkg/mod/connectrpc.com/connect@v1.16.2/envelope.go:212 +0x3c
connectrpc.com/connect.(*envelopeWriter).Write(0x14001efd258, 0x1400375d6b0)
	/Users/jlewi/go/pkg/mod/connectrpc.com/connect@v1.16.2/envelope.go:167 +0x1f8
connectrpc.com/connect.(*envelopeWriter).marshalAppend(0x14001efd258, {0x104a86ac0, 0x14000ab0000}, {0x12cfa49b8, 0x105d48c40})
	/Users/jlewi/go/pkg/mod/connectrpc.com/connect@v1.16.2/envelope.go:195 +0x22c
connectrpc.com/connect.(*envelopeWriter).Marshal(0x14001efd258?, {0x104a86ac0?, 0x14000ab0000?})
	/Users/jlewi/go/pkg/mod/connectrpc.com/connect@v1.16.2/envelope.go:143 +0x120
connectrpc.com/connect.(*connectStreamingHandlerConn).Send(0x0?, {0x104a86ac0?, 0x14000ab0000?})
	/Users/jlewi/go/pkg/mod/connectrpc.com/connect@v1.16.2/protocol_connect.go:809 +0x68
connectrpc.com/connect.(*errorTranslatingHandlerConnCloser).Send(0x14000713a80, {0x104a86ac0?, 0x14000ab0000?})
	/Users/jlewi/go/pkg/mod/connectrpc.com/connect@v1.16.2/protocol.go:176 +0x38
connectrpc.com/otelconnect.(*streamingState).send(0x140009f4240, {0x104beb9b0, 0x14002f00d80}, {0x104a86ac0, 0x14000ab0000}, {0x12cfa4260?, 0x14000713a80?})
	/Users/jlewi/go/pkg/mod/connectrpc.com/otelconnect@v0.7.1/streaming.go:102 +0x5c
connectrpc.com/otelconnect.(*Interceptor).WrapStreamingHandler.func1.2({0x104a86ac0?, 0x14000ab0000?}, {0x12d4c8ee8?, 0x14000713a80?})
	/Users/jlewi/go/pkg/mod/connectrpc.com/otelconnect@v0.7.1/interceptor.go:321 +0x74
connectrpc.com/otelconnect.(*streamingHandlerInterceptor).Send(0x40?, {0x104a86ac0?, 0x14000ab0000?})
	/Users/jlewi/go/pkg/mod/connectrpc.com/otelconnect@v0.7.1/payloadinterceptor.go:55 +0x40
connectrpc.com/connect.(*BidiStream[...]).Send(0x14002f00de0?, 0x1400330f680?)
	/Users/jlewi/go/pkg/mod/connectrpc.com/connect@v1.16.2/handler_stream.go:191 +0x30
github.com/jlewi/foyle/app/pkg/agent.(*Agent).StreamGenerate.func1({0x104beb9e8, 0x1400330f680})
	/Users/jlewi/git_foyle/app/pkg/agent/agent.go:291 +0x230
created by github.com/jlewi/foyle/app/pkg/agent.(*Agent).StreamGenerate in goroutine 10128
	/Users/jlewi/git_foyle/app/pkg/agent/agent.go:249 +0x3fc

I think this is version.

2024-11-03T13:02:59.442-0800	INFO	cmd/version.go:41	binary version	{"agentName": "", "version": "0.0.31-2-g1049fad-1049fad", "commit": "1049fad84f92a95274c876e9bad0df17dadb6aa1", "date": "2024-11-01T21:34:05Z", "builtBy": "unknown"}

Which should be the same as this commit
fde802c

This is the line in the panic trace

if err := stream.Send(response); err != nil {

jlewi added a commit that referenced this issue Nov 5, 2024
I think we get this issue (#319) because we check whether the context is
cancelled before generating an AI response and then try to return the
response. However, in between the initial check and actually having the
response to send the context could have been cancelled.

So check if the context is done. before sending the response.

Fix #319
@jlewi jlewi closed this as completed in #332 Nov 5, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant