From 4e2e789cb744a7ab894034289b09e0b80dd5a75f Mon Sep 17 00:00:00 2001 From: Paul Abel <128620221+pdabelf5@users.noreply.github.com> Date: Thu, 26 Sep 2024 10:16:31 +0100 Subject: [PATCH] Slog handler (#6474) --- internal/logger/glog/handler.go | 129 +++++++++++++++++++++++++++ internal/logger/glog/handler_test.go | 93 +++++++++++++++++++ internal/logger/logger.go | 24 +++++ 3 files changed, 246 insertions(+) create mode 100644 internal/logger/glog/handler.go create mode 100644 internal/logger/glog/handler_test.go create mode 100644 internal/logger/logger.go diff --git a/internal/logger/glog/handler.go b/internal/logger/glog/handler.go new file mode 100644 index 0000000000..335310e403 --- /dev/null +++ b/internal/logger/glog/handler.go @@ -0,0 +1,129 @@ +package glog + +// Custom log levels https://go.dev/src/log/slog/example_custom_levels_test.go - for fatal & trace + +import ( + "context" + "io" + "log/slog" + "os" + "runtime" + "strconv" + "strings" + "sync" +) + +const ( + // LevelTrace - Trace Level Logging same as glog.V(3) + LevelTrace = slog.Level(-8) + // LevelDebug - Debug Level Logging same as glog.V(2) + LevelDebug = slog.LevelDebug + // LevelInfo - Info Level Logging same as glog.Info() + LevelInfo = slog.LevelInfo + // LevelWarning - Warn Level Logging same as glog.Warning() + LevelWarning = slog.LevelWarn + // LevelError - Error Level Logging same as glog.Error() + LevelError = slog.LevelError + // LevelFatal - Fatal Level Logging same as glog.Fatal() + LevelFatal = slog.Level(12) +) + +// Handler holds all the parameters for the handler +type Handler struct { + opts Options + mu *sync.Mutex + out io.Writer +} + +// Options contains the log Level +type Options struct { + // Level reports the minimum level to log. + // Levels with lower levels are discarded. + // If nil, the Handler uses [slog.LevelInfo]. + Level slog.Leveler +} + +// New - create a new Handler +func New(out io.Writer, opts *Options) *Handler { + h := &Handler{out: out, mu: &sync.Mutex{}} + if opts != nil { + h.opts = *opts + } + if h.opts.Level == nil { + h.opts.Level = slog.LevelInfo + } + return h +} + +// Enabled - is this log level enabled? +func (h *Handler) Enabled(_ context.Context, level slog.Level) bool { + return level >= h.opts.Level.Level() +} + +// WithGroup - not needed +func (h *Handler) WithGroup(_ string) slog.Handler { + // not needed. + return h +} + +// WithAttrs - not needed +func (h *Handler) WithAttrs(_ []slog.Attr) slog.Handler { + // not needed. + return h +} + +// Handle log event +// Format F20240920 16:53:18.817844 70741 main.go:285] message +// +// YYYYMMDD HH:MM:SS.NNNNNN : +func (h *Handler) Handle(_ context.Context, r slog.Record) error { + buf := make([]byte, 0, 1024) + // LogLevel + switch r.Level { + case LevelTrace: + buf = append(buf, "I"...) + case LevelDebug: + buf = append(buf, "I"...) + case LevelInfo: + buf = append(buf, "I"...) + case LevelWarning: + buf = append(buf, "W"...) + case LevelError: + buf = append(buf, "E"...) + case LevelFatal: + buf = append(buf, "F"...) + } + + // date/time + if !r.Time.IsZero() { + buf = append(buf, r.Time.Format("20060102 15:04:05.000000")...) + } + + buf = append(buf, " "...) + + // PID + buf = append(buf, strconv.Itoa(os.Getpid())...) + + buf = append(buf, " "...) + // Log line + if r.PC != 0 { + fs := runtime.CallersFrames([]uintptr{r.PC}) + f, _ := fs.Next() + buf = append(buf, getShortFileName(f.File)...) + buf = append(buf, ":"...) + buf = append(buf, strconv.Itoa(f.Line)...) + } + buf = append(buf, "]"...) + buf = append(buf, " "...) + buf = append(buf, r.Message...) + buf = append(buf, "\n"...) + h.mu.Lock() + defer h.mu.Unlock() + _, err := h.out.Write(buf) + return err +} + +func getShortFileName(f string) string { + fp := strings.Split(f, "/") + return fp[len(fp)-1] +} diff --git a/internal/logger/glog/handler_test.go b/internal/logger/glog/handler_test.go new file mode 100644 index 0000000000..ef99f00092 --- /dev/null +++ b/internal/logger/glog/handler_test.go @@ -0,0 +1,93 @@ +package glog + +import ( + "bytes" + "context" + "log/slog" + "regexp" + "testing" +) + +func TestGlogFormat(t *testing.T) { + var buf bytes.Buffer + l := slog.New(New(&buf, nil)) + l.Info("hello") + got := buf.String() + wantre := `^\w\d{8}\s\d+:\d+:\d+.\d{6}\s+\d+\s\w+\.go:\d+\]\s.*\s$` + re := regexp.MustCompile(wantre) + if !re.MatchString(got) { + t.Errorf("\ngot:\n%q\nwant:\n%q", got, wantre) + } +} + +func TestGlogLogLevels(t *testing.T) { + testCases := []struct { + name string + level slog.Level + wantre string + }{ + { + name: "Trace level log message", + level: LevelTrace, + wantre: `^I\d{8}\s\d+:\d+:\d+.\d{6}\s+\d+\s\w+\.go:\d+\]\s.*\s$`, + }, + { + name: "Debug level log message", + level: LevelDebug, + wantre: `^I\d{8}\s\d+:\d+:\d+.\d{6}\s+\d+\s\w+\.go:\d+\]\s.*\s$`, + }, + { + name: "Info level log message", + level: LevelInfo, + wantre: `^I\d{8}\s\d+:\d+:\d+.\d{6}\s+\d+\s\w+\.go:\d+\]\s.*\s$`, + }, + { + name: "Warning level log message", + level: LevelWarning, + wantre: `^W\d{8}\s\d+:\d+:\d+.\d{6}\s+\d+\s\w+\.go:\d+\]\s.*\s$`, + }, + { + name: "Error level log message", + level: LevelError, + wantre: `^E\d{8}\s\d+:\d+:\d+.\d{6}\s+\d+\s\w+\.go:\d+\]\s.*\s$`, + }, + { + name: "Fatal level log message", + level: LevelFatal, + wantre: `^F\d{8}\s\d+:\d+:\d+.\d{6}\s+\d+\s\w+\.go:\d+\]\s.*\s$`, + }, + } + t.Parallel() + for _, tc := range testCases { + t.Run(tc.name, func(t *testing.T) { + var buf bytes.Buffer + l := slog.New(New(&buf, &Options{Level: tc.level})) + l.Log(context.Background(), tc.level, "test") + got := buf.String() + re := regexp.MustCompile(tc.wantre) + if !re.MatchString(got) { + t.Errorf("\ngot:\n%q\nwant:\n%q", got, tc.wantre) + } + }) + } +} + +func TestGlogDefaultLevel(t *testing.T) { + var buf bytes.Buffer + l := slog.New(New(&buf, nil)) + + l.Debug("test") + if got := buf.Len(); got != 0 { + t.Errorf("got buf.Len() = %d, want 0", got) + } +} + +func TestGlogHigherLevel(t *testing.T) { + var buf bytes.Buffer + l := slog.New(New(&buf, &Options{Level: LevelError})) + + l.Info("test") + if got := buf.Len(); got != 0 { + t.Errorf("got buf.Len() = %d, want 0", got) + } +} diff --git a/internal/logger/logger.go b/internal/logger/logger.go new file mode 100644 index 0000000000..a20f59b2c9 --- /dev/null +++ b/internal/logger/logger.go @@ -0,0 +1,24 @@ +package log + +import ( + "context" + "log/slog" + "os" + + "github.com/nginxinc/kubernetes-ingress/internal/logger/glog" +) + +type ctxLogger struct{} + +// ContextWithLogger adds logger to context +func ContextWithLogger(ctx context.Context, l *slog.Logger) context.Context { + return context.WithValue(ctx, ctxLogger{}, l) +} + +// LoggerFromContext returns logger from context +func LoggerFromContext(ctx context.Context) *slog.Logger { + if l, ok := ctx.Value(ctxLogger{}).(*slog.Logger); ok { + return l + } + return slog.New(glog.New(os.Stdout, nil)) +}