chore: more logrus api coverage

.github/workflows/pull-request.yml

@@ -0,0 +1,18 @@
+name: pull-request
+
+on:
+  pull_request:
+    branches:
+      - main
+
+jobs:
+  test:
+    runs-on: ubuntu-22.04
+    steps:
+      - uses: actions/checkout@v3
+      - name: Set up Go
+        uses: actions/setup-go@v3
+        with:
+          go-version: 1.16
+      - name: Run unit tests
+        run: make vet test

go.mod

@@ -16,6 +16,7 @@ require (
 	github.com/philhofer/fwd v1.1.1 // indirect
 	github.com/pkg/errors v0.9.1
 	github.com/sirupsen/logrus v1.8.1
+	github.com/stretchr/testify v1.7.0
 	golang.org/x/crypto v0.0.0-20210513164829-c07d793c2f9a
 	golang.org/x/time v0.0.0-20210220033141-f8bda1e9f3ba // indirect
 	golang.org/x/xerrors v0.0.0-20200804184101-5ec99f83aff1 // indirect

log/log.go

@@ -26,7 +26,7 @@ type LogOptions struct {
 }
 
 func InitLog(opts *LogOptions) {
-	Log = NewLogger()
+	Log = newLogger()
 	Log.SetLevel(logrus.DebugLevel) // default
 	logLevel := param.Lookup("LOG_LEVEL", "/replicated/log_level", false)
 	if logLevel != "" {
@@ -80,73 +80,54 @@ func InitLog(opts *LogOptions) {
 	}
 }
 
+func WithField(key string, value interface{}) *logrus.Entry {
+	return Log.WithField(key, value)
+}
+func WithFields(fields logrus.Fields) *logrus.Entry {
+	return Log.WithFields(fields)
+}
+
 func Debug(args ...interface{}) {
 	Log.Debug(args...)
 }
 func Debugf(format string, args ...interface{}) {
 	Log.Debugf(format, args...)
 }
 
-//func DebugFields(format string, fields logrus.Fields) {
-// 	Log.WithFields(fields).Debugf(format)
-//}
-
 func Info(args ...interface{}) {
 	Log.Info(args...)
 }
 func Infof(format string, args ...interface{}) {
 	Log.Infof(format, args...)
 }
 
-//func InfoFields(format string, fields logrus.Fields) {
-// 	Log.WithFields(fields).Infof(format)
-//}
-
 func Warning(args ...interface{}) {
-	err := errors.New(fmt.Sprint(args...), 1)
-	errFields := logrus.Fields{"saaskit.error": err}
-	Log.WithFields(errFields).Warning(args...)
+	Log.WithFields(getSaaskitError(args, 1)).Warning(args...)
 }
 func Warningf(format string, args ...interface{}) {
-	err := errors.New(fmt.Errorf(format, args...), 1)
-	errFields := logrus.Fields{"saaskit.error": err}
-	Log.WithFields(errFields).Warningf(err.Error())
+	Log.WithFields(getSaaskitErrorf(format, args, 1)).Warningf(format, args...)
+}
+func Warn(args ...interface{}) {
+	Log.WithFields(getSaaskitError(args, 1)).Warning(args...)
+}
+func Warnf(format string, args ...interface{}) {
+	Log.WithFields(getSaaskitErrorf(format, args, 1)).Warningf(format, args...)
 }
-
-//func WarningFields(format string, fields logrus.Fields) {
-//	err := errors.New(fmt.Errorf(format, args...), 1)
-//	errFields := logrus.Fields{"saaskit.error": err}
-// 	Log.WithFields(errFields).WithFields(fields).Warningf(message)
-//}
 
 func Error(args ...interface{}) {
-	err := errors.New(fmt.Sprint(args...), 1)
-	errFields := logrus.Fields{"saaskit.error": err}
-	Log.WithFields(errFields).Error(args...)
+	Log.WithFields(getSaaskitError(args, 1)).Error(args...)
 }
 func Errorf(format string, args ...interface{}) {
-	err := errors.New(fmt.Errorf(format, args...), 1)
-	errFields := logrus.Fields{"saaskit.error": err}
-	Log.WithFields(errFields).Errorf(err.Error())
+	Log.WithFields(getSaaskitErrorf(format, args, 1)).Errorf(format, args...)
 }
 
 func Fatal(args ...interface{}) {
-	err := errors.New(fmt.Sprint(args...), 1)
-	errFields := logrus.Fields{"saaskit.error": err}
-	Log.WithFields(errFields).Fatal(args...)
+	Log.WithFields(getSaaskitError(args, 1)).Fatal(args...)
 }
 func Fatalf(format string, args ...interface{}) {
-	err := errors.New(fmt.Errorf(format, args...), 1)
-	errFields := logrus.Fields{"saaskit.error": err}
-	Log.WithFields(errFields).Fatalf(err.Error())
+	Log.WithFields(getSaaskitErrorf(format, args, 1)).Fatalf(format, args...)
 }
 
-//func ErrorFields(format string, fields logrus.Fields) {
-//	err := errors.New(fmt.Errorf(format, args...), 1)
-//	errFields := logrus.Fields{"saaskit.error": err}
-// 	Log.WithFields(errFields).WithFields(fields).Errorf(message)
-//}
-
 func shortPath(pathIn string) string {
 	projectName := param.Lookup("PROJECT_NAME", "", false)
 	if projectName == "" || !strings.Contains(pathIn, projectName) {
@@ -185,3 +166,15 @@ func filterEvents(event *bugsnag.Event, config *bugsnag.Configuration) error {
 	// continue notifying as normal
 	return nil
 }
+
+func getSaaskitError(args []interface{}, skip int) logrus.Fields {
+	if err, ok := args[0].(error); ok {
+		return logrus.Fields{"saaskit.error": err}
+	} else {
+		return getSaaskitError([]interface{}{errors.New(fmt.Sprint(args...), skip+1)}, 0)
+	}
+}
+
+func getSaaskitErrorf(format string, args []interface{}, skip int) logrus.Fields {
+	return getSaaskitError([]interface{}{errors.New(fmt.Sprintf(format, args...), skip+1)}, 0)
+}

log/log_test.go

@@ -1,15 +1,21 @@
 package log
 
 import (
+	"bytes"
 	"context"
 	goerrors "errors"
 	"fmt"
+	"runtime"
+	"strings"
 	"testing"
 
-	perrors "github.com/pkg/errors"
-
-	"github.com/bugsnag/bugsnag-go/v2"
+	bugsnag "github.com/bugsnag/bugsnag-go/v2"
 	"github.com/bugsnag/bugsnag-go/v2/errors"
+	perrors "github.com/pkg/errors"
+	"github.com/replicatedcom/saaskit/param"
+	"github.com/sirupsen/logrus"
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
 )
 
 func TestFilterEvents(t *testing.T) {
@@ -35,3 +41,147 @@ func TestFilterEvents(t *testing.T) {
 		}
 	}
 }
+
+func TestLogMiddleware(t *testing.T) {
+	param.Init(nil)
+
+	h := &hook{}
+
+	out := bytes.NewBuffer(nil)
+	log := newLogger()
+	log.SetOutput(out)
+
+	log.OnBeforeLog(func(entry *logrus.Entry) *logrus.Entry {
+		_, file, line, _ := runtime.Caller(5)
+		fields := logrus.Fields{
+			"saaskit.file_loc": fmt.Sprintf("%s:%d", shortPath(file), line),
+		}
+		return entry.WithFields(fields)
+	})
+
+	log.AddHook(h)
+
+	log.Error("test")
+	assert.Contains(t, out.String(), "saaskit.file_loc")
+
+	assert.Len(t, h.entries, 1)
+	assert.Contains(t, h.entries[0].Data, "saaskit.file_loc")
+
+	out = bytes.NewBuffer(nil)
+	log.SetOutput(out)
+	h.reset()
+
+	log.WithField("test", "test").WithField("test2", "test2").Error("test")
+	assert.Contains(t, out.String(), "saaskit.file_loc")
+
+	assert.Len(t, h.entries, 1)
+	assert.Contains(t, h.entries[0].Data, "saaskit.file_loc")
+}
+
+func TestSaaskitError(t *testing.T) {
+	param.Init(nil)
+
+	Log = newLogger()
+	Log.SetLevel(logrus.DebugLevel) // default
+
+	tests := []struct {
+		name        string
+		args        []interface{}
+		wantErrType interface{}
+	}{
+		{
+			name:        "preserve error type",
+			args:        []interface{}{myError{}},
+			wantErrType: myError{},
+		},
+		{
+			name:        "bugsnag error",
+			args:        []interface{}{"test1", "test2"},
+			wantErrType: &errors.Error{},
+		},
+	}
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			out := bytes.NewBuffer(nil)
+			Log.SetOutput(out)
+
+			h := &hook{}
+			Log.AddHook(h)
+
+			Error(tt.args...)
+
+			require.Len(t, h.entries, 1)
+			require.Contains(t, h.entries[0].Data, "saaskit.error")
+			assert.IsType(t, tt.wantErrType, h.entries[0].Data["saaskit.error"])
+			if bugsnagErr, ok := h.entries[0].Data["saaskit.error"].(*errors.Error); ok {
+				firstLine := strings.Split(string(bugsnagErr.Stack()), "\n")[0]
+				assert.Contains(t, firstLine, "log_test.go:")
+			}
+		})
+	}
+}
+
+func TestSaaskitErrorf(t *testing.T) {
+	param.Init(nil)
+
+	Log = newLogger()
+	Log.SetLevel(logrus.DebugLevel) // default
+
+	tests := []struct {
+		name   string
+		format string
+		args   []interface{}
+	}{
+		{
+			name:   "bugsnag error",
+			format: "test %s %s",
+			args:   []interface{}{"test1", "test2"},
+		},
+	}
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			out := bytes.NewBuffer(nil)
+			Log.SetOutput(out)
+
+			h := &hook{}
+			Log.AddHook(h)
+
+			Errorf(tt.format, tt.args...)
+
+			require.Len(t, h.entries, 1)
+			require.Contains(t, h.entries[0].Data, "saaskit.error")
+			assert.IsType(t, &errors.Error{}, h.entries[0].Data["saaskit.error"])
+			bugsnagErr, _ := h.entries[0].Data["saaskit.error"].(*errors.Error)
+			firstLine := strings.Split(string(bugsnagErr.Stack()), "\n")[0]
+			assert.Contains(t, firstLine, "log_test.go:")
+		})
+	}
+}
+
+type hook struct {
+	entries []*logrus.Entry
+}
+
+func (h *hook) Fire(entry *logrus.Entry) error {
+	h.entries = append(h.entries, entry)
+	return nil
+}
+
+func (h *hook) reset() {
+	h.entries = nil
+}
+
+func (h *hook) Levels() []logrus.Level {
+	return []logrus.Level{
+		logrus.ErrorLevel,
+	}
+}
+
+var _ error = myError{}
+
+type myError struct {
+}
+
+func (e myError) Error() string {
+	return "my error"
+}

log/logger.go

@@ -12,7 +12,7 @@ type Logger struct {
 	middleware middlewareStack
 }
 
-func NewLogger() Logger {
+func newLogger() Logger {
 	return Logger{logrus.New(), middlewareStack{}}
 }
 
@@ -43,6 +43,10 @@ func (logger *Logger) SetOutput(output io.Writer) {
 	logger.logger.SetOutput(output)
 }
 
+func (logger *Logger) SetReportCaller(reportCaller bool) {
+	logger.logger.SetReportCaller(reportCaller)
+}
+
 func (logger *Logger) OnBeforeLog(callback beforeFunc) {
 	logger.middleware.OnBeforeLog(callback)
 }
@@ -99,13 +103,27 @@ func (logger *Logger) Warning(args ...interface{}) {
 	}
 }
 
+func (logger *Logger) Warn(args ...interface{}) {
+	if logger.IsLevelEnabled(logrus.WarnLevel) {
+		entry := logrus.NewEntry(logger.logger)
+		runMiddleware(entry, logger.middleware).Warning(args...)
+	}
+}
+
 func (logger *Logger) Warningf(format string, args ...interface{}) {
 	if logger.IsLevelEnabled(logrus.WarnLevel) {
 		entry := logrus.NewEntry(logger.logger)
 		runMiddleware(entry, logger.middleware).Warningf(format, args...)
 	}
 }
 
+func (logger *Logger) Warnf(format string, args ...interface{}) {
+	if logger.IsLevelEnabled(logrus.WarnLevel) {
+		entry := logrus.NewEntry(logger.logger)
+		runMiddleware(entry, logger.middleware).Warningf(format, args...)
+	}
+}
+
 func (logger *Logger) Error(args ...interface{}) {
 	if logger.IsLevelEnabled(logrus.ErrorLevel) {
 		entry := logrus.NewEntry(logger.logger)

log/mail.go

@@ -17,7 +17,7 @@ type MailLogOptions struct {
 }
 
 func InitMail(opts *MailLogOptions) {
-	MailLog = NewLogger()
+	MailLog = newLogger()
 	MailLog.SetOutput(ioutil.Discard)
 
 	if opts == nil {

log/slack.go

@@ -17,7 +17,7 @@ type SlackLogOptions struct {
 }
 
 func InitSlack(opts *SlackLogOptions) {
-	SlackLog = NewLogger()
+	SlackLog = newLogger()
 	MailLog.SetOutput(ioutil.Discard)
 
 	if opts == nil {