From d27db627b1dd46cbf1c101e2ea065eaba28c0337 Mon Sep 17 00:00:00 2001 From: Jordan Krage Date: Mon, 25 Sep 2023 20:17:41 -0500 Subject: [PATCH] pkg/loop: fix logger --- pkg/loop/logger.go | 24 ++++++--- pkg/loop/logger_loop_test.go | 71 +++++++++++++++++++++++++++ pkg/loop/logger_test.go | 95 ++++++++++++------------------------ 3 files changed, 120 insertions(+), 70 deletions(-) create mode 100644 pkg/loop/logger_loop_test.go diff --git a/pkg/loop/logger.go b/pkg/loop/logger.go index dbc8b9b8d..0de37d64f 100644 --- a/pkg/loop/logger.go +++ b/pkg/loop/logger.go @@ -37,17 +37,27 @@ func (h *hclSinkAdapter) named(name string) logger.Logger { return v.(func() logger.Logger)() } -func (h *hclSinkAdapter) Accept(_ string, level hclog.Level, msg string, args ...interface{}) { - l := h.l +func removeArg(args []interface{}, key string) ([]interface{}, string) { + if len(args) < 2 { + return args, "" + } for i := 0; i+1 < len(args); i += 2 { - if args[i] == "logger" { - if name, ok := args[i+1].(string); ok { - l = h.named(name) - args = slices.Delete(args, i, i+1) - break + if args[i] == key { + if v, ok := (args)[i+1].(string); ok { + return slices.Delete(args, i, i+2), v } + break } } + return args, "" +} + +func (h *hclSinkAdapter) Accept(_ string, level hclog.Level, msg string, args ...interface{}) { + l := h.l + var name string + if args, name = removeArg(args, "logger"); name != "" { + l = h.named(name) + } switch level { case hclog.NoLevel: case hclog.Debug, hclog.Trace: diff --git a/pkg/loop/logger_loop_test.go b/pkg/loop/logger_loop_test.go new file mode 100644 index 000000000..0b0255cf4 --- /dev/null +++ b/pkg/loop/logger_loop_test.go @@ -0,0 +1,71 @@ +package loop_test + +import ( + "context" + "errors" + "testing" + "time" + + "github.com/hashicorp/go-plugin" + "github.com/stretchr/testify/require" + "go.uber.org/zap/zapcore" + "go.uber.org/zap/zaptest/observer" + "google.golang.org/grpc" + + "github.com/smartcontractkit/chainlink-relay/pkg/logger" + "github.com/smartcontractkit/chainlink-relay/pkg/loop" +) + +const PluginLoggerTestName = "logger-test" + +const LoggerTestName = "server-side-logger-name" + +func TestHCLogLogger(t *testing.T) { + lggr, ol := logger.TestObserved(t, zapcore.ErrorLevel) + loggerTest := &GRPCPluginLoggerTest{Logger: lggr} + cc := loggerTest.ClientConfig() + cc.Cmd = helperProcess(PluginLoggerTestName) + c := plugin.NewClient(cc) + t.Cleanup(c.Kill) + _, err := c.Client() + require.Error(t, err) + + // Some logs should come through with plugin-side names + require.NotEmpty(t, ol.Filter(func(entry observer.LoggedEntry) bool { + return entry.LoggerName == LoggerTestName + }), ol.All()) +} + +type GRPCPluginLoggerTest struct { + plugin.NetRPCUnsupportedPlugin + + logger.Logger +} + +func (g *GRPCPluginLoggerTest) GRPCServer(*plugin.GRPCBroker, *grpc.Server) (err error) { + err = errors.New("test error") + g.Logger.Errorw("Error!", "err", err) + g.Logger.Sync() + time.Sleep(time.Second) + return err +} + +func (g *GRPCPluginLoggerTest) GRPCClient(context.Context, *plugin.GRPCBroker, *grpc.ClientConn) (interface{}, error) { + return nil, errors.New("unimplemented") +} + +func (g *GRPCPluginLoggerTest) ClientConfig() *plugin.ClientConfig { + return &plugin.ClientConfig{ + HandshakeConfig: PluginLoggerTestHandshakeConfig(), + Plugins: map[string]plugin.Plugin{PluginLoggerTestName: g}, + AllowedProtocols: []plugin.Protocol{plugin.ProtocolGRPC}, + Logger: loop.HCLogLogger(g.Logger), + } +} + +func PluginLoggerTestHandshakeConfig() plugin.HandshakeConfig { + return plugin.HandshakeConfig{ + MagicCookieKey: "CL_PLUGIN_LOGGER_TEST_MAGIC_COOKIE", + MagicCookieValue: "272d1867cdc8042f9405d7c1da3762ec", + } +} diff --git a/pkg/loop/logger_test.go b/pkg/loop/logger_test.go index 0b0255cf4..419a7e727 100644 --- a/pkg/loop/logger_test.go +++ b/pkg/loop/logger_test.go @@ -1,71 +1,40 @@ -package loop_test +package loop import ( - "context" - "errors" "testing" - "time" - "github.com/hashicorp/go-plugin" - "github.com/stretchr/testify/require" - "go.uber.org/zap/zapcore" - "go.uber.org/zap/zaptest/observer" - "google.golang.org/grpc" - - "github.com/smartcontractkit/chainlink-relay/pkg/logger" - "github.com/smartcontractkit/chainlink-relay/pkg/loop" + "github.com/stretchr/testify/assert" ) -const PluginLoggerTestName = "logger-test" - -const LoggerTestName = "server-side-logger-name" - -func TestHCLogLogger(t *testing.T) { - lggr, ol := logger.TestObserved(t, zapcore.ErrorLevel) - loggerTest := &GRPCPluginLoggerTest{Logger: lggr} - cc := loggerTest.ClientConfig() - cc.Cmd = helperProcess(PluginLoggerTestName) - c := plugin.NewClient(cc) - t.Cleanup(c.Kill) - _, err := c.Client() - require.Error(t, err) - - // Some logs should come through with plugin-side names - require.NotEmpty(t, ol.Filter(func(entry observer.LoggedEntry) bool { - return entry.LoggerName == LoggerTestName - }), ol.All()) -} - -type GRPCPluginLoggerTest struct { - plugin.NetRPCUnsupportedPlugin - - logger.Logger -} - -func (g *GRPCPluginLoggerTest) GRPCServer(*plugin.GRPCBroker, *grpc.Server) (err error) { - err = errors.New("test error") - g.Logger.Errorw("Error!", "err", err) - g.Logger.Sync() - time.Sleep(time.Second) - return err -} - -func (g *GRPCPluginLoggerTest) GRPCClient(context.Context, *plugin.GRPCBroker, *grpc.ClientConn) (interface{}, error) { - return nil, errors.New("unimplemented") -} - -func (g *GRPCPluginLoggerTest) ClientConfig() *plugin.ClientConfig { - return &plugin.ClientConfig{ - HandshakeConfig: PluginLoggerTestHandshakeConfig(), - Plugins: map[string]plugin.Plugin{PluginLoggerTestName: g}, - AllowedProtocols: []plugin.Protocol{plugin.ProtocolGRPC}, - Logger: loop.HCLogLogger(g.Logger), - } -} - -func PluginLoggerTestHandshakeConfig() plugin.HandshakeConfig { - return plugin.HandshakeConfig{ - MagicCookieKey: "CL_PLUGIN_LOGGER_TEST_MAGIC_COOKIE", - MagicCookieValue: "272d1867cdc8042f9405d7c1da3762ec", +func Test_removeArg(t *testing.T) { + for _, tt := range []struct { + name string + args []interface{} + key string + + wantArgs []interface{} + wantVal string + }{ + {"empty", nil, "logger", + nil, ""}, + {"simple", []any{"logger", "foo"}, "logger", + []any{}, "foo"}, + {"multi", []any{"logger", "foo", "bar", "baz"}, "logger", + []any{"bar", "baz"}, "foo"}, + {"reorder", []any{"bar", "baz", "logger", "foo"}, "logger", + []any{"bar", "baz"}, "foo"}, + + {"invalid", []any{"logger"}, "logger", + []any{"logger"}, ""}, + {"invalid-multi", []any{"foo", "bar", "logger"}, "logger", + []any{"foo", "bar", "logger"}, ""}, + {"value", []any{"foo", "logger", "bar", "baz"}, "logger", + []any{"foo", "logger", "bar", "baz"}, ""}, + } { + t.Run(tt.name, func(t *testing.T) { + args, val := removeArg(tt.args, tt.key) + assert.ElementsMatch(t, tt.wantArgs, args) + assert.Equal(t, tt.wantVal, val) + }) } }