Feat(Logging): create new JSON logger

Signed-off-by: Sébastien GLON <sebastien.glon@ubble.ai>

src/jobservice/logger/backend/db_logger.go

@@ -26,7 +26,7 @@ func NewDBLogger(key string, level string, depth int) (*DBLogger, error) {
 	bw := bufio.NewWriter(buffer)
 	logLevel := parseLevel(level)
 
-	backendLogger := log.New(bw, log.NewTextFormatter(), logLevel, depth)
+	backendLogger := log.New(bw, log.NewFormatter(), logLevel, depth)
 
 	return &DBLogger{
 		backendLogger: backendLogger,

src/jobservice/logger/backend/file_logger.go

@@ -21,7 +21,7 @@ func NewFileLogger(level string, logPath string, depth int) (*FileLogger, error)
 		return nil, err
 	}
 	logLevel := parseLevel(level)
-	backendLogger := log.New(f, log.NewTextFormatter(), logLevel, depth)
+	backendLogger := log.New(f, log.NewFormatter(), logLevel, depth)
 
 	return &FileLogger{
 		backendLogger: backendLogger,

src/jobservice/logger/backend/std_logger.go

@@ -26,7 +26,7 @@ func NewStdOutputLogger(level string, output string, depth int) *StdOutputLogger
 	if output == StdErr {
 		logStream = os.Stderr
 	}
-	backendLogger := log.New(logStream, log.NewTextFormatter(), logLevel, depth)
+	backendLogger := log.New(logStream, log.NewFormatter(), logLevel, depth)
 
 	return &StdOutputLogger{
 		backendLogger: backendLogger,

src/lib/log/formatter.go

@@ -14,7 +14,20 @@
 
 package log
 
+import "os"
+
 // Formatter formats records in different ways: text, json, etc.
 type Formatter interface {
 	Format(*Record) ([]byte, error)
 }
+
+// NewTextFormatter returns a TextFormatter, the format of time is time.RFC3339
+func NewFormatter() Formatter {
+	switch os.Getenv("LOG_FORMAT") {
+	case "json":
+		return NewJsonFormatter()
+	default:
+		return NewTextFormatter()
+	}
+
+}

src/lib/log/jsonformatter.go

@@ -0,0 +1,60 @@
+// Copyright Project Harbor Authors
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//    http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+package log
+
+import (
+	"encoding/json"
+	"fmt"
+	"time"
+)
+
+// JsonFormatter represents a kind of formatter that formats the logs as plain text
+type JsonFormatter struct {
+	// timeFormat string
+}
+
+// NewTextFormatter returns a TextFormatter, the format of time is time.RFC3339
+func NewJsonFormatter() Formatter {
+	return &JsonFormatter{
+		// timeFormat: defaultTimeFormat,
+	}
+}
+
+// Format formats the logs as "time [level] line message"
+func (t *JsonFormatter) Format(r *Record) (b []byte, err error) {
+	//	s := fmt.Sprintf("%s [%s] ", r.Time.Format(t.timeFormat), r.Lvl.string())
+	b, err = json.Marshal(r)
+	if err != nil {
+		fmt.Println(err)
+		return
+	}
+
+	return
+}
+
+// // SetTimeFormat sets time format of JsonFormatter if the parameter fmt is not null
+// func (t *JsonFormatter) SetTimeFormat(fmt string) {
+// 	if len(fmt) != 0 {
+// 		t.timeFormat = fmt
+// 	}
+// }
+
+func (c RecordTime) MarshalJSON() ([]byte, error) {
+	return []byte(`"` + time.Time(c).Format(time.RFC3339) + `"`), nil
+}
+
+func (l Level) MarshalJSON() (b []byte, err error) {
+	return []byte(`"` + l.string() + `"`), nil
+}

src/lib/log/logger.go

@@ -26,7 +26,7 @@ import (
 )
 
 // NOTE: the default depth for the logger is 3 so that we can get the correct file and line when use the logger to log message
-var logger = New(os.Stdout, NewTextFormatter(), WarningLevel, 3)
+var logger = New(os.Stdout, NewFormatter(), WarningLevel, 3)
 
 const srcSeparator = "harbor" + string(os.PathSeparator) + "src"
 
@@ -141,7 +141,6 @@ func (l *Logger) WithFields(fields Fields) *Logger {
 		}
 
 		r.fields = copyFields
-		r.fieldsStr = "[" + strings.Join(parts, " ") + "]"
 	}
 
 	return r
@@ -198,71 +197,71 @@ func (l *Logger) output(record *Record) (err error) {
 // Debug ...
 func (l *Logger) Debug(v ...interface{}) {
 	if l.lvl <= DebugLevel {
-		record := NewRecord(time.Now(), fmt.Sprint(v...), l.getLine(), DebugLevel)
+		record := NewRecord(time.Now(), fmt.Sprint(v...), l.getLine(), DebugLevel, l.fields)
 		_ = l.output(record)
 	}
 }
 
 // Debugf ...
 func (l *Logger) Debugf(format string, v ...interface{}) {
 	if l.lvl <= DebugLevel {
-		record := NewRecord(time.Now(), fmt.Sprintf(format, v...), l.getLine(), DebugLevel)
+		record := NewRecord(time.Now(), fmt.Sprintf(format, v...), l.getLine(), DebugLevel, l.fields)
 		_ = l.output(record)
 	}
 }
 
 // Info ...
 func (l *Logger) Info(v ...interface{}) {
 	if l.lvl <= InfoLevel {
-		record := NewRecord(time.Now(), fmt.Sprint(v...), l.getLine(), InfoLevel)
+		record := NewRecord(time.Now(), fmt.Sprint(v...), l.getLine(), InfoLevel, l.fields)
 		_ = l.output(record)
 	}
 }
 
 // Infof ...
 func (l *Logger) Infof(format string, v ...interface{}) {
 	if l.lvl <= InfoLevel {
-		record := NewRecord(time.Now(), fmt.Sprintf(format, v...), l.getLine(), InfoLevel)
+		record := NewRecord(time.Now(), fmt.Sprintf(format, v...), l.getLine(), InfoLevel, l.fields)
 		_ = l.output(record)
 	}
 }
 
 // Warning ...
 func (l *Logger) Warning(v ...interface{}) {
 	if l.lvl <= WarningLevel {
-		record := NewRecord(time.Now(), fmt.Sprint(v...), l.getLine(), WarningLevel)
+		record := NewRecord(time.Now(), fmt.Sprint(v...), l.getLine(), WarningLevel, l.fields)
 		_ = l.output(record)
 	}
 }
 
 // Warningf ...
 func (l *Logger) Warningf(format string, v ...interface{}) {
 	if l.lvl <= WarningLevel {
-		record := NewRecord(time.Now(), fmt.Sprintf(format, v...), l.getLine(), WarningLevel)
+		record := NewRecord(time.Now(), fmt.Sprintf(format, v...), l.getLine(), WarningLevel, l.fields)
 		_ = l.output(record)
 	}
 }
 
 // Error ...
 func (l *Logger) Error(v ...interface{}) {
 	if l.lvl <= ErrorLevel {
-		record := NewRecord(time.Now(), fmt.Sprint(v...), l.getLine(), ErrorLevel)
+		record := NewRecord(time.Now(), fmt.Sprint(v...), l.getLine(), ErrorLevel, l.fields)
 		_ = l.output(record)
 	}
 }
 
 // Errorf ...
 func (l *Logger) Errorf(format string, v ...interface{}) {
 	if l.lvl <= ErrorLevel {
-		record := NewRecord(time.Now(), fmt.Sprintf(format, v...), l.getLine(), ErrorLevel)
+		record := NewRecord(time.Now(), fmt.Sprintf(format, v...), l.getLine(), ErrorLevel, l.fields)
 		_ = l.output(record)
 	}
 }
 
 // Fatal ...
 func (l *Logger) Fatal(v ...interface{}) {
 	if l.lvl <= FatalLevel {
-		record := NewRecord(time.Now(), fmt.Sprint(v...), l.getLine(), FatalLevel)
+		record := NewRecord(time.Now(), fmt.Sprint(v...), l.getLine(), FatalLevel, l.fields)
 		_ = l.output(record)
 	}
 	os.Exit(1)
@@ -271,7 +270,7 @@ func (l *Logger) Fatal(v ...interface{}) {
 // Fatalf ...
 func (l *Logger) Fatalf(format string, v ...interface{}) {
 	if l.lvl <= FatalLevel {
-		record := NewRecord(time.Now(), fmt.Sprintf(format, v...), l.getLine(), FatalLevel)
+		record := NewRecord(time.Now(), fmt.Sprintf(format, v...), l.getLine(), FatalLevel, l.fields)
 		_ = l.output(record)
 	}
 	os.Exit(1)
@@ -287,13 +286,6 @@ func (l *Logger) getLine() string {
 	if !l.skipLine {
 		str = line(l.callDepth)
 	}
-
-	str = str + l.fieldsStr
-
-	if str != "" {
-		str = str + ":"
-	}
-
 	return str
 }
 

src/lib/log/logger_test.go

@@ -30,7 +30,7 @@ func contains(t *testing.T, str string, lvl string, line, msg string) bool {
 	return strings.Contains(str, lvl) && strings.Contains(str, line) && strings.Contains(str, msg)
 }
 
-func TestSetx(t *testing.T) {
+func TestTextSetx(t *testing.T) {
 	logger := New(nil, nil, WarningLevel)
 	logger.SetOutput(os.Stdout)
 	fmt := NewTextFormatter()
@@ -50,17 +50,37 @@ func TestSetx(t *testing.T) {
 	}
 }
 
+func TestJsonSetx(t *testing.T) {
+	logger := New(nil, nil, WarningLevel)
+	logger.SetOutput(os.Stdout)
+	fmt := NewJsonFormatter()
+	logger.setFormatter(fmt)
+	logger.setLevel(DebugLevel)
+
+	if logger.out != os.Stdout {
+		t.Errorf("unexpected outer: %v != %v", logger.out, os.Stdout)
+	}
+
+	if logger.fmtter != fmt {
+		t.Errorf("unexpected formatter: %v != %v", logger.fmtter, fmt)
+	}
+
+	if logger.lvl != DebugLevel {
+		t.Errorf("unexpected log level: %v != %v", logger.lvl, DebugLevel)
+	}
+}
+
 func TestWithFields(t *testing.T) {
 	buf := enter()
 	defer exit()
 
-	logger.WithFields(Fields{"action": "create"}).Info(message)
+	logger.WithFields(Fields{"action": "create", "field2": "value2"}).Info(message)
 
 	str := buf.String()
 
 	var (
 		expectedLevel = InfoLevel.string()
-		expectLine    = `[action="create"]`
+		expectLine    = `[action="create" field2="value2"]`
 		expectMsg     = "message"
 	)
 
@@ -168,7 +188,7 @@ func TestWarningf(t *testing.T) {
 func TestError(t *testing.T) {
 	var (
 		expectedLevel = ErrorLevel.string()
-		expectLine    = "logger_test.go:178"
+		expectLine    = "logger_test.go:198"
 		expectMsg     = "message"
 	)
 
@@ -186,7 +206,7 @@ func TestError(t *testing.T) {
 func TestErrorf(t *testing.T) {
 	var (
 		expectedLevel = ErrorLevel.string()
-		expectLine    = "logger_test.go:196"
+		expectLine    = "logger_test.go:216"
 		expectMsg     = "message"
 	)
 
@@ -204,7 +224,7 @@ func TestErrorf(t *testing.T) {
 func TestDefaultLoggerErrorf(t *testing.T) {
 	var (
 		expectedLevel = ErrorLevel.string()
-		expectLine    = "logger_test.go:214"
+		expectLine    = "logger_test.go:234"
 		expectMsg     = "message"
 	)
 
@@ -219,6 +239,29 @@ func TestDefaultLoggerErrorf(t *testing.T) {
 	}
 }
 
+func TestJsonFormatWithFields(t *testing.T) {
+	var (
+		expectedLevel = InfoLevel.string()
+		expectLine    = `{"action":"create"}`
+		expectMsg     = "message"
+	)
+
+	logger := New(nil, nil, InfoLevel)
+	b := make([]byte, 0, 32)
+	buf := bytes.NewBuffer(b)
+	logger.SetOutput(buf)
+
+	fmt := NewJsonFormatter()
+	logger.setFormatter(fmt)
+	logger.WithFields(Fields{"action": "create"}).Info(message)
+
+	str := buf.String()
+
+	if !contains(t, str, expectedLevel, expectLine, expectMsg) {
+		t.Errorf("unexpected message: %s, expected level: %s, expected line: %s, expected message: %s", str, expectedLevel, expectLine, expectMsg)
+	}
+}
+
 func enter() *bytes.Buffer {
 	b := make([]byte, 0, 32)
 	buf := bytes.NewBuffer(b)

src/lib/log/record.go

@@ -20,18 +20,22 @@ import (
 
 // Record holds information about log
 type Record struct {
-	Time time.Time // time when the log produced
-	Msg  string    // content of the log
-	Line string    // in which file and line that the log produced
-	Lvl  Level     // level of the log
+	Time   RecordTime // time when the log produced
+	Msg    string     // content of the log
+	Line   string     // in which file and line that the log produced
+	Lvl    Level      `json:"level"` // level of the log
+	Fields map[string]interface{}
 }
 
+type RecordTime time.Time
+
 // NewRecord creates a record according to the arguments provided and returns it
-func NewRecord(time time.Time, msg, line string, lvl Level) *Record {
+func NewRecord(time time.Time, msg, line string, lvl Level, fields map[string]interface{}) *Record {
 	return &Record{
-		Time: time,
-		Msg:  msg,
-		Line: line,
-		Lvl:  lvl,
+		Time:   RecordTime(time),
+		Msg:    msg,
+		Line:   line,
+		Lvl:    lvl,
+		Fields: fields,
 	}
 }