Begin v2 of the API, fixes memory usage

context.go

@@ -27,7 +27,7 @@ func WithContext(ctx context.Context, logger Logger, args ...interface{}) contex
 // this will never return a nil value.
 func FromContext(ctx context.Context) Logger {
 	logger, _ := ctx.Value(contextKey).(Logger)
-	if logger == nil {
+	if logger.impl == nil {
 		return L()
 	}
 

global.go

@@ -36,7 +36,7 @@ func Default() Logger {
 	protect.Do(func() {
 		// If SetDefault was used before Default() was called, we need to
 		// detect that here.
-		if def == nil {
+		if def.impl == nil {
 			def = New(DefaultOptions)
 		}
 	})

interceptlogger.go

@@ -10,10 +10,10 @@ import (
 	"sync/atomic"
 )
 
-var _ Logger = &interceptLogger{}
+var _ LogImpl = &interceptLogger{}
 
 type interceptLogger struct {
-	Logger
+	LogImpl
 
 	mu        *sync.Mutex
 	sinkCount *int32
@@ -24,10 +24,10 @@ func NewInterceptLogger(opts *LoggerOptions) InterceptLogger {
 	l := newLogger(opts)
 	if l.callerOffset > 0 {
 		// extra frames for interceptLogger.{Warn,Info,Log,etc...}, and interceptLogger.log
-		l.callerOffset += 2
+		l.callerOffset += 0
 	}
 	intercept := &interceptLogger{
-		Logger:    l,
+		LogImpl:   l,
 		mu:        new(sync.Mutex),
 		sinkCount: new(int32),
 		Sinks:     make(map[SinkAdapter]struct{}),
@@ -47,7 +47,7 @@ func (i *interceptLogger) Log(level Level, msg string, args ...interface{}) {
 // depth. By having all the methods call the same helper we ensure the stack
 // frame depth is the same.
 func (i *interceptLogger) log(level Level, msg string, args ...interface{}) {
-	i.Logger.Log(level, msg, args...)
+	i.LogImpl.Log(level, msg, args...)
 	if atomic.LoadInt32(i.sinkCount) == 0 {
 		return
 	}
@@ -85,7 +85,7 @@ func (i *interceptLogger) Error(msg string, args ...interface{}) {
 }
 
 func (i *interceptLogger) retrieveImplied(args ...interface{}) []interface{} {
-	top := i.Logger.ImpliedArgs()
+	top := i.LogImpl.ImpliedArgs()
 
 	cp := make([]interface{}, len(top)+len(args))
 	copy(cp, top)
@@ -97,15 +97,15 @@ func (i *interceptLogger) retrieveImplied(args ...interface{}) []interface{} {
 // Create a new sub-Logger that a name descending from the current name.
 // This is used to create a subsystem specific Logger.
 // Registered sinks will subscribe to these messages as well.
-func (i *interceptLogger) Named(name string) Logger {
+func (i *interceptLogger) Named(name string) LogImpl {
 	return i.NamedIntercept(name)
 }
 
 // Create a new sub-Logger with an explicit name. This ignores the current
 // name. This is used to create a standalone logger that doesn't fall
 // within the normal hierarchy. Registered sinks will subscribe
 // to these messages as well.
-func (i *interceptLogger) ResetNamed(name string) Logger {
+func (i *interceptLogger) ResetNamed(name string) LogImpl {
 	return i.ResetNamedIntercept(name)
 }
 
@@ -116,7 +116,7 @@ func (i *interceptLogger) NamedIntercept(name string) InterceptLogger {
 	var sub interceptLogger
 
 	sub = *i
-	sub.Logger = i.Logger.Named(name)
+	sub.LogImpl = i.LogImpl.Named(name)
 	return &sub
 }
 
@@ -128,19 +128,19 @@ func (i *interceptLogger) ResetNamedIntercept(name string) InterceptLogger {
 	var sub interceptLogger
 
 	sub = *i
-	sub.Logger = i.Logger.ResetNamed(name)
+	sub.LogImpl = i.LogImpl.ResetNamed(name)
 	return &sub
 }
 
 // Return a sub-Logger for which every emitted log message will contain
 // the given key/value pairs. This is used to create a context specific
 // Logger.
-func (i *interceptLogger) With(args ...interface{}) Logger {
+func (i *interceptLogger) With(args ...interface{}) LogImpl {
 	var sub interceptLogger
 
 	sub = *i
 
-	sub.Logger = i.Logger.With(args...)
+	sub.LogImpl = i.LogImpl.With(args...)
 
 	return &sub
 }
@@ -191,15 +191,15 @@ func (i *interceptLogger) StandardWriter(opts *StandardLoggerOptions) io.Writer
 }
 
 func (i *interceptLogger) ResetOutput(opts *LoggerOptions) error {
-	if or, ok := i.Logger.(OutputResettable); ok {
+	if or, ok := i.LogImpl.(OutputResettable); ok {
 		return or.ResetOutput(opts)
 	} else {
 		return nil
 	}
 }
 
 func (i *interceptLogger) ResetOutputWithFlush(opts *LoggerOptions, flushable Flushable) error {
-	if or, ok := i.Logger.(OutputResettable); ok {
+	if or, ok := i.LogImpl.(OutputResettable); ok {
 		return or.ResetOutputWithFlush(opts, flushable)
 	} else {
 		return nil

intlogger.go

@@ -75,7 +75,7 @@ func init() {
 }
 
 // Make sure that intLogger is a Logger
-var _ Logger = &intLogger{}
+var _ LogImpl = &intLogger{}
 
 // intLogger is an internal logger implementation. Internal in that it is
 // defined entirely by this package.
@@ -117,12 +117,14 @@ type intLogger struct {
 	independentLevels bool
 	syncParentLevel   bool
 
-	subloggerHook func(sub Logger) Logger
+	subloggerHook func(sub LogImpl) LogImpl
 }
 
 // New returns a configured logger.
 func New(opts *LoggerOptions) Logger {
-	return newLogger(opts)
+	return Logger{
+		impl: newLogger(opts),
+	}
 }
 
 // NewSinkAdapter returns a SinkAdapter with configured settings
@@ -213,13 +215,13 @@ func newLogger(opts *LoggerOptions) *intLogger {
 	return l
 }
 
-func identityHook(logger Logger) Logger {
+func identityHook(logger LogImpl) LogImpl {
 	return logger
 }
 
 // offsetIntLogger is the stack frame offset in the call stack for the caller to
 // one of the Warn, Info, Log, etc methods.
-const offsetIntLogger = 3
+const offsetIntLogger = 4
 
 // Log a message and a set of key/value pairs if the given level is at
 // or more severe that the threshold configured in the Logger.
@@ -721,6 +723,11 @@ func (l *intLogger) Log(level Level, msg string, args ...interface{}) {
 	l.log(l.Name(), level, msg, args...)
 }
 
+// Emit the message and args at the provided level
+func (l *intLogger) LogRecord(r Record) {
+	l.log(l.Name(), r.Level, r.Msg, r.Args...)
+}
+
 // Emit the message and args at DEBUG level
 func (l *intLogger) Debug(msg string, args ...interface{}) {
 	l.log(l.Name(), Debug, msg, args...)
@@ -776,7 +783,7 @@ const MissingKey = "EXTRA_VALUE_AT_END"
 // Return a sub-Logger for which every emitted log message will contain
 // the given key/value pairs. This is used to create a context specific
 // Logger.
-func (l *intLogger) With(args ...interface{}) Logger {
+func (l *intLogger) With(args ...interface{}) LogImpl {
 	var extra interface{}
 
 	if len(args)%2 != 0 {
@@ -823,7 +830,7 @@ func (l *intLogger) With(args ...interface{}) Logger {
 
 // Create a new sub-Logger that a name decending from the current name.
 // This is used to create a subsystem specific Logger.
-func (l *intLogger) Named(name string) Logger {
+func (l *intLogger) Named(name string) LogImpl {
 	sl := l.copy()
 
 	if sl.name != "" {
@@ -838,7 +845,7 @@ func (l *intLogger) Named(name string) Logger {
 // Create a new sub-Logger with an explicit name. This ignores the current
 // name. This is used to create a standalone logger that doesn't fall
 // within the normal hierarchy.
-func (l *intLogger) ResetNamed(name string) Logger {
+func (l *intLogger) ResetNamed(name string) LogImpl {
 	sl := l.copy()
 
 	sl.name = name

logger.go

@@ -144,14 +144,16 @@ func (l Level) String() string {
 	}
 }
 
-// Logger describes the interface that must be implemented by all loggers.
-type Logger interface {
+// LogImpl describes the interface that must be implemented by all loggers.
+type LogImpl interface {
 	// Args are alternating key, val pairs
 	// keys must be strings
 	// vals can be any type, but display is implementation specific
 	// Emit a message and key/value pairs at a provided log level
 	Log(level Level, msg string, args ...interface{})
 
+	LogRecord(Record)
+
 	// Emit a message and key/value pairs at the TRACE level
 	Trace(msg string, args ...interface{})
 
@@ -187,7 +189,7 @@ type Logger interface {
 	ImpliedArgs() []interface{}
 
 	// Creates a sublogger that will always have the given key/value pairs
-	With(args ...interface{}) Logger
+	With(args ...interface{}) LogImpl
 
 	// Returns the Name of the logger
 	Name() string
@@ -196,12 +198,12 @@ type Logger interface {
 	// If the logger already has a name, the new value will be appended to the current
 	// name. That way, a major subsystem can use this to decorate all it's own logs
 	// without losing context.
-	Named(name string) Logger
+	Named(name string) LogImpl
 
 	// Create a logger that will prepend the name string on the front of all messages.
 	// This sets the name of the logger to the value directly, unlike Named which honor
 	// the current name as well.
-	ResetNamed(name string) Logger
+	ResetNamed(name string) LogImpl
 
 	// Updates the level. This should affect all related loggers as well,
 	// unless they were created with IndependentLevels. If an
@@ -327,7 +329,7 @@ type LoggerOptions struct {
 	// the newly created Logger and the returned Logger is returned from the
 	// original function. This option allows customization via interception and
 	// wrapping of Logger instances.
-	SubloggerHook func(sub Logger) Logger
+	SubloggerHook func(sub LogImpl) LogImpl
 }
 
 // InterceptLogger describes the interface for using a logger
@@ -337,7 +339,7 @@ type LoggerOptions struct {
 // at a higher one.
 type InterceptLogger interface {
 	// Logger is the root logger for an InterceptLogger
-	Logger
+	LogImpl
 
 	// RegisterSink adds a SinkAdapter to the InterceptLogger
 	RegisterSink(sink SinkAdapter)

logger_test.go

@@ -538,7 +538,7 @@ func TestLogger(t *testing.T) {
 
 		assert.Equal(t, "[INFO]  this is test: production=\"12 beans/day\"\n", rest)
 
-		logger.(OutputResettable).ResetOutput(&LoggerOptions{
+		logger.impl.(OutputResettable).ResetOutput(&LoggerOptions{
 			Output: &second,
 		})
 
@@ -568,7 +568,7 @@ func TestLogger(t *testing.T) {
 		str := first.String()
 		assert.Empty(t, str)
 
-		logger.(OutputResettable).ResetOutputWithFlush(&LoggerOptions{
+		logger.impl.(OutputResettable).ResetOutputWithFlush(&LoggerOptions{
 			Output: &second,
 		}, &first)
 

memory_test.go

@@ -0,0 +1,52 @@
+package hclog
+
+import (
+	"bytes"
+	"testing"
+)
+
+func BenchmarkLoggerMemory(b *testing.B) {
+	var buf bytes.Buffer
+
+	logger := New(&LoggerOptions{
+		Name:   "test",
+		Output: &buf,
+		Level:  Info,
+	})
+
+	for i := 0; i < b.N; i++ {
+		logger.Trace("this is some message",
+			"name", "foo",
+			"what", "benchmarking yourself",
+		)
+
+		if buf.Len() != 0 {
+			panic("oops")
+		}
+	}
+}
+
+func TestLoggerMemory(t *testing.T) {
+	var buf bytes.Buffer
+
+	logger := New(&LoggerOptions{
+		Name:   "test",
+		Output: &buf,
+		Level:  Info,
+	})
+
+	avg := testing.AllocsPerRun(100, func() {
+		logger.Trace("this is some message",
+			"name", "foo",
+			"what", "benchmarking yourself",
+		)
+
+		if buf.Len() != 0 {
+			panic("oops")
+		}
+	})
+
+	if avg != 0 {
+		t.Fatalf("ignored logs allocated")
+	}
+}

nulllogger.go

@@ -12,13 +12,14 @@ import (
 // NewNullLogger instantiates a Logger for which all calls
 // will succeed without doing anything.
 // Useful for testing purposes.
-func NewNullLogger() Logger {
+func NewNullLogger() LogImpl {
 	return &nullLogger{}
 }
 
 type nullLogger struct{}
 
 func (l *nullLogger) Log(level Level, msg string, args ...interface{}) {}
+func (l *nullLogger) LogRecord(r Record)                               {}
 
 func (l *nullLogger) Trace(msg string, args ...interface{}) {}
 
@@ -42,13 +43,13 @@ func (l *nullLogger) IsError() bool { return false }
 
 func (l *nullLogger) ImpliedArgs() []interface{} { return []interface{}{} }
 
-func (l *nullLogger) With(args ...interface{}) Logger { return l }
+func (l *nullLogger) With(args ...interface{}) LogImpl { return l }
 
 func (l *nullLogger) Name() string { return "" }
 
-func (l *nullLogger) Named(name string) Logger { return l }
+func (l *nullLogger) Named(name string) LogImpl { return l }
 
-func (l *nullLogger) ResetNamed(name string) Logger { return l }
+func (l *nullLogger) ResetNamed(name string) LogImpl { return l }
 
 func (l *nullLogger) SetLevel(level Level) {}
 

record.go

@@ -0,0 +1,22 @@
+package hclog
+
+const inlineArgs = 10
+
+type Record struct {
+	Level    Level
+	Msg      string
+	CallerPc uintptr
+
+	inline [inlineArgs]interface{}
+	Args   []interface{}
+}
+
+func (r *Record) SetArgs(args []interface{}) {
+	if len(args) > inlineArgs {
+		r.Args = make([]interface{}, len(args))
+		copy(r.Args, args)
+	} else {
+		copy(r.inline[:], args)
+		r.Args = r.inline[:]
+	}
+}