Add/update unit test cases for the new implemented job logger framework

Signed-off-by: Steven Zou <szou@vmware.com>

src/jobservice/logger/backend/file_logger_test.go

@@ -0,0 +1,30 @@
+package backend
+
+import (
+	"os"
+	"path"
+	"testing"
+)
+
+// Test file logger creation with non existing file path
+func TestFileLoggerCreation(t *testing.T) {
+	if _, err := NewFileLogger("DEBUG", "/non-existing/a.log"); err == nil {
+		t.Fatalf("expect non nil error but got nil when creating file logger with non existing path")
+	}
+}
+
+// Test file logger
+func TestFileLogger(t *testing.T) {
+	l, err := NewFileLogger("DEBUG", path.Join(os.TempDir(), "TestFileLogger.log"))
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	l.Debug("TestFileLogger")
+	l.Info("TestFileLogger")
+	l.Warning("TestFileLogger")
+	l.Error("TestFileLogger")
+	l.Debugf("%s", "TestFileLogger")
+	l.Warningf("%s", "TestFileLogger")
+	l.Errorf("%s", "TestFileLogger")
+}

src/jobservice/logger/backend/std_logger_test.go

@@ -0,0 +1,16 @@
+package backend
+
+import "testing"
+
+// Test std logger
+func TestStdLogger(t *testing.T) {
+	l := NewStdOutputLogger("DEBUG", StdErr)
+	l.Debug("TestStdLogger")
+	l.Debugf("%s", "TestStdLogger")
+	l.Info("TestStdLogger")
+	l.Infof("%s", "TestStdLogger")
+	l.Warning("TestStdLogger")
+	l.Warningf("%s", "TestStdLogger")
+	l.Error("TestStdLogger")
+	l.Errorf("%s", "TestStdLogger")
+}

src/jobservice/logger/backend/utils_test.go

@@ -0,0 +1,29 @@
+package backend
+
+import (
+	"testing"
+
+	"github.com/goharbor/harbor/src/common/utils/log"
+)
+
+// Test parseLevel
+func TestParseLevel(t *testing.T) {
+	if l := parseLevel(""); l != log.WarningLevel {
+		t.Errorf("expect level %d but got %d", log.WarningLevel, l)
+	}
+	if l := parseLevel("DEBUG"); l != log.DebugLevel {
+		t.Errorf("expect level %d but got %d", log.DebugLevel, l)
+	}
+	if l := parseLevel("info"); l != log.InfoLevel {
+		t.Errorf("expect level %d but got %d", log.InfoLevel, l)
+	}
+	if l := parseLevel("warning"); l != log.WarningLevel {
+		t.Errorf("expect level %d but got %d", log.WarningLevel, l)
+	}
+	if l := parseLevel("error"); l != log.ErrorLevel {
+		t.Errorf("expect level %d but got %d", log.ErrorLevel, l)
+	}
+	if l := parseLevel("FATAL"); l != log.FatalLevel {
+		t.Errorf("expect level %d but got %d", log.FatalLevel, l)
+	}
+}

src/jobservice/logger/base.go

@@ -12,6 +12,11 @@ import (
 	"github.com/goharbor/harbor/src/jobservice/logger/sweeper"
 )
 
+const (
+	systemKeyServiceLogger = "system.jobServiceLogger"
+	systemKeyLogDataGetter = "system.logDataGetter"
+)
+
 var singletons sync.Map
 
 // GetLogger gets an unified logger entry for logging per the passed settings.
@@ -186,7 +191,8 @@ func Init(ctx context.Context) error {
 	if err != nil {
 		return err
 	}
-	jobServiceLogger = lg
+	// Avoid data race issue
+	singletons.Store(systemKeyServiceLogger, lg)
 
 	jOptions := []Option{}
 	// Append configured sweepers in job loggers if existing
@@ -203,7 +209,8 @@ func Init(ctx context.Context) error {
 		return err
 	}
 	if g != nil {
-		logDataGetter = g
+		// Avoid data race issue
+		singletons.Store(systemKeyLogDataGetter, g)
 	}
 
 	// If sweepers configured

src/jobservice/logger/base_test.go

@@ -0,0 +1,216 @@
+package logger
+
+import (
+	"context"
+	"fmt"
+	"io/ioutil"
+	"os"
+	"path"
+	"testing"
+
+	"github.com/goharbor/harbor/src/jobservice/config"
+	"github.com/goharbor/harbor/src/jobservice/logger/backend"
+)
+
+// Test one single std logger
+func TestGetLoggerSingleStd(t *testing.T) {
+	l, err := GetLogger(BackendOption("STD_OUTPUT", "DEBUG", nil))
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	l.Debugf("Verify logger testing: %s", "case_1")
+
+	lSettings := map[string]interface{}{}
+	lSettings["output"] = backend.StdErr
+	l, err = GetLogger(BackendOption("STD_OUTPUT", "ERROR", lSettings))
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	l.Errorf("Verify logger testing: %s", "case_2")
+
+	// With empty options
+	l, err = GetLogger()
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	l.Warningf("Verify logger testing: %s", "case_3")
+}
+
+// Test one single file logger
+func TestGetLoggerSingleFile(t *testing.T) {
+	_, err := GetLogger(BackendOption("FILE", "DEBUG", nil))
+	if err == nil {
+		t.Fatalf("expect non nil error when creating file logger with empty settings but got nil error: %s", "case_4")
+	}
+
+	lSettings := map[string]interface{}{}
+	lSettings["base_dir"] = os.TempDir()
+	lSettings["filename"] = fmt.Sprintf("%s.log", "fake_job_ID")
+	defer func() {
+		if err := os.Remove(path.Join(os.TempDir(), lSettings["filename"].(string))); err != nil {
+			t.Error(err)
+		}
+	}()
+
+	l, err := GetLogger(BackendOption("FILE", "DEBUG", lSettings))
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	l.Debugf("Verify logger testing: %s", "case_5")
+}
+
+// Test getting multi loggers
+func TestGetLoggersMulti(t *testing.T) {
+	lSettings := map[string]interface{}{}
+	lSettings["base_dir"] = os.TempDir()
+	lSettings["filename"] = fmt.Sprintf("%s.log", "fake_job_ID2")
+	defer func() {
+		if err := os.Remove(path.Join(os.TempDir(), lSettings["filename"].(string))); err != nil {
+			t.Error(err)
+		}
+	}()
+
+	ops := []Option{}
+	ops = append(
+		ops,
+		BackendOption("STD_OUTPUT", "DEBUG", nil),
+		BackendOption("FILE", "DEBUG", lSettings),
+	)
+
+	l, err := GetLogger(ops...)
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	l.Infof("Verify logger testing: %s", "case_6")
+}
+
+// Test getting sweepers
+func TestGetSweeper(t *testing.T) {
+	ctx, cancel := context.WithCancel(context.Background())
+	defer cancel()
+
+	_, err := GetSweeper(ctx)
+	if err == nil {
+		t.Fatalf("expect non nil error but got nil error when getting sweeper with empty settings: %s", "case_7")
+	}
+
+	_, err = GetSweeper(ctx, SweeperOption("STD_OUTPUT", 1, nil))
+	if err == nil {
+		t.Fatalf("expect non nil error but got nil error when getting sweeper with name 'STD_OUTPUT': %s", "case_8")
+	}
+
+	sSettings := map[string]interface{}{}
+	sSettings["work_dir"] = os.TempDir()
+	s, err := GetSweeper(ctx, SweeperOption("FILE", 5, sSettings))
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	_, err = s.Sweep()
+	if err != nil {
+		t.Fatalf("[%s] start sweeper error: %s", "case_9", err)
+	}
+}
+
+// Test getting getters
+func TestGetGetter(t *testing.T) {
+	_, err := GetLogDataGetter()
+	if err == nil {
+		t.Fatalf("error should be returned if no options provided: %s", "case_10")
+	}
+
+	// no configured
+	g, err := GetLogDataGetter(GetterOption("STD_OUTPUT", nil))
+	if err != nil || g != nil {
+		t.Fatalf("nil interface with nil error should be returned if no log data getter configured: %s", "case_11")
+	}
+
+	lSettings := map[string]interface{}{}
+	_, err = GetLogDataGetter(GetterOption("FILE", lSettings))
+	if err == nil {
+		t.Fatalf("expect non nil error but got nil one: %s", "case_12")
+	}
+
+	lSettings["base_dir"] = os.TempDir()
+	g, err = GetLogDataGetter(GetterOption("FILE", lSettings))
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	logFile := path.Join(os.TempDir(), "fake_log_file.log")
+	if err := ioutil.WriteFile(logFile, []byte("hello log getter"), 0644); err != nil {
+		t.Fatal(err)
+	}
+	defer func() {
+		if err := os.Remove(logFile); err != nil {
+			t.Error(err)
+		}
+	}()
+
+	data, err := g.Retrieve("fake_log_file")
+	if err != nil {
+		t.Error(err)
+	}
+
+	if len(data) != 16 {
+		t.Errorf("expect 16 bytes data but got %d bytes", len(data))
+	}
+}
+
+// Test init
+func TestLoggerInit(t *testing.T) {
+	ctx, cancel := context.WithCancel(context.Background())
+	defer cancel()
+
+	oldJobLoggerCfg := config.DefaultConfig.JobLoggerConfigs
+	oldLoggerCfg := config.DefaultConfig.LoggerConfigs
+	defer func() {
+		config.DefaultConfig.JobLoggerConfigs = oldJobLoggerCfg
+		config.DefaultConfig.LoggerConfigs = oldLoggerCfg
+	}()
+
+	config.DefaultConfig.JobLoggerConfigs = []*config.LoggerConfig{
+		{
+			Name:  "STD_OUTPUT",
+			Level: "DEBUG",
+			Settings: map[string]interface{}{
+				"output": backend.StdErr,
+			},
+		},
+		{
+			Name:  "FILE",
+			Level: "ERROR",
+			Settings: map[string]interface{}{
+				"base_dir": os.TempDir(),
+			},
+			Sweeper: &config.LogSweeperConfig{
+				Duration: 5,
+				Settings: map[string]interface{}{
+					"work_dir": os.TempDir(),
+				},
+			},
+		},
+	}
+
+	config.DefaultConfig.LoggerConfigs = []*config.LoggerConfig{
+		{
+			Name:  "STD_OUTPUT",
+			Level: "DEBUG",
+		},
+	}
+
+	if err := Init(ctx); err != nil {
+		t.Fatal(err)
+	}
+
+	Debug("Verify logger init: case_13")
+	Info("Verify logger init: case_13")
+	Infof("Verify logger init: %s", "case_13")
+	Error("Verify logger init: case_13")
+	Errorf("Verify logger init: %s", "case_13")
+}

src/jobservice/logger/getter/file_getter_test.go

@@ -0,0 +1,41 @@
+package getter
+
+import (
+	"io/ioutil"
+	"os"
+	"path"
+	"testing"
+
+	"github.com/goharbor/harbor/src/jobservice/errs"
+)
+
+// Test the log data getter
+func TestLogDataGetter(t *testing.T) {
+	fakeLog := path.Join(os.TempDir(), "TestLogDataGetter.log")
+	if err := ioutil.WriteFile(fakeLog, []byte("hello"), 0644); err != nil {
+		t.Fatal(err)
+	}
+	defer func() {
+		if err := os.Remove(fakeLog); err != nil {
+			t.Error(err)
+		}
+	}()
+
+	fg := NewFileGetter(os.TempDir())
+	if _, err := fg.Retrieve("not-existing"); err != nil {
+		if !errs.IsObjectNotFoundError(err) {
+			t.Error("expect object not found error but got other error")
+		}
+	} else {
+		t.Error("expect non nil error but got nil")
+	}
+
+	data, err := fg.Retrieve("TestLogDataGetter")
+	if err != nil {
+		t.Error(err)
+	}
+
+	if len(data) != 5 {
+		t.Errorf("expect reading 5 bytes but got %d bytes", len(data))
+	}
+}

src/jobservice/logger/log_data_handler.go

@@ -6,18 +6,18 @@ import (
 	"github.com/goharbor/harbor/src/jobservice/logger/getter"
 )
 
-var logDataGetter getter.Interface
-
 // Retrieve is wrapper func for getter.Retrieve
 func Retrieve(logID string) ([]byte, error) {
-	if logDataGetter == nil {
+	val, ok := singletons.Load(systemKeyLogDataGetter)
+	if !ok {
 		return nil, errors.New("no log data getter is configured")
 	}
 
-	return logDataGetter.Retrieve(logID)
+	return val.(getter.Interface).Retrieve(logID)
 }
 
 // HasLogGetterConfigured checks if a log data getter is there for using
 func HasLogGetterConfigured() bool {
-	return logDataGetter != nil
+	_, ok := singletons.Load(systemKeyLogDataGetter)
+	return ok
 }

src/jobservice/logger/service.go

@@ -19,104 +19,101 @@ import (
 )
 
 // jobServiceLogger is used to log for job service itself
-var jobServiceLogger Interface
+func jobServiceLogger() (Interface, bool) {
+	val, ok := singletons.Load(systemKeyServiceLogger)
+	if ok {
+		return val.(Interface), ok
+	}
+
+	return nil, false
+}
 
 // Debug ...
 func Debug(v ...interface{}) {
-	if jobServiceLogger != nil {
-		jobServiceLogger.Debug(v...)
-		return
-	}
-
+	if jLogger, ok := jobServiceLogger(); ok {
+		jLogger.Debug(v...)
+	} else {
 		log.Println(v...)
 	}
+}
 
 // Debugf for debuging with format
 func Debugf(format string, v ...interface{}) {
-	if jobServiceLogger != nil {
-		jobServiceLogger.Debugf(format, v...)
-		return
-	}
-
+	if jLogger, ok := jobServiceLogger(); ok {
+		jLogger.Debugf(format, v...)
+	} else {
 		log.Printf(format, v...)
 	}
+}
 
 // Info ...
 func Info(v ...interface{}) {
-	if jobServiceLogger != nil {
-		jobServiceLogger.Info(v...)
-		return
-	}
-
+	if jLogger, ok := jobServiceLogger(); ok {
+		jLogger.Info(v...)
+	} else {
 		log.Println(v...)
 	}
+}
 
 // Infof for logging info with format
 func Infof(format string, v ...interface{}) {
-	if jobServiceLogger != nil {
-		jobServiceLogger.Infof(format, v...)
-		return
-	}
-
+	if jLogger, ok := jobServiceLogger(); ok {
+		jLogger.Infof(format, v...)
+	} else {
 		log.Printf(format, v...)
 	}
+}
 
 // Warning ...
 func Warning(v ...interface{}) {
-	if jobServiceLogger != nil {
-		jobServiceLogger.Warning(v...)
-		return
-	}
-
+	if jLogger, ok := jobServiceLogger(); ok {
+		jLogger.Warning(v...)
+	} else {
 		log.Println(v...)
 	}
+}
 
 // Warningf for warning with format
 func Warningf(format string, v ...interface{}) {
-	if jobServiceLogger != nil {
-		jobServiceLogger.Warningf(format, v...)
-		return
-	}
-
+	if jLogger, ok := jobServiceLogger(); ok {
+		jLogger.Warningf(format, v...)
+	} else {
 		log.Printf(format, v...)
 	}
+}
 
 // Error for logging error
 func Error(v ...interface{}) {
-	if jobServiceLogger != nil {
-		jobServiceLogger.Error(v...)
-		return
-	}
-
+	if jLogger, ok := jobServiceLogger(); ok {
+		jLogger.Error(v...)
+	} else {
 		log.Println(v...)
 	}
+}
 
 // Errorf for logging error with format
 func Errorf(format string, v ...interface{}) {
-	if jobServiceLogger != nil {
-		jobServiceLogger.Errorf(format, v...)
-		return
-	}
-
+	if jLogger, ok := jobServiceLogger(); ok {
+		jLogger.Errorf(format, v...)
+	} else {
 		log.Printf(format, v...)
 	}
+}
 
 // Fatal ...
 func Fatal(v ...interface{}) {
-	if jobServiceLogger != nil {
-		jobServiceLogger.Fatal(v...)
-		return
+	if jLogger, ok := jobServiceLogger(); ok {
+		jLogger.Fatal(v...)
+	} else {
+		log.Fatalln(v...)
 	}
-
-	log.Fatal(v...)
 }
 
 // Fatalf for fatal error with error
 func Fatalf(format string, v ...interface{}) {
-	if jobServiceLogger != nil {
-		jobServiceLogger.Fatalf(format, v...)
-		return
-	}
-
+	if jLogger, ok := jobServiceLogger(); ok {
+		jLogger.Fatalf(format, v...)
+	} else {
 		log.Fatalf(format, v...)
 	}
+}

src/jobservice/logger/sweeper/file_sweeper_test.go

@@ -0,0 +1,45 @@
+package sweeper
+
+import (
+	"io/ioutil"
+	"os"
+	"path"
+	"testing"
+	"time"
+)
+
+// Test file sweeper
+func TestFileSweeper(t *testing.T) {
+	workDir := path.Join(os.TempDir(), "job_logs")
+	if err := os.Mkdir(workDir, os.ModePerm); err != nil {
+		t.Fatal(err)
+	}
+	defer func() {
+		if err := os.RemoveAll(workDir); err != nil {
+			t.Error(err)
+		}
+	}()
+
+	logFile := path.Join(workDir, "TestFileSweeper.log")
+	if err := ioutil.WriteFile(logFile, []byte("hello"), os.ModePerm); err != nil {
+		t.Fatal(err)
+	}
+	oldModTime := time.Unix(time.Now().Unix()-6*24*3600, 0)
+	if err := os.Chtimes(logFile, oldModTime, oldModTime); err != nil {
+		t.Error(err)
+	}
+
+	fs := NewFileSweeper(workDir, 5)
+	if fs.Duration() != 5 {
+		t.Errorf("expect duration 5 but got %d", fs.Duration())
+	}
+
+	count, err := fs.Sweep()
+	if err != nil {
+		t.Error(err)
+	}
+
+	if count != 1 {
+		t.Errorf("expect count 1 but got %d", count)
+	}
+}

src/jobservice/pool/redis_job_wrapper_test.go

@@ -21,6 +21,7 @@ import (
 	"time"
 
 	"github.com/goharbor/harbor/src/jobservice/job"
+	"github.com/goharbor/harbor/src/jobservice/logger/backend"
 	"github.com/goharbor/harbor/src/jobservice/models"
 	"github.com/goharbor/harbor/src/jobservice/utils"
 
@@ -56,16 +57,34 @@ func TestJobWrapper(t *testing.T) {
 		EnqueuedAt: time.Now().Add(5 * time.Minute).Unix(),
 	}
 
-	oldLogConfig := config.DefaultConfig.LoggerConfig
+	oldJobLoggerCfg := config.DefaultConfig.JobLoggerConfigs
 	defer func() {
-		config.DefaultConfig.LoggerConfig = oldLogConfig
+		config.DefaultConfig.JobLoggerConfigs = oldJobLoggerCfg
 	}()
 
-	config.DefaultConfig.LoggerConfig = &config.LoggerConfig{
-		LogLevel:      "debug",
-		ArchivePeriod: 1,
-		BasePath:      os.TempDir(),
+	config.DefaultConfig.JobLoggerConfigs = []*config.LoggerConfig{
+		{
+			Name:  "STD_OUTPUT",
+			Level: "DEBUG",
+			Settings: map[string]interface{}{
+				"output": backend.StdErr,
+			},
+		},
+		{
+			Name:  "FILE",
+			Level: "ERROR",
+			Settings: map[string]interface{}{
+				"base_dir": os.TempDir(),
+			},
+			Sweeper: &config.LogSweeperConfig{
+				Duration: 5,
+				Settings: map[string]interface{}{
+					"work_dir": os.TempDir(),
+				},
+			},
+		},
 	}
+
 	if err := wrapper.Run(j); err != nil {
 		t.Fatal(err)
 	}