Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Extend WithLazy() method to SugaredLogger #1378

Merged
merged 2 commits into from Nov 25, 2023
Merged
Show file tree
Hide file tree
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
15 changes: 15 additions & 0 deletions sugar.go
Expand Up @@ -115,6 +115,21 @@ func (s *SugaredLogger) With(args ...interface{}) *SugaredLogger {
return &SugaredLogger{base: s.base.With(s.sweetenFields(args)...)}
}

// WithLazy adds a variadic number of fields to the logging context lazily.
// The fields are evaluated only if the logger is further chained with [With]
// or is written to with any of the log level methods.
// Until that occurs, the logger may retain references to objects inside the fields,
// and logging will reflect the state of an object at the time of logging,
// not the time of WithLazy().
//
// Similar to [With], fields added to the child don't affect the parent,
// and vice versa. Also, the keys in key-value pairs should be strings. In development,
// passing a non-string key panics, while in production it logs an error and skips the pair.
// Passing an orphaned key has the same behavior.
func (s *SugaredLogger) WithLazy(args ...interface{}) *SugaredLogger {
return &SugaredLogger{base: s.base.WithLazy(s.sweetenFields(args)...)}
}

// Level reports the minimum enabled level for this logger.
//
// For NopLoggers, this is [zapcore.InvalidLevel].
Expand Down
99 changes: 91 additions & 8 deletions sugar_test.go
Expand Up @@ -22,6 +22,8 @@ package zap

import (
"errors"
"fmt"
"strconv"
"testing"

"go.uber.org/zap/internal/exit"
Expand Down Expand Up @@ -54,6 +56,9 @@ func TestSugarWith(t *testing.T) {
}
}

type withAny func(*SugaredLogger, ...interface{}) *SugaredLogger
withMethods := []withAny{(*SugaredLogger).With, (*SugaredLogger).WithLazy}

tests := []struct {
desc string
args []interface{}
Expand Down Expand Up @@ -141,16 +146,94 @@ func TestSugarWith(t *testing.T) {
}

for _, tt := range tests {
withSugar(t, DebugLevel, nil, func(logger *SugaredLogger, logs *observer.ObservedLogs) {
logger.With(tt.args...).Info("")
output := logs.AllUntimed()
if len(tt.errLogs) > 0 {
for i := range tt.errLogs {
assert.Equal(t, tt.errLogs[i], output[i], "Unexpected error log at position %d for scenario %s.", i, tt.desc)
for _, withMethod := range withMethods {
withSugar(t, DebugLevel, nil, func(logger *SugaredLogger, logs *observer.ObservedLogs) {
withMethod(logger, tt.args...).Info("")
output := logs.AllUntimed()
if len(tt.errLogs) > 0 {
for i := range tt.errLogs {
assert.Equal(t, tt.errLogs[i], output[i], "Unexpected error log at position %d for scenario %s.", i, tt.desc)
}
}
assert.Equal(t, len(tt.errLogs)+1, len(output), "Expected only one non-error message to be logged in scenario %s.", tt.desc)
assert.Equal(t, tt.expected, output[len(tt.errLogs)].Context, "Unexpected message context in scenario %s.", tt.desc)
})
}
}
}

func TestSugarWithCaptures(t *testing.T) {
type withAny func(*SugaredLogger, ...interface{}) *SugaredLogger

tests := []struct {
name string
withMethods []withAny
wantJSON []string
}{
{
name: "with captures arguments at time of With",
withMethods: []withAny{(*SugaredLogger).With},
wantJSON: []string{
`{
"m": "hello 0",
"a0": [0],
"b0": [1]
}`,
`{
"m": "world 0",
"a0": [0],
"c0": [2]
}`,
},
},
{
name: "lazy with captures arguments at time of With or Logging",
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I suspect that this may be a typo in the original zap.Logger PR, but I think the test case name should be "lazy with captures arguments at time of Logging"

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, I think so, fixed

withMethods: []withAny{(*SugaredLogger).WithLazy},
wantJSON: []string{
`{
"m": "hello 0",
"a0": [1],
"b0": [1]
}`,
`{
"m": "world 0",
"a0": [1],
"c0": [2]
}`,
},
},
}

for _, tt := range tests {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

https://github.com/uber-go/zap/pull/1319/files also has a few more scenarios for the capture tests. While you are testing some aspect of chained With and WithLazy, I think it makes sense to also test interleaved calls of With then WithLazy and vis-versa as well.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I was actually thinking about including those interleaved With and WithLazy tests at first. But then I thought, since lazyWithCore already covers what we need, maybe it’s better not to repeat the same stuff? I just focused on showing how With and WithLazy are different, especially with how WithLazy uses that extra core.

I'm totally fine with adding more tests if it really helps. What do you think?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I agree that there would be testing overlap between the two loggers.

I think it would be nice for zap to set up testing in a way that would be easy to verify sugared and non sugared behavior through the same process where they should be similar. However, that doesn't need to be part of this change.

t.Run(tt.name, func(t *testing.T) {
enc := zapcore.NewJSONEncoder(zapcore.EncoderConfig{
MessageKey: "m",
})

var bs ztest.Buffer
logger := New(zapcore.NewCore(enc, &bs, DebugLevel)).Sugar()

for i, withMethod := range tt.withMethods {
iStr := strconv.Itoa(i)
x := 10 * i
arr := zapcore.ArrayMarshalerFunc(func(enc zapcore.ArrayEncoder) error {
enc.AppendInt(x)
return nil
})

logger = withMethod(logger, Array("a"+iStr, arr))
x++
logger.Infow(fmt.Sprintf("hello %d", i), Array("b"+iStr, arr))
x++
logger = withMethod(logger, Array("c"+iStr, arr))
logger.Infow(fmt.Sprintf("world %d", i))
}

if lines := bs.Lines(); assert.Len(t, lines, len(tt.wantJSON)) {
for i, want := range tt.wantJSON {
assert.JSONEq(t, want, lines[i], "Unexpected output from the %d'th log.", i)
}
}
assert.Equal(t, len(tt.errLogs)+1, len(output), "Expected only one non-error message to be logged in scenario %s.", tt.desc)
assert.Equal(t, tt.expected, output[len(tt.errLogs)].Context, "Unexpected message context in scenario %s.", tt.desc)
})
}
}
Expand Down