From 5fe5ca9e806e866b269670f129e59ae5ea8fb4f0 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Chris=20Suszy=C5=84ski?= Date: Fri, 22 Apr 2022 13:44:55 +0200 Subject: [PATCH 1/7] Deterministic calc of POSIX return code for Fatal --- internal/exit/exit.go | 23 ++++++++++++----- internal/exit/exit_test.go | 23 ++++++++++++----- logger.go | 4 +-- logger_test.go | 10 ++++++- zapcore/entry.go | 53 ++++++++++++++++++++++++++------------ zapcore/entry_test.go | 23 ++++++++++++++++- 6 files changed, 102 insertions(+), 34 deletions(-) diff --git a/internal/exit/exit.go b/internal/exit/exit.go index dfc5b05fe..242a197f9 100644 --- a/internal/exit/exit.go +++ b/internal/exit/exit.go @@ -24,24 +24,32 @@ package exit import "os" -var real = func() { os.Exit(1) } +var realFn = func(code int) { os.Exit(code) } // Exit normally terminates the process by calling os.Exit(1). If the package // is stubbed, it instead records a call in the testing spy. +// Deprecated: use With() instead. func Exit() { - real() + With(1) +} + +// With terminates the process by calling os.Exit(code). If the package is +// stubbed, it instead records a call in the testing spy. +func With(code int) { + realFn(code) } // A StubbedExit is a testing fake for os.Exit. type StubbedExit struct { Exited bool - prev func() + Code int + prev func(code int) } // Stub substitutes a fake for the call to os.Exit(1). func Stub() *StubbedExit { - s := &StubbedExit{prev: real} - real = s.exit + s := &StubbedExit{prev: realFn} + realFn = s.exit return s } @@ -56,9 +64,10 @@ func WithStub(f func()) *StubbedExit { // Unstub restores the previous exit function. func (se *StubbedExit) Unstub() { - real = se.prev + realFn = se.prev } -func (se *StubbedExit) exit() { +func (se *StubbedExit) exit(code int) { se.Exited = true + se.Code = code } diff --git a/internal/exit/exit_test.go b/internal/exit/exit_test.go index 300cdc309..5ef632c4b 100644 --- a/internal/exit/exit_test.go +++ b/internal/exit/exit_test.go @@ -18,25 +18,34 @@ // OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN // THE SOFTWARE. -package exit +package exit_test import ( "testing" "github.com/stretchr/testify/assert" + "go.uber.org/zap/internal/exit" ) func TestStub(t *testing.T) { + type want struct { + exit bool + code int + } tests := []struct { - f func() - want bool + f func() + want }{ - {Exit, true}, - {func() {}, false}, + {func() { + exit.With(42) + }, want{exit: true, code: 42}}, + {exit.Exit, want{exit: true, code: 1}}, + {func() {}, want{}}, } for _, tt := range tests { - s := WithStub(tt.f) - assert.Equal(t, tt.want, s.Exited, "Stub captured unexpected exit value.") + s := exit.WithStub(tt.f) + assert.Equal(t, tt.want.exit, s.Exited, "Stub captured unexpected exit value.") + assert.Equal(t, tt.want.code, s.Code, "Stub captured unexpected exit value.") } } diff --git a/logger.go b/logger.go index 087c74222..3acb6e31a 100644 --- a/logger.go +++ b/logger.go @@ -288,9 +288,9 @@ func (log *Logger) check(lvl zapcore.Level, msg string) *zapcore.CheckedEntry { ce = ce.Should(ent, zapcore.WriteThenPanic) case zapcore.FatalLevel: onFatal := log.onFatal - // Noop is the default value for CheckWriteAction, and it leads to + // The nil is the default value for CheckWriteAction, and it leads to // continued execution after a Fatal which is unexpected. - if onFatal == zapcore.WriteThenNoop { + if onFatal == nil { onFatal = zapcore.WriteThenFatal } ce = ce.Should(ent, onFatal) diff --git a/logger_test.go b/logger_test.go index 6fbf12266..e070d4b3c 100644 --- a/logger_test.go +++ b/logger_test.go @@ -213,8 +213,15 @@ func TestLoggerAlwaysFatals(t *testing.T) { // Users can disable writing out fatal-level logs, but calls to logger.Fatal() // should still terminate the process. withLogger(t, FatalLevel+1, nil, func(logger *Logger, logs *observer.ObservedLogs) { - stub := exit.WithStub(func() { logger.Fatal("") }) + stub := exit.WithStub(func() { logger.Fatal("foo") }) assert.True(t, stub.Exited, "Expected calls to logger.Fatal to terminate process.") + assert.Equal(t, 1, stub.Code, "Expected calls to logger.Fatal to terminate process with predictable retcode.") + + logger = logger.WithOptions(OnFatal(zapcore.WriteThenPosixExitCode)) + err := errors.New("bar") + stub = exit.WithStub(func() { logger.Fatal("foo", Error(err)) }) + assert.True(t, stub.Exited, "Expected calls to logger.Fatal to terminate process.") + assert.Equal(t, 129, stub.Code, "Expected calls to logger.Fatal to terminate process with predictable retcode.") stub = exit.WithStub(func() { if ce := logger.Check(FatalLevel, ""); ce != nil { @@ -222,6 +229,7 @@ func TestLoggerAlwaysFatals(t *testing.T) { } }) assert.True(t, stub.Exited, "Expected calls to logger.Check(FatalLevel, ...) to terminate process.") + assert.Equal(t, 1, stub.Code, "Expected calls to logger.Check(FatalLevel, ...) to terminate process with predictable retcode.") assert.Equal(t, 0, logs.Len(), "Shouldn't write out logs when fatal-level logging is disabled.") }) diff --git a/zapcore/entry.go b/zapcore/entry.go index 0885505b7..4ebd64885 100644 --- a/zapcore/entry.go +++ b/zapcore/entry.go @@ -22,6 +22,7 @@ package zapcore import ( "fmt" + "hash/crc32" "runtime" "strings" "sync" @@ -154,18 +155,30 @@ type Entry struct { // CheckWriteAction indicates what action to take after a log entry is // processed. Actions are ordered in increasing severity. -type CheckWriteAction uint8 +type CheckWriteAction func(*CheckedEntry, []Field) -const ( +var ( // WriteThenNoop indicates that nothing special needs to be done. It's the // default behavior. - WriteThenNoop CheckWriteAction = iota + WriteThenNoop CheckWriteAction // WriteThenGoexit runs runtime.Goexit after Write. - WriteThenGoexit + WriteThenGoexit CheckWriteAction = func(ce *CheckedEntry, fields []Field) { + runtime.Goexit() + } // WriteThenPanic causes a panic after Write. - WriteThenPanic - // WriteThenFatal causes a fatal os.Exit after Write. - WriteThenFatal + WriteThenPanic CheckWriteAction = func(ce *CheckedEntry, fields []Field) { + panic(ce.Message) + } + // WriteThenFatal causes a fatal os.Exit(1) after Write. + WriteThenFatal CheckWriteAction = func(ce *CheckedEntry, fields []Field) { + exit.With(1) + } + // WriteThenPosixExitCode causes an os.Exit(code) after Write. The code is + // calculated deterministically from the message, or from attached error + // Field. + WriteThenPosixExitCode CheckWriteAction = func(ce *CheckedEntry, fields []Field) { + exit.With(retcode(ce, fields)) + } ) // CheckedEntry is an Entry together with a collection of Cores that have @@ -186,7 +199,9 @@ func (ce *CheckedEntry) reset() { ce.Entry = Entry{} ce.ErrorOutput = nil ce.dirty = false - ce.should = WriteThenNoop + if ce.should != nil { + ce.should = WriteThenNoop + } for i := range ce.cores { // don't keep references to cores ce.cores[i] = nil @@ -224,16 +239,11 @@ func (ce *CheckedEntry) Write(fields ...Field) { ce.ErrorOutput.Sync() } - should, msg := ce.should, ce.Message putCheckedEntry(ce) - switch should { - case WriteThenPanic: - panic(msg) - case WriteThenFatal: - exit.Exit() - case WriteThenGoexit: - runtime.Goexit() + // Terminal operation + if ce.should != nil { + ce.should(ce, fields) } } @@ -260,3 +270,14 @@ func (ce *CheckedEntry) Should(ent Entry, should CheckWriteAction) *CheckedEntry ce.should = should return ce } + +func retcode(ce *CheckedEntry, fields []Field) int { + msg := ce.Message + for _, field := range fields { + if field.Type == ErrorType { + msg = field.Interface.(error).Error() + break + } + } + return int(crc32.ChecksumIEEE([]byte(msg)))%254 + 1 +} diff --git a/zapcore/entry_test.go b/zapcore/entry_test.go index 4c2d67eae..af2f54fde 100644 --- a/zapcore/entry_test.go +++ b/zapcore/entry_test.go @@ -64,7 +64,7 @@ func TestPutNilEntry(t *testing.T) { assert.NotNil(t, ce, "Expected only non-nil CheckedEntries in pool.") assert.False(t, ce.dirty, "Unexpected dirty bit set.") assert.Nil(t, ce.ErrorOutput, "Non-nil ErrorOutput.") - assert.Equal(t, WriteThenNoop, ce.should, "Unexpected terminal behavior.") + assert.Nil(t, ce.should, "Unexpected terminal behavior.") assert.Equal(t, 0, len(ce.cores), "Expected empty slice of cores.") assert.True(t, cap(ce.cores) > 0, "Expected pooled CheckedEntries to pre-allocate slice of Cores.") } @@ -128,5 +128,26 @@ func TestCheckedEntryWrite(t *testing.T) { ce.Write() }) assert.True(t, stub.Exited, "Expected to exit when WriteThenFatal is set.") + assert.Equal(t, 1, stub.Code, "Expected to exit when WriteThenFatal is set.") + }) + + t.Run("WriteThenPosixExitCode", func(t *testing.T) { + var ce *CheckedEntry + ce = ce.Should(Entry{Message: "foo"}, WriteThenPosixExitCode) + stub := exit.WithStub(func() { + ce.Write() + }) + assert.True(t, stub.Exited, "Expected to exit when WriteThenPosixExitCode is set.") + assert.Equal(t, 38, stub.Code, "Expected to exit with specific code when WriteThenPosixExitCode is set.") + }) + + t.Run("Custom", func(t *testing.T) { + var called bool + var ce *CheckedEntry + ce = ce.Should(Entry{}, func(entry *CheckedEntry, fields []Field) { + called = true + }) + ce.Write() + assert.True(t, called, "Expected to call custom action after Write.") }) } From e6465c2bc08566ee1df801d2caceae00e200519e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Chris=20Suszy=C5=84ski?= Date: Tue, 26 Apr 2022 12:24:39 +0200 Subject: [PATCH 2/7] Adjusting to @abhinav review --- logger.go | 2 +- logger_test.go | 2 +- options.go | 7 +++++- zapcore/entry.go | 54 +++++++++++++++++++++++++------------------ zapcore/entry_test.go | 24 +++++++++++-------- 5 files changed, 55 insertions(+), 34 deletions(-) diff --git a/logger.go b/logger.go index 3acb6e31a..aee88fa06 100644 --- a/logger.go +++ b/logger.go @@ -42,7 +42,7 @@ type Logger struct { development bool addCaller bool - onFatal zapcore.CheckWriteAction // default is WriteThenFatal + onFatal zapcore.CheckWriteHook // default is WriteThenFatal name string errorOutput zapcore.WriteSyncer diff --git a/logger_test.go b/logger_test.go index e070d4b3c..497a21349 100644 --- a/logger_test.go +++ b/logger_test.go @@ -217,7 +217,7 @@ func TestLoggerAlwaysFatals(t *testing.T) { assert.True(t, stub.Exited, "Expected calls to logger.Fatal to terminate process.") assert.Equal(t, 1, stub.Code, "Expected calls to logger.Fatal to terminate process with predictable retcode.") - logger = logger.WithOptions(OnFatal(zapcore.WriteThenPosixExitCode)) + logger = logger.WithOptions(OnFatal(zapcore.WriteThenPosixExit)) err := errors.New("bar") stub = exit.WithStub(func() { logger.Fatal("foo", Error(err)) }) assert.True(t, stub.Exited, "Expected calls to logger.Fatal to terminate process.") diff --git a/options.go b/options.go index e9e66161f..e65175304 100644 --- a/options.go +++ b/options.go @@ -134,8 +134,13 @@ func IncreaseLevel(lvl zapcore.LevelEnabler) Option { // OnFatal sets the action to take on fatal logs. func OnFatal(action zapcore.CheckWriteAction) Option { + return OnFatalHook(action) +} + +// OnFatalHook allows to set a custom action to take on fatal logs. +func OnFatalHook(hook zapcore.CheckWriteHook) Option { return optionFunc(func(log *Logger) { - log.onFatal = action + log.onFatal = hook }) } diff --git a/zapcore/entry.go b/zapcore/entry.go index 4ebd64885..898d83e35 100644 --- a/zapcore/entry.go +++ b/zapcore/entry.go @@ -28,10 +28,9 @@ import ( "sync" "time" + "go.uber.org/multierr" "go.uber.org/zap/internal/bufferpool" "go.uber.org/zap/internal/exit" - - "go.uber.org/multierr" ) var ( @@ -153,33 +152,44 @@ type Entry struct { Stack string } +// CheckWriteHook allows to customize the action to take after a Fatal log entry +// is processed. +type CheckWriteHook interface { + OnWrite(*CheckedEntry, []Field) +} + // CheckWriteAction indicates what action to take after a log entry is // processed. Actions are ordered in increasing severity. -type CheckWriteAction func(*CheckedEntry, []Field) +type CheckWriteAction uint8 -var ( +const ( // WriteThenNoop indicates that nothing special needs to be done. It's the // default behavior. - WriteThenNoop CheckWriteAction + WriteThenNoop CheckWriteAction = iota // WriteThenGoexit runs runtime.Goexit after Write. - WriteThenGoexit CheckWriteAction = func(ce *CheckedEntry, fields []Field) { - runtime.Goexit() - } + WriteThenGoexit // WriteThenPanic causes a panic after Write. - WriteThenPanic CheckWriteAction = func(ce *CheckedEntry, fields []Field) { + WriteThenPanic + // WriteThenFatal causes an os.Exit(1) after Write. + WriteThenFatal + // WriteThenPosixExit causes an os.Exit(code) after Write. The exit code is + // calculated deterministically from the Fatal message, or from error Field + // if given. + WriteThenPosixExit +) + +func (a CheckWriteAction) OnWrite(ce *CheckedEntry, fields []Field) { + switch a { + case WriteThenGoexit: + runtime.Goexit() + case WriteThenPanic: panic(ce.Message) - } - // WriteThenFatal causes a fatal os.Exit(1) after Write. - WriteThenFatal CheckWriteAction = func(ce *CheckedEntry, fields []Field) { + case WriteThenFatal: exit.With(1) - } - // WriteThenPosixExitCode causes an os.Exit(code) after Write. The code is - // calculated deterministically from the message, or from attached error - // Field. - WriteThenPosixExitCode CheckWriteAction = func(ce *CheckedEntry, fields []Field) { + case WriteThenPosixExit: exit.With(retcode(ce, fields)) } -) +} // CheckedEntry is an Entry together with a collection of Cores that have // already agreed to log it. @@ -191,7 +201,7 @@ type CheckedEntry struct { Entry ErrorOutput WriteSyncer dirty bool // best-effort detection of pool misuse - should CheckWriteAction + should CheckWriteHook cores []Core } @@ -243,7 +253,7 @@ func (ce *CheckedEntry) Write(fields ...Field) { // Terminal operation if ce.should != nil { - ce.should(ce, fields) + ce.should.OnWrite(ce, fields) } } @@ -259,10 +269,10 @@ func (ce *CheckedEntry) AddCore(ent Entry, core Core) *CheckedEntry { return ce } -// Should sets this CheckedEntry's CheckWriteAction, which controls whether a +// Should sets this CheckedEntry's CheckWriteHook, which controls whether a // Core will panic or fatal after writing this log entry. Like AddCore, it's // safe to call on nil CheckedEntry references. -func (ce *CheckedEntry) Should(ent Entry, should CheckWriteAction) *CheckedEntry { +func (ce *CheckedEntry) Should(ent Entry, should CheckWriteHook) *CheckedEntry { if ce == nil { ce = getCheckedEntry() ce.Entry = ent diff --git a/zapcore/entry_test.go b/zapcore/entry_test.go index af2f54fde..a2242ef4b 100644 --- a/zapcore/entry_test.go +++ b/zapcore/entry_test.go @@ -131,23 +131,29 @@ func TestCheckedEntryWrite(t *testing.T) { assert.Equal(t, 1, stub.Code, "Expected to exit when WriteThenFatal is set.") }) - t.Run("WriteThenPosixExitCode", func(t *testing.T) { + t.Run("WriteThenPosixExit", func(t *testing.T) { var ce *CheckedEntry - ce = ce.Should(Entry{Message: "foo"}, WriteThenPosixExitCode) + ce = ce.Should(Entry{Message: "foo"}, WriteThenPosixExit) stub := exit.WithStub(func() { ce.Write() }) - assert.True(t, stub.Exited, "Expected to exit when WriteThenPosixExitCode is set.") - assert.Equal(t, 38, stub.Code, "Expected to exit with specific code when WriteThenPosixExitCode is set.") + assert.True(t, stub.Exited, "Expected to exit when WriteThenPosixExit is set.") + assert.Equal(t, 38, stub.Code, "Expected to exit with specific code when WriteThenPosixExit is set.") }) t.Run("Custom", func(t *testing.T) { - var called bool var ce *CheckedEntry - ce = ce.Should(Entry{}, func(entry *CheckedEntry, fields []Field) { - called = true - }) + hook := &customHook{} + ce = ce.Should(Entry{}, hook) ce.Write() - assert.True(t, called, "Expected to call custom action after Write.") + assert.True(t, hook.called, "Expected to call custom action after Write.") }) } + +type customHook struct { + called bool +} + +func (c *customHook) OnWrite(_ *CheckedEntry, _ []Field) { + c.called = true +} From 39c2ed3226e16313fc0b516b7fc0503b8b599ffe Mon Sep 17 00:00:00 2001 From: Sung Yoon Whang Date: Tue, 26 Apr 2022 11:11:20 -0700 Subject: [PATCH 3/7] Misc fixes --- logger.go | 4 +-- logger_test.go | 33 +++++++++++++++++------- options.go | 7 ++--- zapcore/entry.go | 59 ++++++++++++++++++++----------------------- zapcore/entry_test.go | 16 +++--------- 5 files changed, 60 insertions(+), 59 deletions(-) diff --git a/logger.go b/logger.go index aee88fa06..e04de7cb3 100644 --- a/logger.go +++ b/logger.go @@ -288,12 +288,12 @@ func (log *Logger) check(lvl zapcore.Level, msg string) *zapcore.CheckedEntry { ce = ce.Should(ent, zapcore.WriteThenPanic) case zapcore.FatalLevel: onFatal := log.onFatal - // The nil is the default value for CheckWriteAction, and it leads to + // nil is the default value for CheckWriteAction, and it leads to // continued execution after a Fatal which is unexpected. if onFatal == nil { onFatal = zapcore.WriteThenFatal } - ce = ce.Should(ent, onFatal) + ce = ce.After(ent, onFatal) case zapcore.DPanicLevel: if log.development { ce = ce.Should(ent, zapcore.WriteThenPanic) diff --git a/logger_test.go b/logger_test.go index 497a21349..c277fb513 100644 --- a/logger_test.go +++ b/logger_test.go @@ -213,15 +213,8 @@ func TestLoggerAlwaysFatals(t *testing.T) { // Users can disable writing out fatal-level logs, but calls to logger.Fatal() // should still terminate the process. withLogger(t, FatalLevel+1, nil, func(logger *Logger, logs *observer.ObservedLogs) { - stub := exit.WithStub(func() { logger.Fatal("foo") }) + stub := exit.WithStub(func() { logger.Fatal("") }) assert.True(t, stub.Exited, "Expected calls to logger.Fatal to terminate process.") - assert.Equal(t, 1, stub.Code, "Expected calls to logger.Fatal to terminate process with predictable retcode.") - - logger = logger.WithOptions(OnFatal(zapcore.WriteThenPosixExit)) - err := errors.New("bar") - stub = exit.WithStub(func() { logger.Fatal("foo", Error(err)) }) - assert.True(t, stub.Exited, "Expected calls to logger.Fatal to terminate process.") - assert.Equal(t, 129, stub.Code, "Expected calls to logger.Fatal to terminate process with predictable retcode.") stub = exit.WithStub(func() { if ce := logger.Check(FatalLevel, ""); ce != nil { @@ -229,7 +222,6 @@ func TestLoggerAlwaysFatals(t *testing.T) { } }) assert.True(t, stub.Exited, "Expected calls to logger.Check(FatalLevel, ...) to terminate process.") - assert.Equal(t, 1, stub.Code, "Expected calls to logger.Check(FatalLevel, ...) to terminate process with predictable retcode.") assert.Equal(t, 0, logs.Len(), "Shouldn't write out logs when fatal-level logging is disabled.") }) @@ -587,6 +579,29 @@ func TestLoggerCustomOnFatal(t *testing.T) { } } +type customWriteHook struct { + called bool +} + +func (h *customWriteHook) OnWrite(_ *zapcore.CheckedEntry, _ []Field) { + h.called = true +} + +func TestLoggerWithFatalHook(t *testing.T) { + h := &customWriteHook{} + withLogger(t, InfoLevel, opts(WithFatalHook(h)), func(logger *Logger, logs *observer.ObservedLogs) { + recovered := make(chan interface{}) + go func() { + defer func() { + recovered <- recover() + }() + logger.Fatal("") + }() + <-recovered + assert.True(t, h.called) + }) +} + func TestNopLogger(t *testing.T) { logger := NewNop() diff --git a/options.go b/options.go index e65175304..d6c3449ca 100644 --- a/options.go +++ b/options.go @@ -133,12 +133,13 @@ func IncreaseLevel(lvl zapcore.LevelEnabler) Option { } // OnFatal sets the action to take on fatal logs. +// Deprecated: Use WithFatalHook instead. func OnFatal(action zapcore.CheckWriteAction) Option { - return OnFatalHook(action) + return WithFatalHook(action) } -// OnFatalHook allows to set a custom action to take on fatal logs. -func OnFatalHook(hook zapcore.CheckWriteHook) Option { +// WithFatalHook sets a CheckWriteHook to run on fatal logs. +func WithFatalHook(hook zapcore.CheckWriteHook) Option { return optionFunc(func(log *Logger) { log.onFatal = hook }) diff --git a/zapcore/entry.go b/zapcore/entry.go index 898d83e35..80c5ff2da 100644 --- a/zapcore/entry.go +++ b/zapcore/entry.go @@ -22,7 +22,6 @@ package zapcore import ( "fmt" - "hash/crc32" "runtime" "strings" "sync" @@ -155,6 +154,7 @@ type Entry struct { // CheckWriteHook allows to customize the action to take after a Fatal log entry // is processed. type CheckWriteHook interface { + // OnWrite gets invoked when an entry is written OnWrite(*CheckedEntry, []Field) } @@ -172,25 +172,26 @@ const ( WriteThenPanic // WriteThenFatal causes an os.Exit(1) after Write. WriteThenFatal - // WriteThenPosixExit causes an os.Exit(code) after Write. The exit code is - // calculated deterministically from the Fatal message, or from error Field - // if given. - WriteThenPosixExit ) -func (a CheckWriteAction) OnWrite(ce *CheckedEntry, fields []Field) { +// OnWrite implements the OnWrite method to keep CheckWriteAction compatible +// with the new CheckWriteHook interface which deprecates CheckWriteAction. +func (a CheckWriteAction) OnWrite(ce *CheckedEntry, _ []Field) { switch a { case WriteThenGoexit: runtime.Goexit() case WriteThenPanic: panic(ce.Message) case WriteThenFatal: - exit.With(1) - case WriteThenPosixExit: - exit.With(retcode(ce, fields)) + exit.Exit() } } +var _ CheckWriteHook = WriteThenNoop +var _ CheckWriteHook = WriteThenGoexit +var _ CheckWriteHook = WriteThenPanic +var _ CheckWriteHook = WriteThenFatal + // CheckedEntry is an Entry together with a collection of Cores that have // already agreed to log it. // @@ -201,7 +202,7 @@ type CheckedEntry struct { Entry ErrorOutput WriteSyncer dirty bool // best-effort detection of pool misuse - should CheckWriteHook + after CheckWriteHook cores []Core } @@ -209,9 +210,7 @@ func (ce *CheckedEntry) reset() { ce.Entry = Entry{} ce.ErrorOutput = nil ce.dirty = false - if ce.should != nil { - ce.should = WriteThenNoop - } + ce.after = nil for i := range ce.cores { // don't keep references to cores ce.cores[i] = nil @@ -249,12 +248,11 @@ func (ce *CheckedEntry) Write(fields ...Field) { ce.ErrorOutput.Sync() } - putCheckedEntry(ce) - - // Terminal operation - if ce.should != nil { - ce.should.OnWrite(ce, fields) + hook := ce.after + if hook != nil { + hook.OnWrite(ce, fields) } + putCheckedEntry(ce) } // AddCore adds a Core that has agreed to log this CheckedEntry. It's intended to be @@ -269,25 +267,22 @@ func (ce *CheckedEntry) AddCore(ent Entry, core Core) *CheckedEntry { return ce } -// Should sets this CheckedEntry's CheckWriteHook, which controls whether a +// Should sets this CheckedEntry's CheckWriteAction, which controls whether a // Core will panic or fatal after writing this log entry. Like AddCore, it's // safe to call on nil CheckedEntry references. -func (ce *CheckedEntry) Should(ent Entry, should CheckWriteHook) *CheckedEntry { +// Deprecated: Use After(ent Entry, after CheckWriteHook) instead. +func (ce *CheckedEntry) Should(ent Entry, should CheckWriteAction) *CheckedEntry { + return ce.After(ent, should) +} + +// After sets this CheckEntry's CheckWriteHook, which will be called after this +// log entry has been written. It's safe to call this on nil CheckedEntry +// references. +func (ce *CheckedEntry) After(ent Entry, hook CheckWriteHook) *CheckedEntry { if ce == nil { ce = getCheckedEntry() ce.Entry = ent } - ce.should = should + ce.after = hook return ce } - -func retcode(ce *CheckedEntry, fields []Field) int { - msg := ce.Message - for _, field := range fields { - if field.Type == ErrorType { - msg = field.Interface.(error).Error() - break - } - } - return int(crc32.ChecksumIEEE([]byte(msg)))%254 + 1 -} diff --git a/zapcore/entry_test.go b/zapcore/entry_test.go index a2242ef4b..d04cad9e7 100644 --- a/zapcore/entry_test.go +++ b/zapcore/entry_test.go @@ -64,7 +64,7 @@ func TestPutNilEntry(t *testing.T) { assert.NotNil(t, ce, "Expected only non-nil CheckedEntries in pool.") assert.False(t, ce.dirty, "Unexpected dirty bit set.") assert.Nil(t, ce.ErrorOutput, "Non-nil ErrorOutput.") - assert.Nil(t, ce.should, "Unexpected terminal behavior.") + assert.Nil(t, ce.after, "Unexpected terminal behavior.") assert.Equal(t, 0, len(ce.cores), "Expected empty slice of cores.") assert.True(t, cap(ce.cores) > 0, "Expected pooled CheckedEntries to pre-allocate slice of Cores.") } @@ -131,20 +131,10 @@ func TestCheckedEntryWrite(t *testing.T) { assert.Equal(t, 1, stub.Code, "Expected to exit when WriteThenFatal is set.") }) - t.Run("WriteThenPosixExit", func(t *testing.T) { - var ce *CheckedEntry - ce = ce.Should(Entry{Message: "foo"}, WriteThenPosixExit) - stub := exit.WithStub(func() { - ce.Write() - }) - assert.True(t, stub.Exited, "Expected to exit when WriteThenPosixExit is set.") - assert.Equal(t, 38, stub.Code, "Expected to exit with specific code when WriteThenPosixExit is set.") - }) - - t.Run("Custom", func(t *testing.T) { + t.Run("After", func(t *testing.T) { var ce *CheckedEntry hook := &customHook{} - ce = ce.Should(Entry{}, hook) + ce = ce.After(Entry{}, hook) ce.Write() assert.True(t, hook.called, "Expected to call custom action after Write.") }) From 68e4105ef8649e3398c062b2eb97f14e7bb5a6e9 Mon Sep 17 00:00:00 2001 From: Sung Yoon Whang Date: Tue, 26 Apr 2022 14:17:31 -0700 Subject: [PATCH 4/7] coverage is good --- internal/exit/exit.go | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/internal/exit/exit.go b/internal/exit/exit.go index 242a197f9..187fe5bfe 100644 --- a/internal/exit/exit.go +++ b/internal/exit/exit.go @@ -24,7 +24,7 @@ package exit import "os" -var realFn = func(code int) { os.Exit(code) } +var _exit = os.Exit // Exit normally terminates the process by calling os.Exit(1). If the package // is stubbed, it instead records a call in the testing spy. @@ -36,7 +36,7 @@ func Exit() { // With terminates the process by calling os.Exit(code). If the package is // stubbed, it instead records a call in the testing spy. func With(code int) { - realFn(code) + _exit(code) } // A StubbedExit is a testing fake for os.Exit. @@ -48,8 +48,8 @@ type StubbedExit struct { // Stub substitutes a fake for the call to os.Exit(1). func Stub() *StubbedExit { - s := &StubbedExit{prev: realFn} - realFn = s.exit + s := &StubbedExit{prev: _exit} + _exit = s.exit return s } @@ -64,7 +64,7 @@ func WithStub(f func()) *StubbedExit { // Unstub restores the previous exit function. func (se *StubbedExit) Unstub() { - realFn = se.prev + _exit = se.prev } func (se *StubbedExit) exit(code int) { From 48f79d39231e5377f26cd915164fc71807571dde Mon Sep 17 00:00:00 2001 From: Abhinav Gupta Date: Tue, 26 Apr 2022 14:17:32 -0700 Subject: [PATCH 5/7] exit_test: Don't embed "want" --- internal/exit/exit_test.go | 8 +++----- 1 file changed, 3 insertions(+), 5 deletions(-) diff --git a/internal/exit/exit_test.go b/internal/exit/exit_test.go index 5ef632c4b..0f86a8844 100644 --- a/internal/exit/exit_test.go +++ b/internal/exit/exit_test.go @@ -33,12 +33,10 @@ func TestStub(t *testing.T) { code int } tests := []struct { - f func() - want + f func() + want want }{ - {func() { - exit.With(42) - }, want{exit: true, code: 42}}, + {func() { exit.With(42) }, want{exit: true, code: 42}}, {exit.Exit, want{exit: true, code: 1}}, {func() {}, want{}}, } From d24760669a8e25d111eaaf911026b69b3be14bc7 Mon Sep 17 00:00:00 2001 From: Abhinav Gupta Date: Tue, 26 Apr 2022 14:22:45 -0700 Subject: [PATCH 6/7] TestLoggerWithFatalHook: Simplify --- logger_test.go | 14 ++++---------- 1 file changed, 4 insertions(+), 10 deletions(-) diff --git a/logger_test.go b/logger_test.go index c277fb513..50f8c6599 100644 --- a/logger_test.go +++ b/logger_test.go @@ -588,17 +588,11 @@ func (h *customWriteHook) OnWrite(_ *zapcore.CheckedEntry, _ []Field) { } func TestLoggerWithFatalHook(t *testing.T) { - h := &customWriteHook{} - withLogger(t, InfoLevel, opts(WithFatalHook(h)), func(logger *Logger, logs *observer.ObservedLogs) { - recovered := make(chan interface{}) - go func() { - defer func() { - recovered <- recover() - }() - logger.Fatal("") - }() - <-recovered + var h customWriteHook + withLogger(t, InfoLevel, opts(WithFatalHook(&h)), func(logger *Logger, logs *observer.ObservedLogs) { + logger.Fatal("great sadness") assert.True(t, h.called) + assert.Equal(t, 1, logs.FilterLevelExact(FatalLevel).Len()) }) } From 7481e89537f7d1c6b723881fc49974429da56f9c Mon Sep 17 00:00:00 2001 From: Abhinav Gupta Date: Tue, 26 Apr 2022 14:29:06 -0700 Subject: [PATCH 7/7] CheckWriteHook: Simpler interface compliance check --- zapcore/entry.go | 5 +---- 1 file changed, 1 insertion(+), 4 deletions(-) diff --git a/zapcore/entry.go b/zapcore/entry.go index 80c5ff2da..b035915f1 100644 --- a/zapcore/entry.go +++ b/zapcore/entry.go @@ -187,10 +187,7 @@ func (a CheckWriteAction) OnWrite(ce *CheckedEntry, _ []Field) { } } -var _ CheckWriteHook = WriteThenNoop -var _ CheckWriteHook = WriteThenGoexit -var _ CheckWriteHook = WriteThenPanic -var _ CheckWriteHook = WriteThenFatal +var _ CheckWriteHook = CheckWriteAction(0) // CheckedEntry is an Entry together with a collection of Cores that have // already agreed to log it.