search

jlewi / foyle

Foyle is a copilot to help developers deploy and operate their applications.
https://foyle.io
Apache License 2.0
110 stars 10 forks source link

Crash: panic: Write called after Handler finished #319

Closed jlewi closed 3 weeks ago

jlewi commented 1 month ago

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 https://github.com/jlewi/foyle/pull/285/commits/e0d65edd4ec05572f3f32423657d56173dd495cf

jlewi commented 3 weeks ago

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

jlewi commented 3 weeks ago

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 https://github.com/jlewi/foyle/commit/fde802c21c222d2a50d063f8e1590fb55e4e0180

This is the line in the panic trace https://github.com/jlewi/foyle/blob/fde802c21c222d2a50d063f8e1590fb55e4e0180/app/pkg/agent/agent.go#L291