tests: use buffer instead of capturer to test logger output (#476)

* tests: use buffer instead of capturer to test logger output * Fix plugin url in tests --------- Co-authored-by: Mostafa Moradian <[email protected]>
gatewayd-io · Mar 4, 2024 · 5795390 · 5795390
1 parent 1eb8084
commit 5795390
Show file tree

Hide file tree

Showing 6 changed files with 136 additions and 93 deletions.
diff --git a/.github/workflows/test.yaml b/.github/workflows/test.yaml
@@ -137,6 +137,7 @@ jobs:
           plugins:
             - name: plugin-template-go
               enabled: True
+              url: github.com/gatewayd-io/plugin-template-go
               localPath: ./ptg
               args: ["--log-level", "debug"]
               env:

diff --git a/cmd/run.go b/cmd/run.go
@@ -5,6 +5,7 @@ import (
 	"crypto/tls"
 	"errors"
 	"fmt"
+	"io"
 	"log"
 	"net/http"
 	"net/url"
@@ -44,6 +45,17 @@ import (
 	"google.golang.org/grpc/credentials"
 )
 
+var _ io.Writer = &cobraCmdWriter{}
+
+type cobraCmdWriter struct {
+	*cobra.Command
+}
+
+func (c *cobraCmdWriter) Write(p []byte) (int, error) {
+	c.Print(string(p))
+	return len(p), nil
+}
+
 // TODO: Get rid of the global variables.
 // https://github.com/gatewayd-io/gatewayd/issues/324
 var (
@@ -212,9 +224,12 @@ var runCmd = &cobra.Command{
 		conf.InitConfig(runCtx)
 
 		// Create and initialize loggers from the config.
+		// Use cobra command cmd instead of os.Stdout for the console output.
+		cmdLogger := &cobraCmdWriter{cmd}
 		for name, cfg := range conf.Global.Loggers {
 			loggers[name] = logging.NewLogger(runCtx, logging.LoggerConfig{
-				Output: cfg.GetOutput(),
+				Output:     cfg.GetOutput(),
+				ConsoleOut: cmdLogger,
 				Level: config.If(
 					config.Exists(config.LogLevels, cfg.Level),
 					config.LogLevels[cfg.Level],

diff --git a/cmd/run_test.go b/cmd/run_test.go
@@ -10,7 +10,6 @@ import (
 	"github.com/gatewayd-io/gatewayd/config"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
-	"github.com/zenizh/go-capturer"
 )
 
 var (
@@ -39,10 +38,9 @@ func Test_runCmd(t *testing.T) {
 	waitGroup.Add(1)
 	go func(waitGroup *sync.WaitGroup) {
 		// Test run command.
-		output := capturer.CaptureOutput(func() {
-			_, err := executeCommandC(rootCmd, "run", "-c", globalTestConfigFile, "-p", pluginTestConfigFile)
-			require.NoError(t, err, "run command should not have returned an error")
-		})
+		output, err := executeCommandC(rootCmd, "run", "-c", globalTestConfigFile, "-p", pluginTestConfigFile)
+		require.NoError(t, err, "run command should not have returned an error")
+
 		// Print the output for debugging purposes.
 		runCmd.Print(output)
 		// Check if GatewayD started and stopped correctly.
@@ -93,10 +91,8 @@ func Test_runCmdWithTLS(t *testing.T) {
 	waitGroup.Add(1)
 	go func(waitGroup *sync.WaitGroup) {
 		// Test run command.
-		output := capturer.CaptureOutput(func() {
-			_, err := executeCommandC(rootCmd, "run", "-c", globalTLSTestConfigFile, "-p", pluginTestConfigFile)
-			require.NoError(t, err, "run command should not have returned an error")
-		})
+		output, err := executeCommandC(rootCmd, "run", "-c", globalTLSTestConfigFile, "-p", pluginTestConfigFile)
+		require.NoError(t, err, "run command should not have returned an error")
 
 		// Print the output for debugging purposes.
 		runCmd.Print(output)
@@ -149,11 +145,10 @@ func Test_runCmdWithMultiTenancy(t *testing.T) {
 	waitGroup.Add(1)
 	go func(waitGroup *sync.WaitGroup) {
 		// Test run command.
-		output := capturer.CaptureOutput(func() {
-			_, err := executeCommandC(
-				rootCmd, "run", "-c", globalTestConfigFile, "-p", pluginTestConfigFile)
-			require.NoError(t, err, "run command should not have returned an error")
-		})
+		output, err := executeCommandC(
+			rootCmd, "run", "-c", globalTestConfigFile, "-p", pluginTestConfigFile)
+		require.NoError(t, err, "run command should not have returned an error")
+
 		// Print the output for debugging purposes.
 		runCmd.Print(output)
 		// Check if GatewayD started and stopped correctly.
@@ -232,10 +227,9 @@ func Test_runCmdWithCachePlugin(t *testing.T) {
 	waitGroup.Add(1)
 	go func(waitGroup *sync.WaitGroup) {
 		// Test run command.
-		output := capturer.CaptureOutput(func() {
-			_, err := executeCommandC(rootCmd, "run", "-c", globalTestConfigFile, "-p", pluginTestConfigFile)
-			require.NoError(t, err, "run command should not have returned an error")
-		})
+		output, err := executeCommandC(rootCmd, "run", "-c", globalTestConfigFile, "-p", pluginTestConfigFile)
+		require.NoError(t, err, "run command should not have returned an error")
+
 		// Print the output for debugging purposes.
 		runCmd.Print(output)
 		// Check if GatewayD started and stopped correctly.

diff --git a/logging/hclog_adapter_test.go b/logging/hclog_adapter_test.go
@@ -1,6 +1,7 @@
 package logging
 
 import (
+	"bytes"
 	"context"
 	"testing"
 	"time"
@@ -9,36 +10,37 @@ import (
 	"github.com/hashicorp/go-hclog"
 	"github.com/rs/zerolog"
 	"github.com/stretchr/testify/assert"
-	"github.com/zenizh/go-capturer"
 )
 
 // TestNewHcLogAdapter tests the HcLogAdapter.
 func TestNewHcLogAdapter(t *testing.T) {
-	consoleOutput := capturer.CaptureStdout(func() {
-		logger := NewLogger(
-			context.Background(),
-			LoggerConfig{
-				Output:            []config.LogOutput{config.Console},
-				Level:             zerolog.TraceLevel,
-				TimeFormat:        zerolog.TimeFormatUnix,
-				ConsoleTimeFormat: time.RFC3339,
-				NoColor:           true,
-			},
-		)
-
-		hcLogAdapter := NewHcLogAdapter(&logger, "test")
-		hcLogAdapter.SetLevel(hclog.Trace)
-
-		hcLogAdapter.Trace("This is a trace message")
-		hcLogAdapter.Debug("This is a debug message")
-		hcLogAdapter.Info("This is an info message")
-		hcLogAdapter.Warn("This is a warn message")
-		hcLogAdapter.Error("This is an error message")
-		hcLogAdapter.Log(hclog.Debug, "This is a log message")
-
-		hcLogAdapter.SetLevel(hclog.Warn)
-		hcLogAdapter.Trace("This is a trace message, but it should not be logged")
-	})
+	out := &bytes.Buffer{}
+	logger := NewLogger(
+		context.Background(),
+		LoggerConfig{
+			Output:            []config.LogOutput{config.Console},
+			Level:             zerolog.TraceLevel,
+			TimeFormat:        zerolog.TimeFormatUnix,
+			ConsoleTimeFormat: time.RFC3339,
+			NoColor:           true,
+			ConsoleOut:        out,
+		},
+	)
+
+	hcLogAdapter := NewHcLogAdapter(&logger, "test")
+	hcLogAdapter.SetLevel(hclog.Trace)
+
+	hcLogAdapter.Trace("This is a trace message")
+	hcLogAdapter.Debug("This is a debug message")
+	hcLogAdapter.Info("This is an info message")
+	hcLogAdapter.Warn("This is a warn message")
+	hcLogAdapter.Error("This is an error message")
+	hcLogAdapter.Log(hclog.Debug, "This is a log message")
+
+	hcLogAdapter.SetLevel(hclog.Warn)
+	hcLogAdapter.Trace("This is a trace message, but it should not be logged")
+
+	consoleOutput := out.String()
 
 	assert.Contains(t, consoleOutput, "TRC This is a trace message")
 	assert.Contains(t, consoleOutput, "DBG This is a debug message")
@@ -53,30 +55,31 @@ func TestNewHcLogAdapter(t *testing.T) {
 // TestNewHcLogAdapter_LogLevel_Difference tests the HcLogAdapter when the
 // logger and the hclog adapter have different log levels.
 func TestNewHcLogAdapter_LogLevel_Difference(t *testing.T) {
-	consoleOutput := capturer.CaptureStdout(func() {
-		logger := NewLogger(
-			context.Background(),
-			LoggerConfig{
-				Output:     []config.LogOutput{config.Console},
-				Level:      zerolog.WarnLevel,
-				TimeFormat: zerolog.TimeFormatUnix,
-				NoColor:    true,
-			},
-		)
-
-		// The logger is set to WarnLevel, but the hclog adapter is set to TraceLevel.
-		// This means that the hclog adapter will log everything, but the logger will
-		// only log WarnLevel and above.
-		hcLogAdapter := NewHcLogAdapter(&logger, "test")
-		hcLogAdapter.SetLevel(hclog.Trace)
-		hcLogAdapter.Trace("This is a trace message, but it should not be logged")
-		hcLogAdapter.Debug("This is a debug message, but it should not be logged")
-		hcLogAdapter.Info("This is an info message, but it should not be logged")
-		hcLogAdapter.Warn("This is a warn message")
-		hcLogAdapter.Error("This is an error message")
-		hcLogAdapter.Log(hclog.Debug, "This is a log message, but it should not be logged")
-	})
+	out := &bytes.Buffer{}
+	logger := NewLogger(
+		context.Background(),
+		LoggerConfig{
+			Output:     []config.LogOutput{config.Console},
+			ConsoleOut: out,
+			Level:      zerolog.WarnLevel,
+			TimeFormat: zerolog.TimeFormatUnix,
+			NoColor:    true,
+		},
+	)
 
+	// The logger is set to WarnLevel, but the hclog adapter is set to TraceLevel.
+	// This means that the hclog adapter will log everything, but the logger will
+	// only log WarnLevel and above.
+	hcLogAdapter := NewHcLogAdapter(&logger, "test")
+	hcLogAdapter.SetLevel(hclog.Trace)
+	hcLogAdapter.Trace("This is a trace message, but it should not be logged")
+	hcLogAdapter.Debug("This is a debug message, but it should not be logged")
+	hcLogAdapter.Info("This is an info message, but it should not be logged")
+	hcLogAdapter.Warn("This is a warn message")
+	hcLogAdapter.Error("This is an error message")
+	hcLogAdapter.Log(hclog.Debug, "This is a log message, but it should not be logged")
+
+	consoleOutput := out.String()
 	assert.NotContains(t, consoleOutput, "TRC This is a trace message, but it should not be logged")
 	assert.NotContains(t, consoleOutput, "DBG This is a debug message, but it should not be logged")
 	assert.NotContains(t, consoleOutput, "INF This is an info message, but it should not be logged")
@@ -87,29 +90,30 @@ func TestNewHcLogAdapter_LogLevel_Difference(t *testing.T) {
 
 // TestNewHcLogAdapter_Log tests the HcLogAdapter.Log method.
 func TestNewHcLogAdapter_Log(t *testing.T) {
-	consoleOutput := capturer.CaptureStdout(func() {
-		logger := NewLogger(
-			context.Background(),
-			LoggerConfig{
-				Output:     []config.LogOutput{config.Console},
-				Level:      zerolog.TraceLevel,
-				TimeFormat: zerolog.TimeFormatUnix,
-				NoColor:    true,
-			},
-		)
-
-		hcLogAdapter := NewHcLogAdapter(&logger, "test")
-		hcLogAdapter.SetLevel(hclog.Trace)
-
-		hcLogAdapter.Log(hclog.Off, "This is a message")
-		hcLogAdapter.Log(hclog.NoLevel, "This is yet another message")
-		hcLogAdapter.Log(hclog.Trace, "This is a trace message")
-		hcLogAdapter.Log(hclog.Debug, "This is a debug message")
-		hcLogAdapter.Log(hclog.Info, "This is an info message")
-		hcLogAdapter.Log(hclog.Warn, "This is a warn message")
-		hcLogAdapter.Log(hclog.Error, "This is an error message")
-	})
+	out := &bytes.Buffer{}
+	logger := NewLogger(
+		context.Background(),
+		LoggerConfig{
+			Output:     []config.LogOutput{config.Console},
+			ConsoleOut: out,
+			Level:      zerolog.TraceLevel,
+			TimeFormat: zerolog.TimeFormatUnix,
+			NoColor:    true,
+		},
+	)
+
+	hcLogAdapter := NewHcLogAdapter(&logger, "test")
+	hcLogAdapter.SetLevel(hclog.Trace)
+
+	hcLogAdapter.Log(hclog.Off, "This is a message")
+	hcLogAdapter.Log(hclog.NoLevel, "This is yet another message")
+	hcLogAdapter.Log(hclog.Trace, "This is a trace message")
+	hcLogAdapter.Log(hclog.Debug, "This is a debug message")
+	hcLogAdapter.Log(hclog.Info, "This is an info message")
+	hcLogAdapter.Log(hclog.Warn, "This is a warn message")
+	hcLogAdapter.Log(hclog.Error, "This is an error message")
 
+	consoleOutput := out.String()
 	assert.NotContains(t, consoleOutput, "This is a message")
 	assert.NotContains(t, consoleOutput, "This is yet another message")
 	assert.Contains(t, consoleOutput, "TRC This is a trace message")
@@ -137,5 +141,5 @@ func TestNewHcLogAdapter_GetLevel(t *testing.T) {
 	hcLogAdapter.SetLevel(hclog.Debug)
 	assert.Equal(t, hclog.Debug, hcLogAdapter.GetLevel())
 	assert.NotEqual(t, zerolog.DebugLevel, logger.GetLevel(),
-		"The logger should not be affected by the hclog adapter's level")
+		"The logger should not be affected by the hclog adapter's loggerLevel")
 }
diff --git a/logging/logger.go b/logging/logger.go
@@ -36,6 +36,9 @@ type LoggerConfig struct {
 	Compress   bool
 	LocalTime  bool
 
+	// the output of config.Console log will be written to this writer, if it is nil os.Stdout will be used.
+	ConsoleOut io.Writer
+
 	// group name
 	Name string
 }
@@ -45,8 +48,13 @@ func NewLogger(ctx context.Context, cfg LoggerConfig) zerolog.Logger {
 	_, span := otel.Tracer(config.TracerName).Start(ctx, "Create new logger")
 
 	// Create a new logger.
+	var consoleOut io.Writer = os.Stdout
+	if cfg.ConsoleOut != nil {
+		consoleOut = cfg.ConsoleOut
+	}
+
 	consoleWriter := zerolog.ConsoleWriter{
-		Out:        os.Stdout,
+		Out:        consoleOut,
 		TimeFormat: cfg.ConsoleTimeFormat,
 		NoColor:    cfg.NoColor,
 	}
@@ -92,7 +100,6 @@ func NewLogger(ctx context.Context, cfg LoggerConfig) zerolog.Logger {
 			outputs = append(outputs, consoleWriter)
 		}
 	}
-
 	zerolog.SetGlobalLevel(cfg.Level)
 	zerolog.TimeFieldFormat = cfg.TimeFormat
 

diff --git a/logging/logger_test.go b/logging/logger_test.go
@@ -1,6 +1,7 @@
 package logging
 
 import (
+	"bytes"
 	"context"
 	"os"
 	"testing"
@@ -106,6 +107,27 @@ func TestNewLogger_Stderr(t *testing.T) {
 	assert.Contains(t, stderr, `"key":"value"`)
 }
 
+// TestNewLogger_CustomOutput tests the creation of a new logger with bytes.Buffer as custom output.
+func TestNewLogger_ConsoleOut(t *testing.T) {
+	out := &bytes.Buffer{}
+	logger := NewLogger(
+		context.Background(),
+		LoggerConfig{
+			Output:     []config.LogOutput{config.Console},
+			ConsoleOut: out,
+			Level:      zerolog.DebugLevel,
+			TimeFormat: zerolog.TimeFormatUnix,
+			NoColor:    true,
+		},
+	)
+	assert.NotNil(t, logger)
+
+	logger.Error().Str("key", "value").Msg("This is an error")
+	got := out.String()
+	assert.Contains(t, got, `ERR This is an error`)
+	assert.Contains(t, got, `key=value`)
+}
+
 // TestNewLogger_MultipleOutputs tests the creation of a new logger with multiple outputs.
 func TestNewLogger_MultipleOutputs(t *testing.T) {
 	stderr := capturer.CaptureStderr(func() {