feat: logging interface and default implementation

- provided logging interface
- log levels supported - CRITICAL, ERROR, WARNING, INFO, DEBUG, where
INFO is default logging level
-logging levels will be managed by framework which is module based,
where each modules can maintain their own logging levels
- refers issue hyperledger-archives#21 where more details can be found

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

pkg/common/logging/api/loggerapi.go

@@ -0,0 +1,46 @@
+/*
+Copyright SecureKey Technologies Inc. All Rights Reserved.
+
+SPDX-License-Identifier: Apache-2.0
+*/
+
+package api
+
+// Level defines all available log levels for logging messages.
+type Level int
+
+// Log levels.
+const (
+	CRITICAL Level = iota
+	ERROR
+	WARNING
+	INFO //default logging level
+	DEBUG
+)
+
+//Logger - Standard logger interface
+type Logger interface {
+
+	//Fatalf is critical fatal logging, should possibly followed by system shutdown
+	Fatalf(msg string, args ...interface{})
+
+	//Panicf is critical logging, should possibly followed by panic
+	Panicf(msg string, args ...interface{})
+
+	//Debugf is for logging verbose messages
+	Debugf(msg string, args ...interface{})
+
+	//Infof for logging general logging messages
+	Infof(msg string, args ...interface{})
+
+	//Warnf is for logging messages about possible issues
+	Warnf(msg string, args ...interface{})
+
+	//Errorf is for logging errors
+	Errorf(msg string, args ...interface{})
+}
+
+// LoggerProvider is a factory for moduled loggers
+type LoggerProvider interface {
+	GetLogger(module string) Logger
+}

pkg/common/logging/logger.go

@@ -0,0 +1,172 @@
+/*
+Copyright SecureKey Technologies Inc. All Rights Reserved.
+
+SPDX-License-Identifier: Apache-2.0
+*/
+
+package logging
+
+import (
+	"sync"
+
+	"github.com/hyperledger/aries-framework-go/pkg/common/logging/api"
+	"github.com/hyperledger/aries-framework-go/pkg/internal/common/logging/metadata"
+	"github.com/hyperledger/aries-framework-go/pkg/internal/common/logging/modlog"
+)
+
+const (
+	//loggerNotInitializedMsg is used when a logger is not initialized before logging
+	loggerNotInitializedMsg = "Default logger initialized (please call logging.InitLogger if you wish to use a custom logger)"
+	loggerModule            = "aries-framework/common"
+)
+
+//Logger is a basic implementation of api.Logger interface.
+//It encapsulates default or custom logger to provide module and level based logging.
+type Logger struct {
+	instance api.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
+func NewLogger(module string) *Logger {
+	return &Logger{module: module}
+}
+
+// loggerProviderInstance is logger factory singleton - access only via loggerProvider()
+var loggerProviderInstance api.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 api.LoggerProvider) {
+	loggerProviderOnce.Do(func() {
+		loggerProviderInstance = modlog.ModuledLoggerProvider(modlog.WithCustomProvider(l))
+		logger := loggerProviderInstance.GetLogger(loggerModule)
+		logger.Debugf("Logger provider initialized")
+	})
+}
+
+func loggerProvider() api.LoggerProvider {
+	loggerProviderOnce.Do(func() {
+		// A custom logger must be initialized prior to the first log output
+		// Otherwise the built-in logger is used
+		loggerProviderInstance = modlog.ModuledLoggerProvider()
+		logger := loggerProviderInstance.GetLogger(loggerModule)
+		logger.Debugf(loggerNotInitializedMsg)
+	})
+	return loggerProviderInstance
+}
+
+//Fatalf calls Fatalf function of underlying logger
+//should possibly cause system shutdown based on implementation
+func (l *Logger) 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 *Logger) Panicf(msg string, args ...interface{}) {
+	l.logger().Panicf(msg, args...)
+}
+
+//Debugf calls Debugf function of underlying logger
+func (l *Logger) Debugf(msg string, args ...interface{}) {
+	l.logger().Debugf(msg, args...)
+}
+
+//Infof calls Infof function of underlying logger
+func (l *Logger) Infof(msg string, args ...interface{}) {
+	l.logger().Infof(msg, args...)
+}
+
+//Warnf calls Warnf function of underlying logger
+func (l *Logger) Warnf(msg string, args ...interface{}) {
+	l.logger().Warnf(msg, args...)
+}
+
+//Errorf calls Errorf function of underlying logger
+func (l *Logger) Errorf(msg string, args ...interface{}) {
+	l.logger().Errorf(msg, args...)
+}
+
+func (l *Logger) logger() api.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 api.Level) {
+	modlog.SetLevel(module, 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) api.Level {
+	return modlog.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 api.Level) bool {
+	return modlog.IsEnabledFor(module, level)
+}
+
+// LogLevel returns the log level from a string representation.
+//  Parameters:
+//  level is logging level in string representation
+//
+//  Returns:
+//  logging level
+func LogLevel(level string) (api.Level, error) {
+	return metadata.ParseLevel(level)
+}
+
+//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 api.Level) {
+	modlog.ShowCallerInfo(module, 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 api.Level) {
+	modlog.HideCallerInfo(module, 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
+func IsCallerInfoEnabled(module string, level api.Level) bool {
+	return modlog.IsCallerInfoEnabled(module, level)
+}

pkg/common/logging/logger_test.go

@@ -0,0 +1,140 @@
+/*
+Copyright SecureKey Technologies Inc. All Rights Reserved.
+
+SPDX-License-Identifier: Apache-2.0
+*/
+
+package logging
+
+import (
+	"sync"
+	"testing"
+
+	"github.com/stretchr/testify/require"
+
+	"github.com/hyperledger/aries-framework-go/pkg/common/logging/api"
+	"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"
+	logger := NewLogger(module)
+
+	//force logger instance loading
+	logger.Infof("sample output")
+
+	modlog.SwitchLogOutputToBuffer(logger.instance)
+	modlog.VerifyDefaultLogging(t, logger, module, SetLevel)
+
+}
+
+//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"
+
+	Initialize(modlog.NewCustomLoggingProvider())
+
+	logger := NewLogger(module)
+
+	modlog.VerifyCustomLogger(t, logger, module)
+}
+
+//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, api.CRITICAL)
+	require.Equal(t, api.CRITICAL, GetLevel(module))
+	verifyLevels(t, module, []api.Level{api.CRITICAL}, []api.Level{api.ERROR, api.WARNING, api.INFO, api.DEBUG})
+
+	module = "sample-module-error"
+	SetLevel(module, api.ERROR)
+	require.Equal(t, api.ERROR, GetLevel(module))
+	verifyLevels(t, module, []api.Level{api.CRITICAL, api.ERROR}, []api.Level{api.WARNING, api.INFO, api.DEBUG})
+
+	module = "sample-module-warning"
+	SetLevel(module, api.WARNING)
+	require.Equal(t, api.WARNING, GetLevel(module))
+	verifyLevels(t, module, []api.Level{api.CRITICAL, api.ERROR, api.WARNING}, []api.Level{api.INFO, api.DEBUG})
+
+	module = "sample-module-info"
+	SetLevel(module, api.INFO)
+	require.Equal(t, api.INFO, GetLevel(module))
+	verifyLevels(t, module, []api.Level{api.CRITICAL, api.ERROR, api.WARNING, api.INFO}, []api.Level{api.DEBUG})
+
+	module = "sample-module-debug"
+	SetLevel(module, api.DEBUG)
+	require.Equal(t, api.DEBUG, GetLevel(module))
+	verifyLevels(t, module, []api.Level{api.CRITICAL, api.ERROR, api.WARNING, api.INFO, api.DEBUG}, []api.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, api.CRITICAL)
+	ShowCallerInfo(module, api.DEBUG)
+	HideCallerInfo(module, api.INFO)
+	HideCallerInfo(module, api.ERROR)
+	HideCallerInfo(module, api.WARNING)
+
+	require.True(t, IsCallerInfoEnabled(module, api.CRITICAL))
+	require.True(t, IsCallerInfoEnabled(module, api.DEBUG))
+	require.False(t, IsCallerInfoEnabled(module, api.INFO))
+	require.False(t, IsCallerInfoEnabled(module, api.ERROR))
+	require.False(t, IsCallerInfoEnabled(module, api.WARNING))
+
+}
+
+//TestLogLevel testing 'LogLevel()' used for parsing log levels from strings
+func TestLogLevel(t *testing.T) {
+
+	verifyLevelsNoError := func(expected api.Level, levels ...string) {
+		for _, level := range levels {
+			actual, err := LogLevel(level)
+			require.NoError(t, err, "not supposed to fail while parsing level string [%s]", level)
+			require.Equal(t, expected, actual)
+		}
+	}
+
+	verifyLevelsNoError(api.CRITICAL, "critical", "CRITICAL", "CriticAL")
+	verifyLevelsNoError(api.ERROR, "error", "ERROR", "ErroR")
+	verifyLevelsNoError(api.WARNING, "warning", "WARNING", "WarninG")
+	verifyLevelsNoError(api.DEBUG, "debug", "DEBUG", "DebUg")
+	verifyLevelsNoError(api.INFO, "info", "INFO", "iNFo")
+}
+
+//TestParseLevelError testing 'LogLevel()' used for parsing log levels from strings
+func TestParseLevelError(t *testing.T) {
+
+	verifyLevelError := func(expected api.Level, levels ...string) {
+		for _, level := range levels {
+			_, err := LogLevel(level)
+			require.Error(t, err, "not supposed to succeed while parsing level string [%s]", level)
+		}
+	}
+
+	verifyLevelError(api.DEBUG, "", "D", "DE BUG", ".")
+
+}
+
+func verifyLevels(t *testing.T, module string, enabled []api.Level, disabled []api.Level) {
+	for _, level := range enabled {
+		require.True(t, IsEnabledFor(module, level), "expected level [%s] to be enabled for module [%s]", metadata.ParseString(level), module)
+	}
+	for _, level := range disabled {
+		require.False(t, IsEnabledFor(module, level), "expected level [%s] to be disabled for module [%s]", metadata.ParseString(level), module)
+	}
+}