slog: rethink levels

We want the default level to be Info, so make it zero.

Then rejigger the level numbers to match OpenTelemetry:
- Reverse the direction, so larger numbers are more severe.
- Reduce the gaps between named levels from 10 to 4.

There is still a nice mapping to verbosities: negation.

By making the zero level valid, we lose a level value that means "no
level." We could reinstate it by picking an extreme value,
like math.MinInt. Or we could just omit it; perhaps it's
not needed.

Change-Id: I0f06418b7de79fde0c172e5c9d88c707fac74601
Reviewed-on: https://go-review.googlesource.com/c/exp/+/435896
TryBot-Result: Gopher Robot <gobot@golang.org>
Reviewed-by: Alan Donovan <adonovan@google.com>
Run-TryBot: Jonathan Amsterdam <jba@google.com>
Reviewed-by: Russ Cox <rsc@golang.org>

Author: jba

slog/handler.go

@@ -32,7 +32,6 @@ type Handler interface {
 	// Handle handles the Record.
 	// Handle methods that produce output should observe the following rules:
 	//   - If r.Time() is the zero time, ignore the time.
-	//   - If r.Level() is Level(0), ignore the level.
 	//   - If an Attr's key is the empty string, ignore the Attr.
 	Handle(r Record) error
 
@@ -53,10 +52,8 @@ func (*defaultHandler) Enabled(Level) bool { return true }
 // Let the log.Logger handle time and file/line.
 func (h *defaultHandler) Handle(r Record) error {
 	var b strings.Builder
-	if r.Level() > 0 {
-		b.WriteString(r.Level().String())
-		b.WriteByte(' ')
-	}
+	b.WriteString(r.Level().String())
+	b.WriteByte(' ')
 	r.Attrs(func(a Attr) {
 		fmt.Fprint(&b, a) // Attr.Format will print key=value
 		b.WriteByte(' ')
@@ -144,15 +141,13 @@ func (h *commonHandler) handle(r Record) error {
 		}
 	}
 	// level
-	if r.Level() != 0 {
-		key := "level"
-		val := r.Level()
-		if rep == nil {
-			state.appendKey(key)
-			state.appendString(val.String())
-		} else {
-			state.appendAttr(Any(key, val))
-		}
+	key := "level"
+	val := r.Level()
+	if rep == nil {
+		state.appendKey(key)
+		state.appendString(val.String())
+	} else {
+		state.appendAttr(Any(key, val))
 	}
 	// source
 	if h.opts.AddSource {
@@ -173,14 +168,13 @@ func (h *commonHandler) handle(r Record) error {
 			}
 		}
 	}
-	// message
-	key := "msg"
-	val := r.Message()
+	key = "msg"
+	msg := r.Message()
 	if rep == nil {
 		state.appendKey(key)
-		state.appendString(val)
+		state.appendString(msg)
 	} else {
-		state.appendAttr(String(key, val))
+		state.appendAttr(String(key, msg))
 	}
 	// preformatted Attrs
 	if len(h.preformattedAttrs) > 0 {

slog/level.go

@@ -16,36 +16,36 @@ import (
 type Level int
 
 // The level numbers below don't really matter too much. Any system can map them
-// to another numbering scheme if it wishes. We picked them to satisfy two
+// to another numbering scheme if it wishes. We picked them to satisfy three
 // constraints.
 //
-// First, we wanted to make it easy to work with verbosities instead of levels.
-// Since higher verbosities are less important, higher levels are as well.
+// First, we wanted the default level to be Info, Since Levels are ints, Info is
+// the default value for int, zero.
 //
-// Second, we wanted some room between levels to accommodate schemes with named
+// Second, we wanted to make it easy to work with verbosities instead of levels.
+// Verbosities start at 0 corresponding to Info, and larger values are less severe
+// Negating a verbosity converts it into a Level.
+//
+// Third, we wanted some room between levels to accommodate schemes with named
 // levels between ours. For example, Google Cloud Logging defines a Notice level
 // between Info and Warn. Since there are only a few of these intermediate
-// levels, the gap between the numbers need not be large. We selected a gap of
-// 10, because the majority of humans have 10 fingers.
-//
-// The missing gap between Info and Debug has to do with verbosities again. It
-// is natural to think of verbosity 0 as Info, and then verbosity 1 is the
-// lowest level one would call Debug. The simple formula
-//   level = InfoLevel + verbosity
-// then works well to map verbosities to levels. That is,
+// levels, the gap between the numbers need not be large. Our gap of 4 matches
+// OpenTelemetry's mapping. Subtracting 9 from an OpenTelemetry level in the
+// DEBUG, INFO, WARN and ERROR ranges converts it to the corresponding slog
+// Level range. OpenTelemetry also has the names TRACE and FATAL, which slog
+// does not. But those OpenTelemetry levels can still be represented as slog
+// Levels by using the appropriate integers.
 //
-//   Level(InfoLevel+0).String() == "INFO"
-//   Level(InfoLevel+1).String() == "DEBUG"
-//   Level(InfoLevel+2).String() == "DEBUG+1"
+// The lack of a gap between Debug and Info doesn't follow the pattern.
+// It makes sense, though, that the first negative number is the start
+// of the Debug range.
 //
-// and so on.
-
 // Names for common levels.
 const (
-	ErrorLevel Level = 10
-	WarnLevel  Level = 20
-	InfoLevel  Level = 30
-	DebugLevel Level = 31
+	DebugLevel Level = -1
+	InfoLevel  Level = 0
+	WarnLevel  Level = 4
+	ErrorLevel Level = 8
 )
 
 // String returns a name for the level.
@@ -66,16 +66,14 @@ func (l Level) String() string {
 	}
 
 	switch {
-	case l <= 0:
-		return fmt.Sprintf("!BADLEVEL(%d)", l)
-	case l <= ErrorLevel:
-		return str("ERROR", l-ErrorLevel)
-	case l <= WarnLevel:
+	case l <= DebugLevel:
+		return str("DEBUG", l-DebugLevel)
+	case l < WarnLevel:
+		return str("INFO", l)
+	case l < ErrorLevel:
 		return str("WARN", l-WarnLevel)
-	case l <= InfoLevel:
-		return str("INFO", l-InfoLevel)
 	default:
-		return str("DEBUG", l-DebugLevel)
+		return str("ERROR", l-ErrorLevel)
 	}
 }
 

slog/level_test.go

@@ -14,16 +14,16 @@ func TestLevelString(t *testing.T) {
 		in   Level
 		want string
 	}{
-		{0, "!BADLEVEL(0)"},
+		{0, "INFO"},
 		{ErrorLevel, "ERROR"},
-		{ErrorLevel - 2, "ERROR-2"},
+		{ErrorLevel + 2, "ERROR+2"},
+		{ErrorLevel - 2, "WARN+2"},
 		{WarnLevel, "WARN"},
-		{WarnLevel - 1, "WARN-1"},
+		{WarnLevel - 1, "INFO+3"},
 		{InfoLevel, "INFO"},
-		{InfoLevel - 3, "INFO-3"},
+		{InfoLevel - 3, "DEBUG-2"},
 		{DebugLevel, "DEBUG"},
-		{InfoLevel + 2, "DEBUG+1"},
-		{-1, "!BADLEVEL(-1)"},
+		{DebugLevel - 2, "DEBUG-2"},
 	} {
 		got := test.in.String()
 		if got != test.want {

slog/logger_test.go

@@ -42,11 +42,11 @@ func TestLogTextHandler(t *testing.T) {
 	l.Error("bad", io.EOF, "a", 1)
 	check(`level=ERROR msg=bad a=1 err=EOF`)
 
-	l.Log(WarnLevel-1, "w", Int("a", 1), String("b", "two"))
-	check(`level=WARN-1 msg=w a=1 b=two`)
+	l.Log(WarnLevel+1, "w", Int("a", 1), String("b", "two"))
+	check(`level=WARN\+1 msg=w a=1 b=two`)
 
-	l.LogAttrs(InfoLevel-1, "a b c", Int("a", 1), String("b", "two"))
-	check(`level=INFO-1 msg="a b c" a=1 b=two`)
+	l.LogAttrs(InfoLevel+1, "a b c", Int("a", 1), String("b", "two"))
+	check(`level=INFO\+1 msg="a b c" a=1 b=two`)
 }
 
 func TestConnections(t *testing.T) {

slog/text_handler_test.go

@@ -162,14 +162,14 @@ func TestTextHandlerPreformatted(t *testing.T) {
 	var buf bytes.Buffer
 	var h Handler = NewTextHandler(&buf)
 	h = h.With([]Attr{Duration("dur", time.Minute), Bool("b", true)})
-	// Also test omitting time and level.
-	r := NewRecord(time.Time{}, 0, "m", 0)
+	// Also test omitting time.
+	r := NewRecord(time.Time{}, 0 /* 0 Level is INFO */, "m", 0)
 	r.AddAttrs(Int("a", 1))
 	if err := h.Handle(r); err != nil {
 		t.Fatal(err)
 	}
 	got := strings.TrimSuffix(buf.String(), "\n")
-	want := `msg=m dur=1m0s b=true a=1`
+	want := `level=INFO msg=m dur=1m0s b=true a=1`
 	if got != want {
 		t.Errorf("got %s, want %s", got, want)
 	}