go-chi / chi

lightweight, idiomatic and composable router for building Go HTTP services
https://go-chi.io
MIT License
18.59k stars 988 forks source link

Custom middleware recovery having to be duplicated #911

Open williamhjcho opened 6 months ago

williamhjcho commented 6 months ago

Context

Hello πŸ‘‹

I'm still very new to go and might not be interpreting this correctly, but this is my current use case:

My small service:

Use case

While in debug mode, everything works as expected, outputs are sent to stdout/stderr and formatted properly. But while in release mode, when panicking (which I understand should be rare since errors should be properly handled), the panic is caught by the middleware.Recoverer and printed to stderr directly (via PrintPrettyStack). I wanted a way to get this output and put it into slog.

Why

The PrettyPrintStack outputs multiple lines to stderr, which causes the logger in GCP to interpret each line as an independent log entry.

Current solution

One alternative I tried was to just copy the parsing logic + middleware.Recover logic into a custom middleware. Another way was to create a custom middleware that parses & adds LogEntry to context (an adapted version from middleware.Logger). But I would still need to copy the PrintPrettyStack parsing functionality either way.

Is it possible to expose just the right functions or args to make it easier? Or am I missing something (go or chi related) else entirely to make this work?

williamhjcho commented 6 months ago

Forgot to add the solutions:

With custom recover middleware only

router.Use(middleware.Logger)
router.Use(recoverMiddleware(logger, config.Debug))

func recoverMiddleware(logger *slog.Logger, isDebug bool) func(next http.Handler) http.Handler {
    return func(next http.Handler) http.Handler {
        return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
            defer func() {
                if rvr := recover(); rvr != nil {
                    if rvr == http.ErrAbortHandler {
                        // we don't recover http.ErrAbortHandler so the response
                        // to the client is aborted, this should not be logged
                        panic(rvr)
                    }

                    logEntry := middleware.GetLogEntry(r)
                    if logEntry != nil {
                        logEntry.Panic(rvr, debug.Stack())
                    } else if isDebug {
                        middleware.PrintPrettyStack(rvr)
                    } else {
                        stack := string(debug.Stack())
                        logger.ErrorContext(r.Context(), "panic", "error", rvr, "stack", stack)
                    }

                    if r.Header.Get("Connection") != "Upgrade" {
                        w.WriteHeader(http.StatusInternalServerError)
                    }
                }
            }()

            next.ServeHTTP(w, r)
        })
    }
}

With custom log entry only

router.Use(middleware.RequestLogger(&customLogFormatter{Logger: logger}))
router.Use(middleware.Recoverer)

type customLogFormatter struct {
    Logger *slog.Logger
}

func (f *customLogFormatter) NewLogEntry(r *http.Request) middleware.LogEntry {
    return &customLogEntry{Logger: f.Logger}
}

type customLogEntry struct {
    Logger *slog.Logger
}

func (e *customLogEntry) Write(status, bytes int, header http.Header, elapsed time.Duration, extra interface{}) {
    // no op, gcp logs the request automatically & we don't need to do anything fancy for now (trace ids, etc)
}

func (e *customLogEntry) Panic(v interface{}, stack []byte) {
    e.Logger.Error("panic", "error", v, "stack", string(stack))
}
VojtechVitek commented 2 months ago

Hi @williamhjcho,

Please have a look at https://github.com/golang-cz/httplog, which has native support for slog and has explicit Recover: true option where you can either re-panic or not.

We're planning to release it as github.com/go-chi/httplog@v3 soon. Feedback welcome :)