[exp] slog: Logger
Jonathan Amsterdam (Gerrit)
Attention is currently required from: Alan Donovan, Ian Cottrell.
Jonathan Amsterdam would like Ian Cottrell and Alan Donovan to review this change.
slog: Logger
The Logger type and its methods.
Change-Id: I2447ec7a3dab5c10c8851adcc2b5ae8e7b8e210d
---
A slog/atomic.go
A slog/logger.go
A slog/logger_test.go
M slog/record.go
4 files changed, 593 insertions(+), 0 deletions(-)
diff --git a/slog/atomic.go b/slog/atomic.go
new file mode 100644
index 0000000..2c2f8e4
--- /dev/null
+++ b/slog/atomic.go
@@ -0,0 +1,23 @@
+// Copyright 2022 The Go Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style
+// license that can be found in the LICENSE file.
+
+package slog
+
+import "sync/atomic"
+
+type atomicValue[T any] struct {
+ a atomic.Value
+}
+
+func (av *atomicValue[T]) get() (z T) {
+ v := av.a.Load()
+ if v == nil {
+ return z
+ }
+ return v.(T)
+}
+
+func (av *atomicValue[T]) set(x T) {
+ av.a.Store(x)
+}
diff --git a/slog/logger.go b/slog/logger.go
new file mode 100644
index 0000000..80d6c97
--- /dev/null
+++ b/slog/logger.go
@@ -0,0 +1,221 @@
+// Copyright 2022 The Go Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style
+// license that can be found in the LICENSE file.
+
+package slog
+
+import (
+ "log"
+ "time"
+)
+
+var defaultLogger atomicValue[*Logger]
+
+func init() {
+ defaultLogger.set(&Logger{
+ handler: &defaultHandler{},
+ })
+}
+
+// Default returns the default Logger.
+func Default() *Logger { return defaultLogger.get() }
+
+// SetDefault makes l the default Logger.
+// After this call, output from the log package's default Logger
+// (as with [log.Print], etc.) will be logged at InfoLevel using l's Handler.
+func SetDefault(l *Logger) {
+ defaultLogger.set(l)
+ log.SetOutput(&handlerWriter{l.Handler(), log.Flags()})
+ log.SetFlags(0) // we want just the log message, no time or location
+}
+
+// handlerWriter is an io.Writer that calls a Handler.
+// It is used to link the default log.Logger to the default slog.Logger.
+type handlerWriter struct {
+ h Handler
+ flags int
+}
+
+func (w *handlerWriter) Write(buf []byte) (int, error) {
+ var depth int
+ if w.flags&(log.Lshortfile|log.Llongfile) != 0 {
+ depth = 2
+ }
+ r := MakeRecord(time.Now(), InfoLevel, string(buf[:len(buf)-1]), depth)
+ return len(buf), w.h.Handle(r)
+}
+
+// A Logger generates Records and passes them to a Handler.
+//
+// Loggers are immutable; to create a new one, call [New] or [Logger.With].
+type Logger struct {
+ handler Handler // for structured logging
+}
+
+// Handler returns l's Handler.
+func (l *Logger) Handler() Handler { return l.handler }
+
+// With returns a new Logger whose handler's attributes are a concatenation of
+// l's attributes and the given arguments, converted to Attrs as in
+// [Logger.Log].
+func (l *Logger) With(attrs ...any) *Logger {
+ return &Logger{handler: l.handler.With(argsToAttrs(attrs))}
+}
+
+func argsToAttrs(args []any) []Attr {
+ var r Record
+ setAttrs(&r, args)
+ return r.Attrs()
+}
+
+// New creates a new Logger with the given Handler.
+func New(h Handler) *Logger { return &Logger{handler: h} }
+
+// With calls Logger.With on the default logger.
+func With(attrs ...any) *Logger {
+ return Default().With(attrs...)
+}
+
+// Enabled reports whether l emits log records at level.
+func (l *Logger) Enabled(level Level) bool {
+ return l.Handler().Enabled(level)
+}
+
+// Log emits a log record with the current time and the given level and message.
+// The Record's Attrs consist of the Logger's attributes followed by
+// the Attrs specified by args.
+//
+// The attribute arguments are processed as follows:
+// - If an argument is an Attr, it is used as is.
+// - If an argument is a string and this is not the last argument,
+// the following argument is treated as the value and the two are combined
+// into an Attr.
+// - Otherwise, the argument is treated as a value with key "!BADKEY".
+func (l *Logger) Log(level Level, msg string, args ...any) {
+ l.LogDepth(0, level, msg, args...)
+}
+
+// LogDepth is like [Logger.Log], but accepts a call depth to adjust the
+// file and line number in the log record. 0 refers to the caller
+// of LogDepth; 1 refers to the caller's caller; and so on.
+func (l *Logger) LogDepth(calldepth int, level Level, msg string, args ...any) {
+ if !l.Enabled(level) {
+ return
+ }
+ r := l.makeRecord(msg, level, calldepth)
+ setAttrs(&r, args)
+ _ = l.Handler().Handle(r)
+}
+
+var useSourceLine = true
+
+// Temporary, for benchmarking.
+// Eventually, getting the pc should be fast.
+func disableSourceLine() { useSourceLine = false }
+
+func (l *Logger) makeRecord(msg string, level Level, depth int) Record {
+ if useSourceLine {
+ depth += 5
+ }
+ return MakeRecord(time.Now(), level, msg, depth)
+}
+
+const badKey = "!BADKEY"
+
+func setAttrs(r *Record, args []any) {
+ i := 0
+ for i < len(args) {
+ switch x := args[i].(type) {
+ case string:
+ if i+1 >= len(args) {
+ r.AddAttr(String(badKey, x))
+ } else {
+ r.AddAttr(Any(x, args[i+1]))
+ }
+ i += 2
+ case Attr:
+ r.AddAttr(x)
+ i++
+ default:
+ // If the key is not a string or Attr, treat it as a value with a missing key.
+ r.AddAttr(Any(badKey, x))
+ i++
+ }
+ }
+}
+
+// LogAttrs is a more efficient version of [Logger.Log] that accepts only Attrs.
+func (l *Logger) LogAttrs(level Level, msg string, attrs ...Attr) {
+ l.LogAttrsDepth(0, level, msg, attrs...)
+}
+
+// LogAttrsDepth is like [Logger.LogAttrs], but accepts a call depth argument
+// which it interprets like [Logger.LogDepth].
+func (l *Logger) LogAttrsDepth(calldepth int, level Level, msg string, attrs ...Attr) {
+ if !l.Enabled(level) {
+ return
+ }
+ r := l.makeRecord(msg, level, calldepth)
+ r.addAttrs(attrs)
+ _ = l.Handler().Handle(r)
+}
+
+// Debug logs at DebugLevel.
+func (l *Logger) Debug(msg string, args ...any) {
+ l.LogDepth(0, DebugLevel, msg, args...)
+}
+
+// Info logs at InfoLevel.
+func (l *Logger) Info(msg string, args ...any) {
+ l.LogDepth(0, InfoLevel, msg, args...)
+}
+
+// Warn logs at WarnLevel.
+func (l *Logger) Warn(msg string, args ...any) {
+ l.LogDepth(0, WarnLevel, msg, args...)
+}
+
+// Error logs at ErrorLevel.
+// If err is non-nil, Error appends Any("err", err)
+// to the list of attributes.
+func (l *Logger) Error(msg string, err error, args ...any) {
+ if err != nil {
+ // TODO: avoid the copy.
+ args = append(args[:len(args):len(args)], Any("err", err))
+ }
+ l.LogDepth(0, ErrorLevel, msg, args...)
+}
+
+// Debug calls Logger.Debug on the default logger.
+func Debug(msg string, args ...any) {
+ Default().LogDepth(0, DebugLevel, msg, args...)
+}
+
+// Info calls Logger.Info on the default logger.
+func Info(msg string, args ...any) {
+ Default().LogDepth(0, InfoLevel, msg, args...)
+}
+
+// Warn calls Logger.Warn on the default logger.
+func Warn(msg string, args ...any) {
+ Default().LogDepth(0, WarnLevel, msg, args...)
+}
+
+// Error calls Logger.Error on the default logger.
+func Error(msg string, err error, args ...any) {
+ if err != nil {
+ // TODO: avoid the copy.
+ args = append(args[:len(args):len(args)], Any("err", err))
+ }
+ Default().LogDepth(0, ErrorLevel, msg, args...)
+}
+
+// Log calls Logger.Log on the default logger.
+func Log(level Level, msg string, args ...any) {
+ Default().LogDepth(0, level, msg, args...)
+}
+
+// LogAttrs calls Logger.LogAttrs on the default logger.
+func LogAttrs(level Level, msg string, attrs ...Attr) {
+ Default().LogAttrsDepth(0, level, msg, attrs...)
+}
diff --git a/slog/logger_test.go b/slog/logger_test.go
new file mode 100644
index 0000000..03fedc5
--- /dev/null
+++ b/slog/logger_test.go
@@ -0,0 +1,331 @@
+// Copyright 2022 The Go Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style
+// license that can be found in the LICENSE file.
+
+package slog
+
+import (
+ "bytes"
+ "io"
+ "log"
+ "path/filepath"
+ "regexp"
+ "strings"
+ "testing"
+ "time"
+)
+
+const timeRE = `\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{3}-\d{2}:\d{2}`
+
+func TestLogTextHandler(t *testing.T) {
+ var buf bytes.Buffer
+
+ l := New(NewTextHandler(&buf))
+
+ check := func(want string) {
+ t.Helper()
+ want = "time=" + timeRE + " " + want
+ checkLogOutput(t, buf.String(), want)
+ buf.Reset()
+ }
+
+ l.Info("msg", "a", 1, "b", 2)
+ check(`level=INFO msg=msg a=1 b=2`)
+
+ l.Debug("bg", Int("a", 1), "b", 2)
+ check(`level=DEBUG msg=bg a=1 b=2`)
+
+ l.Warn("w", Duration("dur", 3*time.Second))
+ check(`level=WARN msg=w dur=3s`)
+
+ 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.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) {
+ var logbuf, slogbuf bytes.Buffer
+
+ // The default slog.Logger's handler uses the log package's default output.
+ log.SetOutput(&logbuf)
+ log.SetFlags(log.Flags() | log.Lshortfile)
+ Info("msg", "a", 1)
+ checkLogOutput(t, logbuf.String(),
+ `\d{4}/\d{2}/\d{2} \d{2}:\d{2}:\d{2} logger_test.go:\d\d: INFO a=1 msg`)
+
+ // Once slog.SetDefault is called, the direction is reversed: the default
+ // log.Logger's output goes through the handler.
+ SetDefault(New(NewTextHandler(&slogbuf)))
+ log.Print("msg2")
+ checkLogOutput(t, slogbuf.String(), "time="+timeRE+` level=INFO msg=msg2`)
+
+ // Setting log's output again breaks the connection.
+ logbuf.Reset()
+ slogbuf.Reset()
+ log.SetOutput(&logbuf)
+ log.SetFlags(log.LstdFlags)
+ log.Print("msg3")
+ checkLogOutput(t, logbuf.String(),
+ `\d{4}/\d{2}/\d{2} \d{2}:\d{2}:\d{2} msg3`)
+ if got := slogbuf.String(); got != "" {
+ t.Errorf("got %q, want empty", got)
+ }
+}
+
+func TestAttrs(t *testing.T) {
+ check := func(got []Attr, want ...Attr) {
+ t.Helper()
+ if !attrsEqual(got, want) {
+ t.Errorf("got %v, want %v", got, want)
+ }
+ }
+
+ l1 := New(&captureHandler{}).With("a", 1)
+ l2 := New(l1.Handler()).With("b", 2)
+ l2.Info("m", "c", 3)
+ h := l2.Handler().(*captureHandler)
+ check(h.attrs, Int("a", 1), Int("b", 2))
+ check(h.r.Attrs(), Int("c", 3))
+}
+
+func TestCallDepth(t *testing.T) {
+ h := &captureHandler{}
+
+ check := func(count int) {
+ t.Helper()
+ const wantFile = "logger_test.go"
+ wantLine := 114 + count*2
+ gotFile, gotLine := h.r.SourceLine()
+ gotFile = filepath.Base(gotFile)
+ if gotFile != wantFile || gotLine != wantLine {
+ t.Errorf("got (%s, %d), want (%s, %d)", gotFile, gotLine, wantFile, wantLine)
+ }
+ }
+
+ logger := New(h)
+ SetDefault(logger)
+
+ // Calls to check must be one line apart.
+ logger.Log(InfoLevel, "")
+ check(0)
+ logger.LogAttrs(InfoLevel, "")
+ check(1)
+ logger.Debug("")
+ check(2)
+ logger.Info("")
+ check(3)
+ logger.Warn("")
+ check(4)
+ logger.Error("", nil)
+ check(5)
+ Debug("")
+ check(6)
+ Info("")
+ check(7)
+ Warn("")
+ check(8)
+ Error("", nil)
+ check(9)
+ Log(InfoLevel, "")
+ check(10)
+ LogAttrs(InfoLevel, "")
+ check(11)
+}
+
+func TestAlloc(t *testing.T) {
+ dl := New(discardHandler{})
+ defer func(d *Logger) { SetDefault(d) }(Default())
+ SetDefault(dl)
+
+ t.Run("Info", func(t *testing.T) {
+ wantAllocs(t, 0, func() { Info("hello") })
+ })
+ // t.Run("Error", func(t *testing.T) {
+ // wantAllocs(t, 0, func() { Error("hello", io.EOF) })
+ // })
+ t.Run("logger.Info", func(t *testing.T) {
+ wantAllocs(t, 0, func() { dl.Info("hello") })
+ })
+ t.Run("logger.Log", func(t *testing.T) {
+ wantAllocs(t, 0, func() { dl.Log(DebugLevel, "hello") })
+ })
+ t.Run("2 pairs", func(t *testing.T) {
+ s := "abc"
+ i := 2000
+ wantAllocs(t, 2, func() {
+ dl.Info("hello",
+ "n", i,
+ "s", s,
+ )
+ })
+ })
+ t.Run("2 pairs disabled inline", func(t *testing.T) {
+ l := New(discardHandler{disabled: true})
+ s := "abc"
+ i := 2000
+ wantAllocs(t, 2, func() {
+ l.Log(InfoLevel, "hello",
+ "n", i,
+ "s", s,
+ )
+ })
+ })
+ t.Run("2 pairs disabled", func(t *testing.T) {
+ l := New(discardHandler{disabled: true})
+ s := "abc"
+ i := 2000
+ wantAllocs(t, 0, func() {
+ if l.Enabled(InfoLevel) {
+ l.Log(InfoLevel, "hello",
+ "n", i,
+ "s", s,
+ )
+ }
+ })
+ })
+ t.Run("9 kvs", func(t *testing.T) {
+ s := "abc"
+ i := 2000
+ d := time.Second
+ wantAllocs(t, 10, func() {
+ dl.Info("hello",
+ "n", i, "s", s, "d", d,
+ "n", i, "s", s, "d", d,
+ "n", i, "s", s, "d", d)
+ })
+ })
+ t.Run("pairs", func(t *testing.T) {
+ wantAllocs(t, 0, func() { dl.Info("", "error", io.EOF) })
+ })
+ t.Run("attrs1", func(t *testing.T) {
+ wantAllocs(t, 0, func() { dl.LogAttrs(InfoLevel, "", Int("a", 1)) })
+ wantAllocs(t, 0, func() { dl.LogAttrs(InfoLevel, "", Any("error", io.EOF)) })
+ })
+ t.Run("attrs3", func(t *testing.T) {
+ wantAllocs(t, 0, func() {
+ dl.LogAttrs(InfoLevel, "hello", Int("a", 1), String("b", "two"), Duration("c", time.Second))
+ })
+ })
+ t.Run("attrs3 disabled", func(t *testing.T) {
+ logger := New(discardHandler{disabled: true})
+ wantAllocs(t, 0, func() {
+ logger.LogAttrs(InfoLevel, "hello", Int("a", 1), String("b", "two"), Duration("c", time.Second))
+ })
+ })
+ t.Run("attrs6", func(t *testing.T) {
+ wantAllocs(t, 1, func() {
+ dl.LogAttrs(InfoLevel, "hello",
+ Int("a", 1), String("b", "two"), Duration("c", time.Second),
+ Int("d", 1), String("e", "two"), Duration("f", time.Second))
+ })
+ })
+ t.Run("attrs9", func(t *testing.T) {
+ wantAllocs(t, 1, func() {
+ dl.LogAttrs(InfoLevel, "hello",
+ Int("a", 1), String("b", "two"), Duration("c", time.Second),
+ Int("d", 1), String("e", "two"), Duration("f", time.Second),
+ Int("d", 1), String("e", "two"), Duration("f", time.Second))
+ })
+ })
+}
+
+func TestSetAttrs(t *testing.T) {
+ for _, test := range []struct {
+ args []any
+ want []Attr
+ }{
+ {nil, nil},
+ {[]any{"a", 1}, []Attr{Int("a", 1)}},
+ {[]any{"a", 1, "b", "two"}, []Attr{Int("a", 1), String("b", "two")}},
+ {[]any{"a"}, []Attr{String(badKey, "a")}},
+ {[]any{"a", 1, "b"}, []Attr{Int("a", 1), String(badKey, "b")}},
+ {[]any{"a", 1, 2, 3}, []Attr{Int("a", 1), Int(badKey, 2), Int(badKey, 3)}},
+ } {
+ r := MakeRecord(time.Time{}, 0, "", 0)
+ setAttrs(&r, test.args)
+ got := r.Attrs()
+ if !attrsEqual(got, test.want) {
+ t.Errorf("%v:\ngot %v\nwant %v", test.args, got, test.want)
+ }
+ }
+}
+
+func checkLogOutput(t *testing.T, got, wantRegexp string) {
+ t.Helper()
+ got = clean(got)
+ wantRegexp = "^" + wantRegexp + "$"
+ matched, err := regexp.MatchString(wantRegexp, got)
+ if err != nil {
+ t.Fatal(err)
+ }
+ if !matched {
+ t.Errorf("\ngot %s\nwant %s", got, wantRegexp)
+ }
+}
+
+// clean prepares log output for comparison.
+func clean(s string) string {
+ if len(s) > 0 && s[len(s)-1] == '\n' {
+ s = s[:len(s)-1]
+ }
+ return strings.ReplaceAll(s, "\n", "~")
+}
+
+type captureHandler struct {
+ r Record
+ attrs []Attr
+}
+
+func (h *captureHandler) Handle(r Record) error {
+ h.r = r
+ return nil
+}
+
+func (*captureHandler) Enabled(Level) bool { return true }
+
+func (c *captureHandler) With(as []Attr) Handler {
+ c2 := *c
+ c2.attrs = concat(c2.attrs, as)
+ return &c2
+}
+
+type discardHandler struct {
+ disabled bool
+ attrs []Attr
+}
+
+func (d discardHandler) Enabled(Level) bool { return !d.disabled }
+func (discardHandler) Handle(Record) error { return nil }
+func (d discardHandler) With(as []Attr) Handler {
+ d.attrs = concat(d.attrs, as)
+ return d
+}
+
+// This is a simple benchmark. See the benchmarks subdirectory for more extensive ones.
+func BenchmarkNopLog(b *testing.B) {
+ b.ReportAllocs()
+ disableSourceLine()
+ l := New(&captureHandler{})
+ b.Run("attrs", func(b *testing.B) {
+ for i := 0; i < b.N; i++ {
+ l.LogAttrs(InfoLevel, "msg", Int("a", 1), String("b", "two"), Bool("c", true))
+ }
+ })
+ b.Run("attrs-parallel", func(b *testing.B) {
+ b.RunParallel(func(pb *testing.PB) {
+ for pb.Next() {
+ l.LogAttrs(InfoLevel, "msg", Int("a", 1), String("b", "two"), Bool("c", true))
+ }
+ })
+ })
+ b.Run("keys-values", func(b *testing.B) {
+ for i := 0; i < b.N; i++ {
+ l.Log(InfoLevel, "msg", "a", 1, "b", "two", "c", true)
+ }
+ })
+}
diff --git a/slog/record.go b/slog/record.go
index ffeb7c9..0f78a96 100644
--- a/slog/record.go
+++ b/slog/record.go
@@ -125,3 +125,10 @@
r.tail[r.nTail] = a
r.nTail++
}
+
+func (r *Record) addAttrs(attrs []Attr) {
+ // TODO: be cleverer.
+ for _, a := range attrs {
+ r.AddAttr(a)
+ }
+}
To view, visit change 429436. To unsubscribe, or for help writing mail filters, visit settings.
Alan Donovan (Gerrit)
Attention is currently required from: Ian Cottrell, Jonathan Amsterdam.
10 comments:
File slog/atomic.go:
Patch Set #1, Line 9:
type atomicValue[T any] struct {Inline? This type is used once and doesn't really add anything. Even the nil case of get() is never actually used.
File slog/logger.go:
Patch Set #1, Line 44:
r := MakeRecord(time.Now(), InfoLevel, string(buf[:len(buf)-1]), depth)Why is the last byte omitted? On the assumption that it's a newline? If so that should be verified.
Patch Set #1, Line 48:
// A Logger generates Records and passes them to a Handler."generates" isn't quite right; let's aim at the application programmer here rather than the logging handler implementer. How about something like:
// A Logger records structured information about each call to its
// Log, Debug, Info, Warn, and Error methods made by an application.
// For each call, it creates a Record and passes it to a Handler.Patch Set #1, Line 79:
at level."of the specified level"?
Patch Set #1, Line 107:
_ = l.Handler().Handle(r)Is discarding the Handle errors (here and below) appropriate? Obviously we can't expect the caller to do anything with them, but might this be the only indication that the handler has failed to write the log to the backend server? Should it print to stderr in this case?
Patch Set #1, Line 113:
// Eventually, getting the pc should be fast.Curious: what change are you anticipating?
Patch Set #1, Line 116:
func (l *Logger) makeRecord(msg string, level Level, depth int) Record {I assume this function will go away with useSourceLine, so I won't comment on the duplication w.r.t. the other call of time.Now.
Patch Set #1, Line 126:
i := 0Nit: Factor the calls to AddAttr to make clear that it is called exactly once per iteration?
Nit: use "for i := 0; i < len(args); i++" with an extra i++ only in the string case, to clarify the loop?
File slog/logger_test.go:
Patch Set #1, Line 102:
wantLine := 114 + count*2This constant will cause the test to fail spuriously any time someone makes a sound change to the first 114 lines of this file. Compute the correct value from the first call to check(0).
File slog/record.go:
Patch Set #1, Line 130:
// TODO: be cleverer.Let's chat about the list representation today.
To view, visit change 429436. To unsubscribe, or for help writing mail filters, visit settings.
Jonathan Amsterdam (Gerrit)
Attention is currently required from: Alan Donovan, Ian Cottrell, Jonathan Amsterdam.
Jonathan Amsterdam uploaded patch set #2 to this change.
The following approvals got outdated and were removed: Run-TryBot+1 by Jonathan Amsterdam, TryBot-Result-1 by Gopher Robot
slog: Logger
The Logger type and its methods.
Change-Id: I2447ec7a3dab5c10c8851adcc2b5ae8e7b8e210d
---
A slog/logger.go
A slog/logger_test.go
M slog/record.go
3 files changed, 592 insertions(+), 0 deletions(-)
To view, visit change 429436. To unsubscribe, or for help writing mail filters, visit settings.
Jonathan Amsterdam (Gerrit)
Attention is currently required from: Alan Donovan, Ian Cottrell, Jonathan Amsterdam.
10 comments:
File slog/atomic.go:
Patch Set #1, Line 9:
type atomicValue[T any] struct {
Inline? This type is used once and doesn't really add anything. […]
Done
File slog/logger.go:
Patch Set #1, Line 44:
r := MakeRecord(time.Now(), InfoLevel, string(buf[:len(buf)-1]), depth)Why is the last byte omitted? On the assumption that it's a newline? If so that should be verified.
Done
Patch Set #1, Line 48:
// A Logger generates Records and passes them to a Handler.
"generates" isn't quite right; let's aim at the application programmer here rather than the logging […]
Done
Patch Set #1, Line 79:
at level."of the specified level"?
Done
Patch Set #1, Line 107:
_ = l.Handler().Handle(r)
Is discarding the Handle errors (here and below) appropriate? Obviously we can't expect the caller t […]
This follows the `log` package. (Although log.Output, intended as a low-level function to be wrapped, does return the error.)
It's easy enough to write a Handler that wraps another Handler and exposes the error.
Patch Set #1, Line 113:
// Eventually, getting the pc should be fast.Curious: what change are you anticipating?
I don't know the details, but Russ believes that it is doable.
Patch Set #1, Line 116:
func (l *Logger) makeRecord(msg string, level Level, depth int) Record {
I assume this function will go away with useSourceLine, so I won't comment on the duplication w.r.t. […]
Ack
Patch Set #1, Line 126:
i := 0
Nit: Factor the calls to AddAttr to make clear that it is called exactly once per iteration? […]
Done, in a different way.
File slog/logger_test.go:
Patch Set #1, Line 102:
wantLine := 114 + count*2
This constant will cause the test to fail spuriously any time someone makes a sound change to the fi […]
Done
File slog/record.go:
Patch Set #1, Line 130:
// TODO: be cleverer.Let's chat about the list representation today.
Ack
To view, visit change 429436. To unsubscribe, or for help writing mail filters, visit settings.
Alan Donovan (Gerrit)
Attention is currently required from: Ian Cottrell, Jonathan Amsterdam.
Patch set 3:Code-Review +2
3 comments:
File slog/logger.go:
Patch Set #1, Line 107:
_ = l.Handler().Handle(r)This follows the `log` package. (Although log. […]
Ack
Patch Set #1, Line 126:
i := 0
Done, in a different way.
Fun fact: advancing by x=x[1:] generates slightly worse code than using x[i] because the compiler takes pains to avoid a situation at the end of the loop in which the slice is zero length but points to the object just beyond the array, causing the GC to keep it spuriously live. This can be optimized by doing x[:len:len] before the loop to establish the capacity.
To be clear, this only matters when the loop body is tiny (e.g. typical []byte scanning). I don't think you should change the code here.
File slog/logger.go:
Patch Set #3, Line 47:
buf = buf[:len(buf)-1]Make sure to capture the len(buf) result before truncating buf so that the function doesn't return a short Write.
To view, visit change 429436. To unsubscribe, or for help writing mail filters, visit settings.
Jonathan Amsterdam (Gerrit)
Attention is currently required from: Alan Donovan, Ian Cottrell, Jonathan Amsterdam.
Jonathan Amsterdam uploaded patch set #4 to this change.
The following approvals got outdated and were removed: Run-TryBot+1 by Jonathan Amsterdam, TryBot-Result-1 by Gopher Robot
slog: Logger
The Logger type and its methods.
Change-Id: I2447ec7a3dab5c10c8851adcc2b5ae8e7b8e210d
---
A slog/logger.go
A slog/logger_test.go
M slog/record.go
3 files changed, 593 insertions(+), 0 deletions(-)
To view, visit change 429436. To unsubscribe, or for help writing mail filters, visit settings.
Jonathan Amsterdam (Gerrit)
Attention is currently required from: Alan Donovan, Ian Cottrell, Jonathan Amsterdam.
2 comments:
File slog/logger.go:
Patch Set #1, Line 126:
i := 0Fun fact: advancing by x=x[1:] generates slightly worse code than using x[i] because the compiler ta […]
Good to know!
File slog/logger.go:
Patch Set #3, Line 47:
buf = buf[:len(buf)-1]
Make sure to capture the len(buf) result before truncating buf so that the function doesn't return a […]
Nice catch.
Done.
To view, visit change 429436. To unsubscribe, or for help writing mail filters, visit settings.
Jonathan Amsterdam (Gerrit)
Jonathan Amsterdam submitted this change.
3 is the latest approved patch-set.
The change was submitted with unreviewed changes in the following files:
```
The name of the file: slog/logger.go
Insertions: 2, Deletions: 1.
@@ -43,11 +43,12 @@
depth = 2
}
// Remove final newline.
+ origLen := len(buf) // Report that the entire buf was written.
if len(buf) > 0 && buf[len(buf)-1] == '\n' {
buf = buf[:len(buf)-1]
}
r := MakeRecord(time.Now(), InfoLevel, string(buf), depth)
- return len(buf), w.h.Handle(r)
+ return origLen, w.h.Handle(r)
}
// A Logger records structured information about each call to its
```
slog: Logger
The Logger type and its methods.
Change-Id: I2447ec7a3dab5c10c8851adcc2b5ae8e7b8e210d
Reviewed-on: https://go-review.googlesource.com/c/exp/+/429436
Reviewed-by: Alan Donovan <adon...@google.com>
Run-TryBot: Jonathan Amsterdam <j...@google.com>
---
A slog/logger.go
A slog/logger_test.go
M slog/record.go
3 files changed, 596 insertions(+), 0 deletions(-)
diff --git a/slog/logger.go b/slog/logger.go
new file mode 100644
index 0000000..e653e27
--- /dev/null
+++ b/slog/logger.go
@@ -0,0 +1,237 @@
+// Copyright 2022 The Go Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style
+// license that can be found in the LICENSE file.
+
+package slog
+
+import (
+ "log"
+ "sync/atomic"
+ "time"
+)
+
+var defaultLogger atomic.Value
+
+func init() {
+ defaultLogger.Store(&Logger{
+ handler: &defaultHandler{},
+ })
+}
+
+// Default returns the default Logger.
+func Default() *Logger { return defaultLogger.Load().(*Logger) }
+
+// SetDefault makes l the default Logger.
+// After this call, output from the log package's default Logger
+// (as with [log.Print], etc.) will be logged at InfoLevel using l's Handler.
+func SetDefault(l *Logger) {
+ defaultLogger.Store(l)
+ log.SetOutput(&handlerWriter{l.Handler(), log.Flags()})
+ log.SetFlags(0) // we want just the log message, no time or location
+}
+
+// handlerWriter is an io.Writer that calls a Handler.
+// It is used to link the default log.Logger to the default slog.Logger.
+type handlerWriter struct {
+ h Handler
+ flags int
+}
+
+func (w *handlerWriter) Write(buf []byte) (int, error) {
+ var depth int
+ if w.flags&(log.Lshortfile|log.Llongfile) != 0 {
+ depth = 2
+ }
+ // Remove final newline.
+ origLen := len(buf) // Report that the entire buf was written.
+ if len(buf) > 0 && buf[len(buf)-1] == '\n' {
+ buf = buf[:len(buf)-1]
+ }
+ r := MakeRecord(time.Now(), InfoLevel, string(buf), depth)
+ return origLen, w.h.Handle(r)
+}
+
+// A Logger records structured information about each call to its
+// Log, Debug, Info, Warn, and Error methods.
+// For each call, it creates a Record and passes it to a Handler.
+// Enabled reports whether l emits log records at the given level.+ var attr Attr
+ for len(args) > 0 {
+ attr, args = argsToAttr(args)
+ r.AddAttr(attr)
+ }
+}
+
+// argsToAttrs turns a prefix of the args slice into an Attr and returns
+// the unused portion of the slice.
+// If args[0] is an Attr, it returns it.
+// If args[0] is a string, it treats the first two elements as
+// a key-value pair.
+// Otherwise, it treats args[0] as a value with a missing key.
+func argsToAttr(args []any) (Attr, []any) {
+ switch x := args[0].(type) {
+ case string:
+ if len(args) == 1 {
+ return String(badKey, x), nil
+ }
+ return Any(x, args[1]), args[2:]
+
+ case Attr:
+ return x, args[1:]
+
+ default:
+ return Any(badKey, x), args[1:]
index 0000000..acee8d5
--- /dev/null
+++ b/slog/logger_test.go
@@ -0,0 +1,338 @@
+// Copyright 2022 The Go Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style
+// license that can be found in the LICENSE file.
+
+package slog
+
+import (
+ "bytes"
+ "io"
+ "log"
+ "path/filepath"
+ "regexp"
+ "runtime"+ var startLine int
+
+ check := func(count int) {
+ t.Helper()
+ const wantFile = "logger_test.go"
+ wantLine := startLine + count*2
+ gotFile, gotLine := h.r.SourceLine()
+ gotFile = filepath.Base(gotFile)
+ if gotFile != wantFile || gotLine != wantLine {
+ t.Errorf("got (%s, %d), want (%s, %d)", gotFile, gotLine, wantFile, wantLine)
+ }
+ }
+
+ logger := New(h)
+ SetDefault(logger)
+
+ // Calls to check must be one line apart.
+ // Determine line where calls start.
+ f, _ := runtime.CallersFrames([]uintptr{pc(2)}).Next()
+ startLine = f.Line + 4
+ // Do not change the number of lines between here and the call to check(0).
+
To view, visit change 429436. To unsubscribe, or for help writing mail filters, visit settings.
Bryan Mills (Gerrit)
Attention is currently required from: Jonathan Amsterdam.
1 comment:
Patchset:
Superseded.
This test is now failing on the builders with the same failure mode shown by the TryBots here.
(Why was this change merged without passing TryBots?)
To view, visit change 429436. To unsubscribe, or for help writing mail filters, visit settings.
Jonathan Amsterdam (Gerrit)
1 comment:
Patchset:
This test is now failing on the builders with the same failure mode shown by the TryBots here. […]
https://go-review.git.corp.google.com/c/exp/+/429836 should resolve all failing tests.
Initially the failures were elsewhere (exp/typeparams) and I didn't want to slow my velocity by tracking that down.
To view, visit change 429436. To unsubscribe, or for help writing mail filters, visit settings.
Bryan Mills (Gerrit)
1 comment:
Patchset:
https://go-review.git.corp.google.com/c/exp/+/429836 should resolve all failing tests.
It looks like a couple of the `darwin/amd64` builders and the `linux-amd64-race` builder are still reporting some failures after that CL; filed as #54978.
Initially the failures were elsewhere (exp/typeparams) and I didn't want to slow my velocity by tracking that down.
The `x/exp/typeparams` failures were fixed in CL 428875, which should have resolved easily with a `git codereview sync` (that fix was merged Sep. 6).
The test logs on PS1 also included failures in `x/exp/slog` — AFAICT the TryBots were reporting those failures from the start, just with some others mixed in.
To view, visit change 429436. To unsubscribe, or for help writing mail filters, visit settings.