From ff0585ad680b4754cc34d79795796ebd0b662d63 Mon Sep 17 00:00:00 2001 From: Joakim Olsson Date: Sat, 17 Oct 2026 01:04:48 +0200 Subject: [PATCH] feat: add gqlgen Recover that logs panics as one structured record gqlgen's DefaultRecover prints the panic and debug.PrintStack() to stderr, so the log collector stores every stack line as a separate, level-less entry. Recover logs the panic as a single ERROR record via slog.Default() with panic, stack and path attributes, records it on the active span with status Error, and returns the generic "internal system error" without leaking the panic text. Install with srv.SetRecoverFunc(otelsetup.Recover). Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_01H6eVuR4Yt3m7TbDTDwyZJi --- CLAUDE.md | 8 ++++ go.mod | 2 +- recover.go | 41 +++++++++++++++++ recover_test.go | 117 ++++++++++++++++++++++++++++++++++++++++++++++++ 4 files changed, 167 insertions(+), 1 deletion(-) create mode 100644 recover.go create mode 100644 recover_test.go diff --git a/CLAUDE.md b/CLAUDE.md index e8527c4..f971fe8 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -28,6 +28,12 @@ defer shutdown(ctx) // Wrap HTTP handlers with tracing http.Handle("/", otelsetup.Handler(myHandler)) + +// gqlgen server hooks +srv.AroundOperations(otelsetup.AroundOperations) +srv.AroundRootFields(otelsetup.AroundRootFields) +srv.AroundFields(otelsetup.AroundFields) +srv.SetRecoverFunc(otelsetup.Recover) ``` ### Features @@ -37,6 +43,8 @@ http.Handle("/", otelsetup.Handler(myHandler)) - **Logging** - Stdout log exporter - **Propagation** - TraceContext and Baggage propagation - **HTTP Handler** - Middleware for automatic span creation +- **gqlgen hooks** - Spans per operation, root field and resolver field +- **gqlgen recover** - `Recover` logs a resolver panic as one ERROR record via `slog.Default()` (attributes `panic`, `stack`, `path`), records it on the active span with status Error, and returns the generic "internal system error" to the client (gqlgen's default prints the stack to stderr line by line) ### Environment Variables diff --git a/go.mod b/go.mod index c4afe81..1405d6a 100644 --- a/go.mod +++ b/go.mod @@ -6,6 +6,7 @@ require ( codeberg.org/eventsourced/eventsourced v1.24.0 codeberg.org/eventsourced/pg/v2 v2.3.0 github.com/99designs/gqlgen v0.17.95 + github.com/vektah/gqlparser/v2 v2.5.37 go.opentelemetry.io/otel v1.47.0 go.opentelemetry.io/otel/exporters/otlp/otlpmetric/otlpmetrichttp v1.47.0 go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp v1.47.0 @@ -30,7 +31,6 @@ require ( github.com/pressly/goose/v3 v3.28.0 // indirect github.com/sethvargo/go-retry v0.4.0 // indirect github.com/sosodev/duration v1.4.0 // indirect - github.com/vektah/gqlparser/v2 v2.5.37 // indirect go.opentelemetry.io/auto/sdk v1.2.1 // indirect go.opentelemetry.io/otel/exporters/otlp/otlptrace v1.47.0 // indirect go.opentelemetry.io/otel/log v1.47.0 // indirect diff --git a/recover.go b/recover.go new file mode 100644 index 0000000..f6c0aaf --- /dev/null +++ b/recover.go @@ -0,0 +1,41 @@ +package otelsetup + +import ( + "context" + "fmt" + "log/slog" + "runtime/debug" + + "github.com/99designs/gqlgen/graphql" + "github.com/vektah/gqlparser/v2/gqlerror" + "go.opentelemetry.io/otel/codes" + "go.opentelemetry.io/otel/trace" +) + +// Recover is a gqlgen recover function, installed with srv.SetRecoverFunc(otelsetup.Recover). +// Unlike graphql.DefaultRecover, which prints the stack to stderr line by line, it logs the +// panic as a single structured ERROR record (via slog.Default) with the stack as an attribute, +// records it on the active span and marks the span as failed. The client gets the same generic +// "internal system error" as with the default, without the panic text. +func Recover(ctx context.Context, err any) error { + stack := string(debug.Stack()) + panicErr, ok := err.(error) + if !ok { + panicErr = fmt.Errorf("%v", err) + } + + attrs := []any{ + slog.String("panic", panicErr.Error()), + slog.String("stack", stack), + } + if fc := graphql.GetFieldContext(ctx); fc != nil { + attrs = append(attrs, slog.String("path", fc.Path().String())) + } + slog.Default().ErrorContext(ctx, "recovered panic in graphql resolver", attrs...) + + span := trace.SpanFromContext(ctx) + span.RecordError(panicErr, trace.WithStackTrace(true)) + span.SetStatus(codes.Error, "panic: "+panicErr.Error()) + + return gqlerror.Errorf("internal system error") +} diff --git a/recover_test.go b/recover_test.go new file mode 100644 index 0000000..12db295 --- /dev/null +++ b/recover_test.go @@ -0,0 +1,117 @@ +package otelsetup + +import ( + "context" + "errors" + "log/slog" + "strings" + "sync" + "testing" + + "github.com/99designs/gqlgen/graphql" + "github.com/vektah/gqlparser/v2/gqlerror" + "go.opentelemetry.io/otel/codes" + sdktrace "go.opentelemetry.io/otel/sdk/trace" + "go.opentelemetry.io/otel/sdk/trace/tracetest" +) + +type recordingHandler struct { + mu sync.Mutex + records []slog.Record +} + +func (h *recordingHandler) Enabled(context.Context, slog.Level) bool { return true } + +func (h *recordingHandler) Handle(_ context.Context, r slog.Record) error { + h.mu.Lock() + defer h.mu.Unlock() + h.records = append(h.records, r.Clone()) + return nil +} + +func (h *recordingHandler) WithAttrs([]slog.Attr) slog.Handler { return h } +func (h *recordingHandler) WithGroup(string) slog.Handler { return h } + +func TestRecover(t *testing.T) { + var _ graphql.RecoverFunc = Recover + + tests := []struct { + name string + panicVal any + wantPanic string + }{ + {name: "error value", panicVal: errors.New("runtime error: invalid memory address or nil pointer dereference"), wantPanic: "runtime error: invalid memory address or nil pointer dereference"}, + {name: "string value", panicVal: "boom", wantPanic: "boom"}, + } + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + h := &recordingHandler{} + prev := slog.Default() + slog.SetDefault(slog.New(h)) + t.Cleanup(func() { slog.SetDefault(prev) }) + + sr := tracetest.NewSpanRecorder() + tp := sdktrace.NewTracerProvider(sdktrace.WithSpanProcessor(sr)) + ctx, span := tp.Tracer("test").Start(context.Background(), "resolver") + + err := Recover(ctx, tt.panicVal) + span.End() + + var gqlErr *gqlerror.Error + if !errors.As(err, &gqlErr) || gqlErr.Message != "internal system error" { + t.Fatalf("Recover() error = %v, want gqlerror \"internal system error\"", err) + } + if strings.Contains(err.Error(), tt.wantPanic) { + t.Errorf("Recover() error leaks panic text: %v", err) + } + + if len(h.records) != 1 { + t.Fatalf("got %d log records, want exactly 1", len(h.records)) + } + rec := h.records[0] + if rec.Level != slog.LevelError { + t.Errorf("log level = %v, want ERROR", rec.Level) + } + got := map[string]string{} + rec.Attrs(func(a slog.Attr) bool { + got[a.Key] = a.Value.String() + return true + }) + if got["panic"] != tt.wantPanic { + t.Errorf("panic attr = %q, want %q", got["panic"], tt.wantPanic) + } + if !strings.Contains(got["stack"], "goroutine") { + t.Errorf("stack attr missing stack trace: %q", got["stack"]) + } + + spans := sr.Ended() + if len(spans) != 1 { + t.Fatalf("got %d spans, want 1", len(spans)) + } + s := spans[0] + if s.Status().Code != codes.Error { + t.Errorf("span status = %v, want Error", s.Status().Code) + } + var exception bool + for _, ev := range s.Events() { + if ev.Name != "exception" { + continue + } + exception = true + attrs := map[string]string{} + for _, kv := range ev.Attributes { + attrs[string(kv.Key)] = kv.Value.String() + } + if attrs["exception.message"] != tt.wantPanic { + t.Errorf("exception.message = %q, want %q", attrs["exception.message"], tt.wantPanic) + } + if attrs["exception.stacktrace"] == "" { + t.Error("exception event has no stacktrace") + } + } + if !exception { + t.Error("span has no exception event") + } + }) + } +}