slog: redesign Record
- Return to the implementation consisting of an inline array followed
by a slice.
- Document the alias problems that can arise.
- Provide Record.Clone to make a deep copy so aliasing bugs can be
avoided.
- Replace AddAttr with AddAttrs, to permit more efficiently adding
Attrs, and to provide more implementation flexibility.
- Eliminate random access: support only forward iteration.
Accomplish it with a method that takes a func(Attr).
Call this method "Attrs"; the old "Attrs", which returned a []Attr,
can now be written in terms of the new one.
We do not provide a way to stop iteration early, because the
large majority of uses will want to visit all the Attrs.
- Call the constructor NewRecord, not MakeRecord, because Record isn't
truly a value type.
Change-Id: Iac6843cd8a27e351fc4bde79aa59c6cc2e526e46
Reviewed-on: https://go-review.googlesource.com/c/exp/+/431276
Reviewed-by: Alan Donovan <adonovan@google.com>
Run-TryBot: Jonathan Amsterdam <jba@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
diff --git a/slog/handler.go b/slog/handler.go
index 964db60..a180e47 100644
--- a/slog/handler.go
+++ b/slog/handler.go
@@ -57,10 +57,10 @@
b.WriteString(r.Level().String())
b.WriteByte(' ')
}
- for i := 0; i < r.NumAttrs(); i++ {
- fmt.Fprint(&b, r.Attr(i)) // Attr.Format will print key=value
+ r.Attrs(func(a Attr) {
+ fmt.Fprint(&b, a) // Attr.Format will print key=value
b.WriteByte(' ')
- }
+ })
b.WriteString(r.Message())
return log.Output(4, b.String())
}
@@ -205,13 +205,12 @@
replace(String(key, val))
}
*buf = append(*buf, h.preformattedAttrs...)
- for i := 0; i < r.NumAttrs(); i++ {
- a := r.Attr(i)
+ r.Attrs(func(a Attr) {
if rep != nil {
a = rep(a)
}
appendAttr(app, a)
- }
+ })
app.appendEnd()
buf.WriteByte('\n')
diff --git a/slog/handler_test.go b/slog/handler_test.go
index 3b90dea..8f72301 100644
--- a/slog/handler_test.go
+++ b/slog/handler_test.go
@@ -36,10 +36,8 @@
func TestCommonHandle(t *testing.T) {
tm := time.Now()
- r := MakeRecord(tm, InfoLevel, "message", 1)
- r.AddAttr(String("a", "one"))
- r.AddAttr(Int("b", 2))
- r.AddAttr(Any("", "ignore me"))
+ r := NewRecord(tm, InfoLevel, "message", 1)
+ r.AddAttrs(String("a", "one"), Int("b", 2), Any("", "ignore me"))
for _, test := range []struct {
name string
diff --git a/slog/json_handler_test.go b/slog/json_handler_test.go
index 371c6b3..48e82c0 100644
--- a/slog/json_handler_test.go
+++ b/slog/json_handler_test.go
@@ -21,8 +21,8 @@
func TestJSONHandler(t *testing.T) {
var buf bytes.Buffer
h := NewJSONHandler(&buf)
- r := MakeRecord(testTime, InfoLevel, "m", 0)
- r.AddAttr(Int("a", 1))
+ r := NewRecord(testTime, InfoLevel, "m", 0)
+ r.AddAttrs(Int("a", 1))
if err := h.Handle(r); err != nil {
t.Fatal(err)
}
diff --git a/slog/logger.go b/slog/logger.go
index 52b8f2c..5464212 100644
--- a/slog/logger.go
+++ b/slog/logger.go
@@ -47,7 +47,7 @@
if len(buf) > 0 && buf[len(buf)-1] == '\n' {
buf = buf[:len(buf)-1]
}
- r := MakeRecord(time.Now(), InfoLevel, string(buf), depth)
+ r := NewRecord(time.Now(), InfoLevel, string(buf), depth)
return origLen, w.h.Handle(r)
}
@@ -113,7 +113,7 @@
return
}
r := l.makeRecord(msg, level, calldepth)
- setAttrs(&r, args)
+ r.setAttrsFromArgs(args)
_ = l.Handler().Handle(r)
}
@@ -127,39 +127,7 @@
if useSourceLine {
depth += 5
}
- return MakeRecord(time.Now(), level, msg, depth)
-}
-
-const badKey = "!BADKEY"
-
-func setAttrs(r *Record, args []any) {
- var attr Attr
- for len(args) > 0 {
- attr, args = argsToAttr(args)
- r.AddAttr(attr)
- }
-}
-
-// argsToAttr 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:]
- }
+ return NewRecord(time.Now(), level, msg, depth)
}
// LogAttrs is a more efficient version of [Logger.Log] that accepts only Attrs.
@@ -174,7 +142,7 @@
return
}
r := l.makeRecord(msg, level, calldepth)
- r.addAttrs(attrs)
+ r.AddAttrs(attrs...)
_ = l.Handler().Handle(r)
}
diff --git a/slog/logger_test.go b/slog/logger_test.go
index f6fcb16..7d7bd73 100644
--- a/slog/logger_test.go
+++ b/slog/logger_test.go
@@ -91,7 +91,7 @@
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))
+ check(attrsSlice(h.r), Int("c", 3))
}
func TestCallDepth(t *testing.T) {
@@ -199,7 +199,7 @@
s := "abc"
i := 2000
d := time.Second
- wantAllocs(t, 10, func() {
+ wantAllocs(t, 11, func() {
dl.Info("hello",
"n", i, "s", s, "d", d,
"n", i, "s", s, "d", d,
@@ -253,9 +253,9 @@
{[]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()
+ r := NewRecord(time.Time{}, 0, "", 0)
+ r.setAttrsFromArgs(test.args)
+ got := attrsSlice(r)
if !attrsEqual(got, test.want) {
t.Errorf("%v:\ngot %v\nwant %v", test.args, got, test.want)
}
diff --git a/slog/record.go b/slog/record.go
index 0f78a96..d54afb1 100644
--- a/slog/record.go
+++ b/slog/record.go
@@ -12,6 +12,9 @@
const nAttrsInline = 5
// A Record holds information about a log event.
+// Copies of a Record share state.
+// Do not modify a Record after handing out a copy to it.
+// Use [Record.Clone] to create a copy with no shared state.
type Record struct {
// The time at which the output method (Log, Info, etc.) was called.
time time.Time
@@ -28,26 +31,28 @@
// Allocation optimization: an inline array sized to hold
// the majority of log calls (based on examination of open-source
- // code). The array holds the end of the sequence of Attrs.
- tail [nAttrsInline]Attr
+ // code). It holds the start of the list of Attrs.
+ front [nAttrsInline]Attr
- // The number of Attrs in tail.
- nTail int
+ // The number of Attrs in front.
+ nFront int
- // The sequence of Attrs except for the tail, represented as a functional
- // list of arrays.
- attrs list[[nAttrsInline]Attr]
+ // The list of Attrs except for those in front.
+ // Invariants:
+ // - len(back) > 0 iff nFront == len(front)
+ // - Unused array elements are zero. Used to detect mistakes.
+ back []Attr
}
-// MakeRecord creates a new Record from the given arguments.
-// Use [Record.AddAttr] to add attributes to the Record.
+// NewRecord creates a Record from the given arguments.
+// Use [Record.AddAttrs] to add attributes to the Record.
// If calldepth is greater than zero, [Record.SourceLine] will
// return the file and line number at that depth,
-// where 1 means the caller of MakeRecord.
+// where 1 means the caller of NewRecord.
//
-// MakeRecord is intended for logging APIs that want to support a [Handler] as
+// NewRecord is intended for logging APIs that want to support a [Handler] as
// a backend.
-func MakeRecord(t time.Time, level Level, msg string, calldepth int) Record {
+func NewRecord(t time.Time, level Level, msg string, calldepth int) Record {
var p uintptr
if calldepth > 0 {
p = pc(calldepth + 1)
@@ -85,50 +90,97 @@
return f.File, f.Line
}
-// Attrs returns a copy of the sequence of Attrs in r.
-func (r *Record) Attrs() []Attr {
- res := make([]Attr, 0, r.attrs.len()*nAttrsInline+r.nTail)
- r.attrs = r.attrs.normalize()
- for _, f := range r.attrs.front {
- res = append(res, f[:]...)
+// Clone returns a copy of the record with no shared state.
+// The original record and the clone can both be modified
+// without interfering with each other.
+func (r *Record) Clone() Record {
+ c := *r
+ if len(c.back) > 0 {
+ c.back = make([]Attr, len(c.back))
+ copy(c.back, r.back)
}
- for _, a := range r.tail[:r.nTail] {
- res = append(res, a)
- }
- return res
+ return c
}
-// NumAttrs returns the number of Attrs in r.
+// NumAttrs returns the number of attributes in the Record.
func (r *Record) NumAttrs() int {
- return r.attrs.len()*nAttrsInline + r.nTail
+ return r.nFront + len(r.back)
}
-// Attr returns the i'th Attr in r.
-func (r *Record) Attr(i int) Attr {
- if r.attrs.back != nil {
- r.attrs = r.attrs.normalize()
+// Attrs calls f on each Attr in the Record.
+func (r *Record) Attrs(f func(Attr)) {
+ for i := 0; i < r.nFront; i++ {
+ f(r.front[i])
}
- alen := r.attrs.len() * nAttrsInline
- if i < alen {
- return r.attrs.at(i / nAttrsInline)[i%nAttrsInline]
+ for _, a := range r.back {
+ f(a)
}
- return r.tail[i-alen]
}
-// AddAttr appends an attributes to the record's list of attributes.
-// It does not check for duplicate keys.
-func (r *Record) AddAttr(a Attr) {
- if r.nTail == len(r.tail) {
- r.attrs = r.attrs.append(r.tail)
- r.nTail = 0
+// AddAttrs appends the given attrs to the Record's list of Attrs.
+func (r *Record) AddAttrs(attrs ...Attr) {
+ n := copy(r.front[r.nFront:], attrs)
+ r.nFront += n
+ // Check if a copy was modified by slicing past the end
+ // and seeing if the Attr there is non-zero.
+ if cap(r.back) > len(r.back) {
+ end := r.back[:len(r.back)+1][len(r.back)]
+ if end != (Attr{}) {
+ panic("copies of a slog.Record were both modified")
+ }
}
- r.tail[r.nTail] = a
- r.nTail++
+ r.back = append(r.back, attrs[n:]...)
}
-func (r *Record) addAttrs(attrs []Attr) {
- // TODO: be cleverer.
- for _, a := range attrs {
- r.AddAttr(a)
+func (r *Record) setAttrsFromArgs(args []any) {
+ var a Attr
+ for len(args) > 0 {
+ a, args = argsToAttr(args)
+ if r.nFront < len(r.front) {
+ r.front[r.nFront] = a
+ r.nFront++
+ } else {
+ if r.back == nil {
+ r.back = make([]Attr, 0, countAttrs(args))
+ }
+ r.back = append(r.back, a)
+ }
+ }
+
+}
+
+// countAttrs returns the number of Attrs that would be created from args.
+func countAttrs(args []any) int {
+ n := 0
+ for i := 0; i < len(args); i++ {
+ n++
+ if _, ok := args[i].(string); ok {
+ i++
+ }
+ }
+ return n
+}
+
+const badKey = "!BADKEY"
+
+// argsToAttr turns a prefix of the nonempty args slice into an Attr
+// and returns the unconsumed 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:]
}
}
diff --git a/slog/record_test.go b/slog/record_test.go
index 72baf4e..e526d24 100644
--- a/slog/record_test.go
+++ b/slog/record_test.go
@@ -20,7 +20,7 @@
if g, w := r.NumAttrs(), len(as); g != w {
t.Errorf("NumAttrs: got %d, want %d", g, w)
}
- if got := r.Attrs(); !attrsEqual(got, as) {
+ if got := attrsSlice(r); !attrsEqual(got, as) {
t.Errorf("got %v, want %v", got, as)
}
}
@@ -36,7 +36,7 @@
{-16, "", false},
{1, "record.go", true},
} {
- r := MakeRecord(time.Time{}, 0, "", test.depth)
+ r := NewRecord(time.Time{}, 0, "", test.depth)
gotFile, gotLine := r.SourceLine()
if i := strings.LastIndexByte(gotFile, '/'); i >= 0 {
gotFile = gotFile[i+1:]
@@ -48,7 +48,7 @@
}
}
-func TestAliasing(t *testing.T) {
+func TestAliasingAndClone(t *testing.T) {
intAttrs := func(from, to int) []Attr {
var as []Attr
for i := from; i < to; i++ {
@@ -57,38 +57,50 @@
return as
}
- check := func(r *Record, want []Attr) {
+ check := func(r Record, want []Attr) {
t.Helper()
- got := r.Attrs()
+ got := attrsSlice(r)
if !attrsEqual(got, want) {
t.Errorf("got %v, want %v", got, want)
}
}
- r1 := MakeRecord(time.Time{}, 0, "", 0)
- for i := 0; i < nAttrsInline+3; i++ {
- r1.AddAttr(Int("k", i))
- }
- check(&r1, intAttrs(0, nAttrsInline+3))
+ // Create a record whose Attrs overflow the inline array,
+ // creating a slice in r.back.
+ r1 := NewRecord(time.Time{}, 0, "", 0)
+ r1.AddAttrs(intAttrs(0, nAttrsInline+1)...)
+ // Ensure that r1.back's capacity exceeds its length.
+ b := make([]Attr, len(r1.back), len(r1.back)+1)
+ copy(b, r1.back)
+ r1.back = b
+ // Make a copy that shares state.
r2 := r1
- check(&r2, intAttrs(0, nAttrsInline+3))
- // if cap(r1.attrs2) <= len(r1.attrs2) {
- // t.Fatal("cap not greater than len")
- // }
- r1.AddAttr(Int("k", nAttrsInline+3))
- r2.AddAttr(Int("k", -1))
- check(&r1, intAttrs(0, nAttrsInline+4))
- check(&r2, append(intAttrs(0, nAttrsInline+3), Int("k", -1)))
+ // Adding to both should panic.
+ r1.AddAttrs(Int("p", 0))
+ if !panics(func() { r2.AddAttrs(Int("p", 1)) }) {
+ t.Error("expected panic")
+ }
+ r1Attrs := attrsSlice(r1)
+ // Adding to a clone is fine.
+ r2 = r1.Clone()
+ check(r2, r1Attrs)
+ r2.AddAttrs(Int("p", 2))
+ check(r1, r1Attrs) // r1 is unchanged
+ check(r2, append(slices.Clip(r1Attrs), Int("p", 2)))
}
func newRecordWithAttrs(as []Attr) Record {
- r := MakeRecord(time.Now(), InfoLevel, "", 0)
- for _, a := range as {
- r.AddAttr(a)
- }
+ r := NewRecord(time.Now(), InfoLevel, "", 0)
+ r.AddAttrs(as...)
return r
}
+func attrsSlice(r Record) []Attr {
+ s := make([]Attr, 0, r.NumAttrs())
+ r.Attrs(func(a Attr) { s = append(s, a) })
+ return s
+}
+
func attrsEqual(as1, as2 []Attr) bool {
return slices.EqualFunc(as1, as2, Attr.Equal)
}
@@ -105,7 +117,7 @@
}
func BenchmarkSourceLine(b *testing.B) {
- r := MakeRecord(time.Now(), InfoLevel, "", 5)
+ r := NewRecord(time.Now(), InfoLevel, "", 5)
b.Run("alone", func(b *testing.B) {
for i := 0; i < b.N; i++ {
file, line := r.SourceLine()
@@ -132,13 +144,11 @@
var a Attr
for i := 0; i < b.N; i++ {
- r := MakeRecord(time.Time{}, InfoLevel, "", 0)
+ r := NewRecord(time.Time{}, InfoLevel, "", 0)
for j := 0; j < nAttrs; j++ {
- r.AddAttr(Int("k", j))
+ r.AddAttrs(Int("k", j))
}
- for j := 0; j < nAttrs; j++ {
- a = r.Attr(j)
- }
+ r.Attrs(func(b Attr) { a = b })
}
_ = a
}
diff --git a/slog/text_handler_test.go b/slog/text_handler_test.go
index f95d735..055652b 100644
--- a/slog/text_handler_test.go
+++ b/slog/text_handler_test.go
@@ -54,8 +54,8 @@
t.Run(test.name, func(t *testing.T) {
var buf bytes.Buffer
h := NewTextHandler(&buf)
- r := MakeRecord(testTime, InfoLevel, "a message", 0)
- r.AddAttr(test.attr)
+ r := NewRecord(testTime, InfoLevel, "a message", 0)
+ r.AddAttrs(test.attr)
if err := h.Handle(r); err != nil {
t.Fatal(err)
}
@@ -114,7 +114,7 @@
func TestTextHandlerSource(t *testing.T) {
var buf bytes.Buffer
h := HandlerOptions{AddSource: true}.NewTextHandler(&buf)
- r := MakeRecord(testTime, InfoLevel, "m", 2)
+ r := NewRecord(testTime, InfoLevel, "m", 2)
if err := h.Handle(r); err != nil {
t.Fatal(err)
}
@@ -142,8 +142,8 @@
var h Handler = NewTextHandler(&buf)
h = h.With([]Attr{Duration("dur", time.Minute), Bool("b", true)})
// Also test omitting time and level.
- r := MakeRecord(time.Time{}, 0, "m", 0)
- r.AddAttr(Int("a", 1))
+ r := NewRecord(time.Time{}, 0, "m", 0)
+ r.AddAttrs(Int("a", 1))
if err := h.Handle(r); err != nil {
t.Fatal(err)
}
@@ -155,9 +155,9 @@
}
func TestTextHandlerAlloc(t *testing.T) {
- r := MakeRecord(time.Now(), InfoLevel, "msg", 0)
+ r := NewRecord(time.Now(), InfoLevel, "msg", 0)
for i := 0; i < 10; i++ {
- r.AddAttr(Int("x = y", i))
+ r.AddAttrs(Int("x = y", i))
}
h := NewTextHandler(io.Discard)
wantAllocs(t, 0, func() { h.Handle(r) })
