Make MultiLevelWriter resilient to individual log failure (#282)

Fixes #281

Currently MultiLevelWriter would give up if any individual backing logger
failed. This could result in no logging ever happening if the bad logger
was set up in the first position.

As a motivating factor, this can happen in "normal" circumstances, such
as running as a Windows Service where stderr is not available and therefore
the ConsoleWriter will fail. If you happen to set it as the first logger,
then no logging ever takes place. To make matters worse, connecting a
debugger creates an stderr, so it made it a pretty daunting situation
to overcome.

The proposed solution is to go through all underlying loggers and return
the last error obtained, if any. In practice there isn't much being done
with those errors anyway, as the best way to address logging errors is
to hook a ErrorHandler, which will still be triggered despite this change.

Co-authored-by: Nuno Diegues <nuno@cloudflare.com>

writer.go

@@ -56,30 +56,30 @@ type multiLevelWriter struct {
 
 func (t multiLevelWriter) Write(p []byte) (n int, err error) {
 	for _, w := range t.writers {
-		n, err = w.Write(p)
-		if err != nil {
-			return
-		}
-		if n != len(p) {
-			err = io.ErrShortWrite
-			return
+		if _n, _err := w.Write(p); err == nil {
+			n = _n
+			if _err != nil {
+				err = _err
+			} else if _n != len(p) {
+				err = io.ErrShortWrite
+			}
 		}
 	}
-	return len(p), nil
+	return n, err
 }
 
 func (t multiLevelWriter) WriteLevel(l Level, p []byte) (n int, err error) {
 	for _, w := range t.writers {
-		n, err = w.WriteLevel(l, p)
-		if err != nil {
-			return
-		}
-		if n != len(p) {
-			err = io.ErrShortWrite
-			return
+		if _n, _err := w.WriteLevel(l, p); err == nil {
+			n = _n
+			if _err != nil {
+				err = _err
+			} else if _n != len(p) {
+				err = io.ErrShortWrite
+			}
 		}
 	}
-	return len(p), nil
+	return n, err
 }
 
 // MultiLevelWriter creates a writer that duplicates its writes to all the

writer_test.go

@@ -4,6 +4,8 @@
 package zerolog
 
 import (
+	"errors"
+	"io"
 	"reflect"
 	"testing"
 )
@@ -27,3 +29,85 @@ func TestMultiSyslogWriter(t *testing.T) {
 		t.Errorf("Invalid syslog message routing: want %v, got %v", want, got)
 	}
 }
+
+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 := MultiLevelWriter(writers...)
+
+		logger := New(multiWriter).With().Timestamp().Logger().Level(InfoLevel)
+		logger.Info().Msg("Test msg")
+
+		if len(writers) != writeCalls {
+			t.Errorf("Expected %d writers to have been called but only %d were.", len(writers), writeCalls)
+		}
+		writeCalls = 0
+	}
+}