Skip to content

Commit

Permalink
Support custom loggers
Browse files Browse the repository at this point in the history
Allow to configure custom logger factory. LeveledLogger is now an
interface, and pions logger is DefaultLeveledLogger.  remove globals
Hugo Arregui authored and backkem committed Apr 1, 2019
1 parent 8018f4f commit 5b0f1c8
Showing 6 changed files with 330 additions and 360 deletions.
5 changes: 1 addition & 4 deletions .golangci.yml
Original file line number Diff line number Diff line change
@@ -6,11 +6,8 @@ linters-settings:

linters:
enable-all: true
disable:
- gochecknoinits
- gochecknoglobals

issues:
exclude-use-default: false
max-per-linter: 0
max-same-issues: 50
max-same-issues: 50
1 change: 1 addition & 0 deletions README.md
Original file line number Diff line number Diff line change
@@ -35,6 +35,7 @@ Check out the **[contributing wiki](https://github.com/pions/webrtc/wiki/Contrib
* [Michael MacDonald](https://github.com/mjmac) - *Original Author*
* [Woodrow Douglass](https://github.com/wdouglass) - *Test coverage*
* [Michiel De Backker](https://github.com/backkem) - *Docs*
* [Hugo Arregui](https://github.com/hugoArregui) - *Custom Logs*

### License
MIT License - see [LICENSE](LICENSE) for full text
238 changes: 0 additions & 238 deletions leveled.go

This file was deleted.

217 changes: 217 additions & 0 deletions logger.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,217 @@
package logging

import (
"fmt"
"io"
"log"
"os"
"strings"
"sync"
)

// Use this abstraction to ensure thread-safe access to the logger's io.Writer
// (which could change at runtime)
type loggerWriter struct {
sync.RWMutex
output io.Writer
}

func (lw *loggerWriter) SetOutput(output io.Writer) {
lw.Lock()
defer lw.Unlock()
lw.output = output
}

func (lw *loggerWriter) Write(data []byte) (int, error) {
lw.RLock()
defer lw.RUnlock()
return lw.output.Write(data)
}

// DefaultLeveledLogger encapsulates functionality for providing logging at
// user-defined levels
type DefaultLeveledLogger struct {
level LogLevel
writer *loggerWriter
trace *log.Logger
debug *log.Logger
info *log.Logger
warn *log.Logger
err *log.Logger
}

// WithTraceLogger is a chainable configuration function which sets the
// Trace-level logger
func (ll *DefaultLeveledLogger) WithTraceLogger(log *log.Logger) *DefaultLeveledLogger {
ll.trace = log
return ll
}

// WithDebugLogger is a chainable configuration function which sets the
// Debug-level logger
func (ll *DefaultLeveledLogger) WithDebugLogger(log *log.Logger) *DefaultLeveledLogger {
ll.debug = log
return ll
}

// WithInfoLogger is a chainable configuration function which sets the
// Info-level logger
func (ll *DefaultLeveledLogger) WithInfoLogger(log *log.Logger) *DefaultLeveledLogger {
ll.info = log
return ll
}

// WithWarnLogger is a chainable configuration function which sets the
// Warn-level logger
func (ll *DefaultLeveledLogger) WithWarnLogger(log *log.Logger) *DefaultLeveledLogger {
ll.warn = log
return ll
}

// WithErrorLogger is a chainable configuration function which sets the
// Error-level logger
func (ll *DefaultLeveledLogger) WithErrorLogger(log *log.Logger) *DefaultLeveledLogger {
ll.err = log
return ll
}

// WithOutput is a chainable configuration function which sets the logger's
// logging output to the supplied io.Writer
func (ll *DefaultLeveledLogger) WithOutput(output io.Writer) *DefaultLeveledLogger {
ll.writer.SetOutput(output)
return ll
}

func (ll *DefaultLeveledLogger) logf(logger *log.Logger, level LogLevel, format string, args ...interface{}) {
if ll.level.Get() < level {
return
}

callDepth := 3 // this frame + wrapper func + caller
msg := fmt.Sprintf(format, args...)
if err := logger.Output(callDepth, msg); err != nil {
fmt.Fprintf(os.Stderr, "Unable to log: %s", err)
}
}

// Trace emits the preformatted message if the logger is at or below LogLevelTrace
func (ll *DefaultLeveledLogger) Trace(msg string) {
ll.logf(ll.trace, LogLevelTrace, msg)
}

// Tracef formats and emits a message if the logger is at or below LogLevelTrace
func (ll *DefaultLeveledLogger) Tracef(format string, args ...interface{}) {
ll.logf(ll.trace, LogLevelTrace, format, args...)
}

// Debug emits the preformatted message if the logger is at or below LogLevelDebug
func (ll *DefaultLeveledLogger) Debug(msg string) {
ll.logf(ll.debug, LogLevelDebug, msg)
}

// Debugf formats and emits a message if the logger is at or below LogLevelDebug
func (ll *DefaultLeveledLogger) Debugf(format string, args ...interface{}) {
ll.logf(ll.debug, LogLevelDebug, format, args...)
}

// Info emits the preformatted message if the logger is at or below LogLevelInfo
func (ll *DefaultLeveledLogger) Info(msg string) {
ll.logf(ll.info, LogLevelInfo, msg)
}

// Infof formats and emits a message if the logger is at or below LogLevelInfo
func (ll *DefaultLeveledLogger) Infof(format string, args ...interface{}) {
ll.logf(ll.info, LogLevelInfo, format, args...)
}

// Warn emits the preformatted message if the logger is at or below LogLevelWarn
func (ll *DefaultLeveledLogger) Warn(msg string) {
ll.logf(ll.warn, LogLevelWarn, msg)
}

// Warnf formats and emits a message if the logger is at or below LogLevelWarn
func (ll *DefaultLeveledLogger) Warnf(format string, args ...interface{}) {
ll.logf(ll.warn, LogLevelWarn, format, args...)
}

// Error emits the preformatted message if the logger is at or below LogLevelError
func (ll *DefaultLeveledLogger) Error(msg string) {
ll.logf(ll.err, LogLevelError, msg)
}

// Errorf formats and emits a message if the logger is at or below LogLevelError
func (ll *DefaultLeveledLogger) Errorf(format string, args ...interface{}) {
ll.logf(ll.err, LogLevelError, format, args...)
}

// NewDefaultLeveledLoggerForScope returns a configured LeveledLogger
func NewDefaultLeveledLoggerForScope(scope string, level LogLevel, writer io.Writer) *DefaultLeveledLogger {
if writer == nil {
writer = os.Stdout
}
logger := &DefaultLeveledLogger{
writer: &loggerWriter{output: writer},
level: level,
}
return logger.
WithTraceLogger(log.New(logger.writer, fmt.Sprintf("%s TRACE: ", scope), log.Lmicroseconds|log.Lshortfile)).
WithDebugLogger(log.New(logger.writer, fmt.Sprintf("%s DEBUG: ", scope), log.Lmicroseconds|log.Lshortfile)).
WithInfoLogger(log.New(logger.writer, fmt.Sprintf("%s INFO: ", scope), log.LstdFlags)).
WithWarnLogger(log.New(logger.writer, fmt.Sprintf("%s WARNING: ", scope), log.LstdFlags)).
WithErrorLogger(log.New(logger.writer, fmt.Sprintf("%s ERROR: ", scope), log.LstdFlags))
}

// DefaultLoggerFactory define levels by scopes and creates new DefaultLeveledLogger
type DefaultLoggerFactory struct {
Writer io.Writer
DefaultLogLevel LogLevel
ScopeLevels map[string]LogLevel
}

// NewDefaultLoggerFactory creates a new DefaultLoggerFactory
func NewDefaultLoggerFactory() *DefaultLoggerFactory {
factory := DefaultLoggerFactory{}
factory.DefaultLogLevel = LogLevelError
factory.ScopeLevels = make(map[string]LogLevel)
factory.Writer = os.Stdout

logLevels := map[string]LogLevel{
"ERROR": LogLevelError,
"WARN": LogLevelWarn,
"INFO": LogLevelInfo,
"DEBUG": LogLevelDebug,
"TRACE": LogLevelTrace,
}

for name, level := range logLevels {
env := os.Getenv(fmt.Sprintf("PIONS_LOG_%s", name))
if env == "" {
continue
}

if strings.ToLower(env) == "all" {
factory.DefaultLogLevel = level
continue
}

scopes := strings.Split(strings.ToLower(env), ",")
for _, scope := range scopes {
factory.ScopeLevels[scope] = level
}
}

return &factory
}

// NewLogger returns a configured LeveledLogger for the given , argsscope
func (f *DefaultLoggerFactory) NewLogger(scope string) LeveledLogger {
logLevel := f.DefaultLogLevel
if f.ScopeLevels != nil {
scopeLevel, found := f.ScopeLevels[scope]

if found {
logLevel = scopeLevel
}
}
return NewDefaultLeveledLoggerForScope(scope, logLevel, f.Writer)
}
82 changes: 54 additions & 28 deletions logging_test.go
Original file line number Diff line number Diff line change
@@ -2,17 +2,16 @@ package logging_test

import (
"bytes"
"os"
"strings"
"testing"

"github.com/pions/logging"
)

func TestScopedLogger(t *testing.T) {
func testNoDebugLevel(t *testing.T, logger *logging.DefaultLeveledLogger) {
var outBuf bytes.Buffer
logger := logging.NewScopedLogger("test1").
WithOutput(&outBuf).
WithLogLevel(logging.LogLevelWarn)
logger.WithOutput(&outBuf)

logger.Debug("this shouldn't be logged")
if outBuf.Len() > 0 {
@@ -22,6 +21,26 @@ func TestScopedLogger(t *testing.T) {
if outBuf.Len() > 0 {
t.Error("Debug was logged when it shouldn't have been")
}
}

func testDebugLevel(t *testing.T, logger *logging.DefaultLeveledLogger) {
var outBuf bytes.Buffer
logger.WithOutput(&outBuf)

dbgMsg := "this is a debug message"
logger.Debug(dbgMsg)
if !strings.Contains(outBuf.String(), dbgMsg) {
t.Errorf("Expected to find %q in %q, but didn't", dbgMsg, outBuf.String())
}
logger.Debugf(dbgMsg)
if !strings.Contains(outBuf.String(), dbgMsg) {
t.Errorf("Expected to find %q in %q, but didn't", dbgMsg, outBuf.String())
}
}

func testWarnLevel(t *testing.T, logger *logging.DefaultLeveledLogger) {
var outBuf bytes.Buffer
logger.WithOutput(&outBuf)

warnMsg := "this is a warning message"
logger.Warn(warnMsg)
@@ -32,6 +51,11 @@ func TestScopedLogger(t *testing.T) {
if !strings.Contains(outBuf.String(), warnMsg) {
t.Errorf("Expected to find %q in %q, but didn't", warnMsg, outBuf.String())
}
}

func testErrorLevel(t *testing.T, logger *logging.DefaultLeveledLogger) {
var outBuf bytes.Buffer
logger.WithOutput(&outBuf)

errMsg := "this is an error message"
logger.Error(errMsg)
@@ -44,36 +68,38 @@ func TestScopedLogger(t *testing.T) {
}
}

func TestPackageLevelSettings(t *testing.T) {
var outBuf bytes.Buffer
logger := logging.NewScopedLogger("test2")

// set the package-level writer
logging.SetDefaultWriter(&outBuf)

traceMsg := "this is a trace messages"
logger.Trace(traceMsg)
func TestDefaultLoggerFactory(t *testing.T) {
f := logging.DefaultLoggerFactory{
Writer: os.Stdout,
DefaultLogLevel: logging.LogLevelWarn,
ScopeLevels: map[string]logging.LogLevel{
"foo": logging.LogLevelDebug,
},
}

if outBuf.Len() > 0 {
t.Error("Trace was logged when it shouldn't have been")
logger := f.NewLogger("baz")
bazLogger, ok := logger.(*logging.DefaultLeveledLogger)
if !ok {
t.Error("Invalid logger type")
}

logger.Tracef(traceMsg)
testNoDebugLevel(t, bazLogger)
testWarnLevel(t, bazLogger)

if outBuf.Len() > 0 {
t.Error("Trace was logged when it shouldn't have been")
logger = f.NewLogger("foo")
fooLogger, ok := logger.(*logging.DefaultLeveledLogger)
if !ok {
t.Error("Invalid logger type")
}

// set the logging scope via package
logging.SetLogLevelForScope("test2", logging.LogLevelTrace)
testDebugLevel(t, fooLogger)
}

logger.Trace(traceMsg)
if !strings.Contains(outBuf.String(), traceMsg) {
t.Errorf("Expected to find %q in %q, but didn't", traceMsg, outBuf.String())
}
func TestDefaultLogger(t *testing.T) {
logger := logging.
NewDefaultLeveledLoggerForScope("test1", logging.LogLevelWarn, os.Stdout)

logger.Tracef(traceMsg)
if !strings.Contains(outBuf.String(), traceMsg) {
t.Errorf("Expected to find %q in %q, but didn't", traceMsg, outBuf.String())
}
testNoDebugLevel(t, logger)
testWarnLevel(t, logger)
testErrorLevel(t, logger)
}
147 changes: 57 additions & 90 deletions scoped.go
Original file line number Diff line number Diff line change
@@ -1,105 +1,72 @@
package logging

import (
"fmt"
"os"
"strings"
"sync"
"sync/atomic"
)

type loggerRegistry struct {
sync.RWMutex
scopeLoggers map[string]*LeveledLogger
scopeLevels map[string]LogLevel
}

var (
registry = &loggerRegistry{
scopeLoggers: make(map[string]*LeveledLogger),
scopeLevels: make(map[string]LogLevel),
}
)

// SetLogLevelForScope sets the logging level for the given
// scope, or all scopes if "all" is provided. If a logger
// for the scope does not yet exist, the desired logging
// level is recorded and applied when the scoped logger
// is created.
func SetLogLevelForScope(scope string, level LogLevel) {
registry.Lock()
defer registry.Unlock()

scope = strings.ToLower(scope)
registry.scopeLevels[scope] = level

if scope == "all" {
for _, logger := range registry.scopeLoggers {
logger.SetLevel(level)
}
return
}
// LogLevel represents the level at which the logger will emit log messages
type LogLevel int32

if logger, found := registry.scopeLoggers[scope]; found {
logger.SetLevel(level)
}
// Set updates the LogLevel to the supplied value
func (ll *LogLevel) Set(newLevel LogLevel) {
atomic.StoreInt32((*int32)(ll), int32(newLevel))
}

// NewScopedLogger returns a predefined logger for the given logging scope
// NB: Can be used idempotently
func NewScopedLogger(scope string) *LeveledLogger {
registry.Lock()
defer registry.Unlock()

scope = strings.ToLower(scope)
if _, found := registry.scopeLoggers[scope]; !found {
registry.scopeLoggers[scope] = NewLeveledLoggerForScope(scope)

// Handle a logger being created after init() is run
level := LogLevelDisabled
if allLevel, found := registry.scopeLevels["all"]; found {
level = allLevel
}
if scopeLevel, found := registry.scopeLevels[scope]; found {
if scopeLevel > level {
level = scopeLevel
}
}
if level > LogLevelDisabled {
registry.scopeLoggers[scope].SetLevel(level)
}
}
return registry.scopeLoggers[scope]
// Get retrieves the current LogLevel value
func (ll *LogLevel) Get() LogLevel {
return LogLevel(atomic.LoadInt32((*int32)(ll)))
}

func init() {
logLevels := map[string]LogLevel{
"ERROR": LogLevelError,
"WARN": LogLevelWarn,
"INFO": LogLevelInfo,
"DEBUG": LogLevelDebug,
"TRACE": LogLevelTrace,
func (ll LogLevel) String() string {
switch ll {
case LogLevelDisabled:
return "Disabled"
case LogLevelError:
return "Error"
case LogLevelWarn:
return "Warn"
case LogLevelInfo:
return "Info"
case LogLevelDebug:
return "Debug"
case LogLevelTrace:
return "Trace"
default:
return "UNKNOWN"
}
}

for name, level := range logLevels {
env := os.Getenv(fmt.Sprintf("PIONS_LOG_%s", name))
if env == "" {
continue
}
const (
// LogLevelDisabled completely disables logging of any events
LogLevelDisabled LogLevel = iota
// LogLevelError is for fatal errors which should be handled by user code,
// but are logged to ensure that they are seen
LogLevelError
// LogLevelWarn is for logging abnormal, but non-fatal library operation
LogLevelWarn
// LogLevelInfo is for logging normal library operation (e.g. state transitions, etc.)
LogLevelInfo
// LogLevelDebug is for logging low-level library information (e.g. internal operations)
LogLevelDebug
// LogLevelTrace is for logging very low-level library information (e.g. network traces)
LogLevelTrace
)

if strings.ToLower(env) == "all" {
for _, logger := range registry.scopeLoggers {
logger.SetLevel(level)
}
registry.scopeLevels["all"] = level
continue
}
// LeveledLogger is the basic pions Logger interface
type LeveledLogger interface {
Trace(msg string)
Tracef(format string, args ...interface{})
Debug(msg string)
Debugf(format string, args ...interface{})
Info(msg string)
Infof(format string, args ...interface{})
Warn(msg string)
Warnf(format string, args ...interface{})
Error(msg string)
Errorf(format string, args ...interface{})
}

scopes := strings.Split(strings.ToLower(env), ",")
for _, scope := range scopes {
registry.scopeLevels[scope] = level
if logger, found := registry.scopeLoggers[strings.TrimSpace(scope)]; found {
logger.SetLevel(level)
}
}
}
// LoggerFactory is the basic pions LoggerFactory interface
type LoggerFactory interface {
NewLogger(scope string) LeveledLogger
}

0 comments on commit 5b0f1c8

Please sign in to comment.