Merge branch 'port-2021-05-05' into 'master'

use go convention for v2 in subdirectory

See merge request dms3/public/go-log!3

go.mod

-module gitlab.dms3.io/dms3/public/go-log/v2
+module gitlab.dms3.io/dms3/public/go-log
 
 require (
 	go.uber.org/multierr v1.6.0

v2/core.go

+package log
+
+import (
+	"sync"
+
+	"go.uber.org/multierr"
+	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
+)
+
+var _ zapcore.Core = (*lockedMultiCore)(nil)
+
+type lockedMultiCore struct {
+	mu    sync.RWMutex // guards mutations to cores slice
+	cores []zapcore.Core
+}
+
+func (l *lockedMultiCore) With(fields []zapcore.Field) zapcore.Core {
+	l.mu.RLock()
+	defer l.mu.RUnlock()
+	sub := &lockedMultiCore{
+		cores: make([]zapcore.Core, len(l.cores)),
+	}
+	for i := range l.cores {
+		sub.cores[i] = l.cores[i].With(fields)
+	}
+	return sub
+}
+
+func (l *lockedMultiCore) Enabled(lvl zapcore.Level) bool {
+	l.mu.RLock()
+	defer l.mu.RUnlock()
+	for i := range l.cores {
+		if l.cores[i].Enabled(lvl) {
+			return true
+		}
+	}
+	return false
+}
+
+func (l *lockedMultiCore) Check(ent zapcore.Entry, ce *zapcore.CheckedEntry) *zapcore.CheckedEntry {
+	l.mu.RLock()
+	defer l.mu.RUnlock()
+	for i := range l.cores {
+		ce = l.cores[i].Check(ent, ce)
+	}
+	return ce
+}
+
+func (l *lockedMultiCore) Write(ent zapcore.Entry, fields []zapcore.Field) error {
+	l.mu.RLock()
+	defer l.mu.RUnlock()
+	var err error
+	for i := range l.cores {
+		err = multierr.Append(err, l.cores[i].Write(ent, fields))
+	}
+	return err
+}
+
+func (l *lockedMultiCore) Sync() error {
+	l.mu.RLock()
+	defer l.mu.RUnlock()
+	var err error
+	for i := range l.cores {
+		err = multierr.Append(err, l.cores[i].Sync())
+	}
+	return err
+}
+
+func (l *lockedMultiCore) AddCore(core zapcore.Core) {
+	l.mu.Lock()
+	defer l.mu.Unlock()
+
+	l.cores = append(l.cores, core)
+}
+
+func (l *lockedMultiCore) DeleteCore(core zapcore.Core) {
+	l.mu.Lock()
+	defer l.mu.Unlock()
+
+	w := 0
+	for i := 0; i < len(l.cores); i++ {
+		if l.cores[i] == core {
+			continue
+		}
+		l.cores[w] = l.cores[i]
+		w++
+	}
+	l.cores = l.cores[:w]
+}
+
+func (l *lockedMultiCore) ReplaceCore(original, replacement zapcore.Core) {
+	l.mu.Lock()
+	defer l.mu.Unlock()
+
+	for i := 0; i < len(l.cores); i++ {
+		if l.cores[i] == original {
+			l.cores[i] = replacement
+		}
+	}
+}
+
+func newCore(format LogFormat, ws zapcore.WriteSyncer, level LogLevel) zapcore.Core {
+	encCfg := zap.NewProductionEncoderConfig()
+	encCfg.EncodeTime = zapcore.ISO8601TimeEncoder
+
+	var encoder zapcore.Encoder
+	switch format {
+	case PlaintextOutput:
+		encCfg.EncodeLevel = zapcore.CapitalLevelEncoder
+		encoder = zapcore.NewConsoleEncoder(encCfg)
+	case JSONOutput:
+		encoder = zapcore.NewJSONEncoder(encCfg)
+	default:
+		encCfg.EncodeLevel = zapcore.CapitalColorLevelEncoder
+		encoder = zapcore.NewConsoleEncoder(encCfg)
+	}
+
+	return zapcore.NewCore(encoder, ws, zap.NewAtomicLevelAt(zapcore.Level(level)))
+}

v2/core_test.go

+package log
+
+import (
+	"bytes"
+	"testing"
+	"time"
+
+	"go.uber.org/zap/zapcore"
+)
+
+func TestNewCoreFormat(t *testing.T) {
+	entry := zapcore.Entry{
+		LoggerName: "main",
+		Level:      zapcore.InfoLevel,
+		Message:    "scooby",
+		Time:       time.Date(2010, 5, 23, 15, 14, 0, 0, time.UTC),
+	}
+
+	testCases := []struct {
+		format LogFormat
+		want   string
+	}{
+		{
+			format: ColorizedOutput,
+			want:   "2010-05-23T15:14:00.000Z\t\x1b[34mINFO\x1b[0m\tmain\tscooby\n",
+		},
+		{
+			format: JSONOutput,
+			want:   `{"level":"info","ts":"2010-05-23T15:14:00.000Z","logger":"main","msg":"scooby"}` + "\n",
+		},
+		{
+			format: PlaintextOutput,
+			want:   "2010-05-23T15:14:00.000Z\tINFO\tmain\tscooby\n",
+		},
+	}
+
+	for _, tc := range testCases {
+		buf := &bytes.Buffer{}
+		ws := zapcore.AddSync(buf)
+
+		core := newCore(tc.format, ws, LevelDebug)
+		if err := core.Write(entry, nil); err != nil {
+			t.Fatalf("unexpected error: %v", err)
+		}
+
+		got := buf.String()
+		if got != tc.want {
+			t.Errorf("got %q, want %q", got, tc.want)
+		}
+	}
+
+}
+
+func TestLockedMultiCoreAddCore(t *testing.T) {
+	mc := &lockedMultiCore{}
+
+	buf1 := &bytes.Buffer{}
+	core1 := newCore(PlaintextOutput, zapcore.AddSync(buf1), LevelDebug)
+	mc.AddCore(core1)
+
+	buf2 := &bytes.Buffer{}
+	core2 := newCore(ColorizedOutput, zapcore.AddSync(buf2), LevelDebug)
+	mc.AddCore(core2)
+
+	entry := zapcore.Entry{
+		LoggerName: "main",
+		Level:      zapcore.InfoLevel,
+		Message:    "scooby",
+		Time:       time.Date(2010, 5, 23, 15, 14, 0, 0, time.UTC),
+	}
+	if err := mc.Write(entry, nil); err != nil {
+		t.Fatalf("unexpected error: %v", err)
+	}
+
+	want1 := "2010-05-23T15:14:00.000Z\tINFO\tmain\tscooby\n"
+	got1 := buf1.String()
+	if got1 != want1 {
+		t.Errorf("core1 got %q, want %q", got1, want1)
+	}
+
+	want2 := "2010-05-23T15:14:00.000Z\t\x1b[34mINFO\x1b[0m\tmain\tscooby\n"
+	got2 := buf2.String()
+	if got2 != want2 {
+		t.Errorf("core2 got %q, want %q", got2, want2)
+	}
+
+}
+
+func TestLockedMultiCoreDeleteCore(t *testing.T) {
+
+	mc := &lockedMultiCore{}
+
+	buf1 := &bytes.Buffer{}
+	core1 := newCore(PlaintextOutput, zapcore.AddSync(buf1), LevelDebug)
+	mc.AddCore(core1)
+
+	// Write entry to just first core
+	entry := zapcore.Entry{
+		LoggerName: "main",
+		Level:      zapcore.InfoLevel,
+		Message:    "scooby",
+		Time:       time.Date(2010, 5, 23, 15, 14, 0, 0, time.UTC),
+	}
+	if err := mc.Write(entry, nil); err != nil {
+		t.Fatalf("unexpected error: %v", err)
+	}
+
+	buf2 := &bytes.Buffer{}
+	core2 := newCore(ColorizedOutput, zapcore.AddSync(buf2), LevelDebug)
+	mc.AddCore(core2)
+
+	// Remove the first core
+	mc.DeleteCore(core1)
+
+	// Write another entry
+	entry2 := zapcore.Entry{
+		LoggerName: "main",
+		Level:      zapcore.InfoLevel,
+		Message:    "velma",
+		Time:       time.Date(2010, 5, 23, 15, 15, 0, 0, time.UTC),
+	}
+
+	if err := mc.Write(entry2, nil); err != nil {
+		t.Fatalf("unexpected error: %v", err)
+	}
+
+	want1 := "2010-05-23T15:14:00.000Z\tINFO\tmain\tscooby\n"
+	got1 := buf1.String()
+	if got1 != want1 {
+		t.Errorf("core1 got %q, want %q", got1, want1)
+	}
+
+	want2 := "2010-05-23T15:15:00.000Z\t\x1b[34mINFO\x1b[0m\tmain\tvelma\n"
+	got2 := buf2.String()
+	if got2 != want2 {
+		t.Errorf("core2 got %q, want %q", got2, want2)
+	}
+
+}
+
+func TestLockedMultiCoreReplaceCore(t *testing.T) {
+	mc := &lockedMultiCore{}
+
+	buf1 := &bytes.Buffer{}
+	core1 := newCore(PlaintextOutput, zapcore.AddSync(buf1), LevelDebug)
+	mc.AddCore(core1)
+
+	// Write entry to just first core
+	entry := zapcore.Entry{
+		LoggerName: "main",
+		Level:      zapcore.InfoLevel,
+		Message:    "scooby",
+		Time:       time.Date(2010, 5, 23, 15, 14, 0, 0, time.UTC),
+	}
+	if err := mc.Write(entry, nil); err != nil {
+		t.Fatalf("unexpected error: %v", err)
+	}
+
+	buf2 := &bytes.Buffer{}
+	core2 := newCore(ColorizedOutput, zapcore.AddSync(buf2), LevelDebug)
+
+	// Replace the first core with the second
+	mc.ReplaceCore(core1, core2)
+
+	// Write another entry
+	entry2 := zapcore.Entry{
+		LoggerName: "main",
+		Level:      zapcore.InfoLevel,
+		Message:    "velma",
+		Time:       time.Date(2010, 5, 23, 15, 15, 0, 0, time.UTC),
+	}
+
+	if err := mc.Write(entry2, nil); err != nil {
+		t.Fatalf("unexpected error: %v", err)
+	}
+
+	want1 := "2010-05-23T15:14:00.000Z\tINFO\tmain\tscooby\n"
+	got1 := buf1.String()
+	if got1 != want1 {
+		t.Errorf("core1 got %q, want %q", got1, want1)
+	}
+
+	want2 := "2010-05-23T15:15:00.000Z\t\x1b[34mINFO\x1b[0m\tmain\tvelma\n"
+	got2 := buf2.String()
+	if got2 != want2 {
+		t.Errorf("core2 got %q, want %q", got2, want2)
+	}
+
+}

v2/go.mod

+module gitlab.dms3.io/dms3/public/go-log/v2
+
+require (
+	go.uber.org/multierr v1.6.0
+	go.uber.org/zap v1.16.0
+)
+
+go 1.15

v2/go.sum

+github.com/BurntSushi/toml v0.3.1/go.mod h1:xHWCNGjB5oqiDr8zfno3MHue2Ht5sIBksp03qcyfWMU=
+github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
+github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
+github.com/google/renameio v0.1.0/go.mod h1:KWCgfxg9yswjAJkECMjeO8J8rahYeXnNhOm40UhjYkI=
+github.com/kisielk/gotool v1.0.0/go.mod h1:XhKaO+MFFWcvkIS/tQcRk01m1F5IRFswLeQ+oQHNcck=
+github.com/kr/pretty v0.1.0/go.mod h1:dAy3ld7l9f0ibDNOQOHHMYYIIbhfbHSm3C4ZsoJORNo=
+github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ=
+github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI=
+github.com/pkg/errors v0.8.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
+github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
+github.com/rogpeppe/go-internal v1.3.0/go.mod h1:M8bDsm7K2OlrFYOpmOWEs/qY81heoFRclV5y23lUDJ4=
+github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
+github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI=
+github.com/stretchr/testify v1.4.0/go.mod h1:j7eGeouHqKxXV5pUuKE4zz7dFj8WfuZ+81PSLYec5m4=
+go.uber.org/atomic v1.6.0/go.mod h1:sABNBOSYdrvTF6hTgEIbc7YasKWGhgEQZyfxyTvoXHQ=
+go.uber.org/atomic v1.7.0 h1:ADUqmZGgLDDfbSL9ZmPxKTybcoEYHgpYfELNoN+7hsw=
+go.uber.org/atomic v1.7.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc=
+go.uber.org/multierr v1.5.0/go.mod h1:FeouvMocqHpRaaGuG9EjoKcStLC43Zu/fmqdUMPcKYU=
+go.uber.org/multierr v1.6.0 h1:y6IPFStTAIT5Ytl7/XYmHvzXQ7S3g/IeZW9hyZ5thw4=
+go.uber.org/multierr v1.6.0/go.mod h1:cdWPpRnG4AhwMwsgIHip0KRBQjJy5kYEpYjJxpXp9iU=
+go.uber.org/tools v0.0.0-20190618225709-2cfd321de3ee/go.mod h1:vJERXedbb3MVM5f9Ejo0C68/HhF8uaILCdgjnY+goOA=
+go.uber.org/zap v1.16.0 h1:uFRZXykJGK9lLY4HtgSw44DnIcAM+kRBP7x5m+NpAOM=
+go.uber.org/zap v1.16.0/go.mod h1:MA8QOfq0BHJwdXa996Y4dYkAqRKB8/1K1QMMZVaNZjQ=
+golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w=
+golang.org/x/crypto v0.0.0-20190510104115-cbcb75029529/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI=
+golang.org/x/lint v0.0.0-20190930215403-16217165b5de/go.mod h1:6SW0HCj/g11FgYtHlgUYUwCkIfeOF89ocIRzGO/8vkc=
+golang.org/x/mod v0.0.0-20190513183733-4bf6d317e70e/go.mod h1:mXi4GBBbnImb6dmsKGUJ2LatrhH/nqhxcFungHvyanc=
+golang.org/x/net v0.0.0-20190311183353-d8887717615a/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg=
+golang.org/x/net v0.0.0-20190404232315-eb5bcb51f2a3/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg=
+golang.org/x/net v0.0.0-20190620200207-3b0461eec859/go.mod h1:z5CRVTTTmAJ677TzLLGU+0bjPO0LkuOLi4/5GtJWs/s=
+golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
+golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY=
+golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
+golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ=
+golang.org/x/tools v0.0.0-20190311212946-11955173bddd/go.mod h1:LCzVGOaR6xXOjkQ3onu1FJEFr0SW1gC7cKk1uF8kGRs=
+golang.org/x/tools v0.0.0-20190621195816-6e04913cbbac/go.mod h1:/rFqwRUd4F7ZHNgwSSTFct+R/Kf4OFW1sUzUTQQTgfc=
+golang.org/x/tools v0.0.0-20191029041327-9cc4af7d6b2c/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo=
+golang.org/x/tools v0.0.0-20191029190741-b9c20aec41a5/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo=
+golang.org/x/xerrors v0.0.0-20190717185122-a985d3407aa7/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
+gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
+gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
+gopkg.in/errgo.v2 v2.1.0/go.mod h1:hNsd1EY+bozCKY1Ytp96fpM3vjJbqLJn88ws8XvfDNI=
+gopkg.in/yaml.v2 v2.2.2/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI=
+honnef.co/go/tools v0.0.1-2019.2.3/go.mod h1:a3bituU0lyd329TUQxRnasdCoJDkEUEAqEt0JzvZhAg=

v2/levels.go

+package log
+
+import "go.uber.org/zap/zapcore"
+
+// LogLevel represents a log severity level. Use the package variables as an
+// enum.
+type LogLevel zapcore.Level
+
+var (
+	LevelDebug  = LogLevel(zapcore.DebugLevel)
+	LevelInfo   = LogLevel(zapcore.InfoLevel)
+	LevelWarn   = LogLevel(zapcore.WarnLevel)
+	LevelError  = LogLevel(zapcore.ErrorLevel)
+	LevelDPanic = LogLevel(zapcore.DPanicLevel)
+	LevelPanic  = LogLevel(zapcore.PanicLevel)
+	LevelFatal  = LogLevel(zapcore.FatalLevel)
+)
+
+// LevelFromString parses a string-based level and returns the corresponding
+// LogLevel.
+//
+// Supported strings are: DEBUG, INFO, WARN, ERROR, DPANIC, PANIC, FATAL, and
+// their lower-case forms.
+//
+// The returned LogLevel must be discarded if error is not nil.
+func LevelFromString(level string) (LogLevel, error) {
+	lvl := zapcore.InfoLevel // zero value
+	err := lvl.Set(level)
+	return LogLevel(lvl), err
+}

v2/log.go

+// Package log is the logging library used by IPFS & libp2p
+// (https://gitlab.dms3.io/dms3/public/go-dms3).
+package log
+
+import (
+	"time"
+
+	"go.uber.org/zap"
+)
+
+// StandardLogger provides API compatibility with standard printf loggers
+// eg. go-logging
+type StandardLogger interface {
+	Debug(args ...interface{})
+	Debugf(format string, args ...interface{})
+	Error(args ...interface{})
+	Errorf(format string, args ...interface{})
+	Fatal(args ...interface{})
+	Fatalf(format string, args ...interface{})
+	Info(args ...interface{})
+	Infof(format string, args ...interface{})
+	Panic(args ...interface{})
+	Panicf(format string, args ...interface{})
+	Warn(args ...interface{})
+	Warnf(format string, args ...interface{})
+}
+
+// EventLogger extends the StandardLogger interface to allow for log items
+// containing structured metadata
+type EventLogger interface {
+	StandardLogger
+}
+
+// Logger retrieves an event logger by name
+func Logger(system string) *ZapEventLogger {
+	if len(system) == 0 {
+		setuplog := getLogger("setup-logger")
+		setuplog.Error("Missing name parameter")
+		system = "undefined"
+	}
+
+	logger := getLogger(system)
+	skipLogger := logger.Desugar().WithOptions(zap.AddCallerSkip(1)).Sugar()
+
+	return &ZapEventLogger{
+		system:        system,
+		SugaredLogger: *logger,
+		skipLogger:    *skipLogger,
+	}
+}
+
+// ZapEventLogger implements the EventLogger and wraps a go-logging Logger
+type ZapEventLogger struct {
+	zap.SugaredLogger
+	// used to fix the caller location when calling Warning and Warningf.
+	skipLogger zap.SugaredLogger
+	system     string
+}
+
+// Warning is for compatibility
+// Deprecated: use Warn(args ...interface{}) instead
+func (logger *ZapEventLogger) Warning(args ...interface{}) {
+	logger.skipLogger.Warn(args...)
+}
+
+// Warningf is for compatibility
+// Deprecated: use Warnf(format string, args ...interface{}) instead
+func (logger *ZapEventLogger) Warningf(format string, args ...interface{}) {
+	logger.skipLogger.Warnf(format, args...)
+}
+
+// FormatRFC3339 returns the given time in UTC with RFC3999Nano format.
+func FormatRFC3339(t time.Time) string {
+	return t.UTC().Format(time.RFC3339Nano)
+}

v2/log_level_test.go

+package log
+
+import (
+	"encoding/json"
+	"io"
+	"testing"
+)
+
+func TestLogLevel(t *testing.T) {
+	const subsystem = "log-level-test"
+	logger := Logger(subsystem)
+	reader := NewPipeReader()
+	done := make(chan struct{})
+	go func() {
+		defer close(done)
+		decoder := json.NewDecoder(reader)
+		for {
+			var entry struct {
+				Message string `json:"msg"`
+				Caller  string `json:"caller"`
+			}
+			err := decoder.Decode(&entry)
+			switch err {
+			default:
+				t.Error(err)
+				return
+			case io.EOF:
+				return
+			case nil:
+			}
+			if entry.Message != "bar" {
+				t.Errorf("unexpected message: %s", entry.Message)
+			}
+			if entry.Caller == "" {
+				t.Errorf("no caller in log entry")
+			}
+		}
+	}()
+	logger.Debugw("foo")
+	if err := SetLogLevel(subsystem, "debug"); err != nil {
+		t.Error(err)
+	}
+	logger.Debugw("bar")
+	SetAllLoggers(LevelInfo)
+	logger.Debugw("baz")
+	// ignore the error because
+	// https://github.com/uber-go/zap/issues/880
+	_ = logger.Sync()
+	if err := reader.Close(); err != nil {
+		t.Error(err)
+	}
+	<-done
+}

v2/logbench_test.go

+package log
+
+import (
+	"sync"
+	"testing"
+)
+
+// To run bencharks:
+//   > go test -c .
+//   > ./go-log.test -test.run NONE -test.bench . 2>/dev/null
+// Otherwise you test how fast your terminal can print.
+
+func BenchmarkSimpleInfo(b *testing.B) {
+	l := Logger("bench")
+	err := SetLogLevel("bench", "info")
+	if err != nil {
+		b.Fatal(err)
+	}
+
+	b.ResetTimer()
+	b.ReportAllocs()
+	for i := 0; i < b.N; i++ {
+		l.Info("test")
+	}
+}
+
+var logString = "String, IDK what to write, let's punch a keyboard. jkdlsjklfdjfklsjfklsdjaflkdjfkdjsfkldjsfkdjklfjdslfjakdfjioerjieofjofdnvonoijdfneslkffjsdfljadljfdjkfjkf"
+
+func BenchmarkFormatInfo(b *testing.B) {
+	l := Logger("bench")
+	err := SetLogLevel("bench", "info")
+	if err != nil {
+		b.Fatal(err)
+	}
+
+	b.ResetTimer()
+	b.ReportAllocs()
+	for i := 0; i < b.N; i++ {
+		l.Infof("test %d %s", logString)
+	}
+}
+
+func BenchmarkFormatInfoMulti(b *testing.B) {
+	l := Logger("bench")
+	err := SetLogLevel("bench", "info")
+	if err != nil {
+		b.Fatal(err)
+	}
+	var wg sync.WaitGroup
+
+	goroutines := 16
+
+	run := func() {
+		for i := 0; i < b.N/goroutines; i++ {
+			l.Infof("test %d %s", i, logString)
+		}
+		wg.Done()
+	}
+
+	wg.Add(goroutines)
+
+	b.ResetTimer()
+	b.ReportAllocs()
+	for i := 0; i < goroutines; i++ {
+		go run()
+	}
+	wg.Wait()
+}

v2/path_other.go

+//+build !windows
+
+package log
+
+import (
+	"path/filepath"
+)
+
+func normalizePath(p string) (string, error) {
+	return filepath.Abs(p)
+}

v2/path_windows.go

+//+build windows
+
+package log
+
+import (
+	"fmt"
+	"path/filepath"
+	"strings"
+)
+
+func normalizePath(p string) (string, error) {
+	if p == "" {
+		return "", fmt.Errorf("path empty")
+	}
+	p, err := filepath.Abs(p)
+	if err != nil {
+		return "", err
+	}
+	// Is this _really_ an absolute path?
+	if !strings.HasPrefix(p, "\\\\") {
+		// It's a drive: path!
+		// Return a UNC path.
+		p = "\\\\%3F\\" + p
+	}
+
+	// This will return file:////?/c:/foobar
+	//
+	// Why? Because:
+	//  1. Go will choke on file://c:/ because the "domain" includes a :.
+	//  2. Windows will choke on file:///c:/ because the path will be
+	//     /c:/... which is _relative_ to the current drive.
+	//
+	// This path (a) has no "domain" and (b) starts with a slash. Yay!
+	return "file://" + filepath.ToSlash(p), nil
+}

v2/pipe.go

+package log
+
+import (
+	"io"
+
+	"go.uber.org/multierr"
+	"go.uber.org/zap/zapcore"
+)
+
+// A PipeReader is a reader that reads from the logger. It is synchronous
+// so blocking on read will affect logging performance.
+type PipeReader struct {
+	r      *io.PipeReader
+	closer io.Closer
+	core   zapcore.Core
+}
+
+// Read implements the standard Read interface
+func (p *PipeReader) Read(data []byte) (int, error) {
+	return p.r.Read(data)
+}
+
+// Close unregisters the reader from the logger.
+func (p *PipeReader) Close() error {
+	if p.core != nil {
+		loggerCore.DeleteCore(p.core)
+	}
+	return multierr.Append(p.core.Sync(), p.closer.Close())
+}
+
+// NewPipeReader creates a new in-memory reader that reads from all loggers
+// The caller must call Close on the returned reader when done.
+//
+// By default, it:
+//
+// 1. Logs JSON. This can be changed by passing the PipeFormat option.
+// 2. Logs everything that would otherwise be logged to the "primary" log
+//    output. That is, everything enabled by SetLogLevel. The minimum log level
+//    can be increased by passing the PipeLevel option.
+func NewPipeReader(opts ...PipeReaderOption) *PipeReader {
+	opt := pipeReaderOptions{
+		format: JSONOutput,
+		level:  LevelDebug,
+	}
+
+	for _, o := range opts {
+		o.setOption(&opt)
+	}
+
+	r, w := io.Pipe()
+
+	p := &PipeReader{
+		r:      r,
+		closer: w,
+		core:   newCore(opt.format, zapcore.AddSync(w), opt.level),
+	}
+
+	loggerCore.AddCore(p.core)
+
+	return p
+}
+
+type pipeReaderOptions struct {
+	format LogFormat
+	level  LogLevel
+}
+
+type PipeReaderOption interface {
+	setOption(*pipeReaderOptions)
+}
+
+type pipeReaderOptionFunc func(*pipeReaderOptions)
+
+func (p pipeReaderOptionFunc) setOption(o *pipeReaderOptions) {
+	p(o)
+}
+
+// PipeFormat sets the output format of the pipe reader
+func PipeFormat(format LogFormat) PipeReaderOption {
+	return pipeReaderOptionFunc(func(o *pipeReaderOptions) {
+		o.format = format
+	})
+}
+
+// PipeLevel sets the log level of logs sent to the pipe reader.
+func PipeLevel(level LogLevel) PipeReaderOption {
+	return pipeReaderOptionFunc(func(o *pipeReaderOptions) {
+		o.level = level
+	})
+}

v2/pipe_test.go

+package log
+
+import (
+	"bytes"
+	"io"
+	"strings"
+	"sync"
+	"testing"
+
+	"go.uber.org/zap"
+)
+
+func TestNewPipeReader(t *testing.T) {
+	log := getLogger("test")
+
+	var wg sync.WaitGroup
+	wg.Add(1)
+
+	r := NewPipeReader()
+
+	buf := &bytes.Buffer{}
+	go func() {
+		defer wg.Done()
+		if _, err := io.Copy(buf, r); err != nil && err != io.ErrClosedPipe {
+			t.Errorf("unexpected error: %v", err)
+		}
+	}()
+
+	log.Error("scooby")
+	r.Close()
+	wg.Wait()
+
+	if !strings.Contains(buf.String(), "scooby") {
+		t.Errorf("got %q, wanted it to contain log output", buf.String())
+	}
+
+}
+
+func TestNewPipeReaderFormat(t *testing.T) {
+	log := getLogger("test")
+
+	var wg sync.WaitGroup
+	wg.Add(1)
+
+	r := NewPipeReader(PipeFormat(PlaintextOutput))
+
+	buf := &bytes.Buffer{}
+	go func() {
+		defer wg.Done()
+		if _, err := io.Copy(buf, r); err != nil && err != io.ErrClosedPipe {
+			t.Errorf("unexpected error: %v", err)
+		}
+	}()
+
+	log.Error("scooby")
+	r.Close()
+	wg.Wait()
+
+	if !strings.Contains(buf.String(), "scooby") {
+		t.Errorf("got %q, wanted it to contain log output", buf.String())
+	}
+
+}
+
+func TestNewPipeReaderLevel(t *testing.T) {
+	SetupLogging(Config{
+		Level:  LevelDebug,
+		Format: PlaintextOutput,
+	})
+
+	log := getLogger("test")
+
+	var wg sync.WaitGroup
+	wg.Add(1)
+
+	r := NewPipeReader(PipeLevel(LevelError))
+
+	buf := &bytes.Buffer{}
+	go func() {
+		defer wg.Done()
+		if _, err := io.Copy(buf, r); err != nil && err != io.ErrClosedPipe {
+			t.Errorf("unexpected error: %v", err)
+		}
+	}()
+
+	log.Debug("scooby")
+	log.Info("velma")
+	log.Error("shaggy")
+	r.Close()
+	wg.Wait()
+
+	lineEnding := zap.NewProductionEncoderConfig().LineEnding
+
+	// Should only contain one log line
+	if strings.Count(buf.String(), lineEnding) > 1 {
+		t.Errorf("got %d log lines, wanted 1", strings.Count(buf.String(), lineEnding))
+	}
+
+	if !strings.Contains(buf.String(), "shaggy") {
+		t.Errorf("got %q, wanted it to contain log output", buf.String())
+	}
+
+}

v2/setup.go

+package log
+
+import (
+	"errors"
+	"fmt"
+	"os"
+	"regexp"
+	"strings"
+	"sync"
+
+	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
+)
+
+func init() {
+	SetupLogging(configFromEnv())
+}
+
+// Logging environment variables
+const (
+	// IPFS_* prefixed env vars kept for backwards compatibility
+	// for this release. They will not be available in the next
+	// release.
+	//
+	// GOLOG_* env vars take precedences over IPFS_* env vars.
+	envIPFSLogging    = "IPFS_LOGGING"
+	envIPFSLoggingFmt = "IPFS_LOGGING_FMT"
+
+	envLogging    = "GOLOG_LOG_LEVEL"
+	envLoggingFmt = "GOLOG_LOG_FMT"
+
+	envLoggingFile = "GOLOG_FILE" // /path/to/file
+	envLoggingURL  = "GOLOG_URL"  // url that will be processed by sink in the zap
+
+	envLoggingOutput = "GOLOG_OUTPUT"     // possible values: stdout|stderr|file combine multiple values with '+'
+	envLoggingLabels = "GOLOG_LOG_LABELS" // comma-separated key-value pairs, i.e. "app=example_app,dc=sjc-1"
+)
+
+type LogFormat int
+
+const (
+	ColorizedOutput LogFormat = iota
+	PlaintextOutput
+	JSONOutput
+)
+
+type Config struct {
+	// Format overrides the format of the log output. Defaults to ColorizedOutput
+	Format LogFormat
+
+	// Level is the default minimum enabled logging level.
+	Level LogLevel
+
+	// SubsystemLevels are the default levels per-subsystem. When unspecified, defaults to Level.
+	SubsystemLevels map[string]LogLevel
+
+	// Stderr indicates whether logs should be written to stderr.
+	Stderr bool
+
+	// Stdout indicates whether logs should be written to stdout.
+	Stdout bool
+
+	// File is a path to a file that logs will be written to.
+	File string
+
+	// URL with schema supported by zap. Use zap.RegisterSink
+	URL string
+
+	// Labels is a set of key-values to apply to all loggers
+	Labels map[string]string
+}
+
+// ErrNoSuchLogger is returned when the util pkg is asked for a non existant logger
+var ErrNoSuchLogger = errors.New("Error: No such logger")
+
+var loggerMutex sync.RWMutex // guards access to global logger state
+
+// loggers is the set of loggers in the system
+var loggers = make(map[string]*zap.SugaredLogger)
+var levels = make(map[string]zap.AtomicLevel)
+
+// primaryFormat is the format of the primary core used for logging
+var primaryFormat LogFormat = ColorizedOutput
+
+// defaultLevel is the default log level
+var defaultLevel LogLevel = LevelError
+
+// primaryCore is the primary logging core
+var primaryCore zapcore.Core
+
+// loggerCore is the base for all loggers created by this package
+var loggerCore = &lockedMultiCore{}
+
+// SetupLogging will initialize the logger backend and set the flags.
+// TODO calling this in `init` pushes all configuration to env variables
+// - move it out of `init`? then we need to change all the code (js-dms3, go-dms3) to call this explicitly
+// - have it look for a config file? need to define what that is
+func SetupLogging(cfg Config) {
+	loggerMutex.Lock()
+	defer loggerMutex.Unlock()
+
+	primaryFormat = cfg.Format
+	defaultLevel = cfg.Level
+
+	outputPaths := []string{}
+
+	if cfg.Stderr {
+		outputPaths = append(outputPaths, "stderr")
+	}
+	if cfg.Stdout {
+		outputPaths = append(outputPaths, "stdout")
+	}
+
+	// check if we log to a file
+	if len(cfg.File) > 0 {
+		if path, err := normalizePath(cfg.File); err != nil {
+			fmt.Fprintf(os.Stderr, "failed to resolve log path '%q', logging to %s\n", cfg.File, outputPaths)
+		} else {
+			outputPaths = append(outputPaths, path)
+		}
+	}
+	if len(cfg.URL) > 0 {
+		outputPaths = append(outputPaths, cfg.URL)
+	}
+
+	ws, _, err := zap.Open(outputPaths...)
+	if err != nil {
+		panic(fmt.Sprintf("unable to open logging output: %v", err))
+	}
+
+	newPrimaryCore := newCore(primaryFormat, ws, LevelDebug) // the main core needs to log everything.
+
+	for k, v := range cfg.Labels {
+		newPrimaryCore = newPrimaryCore.With([]zap.Field{zap.String(k, v)})
+	}
+
+	if primaryCore != nil {
+		loggerCore.ReplaceCore(primaryCore, newPrimaryCore)
+	} else {
+		loggerCore.AddCore(newPrimaryCore)
+	}
+	primaryCore = newPrimaryCore
+
+	setAllLoggers(defaultLevel)
+
+	for name, level := range cfg.SubsystemLevels {
+		if leveler, ok := levels[name]; ok {
+			leveler.SetLevel(zapcore.Level(level))
+		} else {
+			levels[name] = zap.NewAtomicLevelAt(zapcore.Level(level))
+		}
+	}
+}
+
+// SetDebugLogging calls SetAllLoggers with logging.DEBUG
+func SetDebugLogging() {
+	SetAllLoggers(LevelDebug)
+}
+
+// SetAllLoggers changes the logging level of all loggers to lvl
+func SetAllLoggers(lvl LogLevel) {
+	loggerMutex.RLock()
+	defer loggerMutex.RUnlock()
+
+	setAllLoggers(lvl)
+}
+
+func setAllLoggers(lvl LogLevel) {
+	for _, l := range levels {
+		l.SetLevel(zapcore.Level(lvl))
+	}
+}
+
+// SetLogLevel changes the log level of a specific subsystem
+// name=="*" changes all subsystems
+func SetLogLevel(name, level string) error {
+	lvl, err := LevelFromString(level)
+	if err != nil {
+		return err
+	}
+
+	// wildcard, change all
+	if name == "*" {
+		SetAllLoggers(lvl)
+		return nil
+	}
+
+	loggerMutex.RLock()
+	defer loggerMutex.RUnlock()
+
+	// Check if we have a logger by that name
+	if _, ok := levels[name]; !ok {
+		return ErrNoSuchLogger
+	}
+
+	levels[name].SetLevel(zapcore.Level(lvl))
+
+	return nil
+}
+
+// SetLogLevelRegex sets all loggers to level `l` that match expression `e`.
+// An error is returned if `e` fails to compile.
+func SetLogLevelRegex(e, l string) error {
+	lvl, err := LevelFromString(l)
+	if err != nil {
+		return err
+	}
+
+	rem, err := regexp.Compile(e)
+	if err != nil {
+		return err
+	}
+
+	loggerMutex.Lock()
+	defer loggerMutex.Unlock()
+	for name := range loggers {
+		if rem.MatchString(name) {
+			levels[name].SetLevel(zapcore.Level(lvl))
+		}
+	}
+	return nil
+}
+
+// GetSubsystems returns a slice containing the
+// names of the current loggers
+func GetSubsystems() []string {
+	loggerMutex.RLock()
+	defer loggerMutex.RUnlock()
+	subs := make([]string, 0, len(loggers))
+
+	for k := range loggers {
+		subs = append(subs, k)
+	}
+	return subs
+}
+
+func getLogger(name string) *zap.SugaredLogger {
+	loggerMutex.Lock()
+	defer loggerMutex.Unlock()
+	log, ok := loggers[name]
+	if !ok {
+		level, ok := levels[name]
+		if !ok {
+			level = zap.NewAtomicLevelAt(zapcore.Level(defaultLevel))
+			levels[name] = level
+		}
+		log = zap.New(loggerCore).
+			WithOptions(
+				zap.IncreaseLevel(level),
+				zap.AddCaller(),
+			).
+			Named(name).
+			Sugar()
+
+		loggers[name] = log
+	}
+
+	return log
+}
+
+// configFromEnv returns a Config with defaults populated using environment variables.
+func configFromEnv() Config {
+	cfg := Config{
+		Format:          ColorizedOutput,
+		Stderr:          true,
+		Level:           LevelError,
+		SubsystemLevels: map[string]LogLevel{},
+		Labels:          map[string]string{},
+	}
+
+	format := os.Getenv(envLoggingFmt)
+	if format == "" {
+		format = os.Getenv(envIPFSLoggingFmt)
+	}
+
+	switch format {
+	case "nocolor":
+		cfg.Format = PlaintextOutput
+	case "json":
+		cfg.Format = JSONOutput
+	}
+
+	lvl := os.Getenv(envLogging)
+	if lvl == "" {
+		lvl = os.Getenv(envIPFSLogging)
+	}
+	if lvl != "" {
+		for _, kvs := range strings.Split(lvl, ",") {
+			kv := strings.SplitN(kvs, "=", 2)
+			lvl, err := LevelFromString(kv[len(kv)-1])
+			if err != nil {
+				fmt.Fprintf(os.Stderr, "error setting log level %q: %s\n", kvs, err)
+				continue
+			}
+			switch len(kv) {
+			case 1:
+				cfg.Level = lvl
+			case 2:
+				cfg.SubsystemLevels[kv[0]] = lvl
+			}
+		}
+	}
+
+	cfg.File = os.Getenv(envLoggingFile)
+	// Disable stderr logging when a file is specified
+	// https://gitlab.dms3.io/dms3/public/go-log/issues/83
+	if cfg.File != "" {
+		cfg.Stderr = false
+	}
+
+	cfg.URL = os.Getenv(envLoggingURL)
+	output := os.Getenv(envLoggingOutput)
+	outputOptions := strings.Split(output, "+")
+	for _, opt := range outputOptions {
+		switch opt {
+		case "stdout":
+			cfg.Stdout = true
+		case "stderr":
+			cfg.Stderr = true
+		case "file":
+			if cfg.File == "" {
+				fmt.Fprint(os.Stderr, "please specify a GOLOG_FILE value to write to")
+			}
+		case "url":
+			if cfg.URL == "" {
+				fmt.Fprint(os.Stderr, "please specify a GOLOG_URL value to write to")
+			}
+		}
+	}
+
+	labels := os.Getenv(envLoggingLabels)
+	if labels != "" {
+		labelKVs := strings.Split(labels, ",")
+		for _, label := range labelKVs {
+			kv := strings.Split(label, "=")
+			if len(kv) != 2 {
+				fmt.Fprint(os.Stderr, "invalid label k=v: ", label)
+				continue
+			}
+			cfg.Labels[kv[0]] = kv[1]
+		}
+	}
+
+	return cfg
+}

v2/setup_test.go

+package log
+
+import (
+	"bytes"
+	"io"
+	"io/ioutil"
+	"os"
+	"strings"
+	"testing"
+)
+
+func TestGetLoggerDefault(t *testing.T) {
+	r, w, err := os.Pipe()
+	if err != nil {
+		t.Fatalf("failed to open pipe: %v", err)
+	}
+
+	stderr := os.Stderr
+	os.Stderr = w
+	defer func() {
+		os.Stderr = stderr
+	}()
+
+	// Call SetupLogging again so it picks up stderr change
+	SetupLogging(Config{Stderr: true})
+	log := getLogger("test")
+
+	log.Error("scooby")
+	w.Close()
+
+	buf := &bytes.Buffer{}
+	if _, err := io.Copy(buf, r); err != nil && err != io.ErrClosedPipe {
+		t.Fatalf("unexpected error: %v", err)
+	}
+
+	if !strings.Contains(buf.String(), "scooby") {
+		t.Errorf("got %q, wanted it to contain log output", buf.String())
+	}
+
+}
+
+func TestLogToFileAndStderr(t *testing.T) {
+	// setup stderr
+	r, w, err := os.Pipe()
+	if err != nil {
+		t.Fatalf("failed to open pipe: %v", err)
+	}
+
+	stderr := os.Stderr
+	os.Stderr = w
+	defer func() {
+		os.Stderr = stderr
+	}()
+
+	// setup file
+	logfile, err := ioutil.TempFile("", "go-log-test")
+	if err != nil {
+		t.Fatal(err)
+	}
+	defer os.Remove(logfile.Name())
+
+	os.Setenv(envLoggingFile, logfile.Name())
+	defer os.Unsetenv(envLoggingFile)
+
+	// set log output env var
+	os.Setenv(envLoggingOutput, "file+stderr")
+	defer os.Unsetenv(envLoggingOutput)
+
+	SetupLogging(configFromEnv())
+
+	log := getLogger("test")
+
+	want := "scooby"
+	log.Error(want)
+	w.Close()
+
+	buf := &bytes.Buffer{}
+	if _, err := io.Copy(buf, r); err != nil && err != io.ErrClosedPipe {
+		t.Fatalf("unexpected error: %v", err)
+	}
+
+	if !strings.Contains(buf.String(), want) {
+		t.Errorf("got %q, wanted it to contain log output", buf.String())
+	}
+
+	content, err := ioutil.ReadFile(logfile.Name())
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	if !strings.Contains(string(content), want) {
+		t.Logf("want: '%s', got: '%s'", want, string(content))
+		t.Fail()
+	}
+}
+
+func TestLogToFile(t *testing.T) {
+	// get tmp log file
+	logfile, err := ioutil.TempFile("", "go-log-test")
+	if err != nil {
+		t.Fatal(err)
+	}
+	defer os.Remove(logfile.Name())
+
+	// set the go-log file env var
+	os.Setenv(envLoggingFile, logfile.Name())
+	defer os.Unsetenv(envLoggingFile)
+
+	SetupLogging(configFromEnv())
+
+	log := getLogger("test")
+
+	// write log to file
+	want := "grokgrokgrok"
+	log.Error(want)
+
+	// read log file and check contents
+	content, err := ioutil.ReadFile(logfile.Name())
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	if !strings.Contains(string(content), want) {
+		t.Logf("want: '%s', got: '%s'", want, string(content))
+		t.Fail()
+	}
+}
+
+func TestLogLabels(t *testing.T) {
+	r, w, err := os.Pipe()
+	if err != nil {
+		t.Fatalf("failed to open pipe: %v", err)
+	}
+
+	stderr := os.Stderr
+	os.Stderr = w
+	defer func() {
+		os.Stderr = stderr
+	}()
+
+	// set the go-log labels env var
+	os.Setenv(envLoggingLabels, "dc=sjc-1,foobar") // foobar to ensure we don't panic on bad input.
+	defer os.Unsetenv(envLoggingLabels)
+	SetupLogging(configFromEnv())
+
+	log := getLogger("test")
+
+	log.Error("scooby")
+	w.Close()
+
+	buf := &bytes.Buffer{}
+	if _, err := io.Copy(buf, r); err != nil && err != io.ErrClosedPipe {
+		t.Fatalf("unexpected error: %v", err)
+	}
+
+	t.Log(buf.String())
+	if !strings.Contains(buf.String(), "{\"dc\": \"sjc-1\"}") {
+		t.Errorf("got %q, wanted it to contain log output", buf.String())
+	}
+}
+
+func TestSubsystemLevels(t *testing.T) {
+	r, w, err := os.Pipe()
+	if err != nil {
+		t.Fatalf("failed to open pipe: %v", err)
+	}
+
+	stderr := os.Stderr
+	os.Stderr = w
+	defer func() {
+		os.Stderr = stderr
+	}()
+
+	// set the go-log labels env var
+	os.Setenv(envLogging, "info,test1=debug")
+	defer os.Unsetenv(envLoggingLabels)
+	SetupLogging(configFromEnv())
+
+	log1 := getLogger("test1")
+	log2 := getLogger("test2")
+
+	log1.Debug("debug1")
+	log1.Info("info1")
+	log2.Debug("debug2")
+	log2.Info("info2")
+	w.Close()
+
+	buf := &bytes.Buffer{}
+	if _, err := io.Copy(buf, r); err != nil && err != io.ErrClosedPipe {
+		t.Fatalf("unexpected error: %v", err)
+	}
+
+	if !strings.Contains(buf.String(), "debug1") {
+		t.Errorf("got %q, wanted it to contain debug1", buf.String())
+	}
+	if strings.Contains(buf.String(), "debug2") {
+		t.Errorf("got %q, wanted it to not contain debug2", buf.String())
+	}
+	if !strings.Contains(buf.String(), "info1") {
+		t.Errorf("got %q, wanted it to contain info1", buf.String())
+	}
+	if !strings.Contains(buf.String(), "info2") {
+		t.Errorf("got %q, wanted it to contain info2", buf.String())
+	}
+}