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

@@ -22,19 +22,26 @@ 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.
 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 {

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()

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

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,50 @@ func Default(logger *alog.Logger) Logger {
 	}
 }
 
+// Filtered returns an advanced 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

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)
+	}
+}