From 55ed995bf08df2859e6e0da36b4a77358efef8f0 Mon Sep 17 00:00:00 2001 From: Devin Carr Date: Thu, 6 Apr 2023 11:31:47 -0700 Subject: [PATCH] TUN-7127: Disconnect logger level requirement for management By default, we want streaming logs to be able to stream debug logs from cloudflared without needing to update the remote cloudflared's configuration. This disconnects the provided local log level sent to console, file, etc. from the level that management tunnel will utilize via requested filters. --- logger/create.go | 38 ++++++++++++----- logger/create_test.go | 94 +++++++++++++++++++++++++++++++------------ management/logger.go | 2 +- 3 files changed, 98 insertions(+), 36 deletions(-) diff --git a/logger/create.go b/logger/create.go index 8b8fed23..d7a987e1 100644 --- a/logger/create.go +++ b/logger/create.go @@ -64,17 +64,36 @@ func fallbackLogger(err error) *zerolog.Logger { return &failLog } -type resilientMultiWriter struct { - writers []io.Writer -} - -// This custom resilientMultiWriter is an alternative to zerolog's so that we can make it resilient to individual +// resilientMultiWriter is an alternative to zerolog's so that we can make it resilient to individual // writer's errors. E.g., when running as a Windows service, the console writer fails, but we don't want to // allow that to prevent all logging to fail due to breaking the for loop upon an error. +type resilientMultiWriter struct { + level zerolog.Level + writers []io.Writer + managementWriter zerolog.LevelWriter +} + func (t resilientMultiWriter) Write(p []byte) (n int, err error) { for _, w := range t.writers { _, _ = w.Write(p) } + if t.managementWriter != nil { + _, _ = t.managementWriter.Write(p) + } + return len(p), nil +} + +func (t resilientMultiWriter) WriteLevel(level zerolog.Level, p []byte) (n int, err error) { + // Only write the event to normal writers if it exceeds the level, but always write to the + // management logger and let it decided with the provided level of the log event. + if t.level <= level { + for _, w := range t.writers { + _, _ = w.Write(p) + } + } + if t.managementWriter != nil { + _, _ = t.managementWriter.WriteLevel(level, p) + } return len(p), nil } @@ -105,17 +124,18 @@ func newZerolog(loggerConfig *Config) *zerolog.Logger { writers = append(writers, rollingLogger) } + var managementWriter zerolog.LevelWriter if features.Contains(features.FeatureManagementLogs) { - writers = append(writers, ManagementLogger) + managementWriter = ManagementLogger } - multi := resilientMultiWriter{writers} - level, levelErr := zerolog.ParseLevel(loggerConfig.MinLevel) if levelErr != nil { level = zerolog.InfoLevel } - log := zerolog.New(multi).With().Timestamp().Logger().Level(level) + + multi := resilientMultiWriter{level, writers, managementWriter} + log := zerolog.New(multi).With().Timestamp().Logger() if !levelErrorLogged && levelErr != nil { log.Error().Msgf("Failed to parse log level %q, using %q instead", loggerConfig.MinLevel, level) levelErrorLogged = true diff --git a/logger/create_test.go b/logger/create_test.go index 21ede396..2e0f9b96 100644 --- a/logger/create_test.go +++ b/logger/create_test.go @@ -9,14 +9,13 @@ import ( "github.com/stretchr/testify/assert" ) -var writeCalls int - type mockedWriter struct { - wantErr bool + wantErr bool + writeCalls int } -func (c mockedWriter) Write(p []byte) (int, error) { - writeCalls++ +func (c *mockedWriter) Write(p []byte) (int, error) { + c.writeCalls++ if c.wantErr { return -1, errors.New("Expected error") @@ -26,65 +25,108 @@ func (c mockedWriter) Write(p []byte) (int, error) { } // Tests that a new writer is only used if it actually works. -func TestResilientMultiWriter(t *testing.T) { +func TestResilientMultiWriter_Errors(t *testing.T) { tests := []struct { name string - writers []io.Writer + writers []*mockedWriter }{ { name: "All valid writers", - writers: []io.Writer{ - mockedWriter{ + writers: []*mockedWriter{ + { wantErr: false, }, - mockedWriter{ + { wantErr: false, }, }, }, { name: "All invalid writers", - writers: []io.Writer{ - mockedWriter{ + writers: []*mockedWriter{ + { wantErr: true, }, - mockedWriter{ + { wantErr: true, }, }, }, { name: "First invalid writer", - writers: []io.Writer{ - mockedWriter{ + writers: []*mockedWriter{ + { wantErr: true, }, - mockedWriter{ + { wantErr: false, }, }, }, { name: "First valid writer", - writers: []io.Writer{ - mockedWriter{ + writers: []*mockedWriter{ + { wantErr: false, }, - mockedWriter{ + { wantErr: true, }, }, }, } - for _, tt := range tests { - writers := tt.writers - multiWriter := resilientMultiWriter{writers} + for _, test := range tests { + t.Run(test.name, func(t *testing.T) { + writers := []io.Writer{} + for _, w := range test.writers { + writers = append(writers, w) + } + multiWriter := resilientMultiWriter{zerolog.InfoLevel, writers, nil} - logger := zerolog.New(multiWriter).With().Timestamp().Logger().Level(zerolog.InfoLevel) - logger.Info().Msg("Test msg") + logger := zerolog.New(multiWriter).With().Timestamp().Logger() + logger.Info().Msg("Test msg") - assert.Equal(t, len(writers), writeCalls) - writeCalls = 0 + for _, w := range test.writers { + // Expect each writer to be written to regardless of the previous writers returning an error + assert.Equal(t, 1, w.writeCalls) + } + }) + } +} + +type mockedManagementWriter struct { + WriteCalls int +} + +func (c *mockedManagementWriter) Write(p []byte) (int, error) { + return len(p), nil +} + +func (c *mockedManagementWriter) WriteLevel(level zerolog.Level, p []byte) (int, error) { + c.WriteCalls++ + return len(p), nil +} + +// Tests that management writer receives write calls of all levels except Disabled +func TestResilientMultiWriter_Management(t *testing.T) { + for _, level := range []zerolog.Level{ + zerolog.DebugLevel, + zerolog.InfoLevel, + zerolog.WarnLevel, + zerolog.ErrorLevel, + zerolog.FatalLevel, + zerolog.PanicLevel, + } { + t.Run(level.String(), func(t *testing.T) { + managementWriter := mockedManagementWriter{} + multiWriter := resilientMultiWriter{level, []io.Writer{&mockedWriter{}}, &managementWriter} + + logger := zerolog.New(multiWriter).With().Timestamp().Logger() + logger.Info().Msg("Test msg") + + // Always write to management + assert.Equal(t, 1, managementWriter.WriteCalls) + }) } } diff --git a/management/logger.go b/management/logger.go index 3af494a4..51e5a2b8 100644 --- a/management/logger.go +++ b/management/logger.go @@ -41,7 +41,7 @@ func NewLogger() *Logger { log := zerolog.New(zerolog.ConsoleWriter{ Out: os.Stdout, TimeFormat: time.RFC3339, - }).With().Timestamp().Logger().Level(zerolog.DebugLevel) + }).With().Timestamp().Logger().Level(zerolog.InfoLevel) return &Logger{ Log: &log, }