From 5bb6cb71f09f8adc76d63f1c614f88236590da05 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Christoph=20St=C3=A4bler?= Date: Fri, 8 Oct 2021 13:08:15 +0200 Subject: [PATCH] Add zap-time-encoding flag MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Adds the --zap-time-encoding flag to specify the output format of the log timestamp. Allows: epoch (floating-point number of seconds since the Unix epoch), nanos (integer of nanoseconds since the Unix epoch), millis (floating-point number of milliseconds since the Unix epoch), iso8601 (ISO8601-formatted string with millisecond precision), rfc3339 (RFC3339-formatted string) and rfc3339nano (RFC3339-formatted string with nanosecond precision). Signed-off-by: Christoph Stäbler --- pkg/log/zap/flags.go | 38 +++++++++++++++++++ pkg/log/zap/zap.go | 20 ++++++++++ pkg/log/zap/zap_test.go | 84 ++++++++++++++++++++++++++++++----------- 3 files changed, 120 insertions(+), 22 deletions(-) diff --git a/pkg/log/zap/flags.go b/pkg/log/zap/flags.go index 3339655075..fb492b14da 100644 --- a/pkg/log/zap/flags.go +++ b/pkg/log/zap/flags.go @@ -128,3 +128,41 @@ func (ev *stackTraceFlag) String() string { func (ev *stackTraceFlag) Type() string { return "level" } + +type timeEncodingFlag struct { + setFunc func(zapcore.TimeEncoder) + value string +} + +var _ flag.Value = &timeEncodingFlag{} + +func (ev *timeEncodingFlag) String() string { + return ev.value +} + +func (ev *timeEncodingFlag) Type() string { + return "time-encoding" +} + +func (ev *timeEncodingFlag) Set(flagValue string) error { + val := strings.ToLower(flagValue) + switch val { + case "rfc3339nano": + ev.setFunc(zapcore.RFC3339NanoTimeEncoder) + case "rfc3339": + ev.setFunc(zapcore.RFC3339TimeEncoder) + case "iso8601": + ev.setFunc(zapcore.ISO8601TimeEncoder) + case "millis": + ev.setFunc(zapcore.EpochMillisTimeEncoder) + case "nanos": + ev.setFunc(zapcore.EpochNanosTimeEncoder) + case "epoch": + ev.setFunc(zapcore.EpochTimeEncoder) + default: + return fmt.Errorf("invalid time-encoding value \"%s\"", flagValue) + } + + ev.value = flagValue + return nil +} diff --git a/pkg/log/zap/zap.go b/pkg/log/zap/zap.go index 22eb5d771a..fb44c88e5b 100644 --- a/pkg/log/zap/zap.go +++ b/pkg/log/zap/zap.go @@ -167,6 +167,9 @@ type Options struct { // ZapOpts allows passing arbitrary zap.Options to configure on the // underlying Zap logger. ZapOpts []zap.Option + // TimeEncoder specifies the encoder for the timestamps in log messages. + // Defaults to EpochTimeEncoder as this is the default in Zap currently. + TimeEncoder zapcore.TimeEncoder } // addDefaults adds defaults to the Options. @@ -212,6 +215,16 @@ func (o *Options) addDefaults() { })) } } + + if o.TimeEncoder == nil { + o.TimeEncoder = zapcore.EpochTimeEncoder + } + f := func(ecfg *zapcore.EncoderConfig) { + ecfg.EncodeTime = o.TimeEncoder + } + // prepend instead of append it in case someone adds a time encoder option in it + o.EncoderConfigOptions = append([]EncoderConfigOption{f}, o.EncoderConfigOptions...) + if o.Encoder == nil { o.Encoder = o.NewEncoder(o.EncoderConfigOptions...) } @@ -273,6 +286,13 @@ func (o *Options) BindFlags(fs *flag.FlagSet) { } fs.Var(&stackVal, "zap-stacktrace-level", "Zap Level at and above which stacktraces are captured (one of 'info', 'error', 'panic').") + + // Set the time encoding + var timeEncoderVal timeEncodingFlag + timeEncoderVal.setFunc = func(fromFlag zapcore.TimeEncoder) { + o.TimeEncoder = fromFlag + } + fs.Var(&timeEncoderVal, "zap-time-encoding", "Zap time encoding (one of 'epoch', 'millis', 'nano', 'iso8601', 'rfc3339' or 'rfc3339nano'). Defaults to 'epoch'.") } // UseFlagOptions configures the logger to use the Options set by parsing zap option flags from the CLI. diff --git a/pkg/log/zap/zap_test.go b/pkg/log/zap/zap_test.go index 095fc54598..b714284da6 100644 --- a/pkg/log/zap/zap_test.go +++ b/pkg/log/zap/zap_test.go @@ -21,6 +21,7 @@ import ( "encoding/json" "flag" "os" + "reflect" "github.com/go-logr/logr" . "github.com/onsi/ginkgo" @@ -472,35 +473,76 @@ var _ = Describe("Zap log level flag options setup", func() { }) }) - Context("with encoder options provided programmatically", func() { + Context("with zap-time-encoding flag provided", func() { + + It("Should set time encoder in options", func() { + args := []string{"--zap-time-encoding=rfc3339"} + fromFlags.BindFlags(&fs) + err := fs.Parse(args) + Expect(err).ToNot(HaveOccurred()) + + opt := Options{} + UseFlagOptions(&fromFlags)(&opt) + opt.addDefaults() + + optVal := reflect.ValueOf(opt.TimeEncoder) + expVal := reflect.ValueOf(zapcore.RFC3339TimeEncoder) + + Expect(optVal.Pointer()).To(Equal(expVal.Pointer())) + }) + + It("Should default to 'epoch' time encoding", func() { + args := []string{""} + fromFlags.BindFlags(&fs) + err := fs.Parse(args) + Expect(err).ToNot(HaveOccurred()) + + opt := Options{} + UseFlagOptions(&fromFlags)(&opt) + opt.addDefaults() + + optVal := reflect.ValueOf(opt.TimeEncoder) + expVal := reflect.ValueOf(zapcore.EpochTimeEncoder) + + Expect(optVal.Pointer()).To(Equal(expVal.Pointer())) + }) + + It("Should return an error message, with unknown time-encoding", func() { + fs = *flag.NewFlagSet(os.Args[0], flag.ContinueOnError) + args := []string{"--zap-time-encoding=foobar"} + fromFlags.BindFlags(&fs) + err := fs.Parse(args) + Expect(err).To(HaveOccurred()) + }) + + It("Should propagate time encoder to logger", func() { + // zaps ISO8601TimeEncoder uses 2006-01-02T15:04:05.000Z0700 as pattern for iso8601 encoding + iso8601Pattern := `^[0-9]{4}-[0-9]{2}-[0-9]{2}T[0-9]{2}:[0-9]{2}:[0-9]{2}.[0-9]{3}(\+[0-9]{4}|Z)` - It("Should set Console Encoder, with given Nanos TimeEncoder option.", func() { + args := []string{"--zap-time-encoding=iso8601"} + fromFlags.BindFlags(&fs) + err := fs.Parse(args) + Expect(err).ToNot(HaveOccurred()) logOut := new(bytes.Buffer) - f := func(ec *zapcore.EncoderConfig) { - if err := ec.EncodeTime.UnmarshalText([]byte("nanos")); err != nil { - Expect(err).ToNot(HaveOccurred()) - } - } - opts := func(o *Options) { - o.EncoderConfigOptions = append(o.EncoderConfigOptions, f) - } - log := New(UseDevMode(true), WriteTo(logOut), opts) - log.Info("This is a test message") + + logger := New(UseFlagOptions(&fromFlags), WriteTo(logOut)) + logger.Info("This is a test message") + outRaw := logOut.Bytes() - // Assert for Console Encoder - res := map[string]interface{}{} - Expect(json.Unmarshal(outRaw, &res)).ToNot(Succeed()) - // Assert for Epoch Nanos TimeEncoder - Expect(string(outRaw)).ShouldNot(ContainSubstring(".")) + res := map[string]interface{}{} + Expect(json.Unmarshal(outRaw, &res)).To(Succeed()) + Expect(res["ts"]).Should(MatchRegexp(iso8601Pattern)) }) + + }) + + Context("with encoder options provided programmatically", func() { + It("Should set JSON Encoder, with given Millis TimeEncoder option, and MessageKey", func() { logOut := new(bytes.Buffer) f := func(ec *zapcore.EncoderConfig) { ec.MessageKey = "MillisTimeFormat" - if err := ec.EncodeTime.UnmarshalText([]byte("millis")); err != nil { - Expect(err).ToNot(HaveOccurred()) - } } opts := func(o *Options) { o.EncoderConfigOptions = append(o.EncoderConfigOptions, f) @@ -511,8 +553,6 @@ var _ = Describe("Zap log level flag options setup", func() { // Assert for JSON Encoder res := map[string]interface{}{} Expect(json.Unmarshal(outRaw, &res)).To(Succeed()) - // Assert for Epoch Nanos TimeEncoder - Expect(string(outRaw)).Should(ContainSubstring(".")) // Assert for MessageKey Expect(string(outRaw)).Should(ContainSubstring("MillisTimeFormat")) })