From 4abba6267ec63ab3a843fa2a1d810fb416eaf007 Mon Sep 17 00:00:00 2001 From: Hamid Sajjadi <118748983+Hamsajj@users.noreply.github.com> Date: Mon, 4 Mar 2024 22:44:21 +0100 Subject: [PATCH 1/2] tests: use buffer instead of capturer to test logger output --- cmd/run.go | 17 +++- cmd/run_test.go | 30 +++---- logging/hclog_adapter_test.go | 148 +++++++++++++++++----------------- logging/logger.go | 11 ++- logging/logger_test.go | 22 +++++ 5 files changed, 135 insertions(+), 93 deletions(-) diff --git a/cmd/run.go b/cmd/run.go index 020c3bb3..c9331c46 100644 --- 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 index 1ce11f1b..5227cbd5 100644 --- 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 index b34235ea..eaf35aa9 100644 --- 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 index 1048ff4d..bf485cbe 100644 --- 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 index 2b7ce44c..bd03cd61 100644 --- 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() { From 66527ad0fadf84691702313ec4cae904b5fd4b39 Mon Sep 17 00:00:00 2001 From: Mostafa Moradian Date: Mon, 4 Mar 2024 23:57:04 +0100 Subject: [PATCH 2/2] Fix plugin url in tests --- .github/workflows/test.yaml | 1 + 1 file changed, 1 insertion(+) diff --git a/.github/workflows/test.yaml b/.github/workflows/test.yaml index 31fb07ca..2aa1ae2d 100644 --- 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: