From de27361ffaf541cac4a9bf9e766d8fe4c5e88375 Mon Sep 17 00:00:00 2001 From: Nuno Diegues Date: Sat, 16 Jan 2021 15:56:44 +0000 Subject: [PATCH] TUN-3767: Tolerate logging errors This addresses a bug where logging would not be output when cloudflared was run as a Windows Service. That was happening because Windows Services have no stderr/out, and the ConsoleWriter log was failing inside zerolog, which would then not proceed to the next logger (the file logger). We now overcome that by using our own multi writer that is resilient to errors. --- logger/create.go | 17 ++++++++- logger/create_test.go | 89 +++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 105 insertions(+), 1 deletion(-) create mode 100644 logger/create_test.go diff --git a/logger/create.go b/logger/create.go index 7afd8fe5..7d8ff933 100644 --- a/logger/create.go +++ b/logger/create.go @@ -37,6 +37,21 @@ 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 +// 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. +func (t resilientMultiWriter) Write(p []byte) (n int, err error) { + for _, w := range t.writers { + _, _ = w.Write(p) + } + return len(p), nil +} + + func newZerolog(loggerConfig *Config) *zerolog.Logger { var writers []io.Writer @@ -62,7 +77,7 @@ func newZerolog(loggerConfig *Config) *zerolog.Logger { writers = append(writers, rollingLogger) } - multi := zerolog.MultiLevelWriter(writers...) + multi := resilientMultiWriter{writers} level, err := zerolog.ParseLevel(loggerConfig.MinLevel) if err != nil { diff --git a/logger/create_test.go b/logger/create_test.go new file mode 100644 index 00000000..2e503f9e --- /dev/null +++ b/logger/create_test.go @@ -0,0 +1,89 @@ +package logger + +import ( + "github.com/pkg/errors" + "github.com/rs/zerolog" + "github.com/stretchr/testify/assert" + "io" + "testing" +) + +var writeCalls int + +type mockedWriter struct { + wantErr bool +} + +func (c mockedWriter) Write(p []byte) (int, error) { + writeCalls++ + + if c.wantErr { + return -1, errors.New("Expected error") + } + + return len(p), nil +} + +// Tests that a new writer is only used if it actually works. +func TestResilientMultiWriter(t *testing.T) { + tests := []struct { + name string + writers []io.Writer + }{ + { + name: "All valid writers", + writers: []io.Writer{ + mockedWriter { + wantErr: false, + }, + mockedWriter { + wantErr: false, + }, + }, + }, + { + name: "All invalid writers", + writers: []io.Writer{ + mockedWriter { + wantErr: true, + }, + mockedWriter { + wantErr: true, + }, + }, + }, + { + name: "First invalid writer", + writers: []io.Writer{ + mockedWriter { + wantErr: true, + }, + mockedWriter { + wantErr: false, + }, + }, + }, + { + name: "First valid writer", + writers: []io.Writer{ + mockedWriter { + wantErr: false, + }, + mockedWriter { + wantErr: true, + }, + }, + }, + } + + for _, tt := range tests { + writers := tt.writers + multiWriter := resilientMultiWriter{writers} + + logger := zerolog.New(multiWriter).With().Timestamp().Logger().Level(zerolog.InfoLevel) + logger.Info().Msg("Test msg") + + assert.Equal(t, len(writers), writeCalls) + writeCalls = 0 + } +} \ No newline at end of file