From c2d25577042e43bee24e180e47a96e3a7b238b8c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Miroslav=20=C5=A0ediv=C3=BD?= Date: Fri, 17 Sep 2021 20:20:10 +0200 Subject: [PATCH] http logger add panic. --- internal/http/logger.go | 100 ++++++++++++++++++++-------------------- internal/http/router.go | 4 +- 2 files changed, 53 insertions(+), 51 deletions(-) diff --git a/internal/http/logger.go b/internal/http/logger.go index 9460f3b2..0f093ef0 100644 --- a/internal/http/logger.go +++ b/internal/http/logger.go @@ -17,11 +17,10 @@ type logFormatter struct { } func (l *logFormatter) NewLogEntry(r *http.Request) middleware.LogEntry { - e := logEntry{logger: l.logger} - e.req.Time = time.Now() + req := map[string]interface{}{} if reqID := middleware.GetReqID(r.Context()); reqID != "" { - e.req.Id = reqID + req["id"] = reqID } scheme := "http" @@ -29,37 +28,38 @@ func (l *logFormatter) NewLogEntry(r *http.Request) middleware.LogEntry { scheme = "https" } - e.req.Scheme = scheme - e.req.Proto = r.Proto - e.req.Method = r.Method - e.req.Remote = r.RemoteAddr - e.req.Agent = r.UserAgent() - e.req.Uri = fmt.Sprintf("%s://%s%s", scheme, r.Host, r.RequestURI) - return &e + req["scheme"] = scheme + req["proto"] = r.Proto + req["method"] = r.Method + req["remote"] = r.RemoteAddr + req["agent"] = r.UserAgent() + req["uri"] = fmt.Sprintf("%s://%s%s", scheme, r.Host, r.RequestURI) + + return &logEntry{ + logger: l.logger.With().Interface("req", req).Logger(), + } } type logEntry struct { - req struct { - Time time.Time - Id string - Scheme string - Proto string - Method string - Remote string - Agent string - Uri string - } - res struct { - Time time.Time - Code int - Bytes int - } - err error - session *types.Session logger zerolog.Logger + err error + panic *logPanic + session *types.Session } -func (e *logEntry) SetError(err error) { +type logPanic struct { + message string + stack string +} + +func (e *logEntry) Panic(v interface{}, stack []byte) { + e.panic = &logPanic{ + message: fmt.Sprintf("%+v", v), + stack: string(stack), + } +} + +func (e *logEntry) Error(err error) { e.err = err } @@ -68,24 +68,33 @@ func (e *logEntry) SetSession(session types.Session) { } func (e *logEntry) Write(status, bytes int, header http.Header, elapsed time.Duration, extra interface{}) { - e.res.Time = time.Now() - e.res.Code = status - e.res.Bytes = bytes + res := map[string]interface{}{} + res["time"] = time.Now().UTC().Format(time.RFC1123) + res["status"] = status + res["bytes"] = bytes + res["elapsed"] = float64(elapsed.Nanoseconds()) / 1000000.0 - logger := e.logger.With(). - Float64("elapsed", float64(elapsed.Nanoseconds())/1000000.0). - Interface("req", e.req). - Interface("res", e.res). - Logger() + logger := e.logger.With().Interface("res", res).Logger() + // add session ID to logs (if exists) if e.session != nil { logger = logger.With().Str("session_id", (*e.session).ID()).Logger() } + // handle panic error message + if e.panic != nil { + logger.WithLevel(zerolog.PanicLevel). + Err(e.err). + Str("stack", e.panic.stack). + Msgf("request failed (%d): %s", status, e.panic.message) + return + } + + // handle panic error message if e.err != nil { httpErr, ok := e.err.(*utils.HTTPError) if !ok { - logger.Err(e.err).Msgf("request failed (%d)", e.res.Code) + logger.Err(e.err).Msgf("request failed (%d)", status) return } @@ -93,11 +102,11 @@ func (e *logEntry) Write(status, bytes int, header http.Header, elapsed time.Dur httpErr.Message = http.StatusText(httpErr.Code) } - var logEvent *zerolog.Event + var logLevel zerolog.Level if httpErr.Code < 500 { - logEvent = logger.Warn() + logLevel = zerolog.WarnLevel } else { - logEvent = logger.Error() + logLevel = zerolog.ErrorLevel } message := httpErr.Message @@ -105,16 +114,9 @@ func (e *logEntry) Write(status, bytes int, header http.Header, elapsed time.Dur message = httpErr.InternalMsg } - logEvent.Err(httpErr.InternalErr).Msgf("request failed (%d): %s", e.res.Code, message) + logger.WithLevel(logLevel).Err(httpErr.InternalErr).Msgf("request failed (%d): %s", status, message) return } - logger.Debug().Msgf("request complete (%d)", e.res.Code) -} - -func (e *logEntry) Panic(v interface{}, stack []byte) { - e.logger.WithLevel(zerolog.PanicLevel). - Interface("req", e.req). - Str("stack", string(stack)). - Msgf("request panic (500): %+v", v) + logger.Debug().Msgf("request complete (%d)", status) } diff --git a/internal/http/router.go b/internal/http/router.go index 0e645537..20e4f03c 100644 --- a/internal/http/router.go +++ b/internal/http/router.go @@ -85,7 +85,7 @@ func routeHandler(fn types.RouterHandler) http.HandlerFunc { logEntry, _ := r.Context().Value(middleware.LogEntryCtxKey).(*logEntry) if err := fn(w, r); err != nil { - logEntry.SetError(err) + logEntry.Error(err) errorHandler(err, w, r) } @@ -104,7 +104,7 @@ func middlewareHandler(fn types.MiddlewareHandler) func(http.Handler) http.Handl ctx, err := fn(w, r) if err != nil { - logEntry.SetError(err) + logEntry.Error(err) errorHandler(err, w, r) // set session if exits