From 4384b864c6d4629ab7b401b4d010c6f8be59c01d Mon Sep 17 00:00:00 2001 From: Sergio Salvatore Date: Wed, 23 Oct 2024 14:42:02 -0400 Subject: [PATCH] Minimum Log Levels In the case of leveled logging, allow the user to set a minimum log level via the leveled.FilteredLogger type or through the gkelog.WithMinSeverity function which pipes it through the context. This allows us to suppress logs that are lower than the minimum level. --- emitter/gkelog/emitter.go | 19 ++++++---- emitter/gkelog/emitter_test.go | 15 ++++++++ emitter/gkelog/severity.go | 23 +++++++++++-- leveled/level_string.go | 27 +++++++++++++++ leveled/logger.go | 63 ++++++++++++++++++++++++++++------ leveled/logger_test.go | 15 ++++++++ 6 files changed, 144 insertions(+), 18 deletions(-) create mode 100644 leveled/level_string.go diff --git a/emitter/gkelog/emitter.go b/emitter/gkelog/emitter.go index 45a06c6..00e3afb 100644 --- a/emitter/gkelog/emitter.go +++ b/emitter/gkelog/emitter.go @@ -22,12 +22,13 @@ var DefaultLogger = alog.New(alog.WithEmitter(Emitter())) type contextKey string var ( - severityKey = contextKey("severity") - requestKey = contextKey("request") - statusKey = contextKey("status") - latencyKey = contextKey("latency") - traceKey = contextKey("trace") - spanKey = contextKey("span") + severityKey = contextKey("severity") + minSeverityKey = contextKey("minSeverity") + requestKey = contextKey("request") + statusKey = contextKey("status") + latencyKey = contextKey("latency") + traceKey = contextKey("trace") + spanKey = contextKey("span") ) // WithSeverity returns a copy of parent with the specified severity value. @@ -35,6 +36,12 @@ func WithSeverity(parent context.Context, severity string) context.Context { return context.WithValue(parent, severityKey, severity) } +// WithMinSeverity sets the minimum severity to log. Use one of the Severity* +// constants. +func WithMinSeverity(parent context.Context, severity string) context.Context { + return context.WithValue(parent, minSeverityKey, severity) +} + // WithRequest returns a copy of parent with the specified http.Request value. // It also calls WithRequestTrace to add trace information to the context. func WithRequest(parent context.Context, req *http.Request) context.Context { diff --git a/emitter/gkelog/emitter_test.go b/emitter/gkelog/emitter_test.go index 1e64562..8bc7f2c 100644 --- a/emitter/gkelog/emitter_test.go +++ b/emitter/gkelog/emitter_test.go @@ -108,6 +108,21 @@ func TestLogSeverity(t *testing.T) { } } +func TestMinLogSeverity(t *testing.T) { + b := &bytes.Buffer{} + ctx := WithMinSeverity(context.Background(), SeverityWarning) + l := alog.New(alog.WithEmitter(Emitter(WithWriter(b))), zeroTimeOpt) + + LogInfo(ctx, l, "NOT LOGGED") // because Info is lower than Warning + LogError(ctx, l, "LOGGED") + + want := `{"time":"0001-01-01T00:00:00Z", "severity":"ERROR", "message":"LOGGED"}` + "\n" + got := b.String() + if got != want { + t.Errorf("got:\n%s\nwant:\n%s", got, want) + } +} + func TestRequest(t *testing.T) { b := &bytes.Buffer{} ctx := context.Background() diff --git a/emitter/gkelog/severity.go b/emitter/gkelog/severity.go index 98cfd0a..e497db5 100644 --- a/emitter/gkelog/severity.go +++ b/emitter/gkelog/severity.go @@ -21,13 +21,32 @@ const ( SeverityEmergency = "EMERGENCY" // One or more systems are unusable. ) +// the priority of each severity level +var severityPriority map[string]uint8 = map[string]uint8{ + SeverityDebug: 0, + SeverityInfo: 1, + SeverityNotice: 2, + SeverityWarning: 3, + SeverityError: 4, + SeverityCritical: 5, + SeverityAlert: 6, + SeverityEmergency: 7, + SeverityDefault: 8, // default will almost always log and should probably not be used +} + // Separate private function so that LogSeverity and the other logs functions // will have the same stack frame depth and thus use the same calldepth value. // See https://golang.org/pkg/runtime/#Caller and // https://godoc.org/github.com/vimeo/alog#Logger.Output func logSeverity(ctx context.Context, logger *alog.Logger, s string, f string, v ...interface{}) { - ctx = WithSeverity(ctx, s) - logger.Output(ctx, 3, fmt.Sprintf(f, v...)) + minSeverity := uint8(0) + if minSeverityVal := ctx.Value(minSeverityKey); minSeverityVal != nil { + minSeverity = severityPriority[minSeverityVal.(string)] + } + if severityPriority[s] >= minSeverity { + ctx = WithSeverity(ctx, s) + logger.Output(ctx, 3, fmt.Sprintf(f, v...)) + } } // LogSeverity writes a log entry using the specified severity diff --git a/leveled/level_string.go b/leveled/level_string.go new file mode 100644 index 0000000..6b4461d --- /dev/null +++ b/leveled/level_string.go @@ -0,0 +1,27 @@ +// Code generated by "stringer -type Level -linecomment"; DO NOT EDIT. + +package leveled + +import "strconv" + +func _() { + // An "invalid array index" compiler error signifies that the constant values have changed. + // Re-run the stringer command to generate them again. + var x [1]struct{} + _ = x[Debug-0] + _ = x[Info-1] + _ = x[Warning-2] + _ = x[Error-3] + _ = x[Critical-4] +} + +const _Level_name = "debuginfowarningerrorcritical" + +var _Level_index = [...]uint8{0, 5, 9, 16, 21, 29} + +func (i Level) String() string { + if i >= Level(len(_Level_index)-1) { + return "Level(" + strconv.FormatInt(int64(i), 10) + ")" + } + return _Level_name[_Level_index[i]:_Level_index[i+1]] +} diff --git a/leveled/logger.go b/leveled/logger.go index 474f66b..9caa72e 100644 --- a/leveled/logger.go +++ b/leveled/logger.go @@ -7,6 +7,20 @@ import ( "github.com/vimeo/alog/v3" ) +// Level represents the severity of a log message. +type Level uint8 + +const ( + Debug Level = iota // debug + Info // info + Warning // warning + Error // error + Critical // critical +) + +// LevelKey is the tag key associated with a level. +const LevelKey = "level" + // Logger is an interface that implements logging functions for different levels of severity. type Logger interface { // Debug logs debugging or trace information. @@ -25,8 +39,20 @@ type Logger interface { Critical(ctx context.Context, f string, v ...interface{}) } +// FilteredLogger amends the Logger interface with a Log method that accepts the +// level to log at. +type FilteredLogger interface { + Logger + Log(ctx context.Context, level Level, f string, v ...interface{}) + SetMinLevel(level Level) +} + type defaultLogger struct { *alog.Logger + + // Indicates the minimum level to log at. If MinLevel is greater than the + // level of a given log message, the log message will be suppressed. + MinLevel Level } // Default returns a Logger that wraps the provided `alog.Logger`. @@ -39,32 +65,49 @@ func Default(logger *alog.Logger) Logger { } } +// Filtered returns a logger that allows for setting the minimum level. +func Filtered(logger *alog.Logger) FilteredLogger { + return &defaultLogger{ + Logger: logger, + } +} + // Debug implements Logger.Debug func (d *defaultLogger) Debug(ctx context.Context, f string, v ...interface{}) { - ctx = alog.AddTags(ctx, "level", "debug") - d.Logger.Output(ctx, 3, fmt.Sprintf(f, v...)) + d.Log(ctx, Debug, f, v...) } // Info implements Logger.Info func (d *defaultLogger) Info(ctx context.Context, f string, v ...interface{}) { - ctx = alog.AddTags(ctx, "level", "info") - d.Logger.Output(ctx, 3, fmt.Sprintf(f, v...)) + d.Log(ctx, Info, f, v...) } // Warning implements Logger.Warning func (d *defaultLogger) Warning(ctx context.Context, f string, v ...interface{}) { - ctx = alog.AddTags(ctx, "level", "warning") - d.Logger.Output(ctx, 3, fmt.Sprintf(f, v...)) + d.Log(ctx, Warning, f, v...) } // Error implements Logger.Error func (d *defaultLogger) Error(ctx context.Context, f string, v ...interface{}) { - ctx = alog.AddTags(ctx, "level", "error") - d.Logger.Output(ctx, 3, fmt.Sprintf(f, v...)) + d.Log(ctx, Error, f, v...) } // Critical implements Logger.Critical func (d *defaultLogger) Critical(ctx context.Context, f string, v ...interface{}) { - ctx = alog.AddTags(ctx, "level", "critical") - d.Logger.Output(ctx, 3, fmt.Sprintf(f, v...)) + d.Log(ctx, Critical, f, v...) } + +// Log implements FilteredLogger.Log +func (d *defaultLogger) Log(ctx context.Context, level Level, f string, v ...interface{}) { + if level >= d.MinLevel { + ctx = alog.AddTags(ctx, LevelKey, level.String()) + d.Logger.Output(ctx, 3, fmt.Sprintf(f, v...)) + } +} + +// SetMinLevel sets the minimum level that will be logged and implements FilteredLogger. +func (d *defaultLogger) SetMinLevel(level Level) { + d.MinLevel = level +} + +//go:generate go run golang.org/x/tools/cmd/stringer@latest -type Level -linecomment diff --git a/leveled/logger_test.go b/leveled/logger_test.go index 0b697a7..12ee467 100644 --- a/leveled/logger_test.go +++ b/leveled/logger_test.go @@ -21,3 +21,18 @@ func TestLogger(t *testing.T) { t.Errorf("got: %#q, want: %#q", got, want) } } + +func TestLogLevels(t *testing.T) { + b := &bytes.Buffer{} + l := Filtered(alog.New(alog.WithEmitter(textlog.Emitter(b)))) + l.SetMinLevel(Warning) + + ctx := context.Background() + ctx = alog.AddTags(ctx, "key", "value") + l.Error(ctx, "I get logged") + l.Debug(ctx, "I don't get logged") + const want = `[key=value level=error] I get logged` + "\n" + if got := b.String(); got != want { + t.Errorf("got: %#q, want: %#q", got, want) + } +}