From 99133fa958baeda67a3eb22ee2adaf8bd2a90ddd Mon Sep 17 00:00:00 2001 From: Brady Briggs Date: Fri, 16 Dec 2022 23:26:52 -0800 Subject: [PATCH 1/3] Update logging example to use preview version of new log/slog --- _examples/logging/main.go | 121 +++++++++++++++++++------------------- 1 file changed, 62 insertions(+), 59 deletions(-) diff --git a/_examples/logging/main.go b/_examples/logging/main.go index f756ad00..451166b4 100644 --- a/_examples/logging/main.go +++ b/_examples/logging/main.go @@ -1,41 +1,42 @@ -// // Custom Structured Logger // ======================== // This example demonstrates how to use middleware.RequestLogger, // middleware.LogFormatter and middleware.LogEntry to build a structured -// logger using the amazing sirupsen/logrus package as the logging +// logger using the preview version of the new log/slog package as the logging // backend. // // Also: check out https://github.com/goware/httplog for an improved context // logger with support for HTTP request logging, based on the example below. -// package main import ( "fmt" "net/http" + "os" "time" + "golang.org/x/exp/slog" + "github.com/go-chi/chi/v5" "github.com/go-chi/chi/v5/middleware" - "github.com/sirupsen/logrus" ) func main() { - - // Setup the logger backend using sirupsen/logrus and configure - // it to use a custom JSONFormatter. See the logrus docs for how to - // configure the backend at github.com/sirupsen/logrus - logger := logrus.New() - logger.Formatter = &logrus.JSONFormatter{ - // disable, as we set our own - DisableTimestamp: true, - } + // Setup a JSON handler for the new log/slog library + slogJSONHandler := slog.HandlerOptions{ + // Remove default time slog.Attr, we create our own later + ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr { + if a.Key == slog.TimeKey { + return slog.Attr{} + } + return a + }, + }.NewJSONHandler(os.Stdout) // Routes r := chi.NewRouter() r.Use(middleware.RequestID) - r.Use(NewStructuredLogger(logger)) + r.Use(NewStructuredLoggerMiddleware(slogJSONHandler)) r.Use(middleware.Recoverer) r.Get("/", func(w http.ResponseWriter, r *http.Request) { @@ -43,76 +44,76 @@ func main() { }) r.Get("/wait", func(w http.ResponseWriter, r *http.Request) { time.Sleep(1 * time.Second) - LogEntrySetField(r, "wait", true) + StructuredLogEntrySetField(r, "wait", true) w.Write([]byte("hi")) }) r.Get("/panic", func(w http.ResponseWriter, r *http.Request) { panic("oops") }) + r.Get("/add_fields", func(w http.ResponseWriter, r *http.Request) { + StructuredLogEntrySetFields(r, map[string]interface{}{"foo": "bar", "bar": "foo"}) + }) http.ListenAndServe(":3333", r) } -// StructuredLogger is a simple, but powerful implementation of a custom structured -// logger backed on logrus. I encourage users to copy it, adapt it and make it their +// StructuredLogHandler is a simple, but powerful implementation of a custom structured +// logger backed on log/slog. I encourage users to copy it, adapt it and make it their // own. Also take a look at https://github.com/go-chi/httplog for a dedicated pkg based // on this work, designed for context-based http routers. -func NewStructuredLogger(logger *logrus.Logger) func(next http.Handler) http.Handler { - return middleware.RequestLogger(&StructuredLogger{logger}) +func NewStructuredLoggerMiddleware(handler slog.Handler) func(next http.Handler) http.Handler { + return middleware.RequestLogger(&StructuredLogHandler{Handler: handler}) } -type StructuredLogger struct { - Logger *logrus.Logger +type StructuredLogHandler struct { + Handler slog.Handler } -func (l *StructuredLogger) NewLogEntry(r *http.Request) middleware.LogEntry { - entry := &StructuredLoggerEntry{Logger: logrus.NewEntry(l.Logger)} - logFields := logrus.Fields{} - - logFields["ts"] = time.Now().UTC().Format(time.RFC1123) +func (l *StructuredLogHandler) NewLogEntry(r *http.Request) middleware.LogEntry { + var slogAttrs []slog.Attr + slogAttrs = append(slogAttrs, slog.String("ts", time.Now().UTC().Format(time.RFC1123))) if reqID := middleware.GetReqID(r.Context()); reqID != "" { - logFields["req_id"] = reqID + slogAttrs = append(slogAttrs, slog.String("req_id", reqID)) } scheme := "http" if r.TLS != nil { scheme = "https" } - logFields["http_scheme"] = scheme - logFields["http_proto"] = r.Proto - logFields["http_method"] = r.Method - - logFields["remote_addr"] = r.RemoteAddr - logFields["user_agent"] = r.UserAgent() - logFields["uri"] = fmt.Sprintf("%s://%s%s", scheme, r.Host, r.RequestURI) + handler := l.Handler.WithAttrs(append(slogAttrs, + slog.String("http_scheme", scheme), + slog.String("http_proto", r.Proto), + slog.String("http_method", r.Method), + slog.String("remote_addr", r.RemoteAddr), + slog.String("user_agent", r.UserAgent()), + slog.String("uri", fmt.Sprintf("%s://%s%s", scheme, r.Host, r.RequestURI)))) - entry.Logger = entry.Logger.WithFields(logFields) + entry := StructuredLogEntry{Logger: slog.New(handler)} - entry.Logger.Infoln("request started") + entry.Logger.LogAttrs(slog.LevelInfo, "request started", slogAttrs...) - return entry + return &entry } -type StructuredLoggerEntry struct { - Logger logrus.FieldLogger +type StructuredLogEntry struct { + Logger *slog.Logger } -func (l *StructuredLoggerEntry) Write(status, bytes int, header http.Header, elapsed time.Duration, extra interface{}) { - l.Logger = l.Logger.WithFields(logrus.Fields{ - "resp_status": status, "resp_bytes_length": bytes, - "resp_elapsed_ms": float64(elapsed.Nanoseconds()) / 1000000.0, - }) - - l.Logger.Infoln("request complete") +func (l *StructuredLogEntry) Write(status, bytes int, header http.Header, elapsed time.Duration, extra interface{}) { + l.Logger.LogAttrs(slog.LevelInfo, "request complete", + slog.Int("resp_status", status), + slog.Int("resp_byte_length", bytes), + slog.Float64("resp_elapsed_ms", float64(elapsed.Nanoseconds())/1000000.0), + ) } -func (l *StructuredLoggerEntry) Panic(v interface{}, stack []byte) { - l.Logger = l.Logger.WithFields(logrus.Fields{ - "stack": string(stack), - "panic": fmt.Sprintf("%+v", v), - }) +func (l *StructuredLogEntry) Panic(v interface{}, stack []byte) { + l.Logger.LogAttrs(slog.LevelInfo, "", + slog.String("stack", string(stack)), + slog.String("panic", fmt.Sprintf("%+v", v)), + ) } // Helper methods used by the application to get the request-scoped @@ -122,19 +123,21 @@ func (l *StructuredLoggerEntry) Panic(v interface{}, stack []byte) { // passes through the handler chain, which at any point can be logged // with a call to .Print(), .Info(), etc. -func GetLogEntry(r *http.Request) logrus.FieldLogger { - entry := middleware.GetLogEntry(r).(*StructuredLoggerEntry) +func GetStructuredLogEntry(r *http.Request) *slog.Logger { + entry := middleware.GetLogEntry(r).(*StructuredLogEntry) return entry.Logger } -func LogEntrySetField(r *http.Request, key string, value interface{}) { - if entry, ok := r.Context().Value(middleware.LogEntryCtxKey).(*StructuredLoggerEntry); ok { - entry.Logger = entry.Logger.WithField(key, value) +func StructuredLogEntrySetField(r *http.Request, key string, value interface{}) { + if entry, ok := r.Context().Value(middleware.LogEntryCtxKey).(*StructuredLogEntry); ok { + entry.Logger = entry.Logger.With(key, value) } } -func LogEntrySetFields(r *http.Request, fields map[string]interface{}) { - if entry, ok := r.Context().Value(middleware.LogEntryCtxKey).(*StructuredLoggerEntry); ok { - entry.Logger = entry.Logger.WithFields(fields) +func StructuredLogEntrySetFields(r *http.Request, fields map[string]interface{}) { + if entry, ok := r.Context().Value(middleware.LogEntryCtxKey).(*StructuredLogEntry); ok { + for k, v := range fields { + entry.Logger = entry.Logger.With(k, v) + } } } From a58ae6533946c9db857d279964aecf935997db6e Mon Sep 17 00:00:00 2001 From: Brady Briggs Date: Mon, 19 Dec 2022 21:16:00 -0800 Subject: [PATCH 2/3] Revert name changes --- _examples/logging/main.go | 38 +++++++++++++++++++------------------- 1 file changed, 19 insertions(+), 19 deletions(-) diff --git a/_examples/logging/main.go b/_examples/logging/main.go index 451166b4..a63fe759 100644 --- a/_examples/logging/main.go +++ b/_examples/logging/main.go @@ -36,7 +36,7 @@ func main() { // Routes r := chi.NewRouter() r.Use(middleware.RequestID) - r.Use(NewStructuredLoggerMiddleware(slogJSONHandler)) + r.Use(NewStructuredLogger(slogJSONHandler)) r.Use(middleware.Recoverer) r.Get("/", func(w http.ResponseWriter, r *http.Request) { @@ -56,25 +56,25 @@ func main() { http.ListenAndServe(":3333", r) } -// StructuredLogHandler is a simple, but powerful implementation of a custom structured +// StructuredLogger is a simple, but powerful implementation of a custom structured // logger backed on log/slog. I encourage users to copy it, adapt it and make it their // own. Also take a look at https://github.com/go-chi/httplog for a dedicated pkg based // on this work, designed for context-based http routers. -func NewStructuredLoggerMiddleware(handler slog.Handler) func(next http.Handler) http.Handler { - return middleware.RequestLogger(&StructuredLogHandler{Handler: handler}) +func NewStructuredLogger(handler slog.Handler) func(next http.Handler) http.Handler { + return middleware.RequestLogger(&StructuredLogger{Logger: handler}) } -type StructuredLogHandler struct { - Handler slog.Handler +type StructuredLogger struct { + Logger slog.Handler } -func (l *StructuredLogHandler) NewLogEntry(r *http.Request) middleware.LogEntry { - var slogAttrs []slog.Attr - slogAttrs = append(slogAttrs, slog.String("ts", time.Now().UTC().Format(time.RFC1123))) +func (l *StructuredLogger) NewLogEntry(r *http.Request) middleware.LogEntry { + var logFields []slog.Attr + logFields = append(logFields, slog.String("ts", time.Now().UTC().Format(time.RFC1123))) if reqID := middleware.GetReqID(r.Context()); reqID != "" { - slogAttrs = append(slogAttrs, slog.String("req_id", reqID)) + logFields = append(logFields, slog.String("req_id", reqID)) } scheme := "http" @@ -82,7 +82,7 @@ func (l *StructuredLogHandler) NewLogEntry(r *http.Request) middleware.LogEntry scheme = "https" } - handler := l.Handler.WithAttrs(append(slogAttrs, + handler := l.Logger.WithAttrs(append(logFields, slog.String("http_scheme", scheme), slog.String("http_proto", r.Proto), slog.String("http_method", r.Method), @@ -90,18 +90,18 @@ func (l *StructuredLogHandler) NewLogEntry(r *http.Request) middleware.LogEntry slog.String("user_agent", r.UserAgent()), slog.String("uri", fmt.Sprintf("%s://%s%s", scheme, r.Host, r.RequestURI)))) - entry := StructuredLogEntry{Logger: slog.New(handler)} + entry := StructuredLoggerEntry{Logger: slog.New(handler)} - entry.Logger.LogAttrs(slog.LevelInfo, "request started", slogAttrs...) + entry.Logger.LogAttrs(slog.LevelInfo, "request started", logFields...) return &entry } -type StructuredLogEntry struct { +type StructuredLoggerEntry struct { Logger *slog.Logger } -func (l *StructuredLogEntry) Write(status, bytes int, header http.Header, elapsed time.Duration, extra interface{}) { +func (l *StructuredLoggerEntry) Write(status, bytes int, header http.Header, elapsed time.Duration, extra interface{}) { l.Logger.LogAttrs(slog.LevelInfo, "request complete", slog.Int("resp_status", status), slog.Int("resp_byte_length", bytes), @@ -109,7 +109,7 @@ func (l *StructuredLogEntry) Write(status, bytes int, header http.Header, elapse ) } -func (l *StructuredLogEntry) Panic(v interface{}, stack []byte) { +func (l *StructuredLoggerEntry) Panic(v interface{}, stack []byte) { l.Logger.LogAttrs(slog.LevelInfo, "", slog.String("stack", string(stack)), slog.String("panic", fmt.Sprintf("%+v", v)), @@ -124,18 +124,18 @@ func (l *StructuredLogEntry) Panic(v interface{}, stack []byte) { // with a call to .Print(), .Info(), etc. func GetStructuredLogEntry(r *http.Request) *slog.Logger { - entry := middleware.GetLogEntry(r).(*StructuredLogEntry) + entry := middleware.GetLogEntry(r).(*StructuredLoggerEntry) return entry.Logger } func StructuredLogEntrySetField(r *http.Request, key string, value interface{}) { - if entry, ok := r.Context().Value(middleware.LogEntryCtxKey).(*StructuredLogEntry); ok { + if entry, ok := r.Context().Value(middleware.LogEntryCtxKey).(*StructuredLoggerEntry); ok { entry.Logger = entry.Logger.With(key, value) } } func StructuredLogEntrySetFields(r *http.Request, fields map[string]interface{}) { - if entry, ok := r.Context().Value(middleware.LogEntryCtxKey).(*StructuredLogEntry); ok { + if entry, ok := r.Context().Value(middleware.LogEntryCtxKey).(*StructuredLoggerEntry); ok { for k, v := range fields { entry.Logger = entry.Logger.With(k, v) } From 51491aba5013b5ccc737b96b9cb09ba978a2edff Mon Sep 17 00:00:00 2001 From: Brady Briggs Date: Mon, 19 Dec 2022 21:20:37 -0800 Subject: [PATCH 3/3] Revert name changes --- _examples/logging/main.go | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/_examples/logging/main.go b/_examples/logging/main.go index a63fe759..233885d8 100644 --- a/_examples/logging/main.go +++ b/_examples/logging/main.go @@ -44,14 +44,14 @@ func main() { }) r.Get("/wait", func(w http.ResponseWriter, r *http.Request) { time.Sleep(1 * time.Second) - StructuredLogEntrySetField(r, "wait", true) + LogEntrySetField(r, "wait", true) w.Write([]byte("hi")) }) r.Get("/panic", func(w http.ResponseWriter, r *http.Request) { panic("oops") }) r.Get("/add_fields", func(w http.ResponseWriter, r *http.Request) { - StructuredLogEntrySetFields(r, map[string]interface{}{"foo": "bar", "bar": "foo"}) + LogEntrySetFields(r, map[string]interface{}{"foo": "bar", "bar": "foo"}) }) http.ListenAndServe(":3333", r) } @@ -123,18 +123,18 @@ func (l *StructuredLoggerEntry) Panic(v interface{}, stack []byte) { // passes through the handler chain, which at any point can be logged // with a call to .Print(), .Info(), etc. -func GetStructuredLogEntry(r *http.Request) *slog.Logger { +func GetLogEntry(r *http.Request) *slog.Logger { entry := middleware.GetLogEntry(r).(*StructuredLoggerEntry) return entry.Logger } -func StructuredLogEntrySetField(r *http.Request, key string, value interface{}) { +func LogEntrySetField(r *http.Request, key string, value interface{}) { if entry, ok := r.Context().Value(middleware.LogEntryCtxKey).(*StructuredLoggerEntry); ok { entry.Logger = entry.Logger.With(key, value) } } -func StructuredLogEntrySetFields(r *http.Request, fields map[string]interface{}) { +func LogEntrySetFields(r *http.Request, fields map[string]interface{}) { if entry, ok := r.Context().Value(middleware.LogEntryCtxKey).(*StructuredLoggerEntry); ok { for k, v := range fields { entry.Logger = entry.Logger.With(k, v)