feat: logger provider injection

- added implementation for logger provider injection using
log.Initialize() function, which should be called before logging any
line to use custom loger implementation
- implemented log.NewLogger() which returns new instance of logger based
on logger provider initialized
- exposed APIs for log level and caller info management
- closes:hyperledger-archives#21

Signed-off-by: sudesh.shetty <[email protected]>

pkg/common/log/logger.go

@@ -0,0 +1,150 @@
+/*
+Copyright SecureKey Technologies Inc. All Rights Reserved.
+
+SPDX-License-Identifier: Apache-2.0
+*/
+
+package log
+
+import (
+	"sync"
+
+	"github.com/hyperledger/aries-framework-go/pkg/internal/common/logging/metadata"
+)
+
+const (
+	//loggerNotInitializedMsg is used when a logger is not initialized before logging
+	loggerNotInitializedMsg = "Default logger initialized (please call log.Initialize() if you wish to use a custom logger)"
+	loggerModule            = "aries-framework/common"
+)
+
+//Log is an implementation of Logger interface.
+//It encapsulates default or custom logger to provide module and level based logging.
+type Log struct {
+	instance Logger
+	module   string
+	once     sync.Once
+}
+
+// NewLogger creates and returns a Logger object based on the given module name.
+// note: the underlying logger instance is lazy initialized on first use.
+// To use your own logger implementation provide logger provider in 'Initialize()' before logging any line.
+// If 'Initialize()' is not called before logging any line then default logging implementation will be used.
+func NewLogger(module string) Logger {
+	return &Log{module: module}
+}
+
+//Fatalf calls Fatalf function of underlying logger
+//should possibly cause system shutdown based on implementation
+func (l *Log) Fatalf(msg string, args ...interface{}) {
+	l.logger().Fatalf(msg, args...)
+}
+
+//Panicf calls Panic function of underlying logger
+//should possibly cause panic based on implementation
+func (l *Log) Panicf(msg string, args ...interface{}) {
+	l.logger().Panicf(msg, args...)
+}
+
+//Debugf calls Debugf function of underlying logger
+func (l *Log) Debugf(msg string, args ...interface{}) {
+	l.logger().Debugf(msg, args...)
+}
+
+//Infof calls Infof function of underlying logger
+func (l *Log) Infof(msg string, args ...interface{}) {
+	l.logger().Infof(msg, args...)
+}
+
+//Warnf calls Warnf function of underlying logger
+func (l *Log) Warnf(msg string, args ...interface{}) {
+	l.logger().Warnf(msg, args...)
+}
+
+//Errorf calls Errorf function of underlying logger
+func (l *Log) Errorf(msg string, args ...interface{}) {
+	l.logger().Errorf(msg, args...)
+}
+
+func (l *Log) logger() Logger {
+	l.once.Do(func() {
+		l.instance = loggerProvider().GetLogger(l.module)
+	})
+	return l.instance
+}
+
+//SetLevel - setting log level for given module
+//  Parameters:
+//  module is module name
+//  level is logging level
+//If not set default logging level is info
+func SetLevel(module string, level Level) {
+	metadata.SetLevel(module, metadata.Level(level))
+}
+
+//GetLevel - getting log level for given module
+//  Parameters:
+//  module is module name
+//
+//  Returns:
+//  logging level
+//If not set default logging level is info
+func GetLevel(module string) Level {
+	return Level(metadata.GetLevel(module))
+}
+
+//IsEnabledFor - Check if given log level is enabled for given module
+//  Parameters:
+//  module is module name
+//  level is logging level
+//
+//  Returns:
+//  is logging enabled for this module and level
+//If not set default logging level is info
+func IsEnabledFor(module string, level Level) bool {
+	return metadata.IsEnabledFor(module, metadata.Level(level))
+}
+
+// ParseLevel returns the log level from a string representation.
+//  Parameters:
+//  level is logging level in string representation
+//
+//  Returns:
+//  logging level
+func ParseLevel(level string) (Level, error) {
+	l, err := metadata.ParseLevel(level)
+	return Level(l), err
+}
+
+//ShowCallerInfo - Show caller info in log lines for given log level and module
+//  Parameters:
+//  module is module name
+//  level is logging level
+//
+//note: based on implementation of custom logger, callerinfo information may not be available for custom logging provider
+func ShowCallerInfo(module string, level Level) {
+	metadata.ShowCallerInfo(module, metadata.Level(level))
+}
+
+//HideCallerInfo - Do not show caller info in log lines for given log level and module
+//  Parameters:
+//  module is module name
+//  level is logging level
+//
+//note: based on implementation of custom logger, callerinfo information may not be available for custom logging provider
+func HideCallerInfo(module string, level Level) {
+	metadata.HideCallerInfo(module, metadata.Level(level))
+}
+
+//IsCallerInfoEnabled - returns if caller info enabled for given log level and module
+//  Parameters:
+//  module is module name
+//  level is logging level
+//
+//  Returns:
+//  is caller info enabled for this module and level
+//
+//note: based on implementation of custom logger, callerinfo information may not be available for custom logging provider
+func IsCallerInfoEnabled(module string, level Level) bool {
+	return metadata.IsCallerInfoEnabled(module, metadata.Level(level))
+}

pkg/common/log/logger_test.go

@@ -0,0 +1,127 @@
+/*
+Copyright SecureKey Technologies Inc. All Rights Reserved.
+
+SPDX-License-Identifier: Apache-2.0
+*/
+
+package log
+
+import (
+	"sync"
+	"testing"
+
+	"github.com/stretchr/testify/require"
+
+	"github.com/hyperledger/aries-framework-go/pkg/internal/common/logging/metadata"
+	"github.com/hyperledger/aries-framework-go/pkg/internal/common/logging/modlog"
+)
+
+//TestDefaultLogger tests default logging feature when no custom logging provider is supplied through 'Initialize()' call
+func TestDefaultLogger(t *testing.T) {
+
+	defer func() { loggerProviderOnce = sync.Once{} }()
+	const module = "sample-module"
+
+	//get new logger since Initialize is not called, default logger implementation will be used
+	logger := NewLogger(module)
+
+	//force logger instance loading to switch output of logger to buffer for testing
+	logger.Infof("sample output")
+	modlog.SwitchLogOutputToBuffer(logger.(*Log).instance)
+
+	//verify default logger
+	modlog.VerifyDefaultLogging(t, logger, module, metadata.SetLevel)
+
+}
+
+//TestAllLevels tests logging level behaviour
+//logging levels can be set per modules, if not set then it will default to 'INFO'
+func TestAllLevels(t *testing.T) {
+
+	module := "sample-module-critical"
+	SetLevel(module, CRITICAL)
+	require.Equal(t, CRITICAL, GetLevel(module))
+	verifyLevels(t, module, []Level{CRITICAL}, []Level{ERROR, WARNING, INFO, DEBUG})
+
+	module = "sample-module-error"
+	SetLevel(module, ERROR)
+	require.Equal(t, ERROR, GetLevel(module))
+	verifyLevels(t, module, []Level{CRITICAL, ERROR}, []Level{WARNING, INFO, DEBUG})
+
+	module = "sample-module-warning"
+	SetLevel(module, WARNING)
+	require.Equal(t, WARNING, GetLevel(module))
+	verifyLevels(t, module, []Level{CRITICAL, ERROR, WARNING}, []Level{INFO, DEBUG})
+
+	module = "sample-module-info"
+	SetLevel(module, INFO)
+	require.Equal(t, INFO, GetLevel(module))
+	verifyLevels(t, module, []Level{CRITICAL, ERROR, WARNING, INFO}, []Level{DEBUG})
+
+	module = "sample-module-debug"
+	SetLevel(module, DEBUG)
+	require.Equal(t, DEBUG, GetLevel(module))
+	verifyLevels(t, module, []Level{CRITICAL, ERROR, WARNING, INFO, DEBUG}, []Level{})
+
+}
+
+//TestCallerInfos callerinfo behavior which displays caller function details in log lines
+//CallerInfo is available in default logger.
+//Based on implementation it may not be available for custom logger
+func TestCallerInfos(t *testing.T) {
+	module := "sample-module-caller-info"
+
+	ShowCallerInfo(module, CRITICAL)
+	ShowCallerInfo(module, DEBUG)
+	HideCallerInfo(module, INFO)
+	HideCallerInfo(module, ERROR)
+	HideCallerInfo(module, WARNING)
+
+	require.True(t, IsCallerInfoEnabled(module, CRITICAL))
+	require.True(t, IsCallerInfoEnabled(module, DEBUG))
+	require.False(t, IsCallerInfoEnabled(module, INFO))
+	require.False(t, IsCallerInfoEnabled(module, ERROR))
+	require.False(t, IsCallerInfoEnabled(module, WARNING))
+
+}
+
+//TestLogLevel testing 'LogLevel()' used for parsing log levels from strings
+func TestLogLevel(t *testing.T) {
+
+	verifyLevelsNoError := func(expected Level, levels ...string) {
+		for _, level := range levels {
+			actual, err := ParseLevel(level)
+			require.NoError(t, err, "not supposed to fail while parsing level string [%s]", level)
+			require.Equal(t, expected, actual)
+		}
+	}
+
+	verifyLevelsNoError(CRITICAL, "critical", "CRITICAL", "CriticAL")
+	verifyLevelsNoError(ERROR, "error", "ERROR", "ErroR")
+	verifyLevelsNoError(WARNING, "warning", "WARNING", "WarninG")
+	verifyLevelsNoError(DEBUG, "debug", "DEBUG", "DebUg")
+	verifyLevelsNoError(INFO, "info", "INFO", "iNFo")
+}
+
+//TestParseLevelError testing 'LogLevel()' used for parsing log levels from strings
+func TestParseLevelError(t *testing.T) {
+
+	verifyLevelError := func(expected Level, levels ...string) {
+		for _, level := range levels {
+			_, err := ParseLevel(level)
+			require.Error(t, err, "not supposed to succeed while parsing level string [%s]", level)
+		}
+	}
+
+	verifyLevelError(DEBUG, "", "D", "DE BUG", ".")
+
+}
+
+func verifyLevels(t *testing.T, module string, enabled []Level, disabled []Level) {
+	for _, level := range enabled {
+		require.True(t, IsEnabledFor(module, level), "expected level [%s] to be enabled for module [%s]", metadata.ParseString(metadata.Level(level)), module)
+	}
+	for _, level := range disabled {
+		require.False(t, IsEnabledFor(module, level), "expected level [%s] to be disabled for module [%s]", metadata.ParseString(metadata.Level(level)), module)
+	}
+}

pkg/common/log/provider.go

@@ -0,0 +1,55 @@
+/*
+Copyright SecureKey Technologies Inc. All Rights Reserved.
+
+SPDX-License-Identifier: Apache-2.0
+*/
+
+package log
+
+import (
+	"sync"
+
+	"github.com/hyperledger/aries-framework-go/pkg/internal/common/logging/modlog"
+)
+
+// loggerProviderInstance is logger factory singleton - access only via loggerProvider()
+var loggerProviderInstance LoggerProvider
+var loggerProviderOnce sync.Once
+
+//Initialize sets new custom logging provider which takes over logging operations.
+//It is required to call this function before making any loggings for using custom loggers.
+func Initialize(l LoggerProvider) {
+	loggerProviderOnce.Do(func() {
+		loggerProviderInstance = &modlogProvider{l}
+		logger := loggerProviderInstance.GetLogger(loggerModule)
+		logger.Debugf("Logger provider initialized")
+	})
+}
+
+func loggerProvider() LoggerProvider {
+	loggerProviderOnce.Do(func() {
+		// A custom logger must be initialized prior to the first log output
+		// Otherwise the built-in logger is used
+		loggerProviderInstance = &modlogProvider{}
+		logger := loggerProviderInstance.GetLogger(loggerModule)
+		logger.Debugf(loggerNotInitializedMsg)
+	})
+	return loggerProviderInstance
+}
+
+// modlogProvider is a module based logger provider wrapped on given custom logging provider
+// if custom logger provider is not provided, then default logger will be used
+type modlogProvider struct {
+	custom LoggerProvider
+}
+
+//GetLogger returns moduled logger implementation.
+func (p *modlogProvider) GetLogger(module string) Logger {
+	var logger Logger
+	if p.custom != nil {
+		logger = p.custom.GetLogger(module)
+	} else {
+		logger = modlog.NewDefLog(module)
+	}
+	return modlog.NewModLog(logger, module)
+}

pkg/common/log/provider_test.go

@@ -0,0 +1,44 @@
+/*
+Copyright SecureKey Technologies Inc. All Rights Reserved.
+
+SPDX-License-Identifier: Apache-2.0
+*/
+
+package log
+
+import (
+	"sync"
+	"testing"
+
+	"github.com/hyperledger/aries-framework-go/pkg/internal/common/logging/modlog"
+)
+
+//TestDefaultLogger tests custom logging feature when custom logging provider is supplied through 'Initialize()' call
+func TestCustomLogger(t *testing.T) {
+
+	defer func() { loggerProviderOnce = sync.Once{} }()
+	const module = "sample-module"
+
+	//intialize logger provider with custom logger provider
+	Initialize(newCustomProvider(module))
+
+	//get logger instance
+	logger := NewLogger(module)
+
+	modlog.VerifyCustomLogger(t, logger, module)
+}
+
+//newCustomProvider return new sample logging provider to demonstrate custom logging provider
+func newCustomProvider(module string) *sampleProvider {
+	return &sampleProvider{modlog.GetSampleCustomLogger(module)}
+}
+
+// sampleProvider is a custom logging provider
+type sampleProvider struct {
+	logger Logger
+}
+
+//GetLogger returns custom logger implementation
+func (p *sampleProvider) GetLogger(module string) Logger {
+	return p.logger
+}