diff --git a/formatter/formatter.go b/formatter/formatter.go new file mode 100644 index 000000000..591a9193b --- /dev/null +++ b/formatter/formatter.go @@ -0,0 +1,51 @@ +package formatter + +import ( + "fmt" + "strings" + "time" + + "github.com/sirupsen/logrus" +) + +// TextFormatter formats logs into text with included source code's path +type TextFormatter struct { + TimestampFormat string + LevelDesc []string +} + +// NewTextFormatter create new MyTextFormatter instance +func NewTextFormatter() *TextFormatter { + return &TextFormatter{ + LevelDesc: []string{"PANC", "FATL", "ERRO", "WARN", "INFO", "DEBG", "TRAC"}, + TimestampFormat: time.RFC3339, // or RFC3339 + } +} + +// Format renders a single log entry +func (f *TextFormatter) Format(entry *logrus.Entry) ([]byte, error) { + var fields string + keys := make([]string, 0, len(entry.Data)) + for k, v := range entry.Data { + if k == "source" { + continue + } + keys = append(keys, fmt.Sprintf("%s: %v", k, v)) + } + + if len(keys) > 0 { + fields = fmt.Sprintf("[%s] ", strings.Join(keys, ", ")) + } + + level := f.parseLevel(entry.Level) + + return []byte(fmt.Sprintf("%s %s %s%s: %s\n", entry.Time.Format(f.TimestampFormat), level, fields, entry.Data["source"], entry.Message)), nil +} + +func (f *TextFormatter) parseLevel(level logrus.Level) string { + if len(f.LevelDesc) < int(level) { + return "" + } + + return f.LevelDesc[level] +} diff --git a/formatter/formatter_test.go b/formatter/formatter_test.go new file mode 100644 index 000000000..8aa1ed4bd --- /dev/null +++ b/formatter/formatter_test.go @@ -0,0 +1,27 @@ +package formatter + +import ( + "testing" + "time" + + "github.com/sirupsen/logrus" + "github.com/stretchr/testify/assert" +) + +func TestLogMessageFormat(t *testing.T) { + + someEntry := &logrus.Entry{ + Data: logrus.Fields{"att1": 1, "att2": 2, "source": "some/fancy/path.go:46"}, + Time: time.Date(2021, time.Month(2), 21, 1, 10, 30, 0, time.UTC), + Level: 3, + Message: "Some Message", + } + + formatter := NewTextFormatter() + result, _ := formatter.Format(someEntry) + + expectedString := "2021-02-21T01:10:30Z WARN [att1: 1, att2: 2] some/fancy/path.go:46: Some Message\n" + parsedString := string(result) + assert.Equal(t, expectedString, parsedString, "The log messages don't match.") + +} diff --git a/formatter/hook.go b/formatter/hook.go new file mode 100644 index 000000000..c3aa77fb3 --- /dev/null +++ b/formatter/hook.go @@ -0,0 +1,61 @@ +package formatter + +import ( + "fmt" + "path" + "runtime/debug" + "strings" + + "github.com/sirupsen/logrus" +) + +// ContextHook is a custom hook for add the source information for the entry +type ContextHook struct { + goModuleName string +} + +// NewContextHook instantiate a new context hook +func NewContextHook() *ContextHook { + hook := &ContextHook{} + hook.goModuleName = hook.moduleName() + "/" + return hook +} + +// Levels set the supported levels for this hook +func (hook ContextHook) Levels() []logrus.Level { + return logrus.AllLevels +} + +// Fire extend with the source information the entry.Data +func (hook ContextHook) Fire(entry *logrus.Entry) error { + src := hook.parseSrc(entry.Caller.File) + entry.Data["source"] = fmt.Sprintf("%s:%v", src, entry.Caller.Line) + return nil +} + +func (hook ContextHook) moduleName() string { + info, ok := debug.ReadBuildInfo() + if ok && info.Main.Path != "" { + return info.Main.Path + } + + return "netbird" +} + +func (hook ContextHook) parseSrc(filePath string) string { + netbirdPath := strings.SplitAfter(filePath, hook.goModuleName) + if len(netbirdPath) > 1 { + return netbirdPath[len(netbirdPath)-1] + } + + // in case of forked repo + netbirdPath = strings.SplitAfter(filePath, "netbird/") + if len(netbirdPath) > 1 { + return netbirdPath[len(netbirdPath)-1] + } + + // in case if log entry is come from external pkg + _, pkg := path.Split(path.Dir(filePath)) + file := path.Base(filePath) + return fmt.Sprintf("%s/%s", pkg, file) +} diff --git a/formatter/hook_test.go b/formatter/hook_test.go new file mode 100644 index 000000000..a4bcb0284 --- /dev/null +++ b/formatter/hook_test.go @@ -0,0 +1,39 @@ +package formatter + +import ( + "testing" + + "github.com/stretchr/testify/assert" +) + +func TestFilePathParsing(t *testing.T) { + + testCases := []struct { + filePath string + expectedFileName string + }{ + // locally cloned repo + { + filePath: "/Users/user/Github/Netbird/netbird/formatter/formatter.go", + expectedFileName: "formatter/formatter.go", + }, + // locally cloned repo with duplicated name in path + { + filePath: "/Users/user/netbird/repos/netbird/formatter/formatter.go", + expectedFileName: "formatter/formatter.go", + }, + // locally cloned repo with renamed package root + { + filePath: "/Users/user/Github/MyOwnNetbirdClient/formatter/formatter.go", + expectedFileName: "formatter/formatter.go", + }, + } + + hook := NewContextHook() + + for _, testCase := range testCases { + parsedString := hook.parseSrc(testCase.filePath) + assert.Equal(t, testCase.expectedFileName, parsedString, "Parsed filepath does not match expected for %s", testCase.filePath) + } + +} diff --git a/formatter/set.go b/formatter/set.go new file mode 100644 index 000000000..2f8e0331f --- /dev/null +++ b/formatter/set.go @@ -0,0 +1,10 @@ +package formatter + +import "github.com/sirupsen/logrus" + +// SetTextFormatter set the formatter for given logger. +func SetTextFormatter(logger *logrus.Logger) { + logger.Formatter = NewTextFormatter() + logger.ReportCaller = true + logger.AddHook(NewContextHook()) +} diff --git a/util/log.go b/util/log.go index b3e13efaa..fda15a541 100644 --- a/util/log.go +++ b/util/log.go @@ -1,14 +1,13 @@ package util import ( + "io" + "path/filepath" + log "github.com/sirupsen/logrus" "gopkg.in/natefinch/lumberjack.v2" - "io" - "path" - "path/filepath" - "runtime" - "strconv" - "time" + + "github.com/netbirdio/netbird/formatter" ) // InitLog parses and sets log-level input @@ -31,21 +30,7 @@ func InitLog(logLevel string, logPath string) error { log.SetOutput(io.Writer(lumberjackLogger)) } - logFormatter := new(log.TextFormatter) - logFormatter.TimestampFormat = time.RFC3339 // or RFC3339 - logFormatter.FullTimestamp = true - logFormatter.CallerPrettyfier = func(frame *runtime.Frame) (function string, file string) { - fileName := path.Base(frame.File) + ":" + strconv.Itoa(frame.Line) - //return frame.Function, fileName - return "", fileName - } - - if level > log.WarnLevel { - log.SetReportCaller(true) - } - - log.SetFormatter(logFormatter) + formatter.SetTextFormatter(log.StandardLogger()) log.SetLevel(level) - return nil }