Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Merged
merged 2 commits into from
Mar 4, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions .github/workflows/test.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -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:
Expand Down
17 changes: 16 additions & 1 deletion cmd/run.go
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@ import (
"crypto/tls"
"errors"
"fmt"
"io"
"log"
"net/http"
"net/url"
Expand Down Expand Up @@ -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 (
Expand Down Expand Up @@ -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],
Expand Down
30 changes: 12 additions & 18 deletions cmd/run_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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 (
Expand Down Expand Up @@ -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.
Expand Down Expand Up @@ -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)
Expand Down Expand Up @@ -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.
Expand Down Expand Up @@ -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.
Expand Down
148 changes: 76 additions & 72 deletions logging/hclog_adapter_test.go
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
package logging

import (
"bytes"
"context"
"testing"
"time"
Expand All @@ -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")
Expand All @@ -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")
Expand All @@ -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")
Expand Down Expand Up @@ -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")
}
11 changes: 9 additions & 2 deletions logging/logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -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
}
Expand All @@ -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,
}
Expand Down Expand Up @@ -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

Expand Down
22 changes: 22 additions & 0 deletions logging/logger_test.go
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
package logging

import (
"bytes"
"context"
"os"
"testing"
Expand Down Expand Up @@ -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() {
Expand Down