logging: Fix log-file configuration. (#1453)

cmd/conduit/main.go

@@ -14,7 +14,6 @@ import (
 	"github.com/algorand/indexer/cmd/conduit/internal/list"
 	"github.com/algorand/indexer/conduit"
 	"github.com/algorand/indexer/conduit/pipeline"
-	// We need to import these so that the package wide init() function gets called
 	_ "github.com/algorand/indexer/conduit/plugins/exporters/all"
 	_ "github.com/algorand/indexer/conduit/plugins/importers/all"
 	_ "github.com/algorand/indexer/conduit/plugins/processors/all"
@@ -23,7 +22,6 @@ import (
 )
 
 var (
-	loggerManager        *loggers.LoggerManager
 	logger               *log.Logger
 	conduitCmd           = makeConduitCmd()
 	initCmd              = makeInitCmd()
@@ -34,7 +32,6 @@ var (
 
 // init() function for main package
 func init() {
-	loggerManager = loggers.MakeLoggerManager(os.Stdout)
 	conduitCmd.AddCommand(initCmd)
 }
 
@@ -57,7 +54,7 @@ func runConduitCmdWithConfig(args *conduit.Args) error {
 		return fmt.Errorf("runConduitCmdWithConfig(): invalid log level: %s", err)
 	}
 
-	logger, err = loggerManager.MakeRootLogger(level, pCfg.LogFile)
+	logger, err = loggers.MakeThreadSafeLogger(level, pCfg.LogFile)
 	if err != nil {
 		return fmt.Errorf("runConduitCmdWithConfig(): failed to create logger: %w", err)
 	}

cmd/conduit/main_test.go

@@ -4,7 +4,6 @@ import (
 	"fmt"
 	"os"
 	"path"
-	"strings"
 	"testing"
 
 	"github.com/stretchr/testify/assert"
@@ -13,7 +12,6 @@ import (
 
 	"github.com/algorand/indexer/conduit"
 	"github.com/algorand/indexer/conduit/pipeline"
-	"github.com/algorand/indexer/loggers"
 )
 
 // TestInitDataDirectory tests the initialization of the data directory
@@ -40,9 +38,7 @@ func TestInitDataDirectory(t *testing.T) {
 
 func TestBanner(t *testing.T) {
 	test := func(t *testing.T, hideBanner bool) {
-		// Install test logger.
-		var logbuilder strings.Builder
-		loggerManager = loggers.MakeLoggerManager(&logbuilder)
+		// Capture stdout.
 		stdout := os.Stdout
 		defer func() {
 			os.Stdout = stdout
@@ -85,3 +81,56 @@ func TestBanner(t *testing.T) {
 		test(t, false)
 	})
 }
+
+func TestLogFile(t *testing.T) {
+	// returns stdout
+	test := func(t *testing.T, logfile string) ([]byte, error) {
+		// Capture stdout.
+		stdout := os.Stdout
+		defer func() {
+			os.Stdout = stdout
+		}()
+		stdoutFilePath := path.Join(t.TempDir(), "stdout.txt")
+		f, err := os.Create(stdoutFilePath)
+		require.NoError(t, err)
+		defer f.Close()
+		os.Stdout = f
+
+		cfg := pipeline.Config{
+			LogFile:     logfile,
+			ConduitArgs: &conduit.Args{ConduitDataDir: t.TempDir()},
+			Importer:    pipeline.NameConfigPair{Name: "test", Config: map[string]interface{}{"a": "a"}},
+			Processors:  nil,
+			Exporter:    pipeline.NameConfigPair{Name: "test", Config: map[string]interface{}{"a": "a"}},
+		}
+		data, err := yaml.Marshal(&cfg)
+		require.NoError(t, err)
+		configFile := path.Join(cfg.ConduitArgs.ConduitDataDir, conduit.DefaultConfigName)
+		os.WriteFile(configFile, data, 0755)
+		require.FileExists(t, configFile)
+
+		err = runConduitCmdWithConfig(cfg.ConduitArgs)
+		return os.ReadFile(stdoutFilePath)
+	}
+
+	// logging to stdout
+	t.Run("conduit-logging-stdout", func(t *testing.T) {
+		data, err := test(t, "")
+		require.NoError(t, err)
+		dataStr := string(data)
+		require.Contains(t, dataStr, "{")
+	})
+
+	// logging to file
+	t.Run("conduit-logging-file", func(t *testing.T) {
+		logfile := path.Join(t.TempDir(), "logfile.txt")
+		data, err := test(t, logfile)
+		require.NoError(t, err)
+		dataStr := string(data)
+		require.NotContains(t, dataStr, "{")
+		logdata, err := os.ReadFile(logfile)
+		require.NoError(t, err)
+		logdataStr := string(logdata)
+		require.Contains(t, logdataStr, "{")
+	})
+}

loggers/loggers.go

@@ -11,13 +11,8 @@ import (
 	"github.com/algorand/indexer/conduit/pipeline"
 )
 
-// LoggerManager a manager that can produce loggers that are synchronized internally
-type LoggerManager struct {
-	internalWriter ThreadSafeWriter
-}
-
-// MakeRootLogger returns a logger that is synchronized with the internal mutex
-func (l *LoggerManager) MakeRootLogger(level log.Level, logFile string) (*log.Logger, error) {
+// MakeThreadSafeLoggerWithWriter creates a logger using a ThreadSafeWriter output.
+func MakeThreadSafeLoggerWithWriter(level log.Level, writer io.Writer) *log.Logger {
 	formatter := pipeline.PluginLogFormatter{
 		Formatter: &log.JSONFormatter{
 			DisableHTMLEscape: true,
@@ -29,28 +24,31 @@ func (l *LoggerManager) MakeRootLogger(level log.Level, logFile string) (*log.Lo
 	logger := log.New()
 	logger.SetFormatter(&formatter)
 	logger.SetLevel(level)
-	logger.SetOutput(l.internalWriter)
 
+	logger.SetOutput(ThreadSafeWriter{
+		Writer: writer,
+		Mutex:  &sync.Mutex{},
+	})
+
+	return logger
+}
+
+// MakeThreadSafeLogger returns a logger that is synchronized with the internal mutex, if no file is provided write
+// to os.Stdout.
+func MakeThreadSafeLogger(level log.Level, logFile string) (*log.Logger, error) {
+	var writer io.Writer
+	// Write to a file or stdout
 	if logFile != "" {
 		f, err := os.OpenFile(logFile, os.O_APPEND|os.O_WRONLY|os.O_CREATE, 0644)
 		if err != nil {
 			return nil, fmt.Errorf("runConduitCmdWithConfig(): %w", err)
 		}
-		l.internalWriter.Mutex.Lock()
-		defer l.internalWriter.Mutex.Unlock()
-		l.internalWriter.Writer = f
+		writer = f
+	} else {
+		writer = os.Stdout
 	}
-	return logger, nil
-}
 
-// MakeLoggerManager returns a logger manager
-func MakeLoggerManager(writer io.Writer) *LoggerManager {
-	return &LoggerManager{
-		internalWriter: ThreadSafeWriter{
-			Writer: writer,
-			Mutex:  &sync.Mutex{},
-		},
-	}
+	return MakeThreadSafeLoggerWithWriter(level, writer), nil
 }
 
 // ThreadSafeWriter a struct that implements io.Writer in a threadsafe way

loggers/loggers_test.go

@@ -3,7 +3,9 @@ package loggers
 import (
 	"encoding/json"
 	"math/rand"
+	"os"
 	"path"
+	"strings"
 	"sync"
 	"sync/atomic"
 	"testing"
@@ -24,19 +26,19 @@ func (f *FakeIoWriter) Write(p []byte) (n int, err error) {
 }
 
 func TestLogToFile(t *testing.T) {
-	fakeWriter := FakeIoWriter{}
-	lMgr := MakeLoggerManager(&fakeWriter)
-
 	logfile := path.Join(t.TempDir(), "mylogfile.txt")
 	require.NoFileExists(t, logfile)
-	logger, err := lMgr.MakeRootLogger(log.InfoLevel, logfile)
+	logger, err := MakeThreadSafeLogger(log.InfoLevel, logfile)
 	require.NoError(t, err)
 
 	testString := "1234abcd"
 	logger.Infof(testString)
 	assert.FileExists(t, logfile)
-	assert.Len(t, fakeWriter.Entries, 1)
-	assert.Contains(t, fakeWriter.Entries[0], testString)
+	data, err := os.ReadFile(logfile)
+	assert.Contains(t, string(data), testString)
+	lines := strings.Split(string(data), "\n")
+	require.Len(t, lines, 2)
+	assert.Equal(t, "", lines[1])
 }
 
 // TestThreadSafetyOfLogger ensures that multiple threads writing to a single source
@@ -45,22 +47,25 @@ func TestThreadSafetyOfLogger(t *testing.T) {
 	var atomicInt int64 = 0
 
 	fakeWriter := FakeIoWriter{}
-	lMgr := MakeLoggerManager(&fakeWriter)
 
 	const numberOfWritesPerLogger = 20
 	const numberOfLoggers = 15
 
 	var wg sync.WaitGroup
 	wg.Add(numberOfLoggers)
+	writer := ThreadSafeWriter{
+		Writer: &fakeWriter,
+		Mutex:  &sync.Mutex{},
+	}
 
 	// Launch go routines
 	for i := 0; i < numberOfLoggers; i++ {
 		go func() {
 			// Sleep a random number of milliseconds before and after to test
 			// that creating a logger doesn't affect thread-safety
 			time.Sleep(time.Duration(rand.Intn(50)) * time.Millisecond)
-			l, err := lMgr.MakeRootLogger(log.InfoLevel, "")
-			require.NoError(t, err)
+			l := log.New()
+			l.SetOutput(writer)
 			l.SetFormatter(&log.JSONFormatter{
 				// We want to disable timestamps to stop logrus from sorting our output
 				DisableTimestamp: true,