From 267a899d86c4973a9f471e2271554a99708ab3c9 Mon Sep 17 00:00:00 2001 From: Aleksandr Razumov Date: Fri, 8 Jan 2021 03:40:07 +0300 Subject: [PATCH] Add WithClock Option (#897) Add WithClock option to control the source of time for logged entries. Fixes #694 Co-authored-by: Abhinav Gupta --- clock.go | 38 ++++++++++++++++++++++++++++++++++++++ clock_test.go | 44 ++++++++++++++++++++++++++++++++++++++++++++ logger.go | 8 +++++--- options.go | 8 ++++++++ zapcore/entry.go | 4 ++-- 5 files changed, 97 insertions(+), 5 deletions(-) create mode 100644 clock.go create mode 100644 clock_test.go diff --git a/clock.go b/clock.go new file mode 100644 index 000000000..7d0e574ed --- /dev/null +++ b/clock.go @@ -0,0 +1,38 @@ +// Copyright (c) 2020 Uber Technologies, Inc. +// +// Permission is hereby granted, free of charge, to any person obtaining a copy +// of this software and associated documentation files (the "Software"), to deal +// in the Software without restriction, including without limitation the rights +// to use, copy, modify, merge, publish, distribute, sublicense, and/or sell +// copies of the Software, and to permit persons to whom the Software is +// furnished to do so, subject to the following conditions: +// +// The above copyright notice and this permission notice shall be included in +// all copies or substantial portions of the Software. +// +// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR +// IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, +// FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE +// AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER +// LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, +// OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN +// THE SOFTWARE. + +package zap + +import "time" + +// Clock is a source of time for logged entries. +type Clock interface { + // Now returns the current local time. + Now() time.Time +} + +// systemClock implements default Clock that uses system time. +type systemClock struct{} + +var _systemClock Clock = systemClock{} + +func (systemClock) Now() time.Time { + return time.Now() +} diff --git a/clock_test.go b/clock_test.go new file mode 100644 index 000000000..0e7bfd863 --- /dev/null +++ b/clock_test.go @@ -0,0 +1,44 @@ +// Copyright (c) 2020 Uber Technologies, Inc. +// +// Permission is hereby granted, free of charge, to any person obtaining a copy +// of this software and associated documentation files (the "Software"), to deal +// in the Software without restriction, including without limitation the rights +// to use, copy, modify, merge, publish, distribute, sublicense, and/or sell +// copies of the Software, and to permit persons to whom the Software is +// furnished to do so, subject to the following conditions: +// +// The above copyright notice and this permission notice shall be included in +// all copies or substantial portions of the Software. +// +// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR +// IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, +// FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE +// AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER +// LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, +// OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN +// THE SOFTWARE. + +package zap + +import ( + "testing" + "time" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + "go.uber.org/zap/zaptest/observer" +) + +type constantClock time.Time + +func (c constantClock) Now() time.Time { return time.Time(c) } + +func TestWithClock(t *testing.T) { + date := time.Date(2077, 1, 23, 10, 15, 13, 441, time.UTC) + clock := constantClock(date) + withLogger(t, DebugLevel, []Option{WithClock(clock)}, func(log *Logger, logs *observer.ObservedLogs) { + log.Info("") + require.Equal(t, 1, logs.Len(), "Expected only one log entry to be written.") + assert.Equal(t, date, logs.All()[0].Entry.Time, "Unexpected entry time.") + }) +} diff --git a/logger.go b/logger.go index bdcc5d666..c4b562640 100644 --- a/logger.go +++ b/logger.go @@ -26,7 +26,6 @@ import ( "os" "runtime" "strings" - "time" "go.uber.org/zap/zapcore" ) @@ -51,6 +50,8 @@ type Logger struct { addStack zapcore.LevelEnabler callerSkip int + + clock Clock } // New constructs a new Logger from the provided zapcore.Core and Options. If @@ -71,6 +72,7 @@ func New(core zapcore.Core, options ...Option) *Logger { core: core, errorOutput: zapcore.Lock(os.Stderr), addStack: zapcore.FatalLevel + 1, + clock: _systemClock, } return log.WithOptions(options...) } @@ -270,7 +272,7 @@ func (log *Logger) check(lvl zapcore.Level, msg string) *zapcore.CheckedEntry { // log message will actually be written somewhere. ent := zapcore.Entry{ LoggerName: log.name, - Time: time.Now(), + Time: log.clock.Now(), Level: lvl, Message: msg, } @@ -307,7 +309,7 @@ func (log *Logger) check(lvl zapcore.Level, msg string) *zapcore.CheckedEntry { if log.addCaller { frame, defined := getCallerFrame(log.callerSkip + callerSkipOffset) if !defined { - fmt.Fprintf(log.errorOutput, "%v Logger.check error: failed to get caller\n", time.Now().UTC()) + fmt.Fprintf(log.errorOutput, "%v Logger.check error: failed to get caller\n", ent.Time.UTC()) log.errorOutput.Sync() } diff --git a/options.go b/options.go index 0135c2092..336dbf804 100644 --- a/options.go +++ b/options.go @@ -138,3 +138,11 @@ func OnFatal(action zapcore.CheckWriteAction) Option { log.onFatal = action }) } + +// WithClock specifies the clock used by the logger to determine the current +// time for logged entries. Defaults to the system clock with time.Now. +func WithClock(clock Clock) Option { + return optionFunc(func(log *Logger) { + log.clock = clock + }) +} diff --git a/zapcore/entry.go b/zapcore/entry.go index 4aa8b4f90..2d815feb8 100644 --- a/zapcore/entry.go +++ b/zapcore/entry.go @@ -208,7 +208,7 @@ func (ce *CheckedEntry) Write(fields ...Field) { // If the entry is dirty, log an internal error; because the // CheckedEntry is being used after it was returned to the pool, // the message may be an amalgamation from multiple call sites. - fmt.Fprintf(ce.ErrorOutput, "%v Unsafe CheckedEntry re-use near Entry %+v.\n", time.Now(), ce.Entry) + fmt.Fprintf(ce.ErrorOutput, "%v Unsafe CheckedEntry re-use near Entry %+v.\n", ce.Time, ce.Entry) ce.ErrorOutput.Sync() } return @@ -221,7 +221,7 @@ func (ce *CheckedEntry) Write(fields ...Field) { } if ce.ErrorOutput != nil { if err != nil { - fmt.Fprintf(ce.ErrorOutput, "%v write error: %v\n", time.Now(), err) + fmt.Fprintf(ce.ErrorOutput, "%v write error: %v\n", ce.Time, err) ce.ErrorOutput.Sync() } }