[ocm-2.1] ensure controller runtime uses logrus for logging

cmd/manager/main.go

@@ -56,6 +56,7 @@ import (
 	"github.com/openshift/hive/pkg/controller/unreachable"
 	"github.com/openshift/hive/pkg/controller/utils"
 	"github.com/openshift/hive/pkg/controller/velerobackup"
+	utillogrus "github.com/openshift/hive/pkg/util/logrus"
 	"github.com/openshift/hive/pkg/version"
 )
 
@@ -165,6 +166,7 @@ func newRootCommand() *cobra.Command {
 				// Create a new Cmd to provide shared dependencies and start components
 				mgr, err := manager.New(cfg, manager.Options{
 					MetricsBindAddress: ":2112",
+					Logger:             utillogrus.NewLogr(log.StandardLogger()),
 				})
 				if err != nil {
 					log.Fatal(err)

cmd/operator/main.go

@@ -33,6 +33,7 @@ import (
 	"github.com/openshift/hive/pkg/apis"
 	"github.com/openshift/hive/pkg/operator"
 	"github.com/openshift/hive/pkg/operator/hive"
+	utillogrus "github.com/openshift/hive/pkg/util/logrus"
 	"github.com/openshift/hive/pkg/version"
 )
 
@@ -108,6 +109,7 @@ func newRootCommand() *cobra.Command {
 				// Create a new Cmd to provide shared dependencies and start components
 				mgr, err := manager.New(cfg, manager.Options{
 					MetricsBindAddress: "0",
+					Logger:             utillogrus.NewLogr(log.StandardLogger()),
 				})
 				if err != nil {
 					log.Fatal(err)

pkg/util/logrus/logr.go

@@ -0,0 +1,62 @@
+package logrus
+
+import (
+	"github.com/go-logr/logr"
+	log "github.com/sirupsen/logrus"
+)
+
+// lgr uses Debug for info output and
+// Error for error at all levels.
+type lgr struct {
+	logger log.FieldLogger
+}
+
+// NewLogr returns a new logger that implements logr.Logger interface
+// using the FieldLogger.
+func NewLogr(logger log.FieldLogger) logr.Logger {
+	return lgr{logger: logger}
+}
+
+var _ logr.Logger = lgr{}
+
+// Info implements logr.InfoLogger
+func (l lgr) Info(msg string, keyAndValues ...interface{}) {
+	l.logger.WithFields(keyAndValuesToFields(keyAndValues...)).Debug(msg)
+}
+
+// Error implements logr.Logger
+func (l lgr) Error(err error, msg string, keyAndValues ...interface{}) {
+	l.logger.WithError(err).WithFields(keyAndValuesToFields(keyAndValues...)).Error(msg)
+}
+
+// Enabled implements logr.InfoLogger
+func (lgr) Enabled() bool {
+	return true
+}
+
+// V implements logr.Logger
+func (l lgr) V(_ int) logr.InfoLogger {
+	return l
+}
+
+// WithName implements logr.Logger
+func (l lgr) WithName(name string) logr.Logger {
+	return lgr{logger: l.logger.WithField("_name", name)}
+}
+
+// WithValues implements logr.Logger
+func (l lgr) WithValues(keyAndValues ...interface{}) logr.Logger {
+	return lgr{logger: l.logger.WithFields(keyAndValuesToFields(keyAndValues...))}
+}
+
+func keyAndValuesToFields(keyAndValues ...interface{}) log.Fields {
+	fields := log.Fields{}
+	for idx := 0; idx < len(keyAndValues); {
+		fields[keyAndValues[idx].(string)] = ""
+		if idx+1 < len(keyAndValues) {
+			fields[keyAndValues[idx].(string)] = keyAndValues[idx+1]
+		}
+		idx += 2
+	}
+	return fields
+}

pkg/util/logrus/logr_test.go

@@ -0,0 +1,123 @@
+package logrus
+
+import (
+	"bytes"
+	"errors"
+	"testing"
+
+	"github.com/go-logr/logr"
+	log "github.com/sirupsen/logrus"
+	"github.com/stretchr/testify/assert"
+)
+
+func Test_keyAndValuesToFields(t *testing.T) {
+	cases := []struct {
+		input  []interface{}
+		output log.Fields
+	}{{
+		input:  nil,
+		output: log.Fields{},
+	}, {
+		input:  []interface{}{},
+		output: log.Fields{},
+	}, {
+		input:  []interface{}{"key1", "value1", "key2", 1, "key3", 3.0, "key4", []int{1, 2}},
+		output: log.Fields{"key1": "value1", "key2": 1, "key3": 3.0, "key4": []int{1, 2}},
+	}, {
+		input:  []interface{}{"key1"},
+		output: log.Fields{"key1": ""},
+	}, {
+		input:  []interface{}{"key1", "value1", "key2"},
+		output: log.Fields{"key1": "value1", "key2": ""},
+	}}
+	for _, test := range cases {
+		fields := keyAndValuesToFields(test.input...)
+		assert.Equal(t, test.output, fields)
+	}
+}
+
+func Test_logr_debug(t *testing.T) {
+	logger := log.New()
+	logger.SetLevel(log.DebugLevel)
+	logger.SetFormatter(&log.TextFormatter{DisableColors: true, DisableTimestamp: true, DisableQuote: true})
+
+	buf := &bytes.Buffer{}
+	logger.SetOutput(buf)
+	l := NewLogr(logger)
+	testRun := func(l logr.Logger) {
+		l.Info("first info message")
+		l.Info("second info message with context", "key1", "value1", "key2", 10)
+
+		l.Error(errors.New("error occurred"), "first error message")
+		l.Error(errors.New("error occurred"), "second error message with context", "key1", "value1", "key2", 10)
+	}
+
+	testRun(l)
+
+	lWithName := l.WithName("test-name")
+	testRun(lWithName)
+
+	lWithFields := l.WithValues("controller", "test-controller")
+	testRun(lWithFields)
+
+	lWithV2 := l.V(2)
+	testRun(lWithV2)
+
+	expected := `level=debug msg=first info message
+level=debug msg=second info message with context key1=value1 key2=10
+level=error msg=first error message error=error occurred
+level=error msg=second error message with context error=error occurred key1=value1 key2=10
+level=debug msg=first info message _name=test-name
+level=debug msg=second info message with context _name=test-name key1=value1 key2=10
+level=error msg=first error message _name=test-name error=error occurred
+level=error msg=second error message with context _name=test-name error=error occurred key1=value1 key2=10
+level=debug msg=first info message controller=test-controller
+level=debug msg=second info message with context controller=test-controller key1=value1 key2=10
+level=error msg=first error message controller=test-controller error=error occurred
+level=error msg=second error message with context controller=test-controller error=error occurred key1=value1 key2=10
+level=debug msg=first info message
+level=debug msg=second info message with context key1=value1 key2=10
+level=error msg=first error message error=error occurred
+level=error msg=second error message with context error=error occurred key1=value1 key2=10
+`
+	assert.Equal(t, expected, buf.String())
+}
+
+func Test_logr_info(t *testing.T) {
+	logger := log.New()
+	logger.SetLevel(log.InfoLevel)
+	logger.SetFormatter(&log.TextFormatter{DisableColors: true, DisableTimestamp: true, DisableQuote: true})
+
+	buf := &bytes.Buffer{}
+	logger.SetOutput(buf)
+	l := NewLogr(logger)
+	testRun := func(l logr.Logger) {
+		l.Info("first info message")
+		l.Info("second info message with context", "key1", "value1", "key2", 10)
+
+		l.Error(errors.New("error occurred"), "first error message")
+		l.Error(errors.New("error occurred"), "second error message with context", "key1", "value1", "key2", 10)
+	}
+
+	testRun(l)
+
+	lWithName := l.WithName("test-name")
+	testRun(lWithName)
+
+	lWithFields := l.WithValues("controller", "test-controller")
+	testRun(lWithFields)
+
+	lWithV2 := l.V(2)
+	testRun(lWithV2)
+
+	expected := `level=error msg=first error message error=error occurred
+level=error msg=second error message with context error=error occurred key1=value1 key2=10
+level=error msg=first error message _name=test-name error=error occurred
+level=error msg=second error message with context _name=test-name error=error occurred key1=value1 key2=10
+level=error msg=first error message controller=test-controller error=error occurred
+level=error msg=second error message with context controller=test-controller error=error occurred key1=value1 key2=10
+level=error msg=first error message error=error occurred
+level=error msg=second error message with context error=error occurred key1=value1 key2=10
+`
+	assert.Equal(t, expected, buf.String())
+}