Merge remote-tracking branch 'upstream/master'

This commit is contained in:
Logan HAUSPIE 2018-08-26 23:31:56 +02:00
commit 0ab534bf6c
No known key found for this signature in database
GPG Key ID: 146A2B64B36C0E64
19 changed files with 657 additions and 59 deletions

View File

@ -1,9 +1,7 @@
language: go language: go
go: go:
- 1.8.x
- 1.9.x - 1.9.x
- 1.10.x - 1.10.x
- tip
env: env:
- GOMAXPROCS=4 GORACE=halt_on_error=1 - GOMAXPROCS=4 GORACE=halt_on_error=1
install: install:

View File

@ -83,14 +83,28 @@ func (entry *Entry) WithFields(fields Fields) *Entry {
for k, v := range fields { for k, v := range fields {
data[k] = v data[k] = v
} }
return &Entry{Logger: entry.Logger, Data: data} return &Entry{Logger: entry.Logger, Data: data, Time: entry.Time}
}
// Overrides the time of the Entry.
func (entry *Entry) WithTime(t time.Time) *Entry {
return &Entry{Logger: entry.Logger, Data: entry.Data, Time: t}
} }
// This function is not declared with a pointer value because otherwise // This function is not declared with a pointer value because otherwise
// race conditions will occur when using multiple goroutines // race conditions will occur when using multiple goroutines
func (entry Entry) log(level Level, msg string) { func (entry Entry) log(level Level, msg string) {
var buffer *bytes.Buffer var buffer *bytes.Buffer
entry.Time = time.Now()
// Default to now, but allow users to override if they want.
//
// We don't have to worry about polluting future calls to Entry#log()
// with this assignment because this function is declared with a
// non-pointer receiver.
if entry.Time.IsZero() {
entry.Time = time.Now()
}
entry.Level = level entry.Level = level
entry.Message = msg entry.Message = msg
@ -113,21 +127,19 @@ func (entry Entry) log(level Level, msg string) {
} }
} }
// This function is not declared with a pointer value because otherwise func (entry *Entry) fireHooks() {
// race conditions will occur when using multiple goroutines
func (entry Entry) fireHooks() {
entry.Logger.mu.Lock() entry.Logger.mu.Lock()
defer entry.Logger.mu.Unlock() defer entry.Logger.mu.Unlock()
err := entry.Logger.Hooks.Fire(entry.Level, &entry) err := entry.Logger.Hooks.Fire(entry.Level, entry)
if err != nil { if err != nil {
fmt.Fprintf(os.Stderr, "Failed to fire hook: %v\n", err) fmt.Fprintf(os.Stderr, "Failed to fire hook: %v\n", err)
} }
} }
func (entry *Entry) write() { func (entry *Entry) write() {
serialized, err := entry.Logger.Formatter.Format(entry)
entry.Logger.mu.Lock() entry.Logger.mu.Lock()
defer entry.Logger.mu.Unlock() defer entry.Logger.mu.Unlock()
serialized, err := entry.Logger.Formatter.Format(entry)
if err != nil { if err != nil {
fmt.Fprintf(os.Stderr, "Failed to obtain reader, %v\n", err) fmt.Fprintf(os.Stderr, "Failed to obtain reader, %v\n", err)
} else { } else {

View File

@ -2,6 +2,7 @@ package logrus
import ( import (
"io" "io"
"time"
) )
var ( var (
@ -15,30 +16,22 @@ func StandardLogger() *Logger {
// SetOutput sets the standard logger output. // SetOutput sets the standard logger output.
func SetOutput(out io.Writer) { func SetOutput(out io.Writer) {
std.mu.Lock() std.SetOutput(out)
defer std.mu.Unlock()
std.Out = out
} }
// SetFormatter sets the standard logger formatter. // SetFormatter sets the standard logger formatter.
func SetFormatter(formatter Formatter) { func SetFormatter(formatter Formatter) {
std.mu.Lock() std.SetFormatter(formatter)
defer std.mu.Unlock()
std.Formatter = formatter
} }
// SetLevel sets the standard logger level. // SetLevel sets the standard logger level.
func SetLevel(level Level) { func SetLevel(level Level) {
std.mu.Lock()
defer std.mu.Unlock()
std.SetLevel(level) std.SetLevel(level)
} }
// GetLevel returns the standard logger level. // GetLevel returns the standard logger level.
func GetLevel() Level { func GetLevel() Level {
std.mu.Lock() return std.GetLevel()
defer std.mu.Unlock()
return std.level()
} }
func IsDebugEnabled() bool { func IsDebugEnabled() bool {
@ -67,9 +60,7 @@ func IsPanicEnabled() bool {
// AddHook adds a hook to the standard logger hooks. // AddHook adds a hook to the standard logger hooks.
func AddHook(hook Hook) { func AddHook(hook Hook) {
std.mu.Lock() std.AddHook(hook)
defer std.mu.Unlock()
std.Hooks.Add(hook)
} }
// WithError creates an entry from the standard logger and adds an error to it, using the value defined in ErrorKey as key. // WithError creates an entry from the standard logger and adds an error to it, using the value defined in ErrorKey as key.
@ -96,6 +87,15 @@ func WithFields(fields Fields) *Entry {
return std.WithFields(fields) return std.WithFields(fields)
} }
// WithTime creats an entry from the standard logger and overrides the time of
// logs generated with it.
//
// Note that it doesn't log until you call Debug, Print, Info, Warn, Fatal
// or Panic on the Entry it returns.
func WithTime(t time.Time) *Entry {
return std.WithTime(t)
}
// Debug logs a message at level Debug on the standard logger. // Debug logs a message at level Debug on the standard logger.
func Debug(args ...interface{}) { func Debug(args ...interface{}) {
std.Debug(args...) std.Debug(args...)
@ -131,7 +131,7 @@ func Panic(args ...interface{}) {
std.Panic(args...) std.Panic(args...)
} }
// Fatal logs a message at level Fatal on the standard logger. // Fatal logs a message at level Fatal on the standard logger then the process will exit with status set to 1.
func Fatal(args ...interface{}) { func Fatal(args ...interface{}) {
std.Fatal(args...) std.Fatal(args...)
} }
@ -171,7 +171,7 @@ func Panicf(format string, args ...interface{}) {
std.Panicf(format, args...) std.Panicf(format, args...)
} }
// Fatalf logs a message at level Fatal on the standard logger. // Fatalf logs a message at level Fatal on the standard logger then the process will exit with status set to 1.
func Fatalf(format string, args ...interface{}) { func Fatalf(format string, args ...interface{}) {
std.Fatalf(format, args...) std.Fatalf(format, args...)
} }
@ -211,7 +211,7 @@ func Panicln(args ...interface{}) {
std.Panicln(args...) std.Panicln(args...)
} }
// Fatalln logs a message at level Fatal on the standard logger. // Fatalln logs a message at level Fatal on the standard logger then the process will exit with status set to 1.
func Fatalln(args ...interface{}) { func Fatalln(args ...interface{}) {
std.Fatalln(args...) std.Fatalln(args...)
} }

View File

@ -34,15 +34,18 @@ func prefixFieldClashes(data Fields, fieldMap FieldMap) {
timeKey := fieldMap.resolve(FieldKeyTime) timeKey := fieldMap.resolve(FieldKeyTime)
if t, ok := data[timeKey]; ok { if t, ok := data[timeKey]; ok {
data["fields."+timeKey] = t data["fields."+timeKey] = t
delete(data, timeKey)
} }
msgKey := fieldMap.resolve(FieldKeyMsg) msgKey := fieldMap.resolve(FieldKeyMsg)
if m, ok := data[msgKey]; ok { if m, ok := data[msgKey]; ok {
data["fields."+msgKey] = m data["fields."+msgKey] = m
delete(data, msgKey)
} }
levelKey := fieldMap.resolve(FieldKeyLevel) levelKey := fieldMap.resolve(FieldKeyLevel)
if l, ok := data[levelKey]; ok { if l, ok := data[levelKey]; ok {
data["fields."+levelKey] = l data["fields."+levelKey] = l
delete(data, levelKey)
} }
} }

View File

@ -1,10 +1,13 @@
package logrus package logrus
import ( import (
"bytes"
"encoding/json"
"sync" "sync"
"testing" "testing"
"github.com/stretchr/testify/assert" "github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
) )
type TestHook struct { type TestHook struct {
@ -85,6 +88,46 @@ func TestCanFireMultipleHooks(t *testing.T) {
}) })
} }
type SingleLevelModifyHook struct {
ModifyHook
}
func (h *SingleLevelModifyHook) Levels() []Level {
return []Level{InfoLevel}
}
func TestHookEntryIsPristine(t *testing.T) {
l := New()
b := &bytes.Buffer{}
l.Formatter = &JSONFormatter{}
l.Out = b
l.AddHook(&SingleLevelModifyHook{})
l.Error("error message")
data := map[string]string{}
err := json.Unmarshal(b.Bytes(), &data)
require.NoError(t, err)
_, ok := data["wow"]
require.False(t, ok)
b.Reset()
l.Info("error message")
data = map[string]string{}
err = json.Unmarshal(b.Bytes(), &data)
require.NoError(t, err)
_, ok = data["wow"]
require.True(t, ok)
b.Reset()
l.Error("error message")
data = map[string]string{}
err = json.Unmarshal(b.Bytes(), &data)
require.NoError(t, err)
_, ok = data["wow"]
require.False(t, ok)
b.Reset()
}
type ErrorHook struct { type ErrorHook struct {
Fired bool Fired bool
} }

View File

@ -15,7 +15,7 @@ type Hook struct {
// Entries is an array of all entries that have been received by this hook. // Entries is an array of all entries that have been received by this hook.
// For safe access, use the AllEntries() method, rather than reading this // For safe access, use the AllEntries() method, rather than reading this
// value directly. // value directly.
Entries []*logrus.Entry Entries []logrus.Entry
mu sync.RWMutex mu sync.RWMutex
} }
@ -52,7 +52,7 @@ func NewNullLogger() (*logrus.Logger, *Hook) {
func (t *Hook) Fire(e *logrus.Entry) error { func (t *Hook) Fire(e *logrus.Entry) error {
t.mu.Lock() t.mu.Lock()
defer t.mu.Unlock() defer t.mu.Unlock()
t.Entries = append(t.Entries, e) t.Entries = append(t.Entries, *e)
return nil return nil
} }
@ -68,9 +68,7 @@ func (t *Hook) LastEntry() *logrus.Entry {
if i < 0 { if i < 0 {
return nil return nil
} }
// Make a copy, for safety return &t.Entries[i]
e := *t.Entries[i]
return &e
} }
// AllEntries returns all entries that were logged. // AllEntries returns all entries that were logged.
@ -79,10 +77,9 @@ func (t *Hook) AllEntries() []*logrus.Entry {
defer t.mu.RUnlock() defer t.mu.RUnlock()
// Make a copy so the returned value won't race with future log requests // Make a copy so the returned value won't race with future log requests
entries := make([]*logrus.Entry, len(t.Entries)) entries := make([]*logrus.Entry, len(t.Entries))
for i, entry := range t.Entries { for i := 0; i < len(t.Entries); i++ {
// Make a copy, for safety // Make a copy, for safety
e := *entry entries[i] = &t.Entries[i]
entries[i] = &e
} }
return entries return entries
} }
@ -91,5 +88,5 @@ func (t *Hook) AllEntries() []*logrus.Entry {
func (t *Hook) Reset() { func (t *Hook) Reset() {
t.mu.Lock() t.mu.Lock()
defer t.mu.Unlock() defer t.mu.Unlock()
t.Entries = make([]*logrus.Entry, 0) t.Entries = make([]logrus.Entry, 0)
} }

View File

@ -1,8 +1,10 @@
package test package test
import ( import (
"math/rand"
"sync" "sync"
"testing" "testing"
"time"
"github.com/sirupsen/logrus" "github.com/sirupsen/logrus"
"github.com/stretchr/testify/assert" "github.com/stretchr/testify/assert"
@ -38,24 +40,34 @@ func TestAllHooks(t *testing.T) {
} }
func TestLoggingWithHooksRace(t *testing.T) { func TestLoggingWithHooksRace(t *testing.T) {
rand.Seed(time.Now().Unix())
unlocker := rand.Int() % 100
assert := assert.New(t) assert := assert.New(t)
logger, hook := NewNullLogger() logger, hook := NewNullLogger()
var wg sync.WaitGroup var wgOne, wgAll sync.WaitGroup
wg.Add(100) wgOne.Add(1)
wgAll.Add(100)
for i := 0; i < 100; i++ { for i := 0; i < 100; i++ {
go func() { go func(i int) {
logger.Info("info") logger.Info("info")
wg.Done() wgAll.Done()
}() if i == unlocker {
wgOne.Done()
}
}(i)
} }
wg.Wait() wgOne.Wait()
assert.Equal(logrus.InfoLevel, hook.LastEntry().Level) assert.Equal(logrus.InfoLevel, hook.LastEntry().Level)
assert.Equal("info", hook.LastEntry().Message) assert.Equal("info", hook.LastEntry().Message)
wgAll.Wait()
entries := hook.AllEntries() entries := hook.AllEntries()
assert.Equal(100, len(entries)) assert.Equal(100, len(entries))
} }

View File

@ -1,6 +1,7 @@
package logrus package logrus
import ( import (
"bytes"
"encoding/json" "encoding/json"
"fmt" "fmt"
) )
@ -33,6 +34,9 @@ type JSONFormatter struct {
// DisableTimestamp allows disabling automatic timestamps in output // DisableTimestamp allows disabling automatic timestamps in output
DisableTimestamp bool DisableTimestamp bool
// DataKey allows users to put all the log entry parameters into a nested dictionary at a given key.
DataKey string
// FieldMap allows users to customize the names of keys for default fields. // FieldMap allows users to customize the names of keys for default fields.
// As an example: // As an example:
// formatter := &JSONFormatter{ // formatter := &JSONFormatter{
@ -58,6 +62,13 @@ func (f *JSONFormatter) Format(entry *Entry) ([]byte, error) {
data[k] = v data[k] = v
} }
} }
if f.DataKey != "" {
newData := make(Fields, 4)
newData[f.DataKey] = data
data = newData
}
prefixFieldClashes(data, f.FieldMap) prefixFieldClashes(data, f.FieldMap)
timestampFormat := f.TimestampFormat timestampFormat := f.TimestampFormat
@ -71,9 +82,15 @@ func (f *JSONFormatter) Format(entry *Entry) ([]byte, error) {
data[f.FieldMap.resolve(FieldKeyMsg)] = entry.Message data[f.FieldMap.resolve(FieldKeyMsg)] = entry.Message
data[f.FieldMap.resolve(FieldKeyLevel)] = entry.Level.String() data[f.FieldMap.resolve(FieldKeyLevel)] = entry.Level.String()
serialized, err := json.Marshal(data) var b *bytes.Buffer
if entry.Buffer != nil {
b = entry.Buffer
} else {
b = &bytes.Buffer{}
}
err := json.NewEncoder(b).Encode(data)
if err != nil { if err != nil {
return nil, fmt.Errorf("Failed to marshal fields to JSON, %v", err) return nil, fmt.Errorf("Failed to marshal fields to JSON, %v", err)
} }
return append(serialized, '\n'), nil return b.Bytes(), nil
} }

View File

@ -161,6 +161,48 @@ func TestFieldClashWithRemappedFields(t *testing.T) {
} }
} }
func TestFieldsInNestedDictionary(t *testing.T) {
formatter := &JSONFormatter{
DataKey: "args",
}
logEntry := WithFields(Fields{
"level": "level",
"test": "test",
})
logEntry.Level = InfoLevel
b, err := formatter.Format(logEntry)
if err != nil {
t.Fatal("Unable to format entry: ", err)
}
entry := make(map[string]interface{})
err = json.Unmarshal(b, &entry)
if err != nil {
t.Fatal("Unable to unmarshal formatted entry: ", err)
}
args := entry["args"].(map[string]interface{})
for _, field := range []string{"test", "level"} {
if value, present := args[field]; !present || value != field {
t.Errorf("Expected field %v to be present under 'args'; untouched", field)
}
}
for _, field := range []string{"test", "fields.level"} {
if _, present := entry[field]; present {
t.Errorf("Expected field %v not to be present at top level", field)
}
}
// with nested object, "level" shouldn't clash
if entry["level"] != "info" {
t.Errorf("Expected 'level' field to contain 'info'")
}
}
func TestJSONEntryEndsWithNewline(t *testing.T) { func TestJSONEntryEndsWithNewline(t *testing.T) {
formatter := &JSONFormatter{} formatter := &JSONFormatter{}

View File

@ -5,12 +5,13 @@ import (
"os" "os"
"sync" "sync"
"sync/atomic" "sync/atomic"
"time"
) )
type Logger struct { type Logger struct {
// The logs are `io.Copy`'d to this in a mutex. It's common to set this to a // The logs are `io.Copy`'d to this in a mutex. It's common to set this to a
// file, or leave it default which is `os.Stderr`. You can also set this to // file, or leave it default which is `os.Stderr`. You can also set this to
// something more adventorous, such as logging to Kafka. // something more adventurous, such as logging to Kafka.
Out io.Writer Out io.Writer
// Hooks for the logger instance. These allow firing events based on logging // Hooks for the logger instance. These allow firing events based on logging
// levels and log entries. For example, to send errors to an error tracking // levels and log entries. For example, to send errors to an error tracking
@ -84,11 +85,12 @@ func (logger *Logger) newEntry() *Entry {
} }
func (logger *Logger) releaseEntry(entry *Entry) { func (logger *Logger) releaseEntry(entry *Entry) {
entry.Data = map[string]interface{}{}
logger.entryPool.Put(entry) logger.entryPool.Put(entry)
} }
// Adds a field to the log entry, note that it doesn't log until you call // Adds a field to the log entry, note that it doesn't log until you call
// Debug, Print, Info, Warn, Fatal or Panic. It only creates a log entry. // Debug, Print, Info, Warn, Error, Fatal or Panic. It only creates a log entry.
// If you want multiple fields, use `WithFields`. // If you want multiple fields, use `WithFields`.
func (logger *Logger) WithField(key string, value interface{}) *Entry { func (logger *Logger) WithField(key string, value interface{}) *Entry {
entry := logger.newEntry() entry := logger.newEntry()
@ -112,6 +114,13 @@ func (logger *Logger) WithError(err error) *Entry {
return entry.WithError(err) return entry.WithError(err)
} }
// Overrides the time of the log entry.
func (logger *Logger) WithTime(t time.Time) *Entry {
entry := logger.newEntry()
defer logger.releaseEntry(entry)
return entry.WithTime(t)
}
func (logger *Logger) Debugf(format string, args ...interface{}) { func (logger *Logger) Debugf(format string, args ...interface{}) {
if logger.IsDebugEnabled() { if logger.IsDebugEnabled() {
entry := logger.newEntry() entry := logger.newEntry()
@ -312,10 +321,17 @@ func (logger *Logger) level() Level {
return Level(atomic.LoadUint32((*uint32)(&logger.Level))) return Level(atomic.LoadUint32((*uint32)(&logger.Level)))
} }
// SetLevel sets the logger level.
func (logger *Logger) SetLevel(level Level) { func (logger *Logger) SetLevel(level Level) {
atomic.StoreUint32((*uint32)(&logger.Level), uint32(level)) atomic.StoreUint32((*uint32)(&logger.Level), uint32(level))
} }
// GetLevel returns the logger level.
func (logger *Logger) GetLevel() Level {
return logger.level()
}
// AddHook adds a hook to the logger hooks.
func (logger *Logger) AddHook(hook Hook) { func (logger *Logger) AddHook(hook Hook) {
logger.mu.Lock() logger.mu.Lock()
defer logger.mu.Unlock() defer logger.mu.Unlock()
@ -344,4 +360,25 @@ func (logger *Logger) IsFatalEnabled() bool {
func (logger *Logger) IsPanicEnabled() bool { func (logger *Logger) IsPanicEnabled() bool {
return logger.level() >= PanicLevel return logger.level() >= PanicLevel
// SetFormatter sets the logger formatter.
func (logger *Logger) SetFormatter(formatter Formatter) {
logger.mu.Lock()
defer logger.mu.Unlock()
logger.Formatter = formatter
}
// SetOutput sets the logger output.
func (logger *Logger) SetOutput(output io.Writer) {
logger.mu.Lock()
defer logger.mu.Unlock()
logger.Out = output
}
// ReplaceHooks replaces the logger hooks and returns the old ones
func (logger *Logger) ReplaceHooks(hooks LevelHooks) LevelHooks {
logger.mu.Lock()
oldHooks := logger.Hooks
logger.Hooks = hooks
logger.mu.Unlock()
return oldHooks
} }

View File

@ -1,6 +1,7 @@
package logrus package logrus
import ( import (
"io/ioutil"
"os" "os"
"testing" "testing"
) )
@ -59,3 +60,26 @@ func doLoggerBenchmarkNoLock(b *testing.B, out *os.File, formatter Formatter, fi
} }
}) })
} }
func BenchmarkLoggerJSONFormatter(b *testing.B) {
doLoggerBenchmarkWithFormatter(b, &JSONFormatter{})
}
func BenchmarkLoggerTextFormatter(b *testing.B) {
doLoggerBenchmarkWithFormatter(b, &TextFormatter{})
}
func doLoggerBenchmarkWithFormatter(b *testing.B, f Formatter) {
b.SetParallelism(100)
log := New()
log.Formatter = f
log.Out = ioutil.Discard
b.RunParallel(func(pb *testing.PB) {
for pb.Next() {
log.
WithField("foo1", "bar1").
WithField("foo2", "bar2").
Info("this is a dummy log")
}
})
}

View File

@ -3,10 +3,12 @@ package logrus
import ( import (
"bytes" "bytes"
"encoding/json" "encoding/json"
"io/ioutil"
"strconv" "strconv"
"strings" "strings"
"sync" "sync"
"testing" "testing"
"time"
"github.com/stretchr/testify/assert" "github.com/stretchr/testify/assert"
) )
@ -209,6 +211,65 @@ func TestDefaultFieldsAreNotPrefixed(t *testing.T) {
}) })
} }
func TestWithTimeShouldOverrideTime(t *testing.T) {
now := time.Now().Add(24 * time.Hour)
LogAndAssertJSON(t, func(log *Logger) {
log.WithTime(now).Info("foobar")
}, func(fields Fields) {
assert.Equal(t, fields["time"], now.Format(defaultTimestampFormat))
})
}
func TestWithTimeShouldNotOverrideFields(t *testing.T) {
now := time.Now().Add(24 * time.Hour)
LogAndAssertJSON(t, func(log *Logger) {
log.WithField("herp", "derp").WithTime(now).Info("blah")
}, func(fields Fields) {
assert.Equal(t, fields["time"], now.Format(defaultTimestampFormat))
assert.Equal(t, fields["herp"], "derp")
})
}
func TestWithFieldShouldNotOverrideTime(t *testing.T) {
now := time.Now().Add(24 * time.Hour)
LogAndAssertJSON(t, func(log *Logger) {
log.WithTime(now).WithField("herp", "derp").Info("blah")
}, func(fields Fields) {
assert.Equal(t, fields["time"], now.Format(defaultTimestampFormat))
assert.Equal(t, fields["herp"], "derp")
})
}
func TestTimeOverrideMultipleLogs(t *testing.T) {
var buffer bytes.Buffer
var firstFields, secondFields Fields
logger := New()
logger.Out = &buffer
formatter := new(JSONFormatter)
formatter.TimestampFormat = time.StampMilli
logger.Formatter = formatter
llog := logger.WithField("herp", "derp")
llog.Info("foo")
err := json.Unmarshal(buffer.Bytes(), &firstFields)
assert.NoError(t, err, "should have decoded first message")
buffer.Reset()
time.Sleep(10 * time.Millisecond)
llog.Info("bar")
err = json.Unmarshal(buffer.Bytes(), &secondFields)
assert.NoError(t, err, "should have decoded second message")
assert.NotEqual(t, firstFields["time"], secondFields["time"], "timestamps should not be equal")
}
func TestDoubleLoggingDoesntPrefixPreviousFields(t *testing.T) { func TestDoubleLoggingDoesntPrefixPreviousFields(t *testing.T) {
var buffer bytes.Buffer var buffer bytes.Buffer
@ -343,6 +404,45 @@ func TestLoggingRace(t *testing.T) {
wg.Wait() wg.Wait()
} }
func TestLoggingRaceWithHooksOnEntry(t *testing.T) {
logger := New()
hook := new(ModifyHook)
logger.AddHook(hook)
entry := logger.WithField("context", "clue")
var wg sync.WaitGroup
wg.Add(100)
for i := 0; i < 100; i++ {
go func() {
entry.Info("info")
wg.Done()
}()
}
wg.Wait()
}
func TestReplaceHooks(t *testing.T) {
old, cur := &TestHook{}, &TestHook{}
logger := New()
logger.SetOutput(ioutil.Discard)
logger.AddHook(old)
hooks := make(LevelHooks)
hooks.Add(cur)
replaced := logger.ReplaceHooks(hooks)
logger.Info("test")
assert.Equal(t, old.Fired, false)
assert.Equal(t, cur.Fired, true)
logger.ReplaceHooks(replaced)
logger.Info("test")
assert.Equal(t, old.Fired, true)
}
// Compile test // Compile test
func TestLogrusInterface(t *testing.T) { func TestLogrusInterface(t *testing.T) {
var buffer bytes.Buffer var buffer bytes.Buffer

View File

@ -1,5 +1,5 @@
// +build darwin freebsd openbsd netbsd dragonfly // +build darwin freebsd openbsd netbsd dragonfly
// +build !appengine,!gopherjs // +build !appengine,!js
package logrus package logrus

View File

@ -1,4 +1,4 @@
// +build appengine gopherjs // +build appengine
package logrus package logrus

11
terminal_check_js.go Normal file
View File

@ -0,0 +1,11 @@
// +build js
package logrus
import (
"io"
)
func checkIfTerminal(w io.Writer) bool {
return false
}

View File

@ -1,4 +1,4 @@
// +build !appengine,!gopherjs // +build !appengine,!js
package logrus package logrus

View File

@ -3,7 +3,7 @@
// Use of this source code is governed by a BSD-style // Use of this source code is governed by a BSD-style
// license that can be found in the LICENSE file. // license that can be found in the LICENSE file.
// +build !appengine,!gopherjs // +build !appengine,!js
package logrus package logrus

View File

@ -3,6 +3,7 @@ package logrus
import ( import (
"bytes" "bytes"
"fmt" "fmt"
"os"
"sort" "sort"
"strings" "strings"
"sync" "sync"
@ -35,6 +36,9 @@ type TextFormatter struct {
// Force disabling colors. // Force disabling colors.
DisableColors bool DisableColors bool
// Override coloring based on CLICOLOR and CLICOLOR_FORCE. - https://bixense.com/clicolors/
EnvironmentOverrideColors bool
// Disable timestamp logging. useful when output is redirected to logging // Disable timestamp logging. useful when output is redirected to logging
// system that already adds timestamps. // system that already adds timestamps.
DisableTimestamp bool DisableTimestamp bool
@ -51,7 +55,6 @@ type TextFormatter struct {
// be desired. // be desired.
DisableSorting bool DisableSorting bool
// Disables the truncation of the level text to 4 characters. // Disables the truncation of the level text to 4 characters.
DisableLevelTruncation bool DisableLevelTruncation bool
@ -61,6 +64,15 @@ type TextFormatter struct {
// Whether the logger's out is to a terminal // Whether the logger's out is to a terminal
isTerminal bool isTerminal bool
// FieldMap allows users to customize the names of keys for default fields.
// As an example:
// formatter := &TextFormatter{
// FieldMap: FieldMap{
// FieldKeyTime: "@timestamp",
// FieldKeyLevel: "@level",
// FieldKeyMsg: "@message"}}
FieldMap FieldMap
sync.Once sync.Once
} }
@ -70,9 +82,26 @@ func (f *TextFormatter) init(entry *Entry) {
} }
} }
func (f *TextFormatter) isColored() bool {
isColored := f.ForceColors || f.isTerminal
if f.EnvironmentOverrideColors {
if force, ok := os.LookupEnv("CLICOLOR_FORCE"); ok && force != "0" {
isColored = true
} else if ok && force == "0" {
isColored = false
} else if os.Getenv("CLICOLOR") == "0" {
isColored = false
}
}
return isColored && !f.DisableColors
}
// Format renders a single log entry // Format renders a single log entry
func (f *TextFormatter) Format(entry *Entry) ([]byte, error) { func (f *TextFormatter) Format(entry *Entry) ([]byte, error) {
var b *bytes.Buffer prefixFieldClashes(entry.Data, f.FieldMap)
keys := make([]string, 0, len(entry.Data)) keys := make([]string, 0, len(entry.Data))
for k := range entry.Data { for k := range entry.Data {
keys = append(keys, k) keys = append(keys, k)
@ -81,31 +110,29 @@ func (f *TextFormatter) Format(entry *Entry) ([]byte, error) {
if !f.DisableSorting { if !f.DisableSorting {
sort.Strings(keys) sort.Strings(keys)
} }
var b *bytes.Buffer
if entry.Buffer != nil { if entry.Buffer != nil {
b = entry.Buffer b = entry.Buffer
} else { } else {
b = &bytes.Buffer{} b = &bytes.Buffer{}
} }
prefixFieldClashes(entry.Data, emptyFieldMap)
f.Do(func() { f.init(entry) }) f.Do(func() { f.init(entry) })
isColored := (f.ForceColors || f.isTerminal) && !f.DisableColors
timestampFormat := f.TimestampFormat timestampFormat := f.TimestampFormat
if timestampFormat == "" { if timestampFormat == "" {
timestampFormat = defaultTimestampFormat timestampFormat = defaultTimestampFormat
} }
if isColored { if f.isColored() {
f.printColored(b, entry, keys, timestampFormat) f.printColored(b, entry, keys, timestampFormat)
} else { } else {
if !f.DisableTimestamp { if !f.DisableTimestamp {
f.appendKeyValue(b, "time", entry.Time.Format(timestampFormat)) f.appendKeyValue(b, f.FieldMap.resolve(FieldKeyTime), entry.Time.Format(timestampFormat))
} }
f.appendKeyValue(b, "level", entry.Level.String()) f.appendKeyValue(b, f.FieldMap.resolve(FieldKeyLevel), entry.Level.String())
if entry.Message != "" { if entry.Message != "" {
f.appendKeyValue(b, "msg", entry.Message) f.appendKeyValue(b, f.FieldMap.resolve(FieldKeyMsg), entry.Message)
} }
for _, key := range keys { for _, key := range keys {
f.appendKeyValue(b, key, entry.Data[key]) f.appendKeyValue(b, key, entry.Data[key])
@ -134,6 +161,10 @@ func (f *TextFormatter) printColored(b *bytes.Buffer, entry *Entry, keys []strin
levelText = levelText[0:4] levelText = levelText[0:4]
} }
// Remove a single newline if it already exists in the message to keep
// the behavior of logrus text_formatter the same as the stdlib log package
entry.Message = strings.TrimSuffix(entry.Message, "\n")
if f.DisableTimestamp { if f.DisableTimestamp {
fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m %-44s ", levelColor, levelText, entry.Message) fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m %-44s ", levelColor, levelText, entry.Message)
} else if !f.FullTimestamp { } else if !f.FullTimestamp {

View File

@ -4,9 +4,12 @@ import (
"bytes" "bytes"
"errors" "errors"
"fmt" "fmt"
"os"
"strings" "strings"
"testing" "testing"
"time" "time"
"github.com/stretchr/testify/assert"
) )
func TestFormatting(t *testing.T) { func TestFormatting(t *testing.T) {
@ -175,5 +178,273 @@ func TestDisableTimestampWithColoredOutput(t *testing.T) {
} }
} }
func TestNewlineBehavior(t *testing.T) {
tf := &TextFormatter{ForceColors: true}
// Ensure a single new line is removed as per stdlib log
e := NewEntry(StandardLogger())
e.Message = "test message\n"
b, _ := tf.Format(e)
if bytes.Contains(b, []byte("test message\n")) {
t.Error("first newline at end of Entry.Message resulted in unexpected 2 newlines in output. Expected newline to be removed.")
}
// Ensure a double new line is reduced to a single new line
e = NewEntry(StandardLogger())
e.Message = "test message\n\n"
b, _ = tf.Format(e)
if bytes.Contains(b, []byte("test message\n\n")) {
t.Error("Double newline at end of Entry.Message resulted in unexpected 2 newlines in output. Expected single newline")
}
if !bytes.Contains(b, []byte("test message\n")) {
t.Error("Double newline at end of Entry.Message did not result in a single newline after formatting")
}
}
func TestTextFormatterFieldMap(t *testing.T) {
formatter := &TextFormatter{
DisableColors: true,
FieldMap: FieldMap{
FieldKeyMsg: "message",
FieldKeyLevel: "somelevel",
FieldKeyTime: "timeywimey",
},
}
entry := &Entry{
Message: "oh hi",
Level: WarnLevel,
Time: time.Date(1981, time.February, 24, 4, 28, 3, 100, time.UTC),
Data: Fields{
"field1": "f1",
"message": "messagefield",
"somelevel": "levelfield",
"timeywimey": "timeywimeyfield",
},
}
b, err := formatter.Format(entry)
if err != nil {
t.Fatal("Unable to format entry: ", err)
}
assert.Equal(t,
`timeywimey="1981-02-24T04:28:03Z" `+
`somelevel=warning `+
`message="oh hi" `+
`field1=f1 `+
`fields.message=messagefield `+
`fields.somelevel=levelfield `+
`fields.timeywimey=timeywimeyfield`+"\n",
string(b),
"Formatted output doesn't respect FieldMap")
}
func TestTextFormatterIsColored(t *testing.T) {
params := []struct {
name string
expectedResult bool
isTerminal bool
disableColor bool
forceColor bool
envColor bool
clicolorIsSet bool
clicolorForceIsSet bool
clicolorVal string
clicolorForceVal string
}{
// Default values
{
name: "testcase1",
expectedResult: false,
isTerminal: false,
disableColor: false,
forceColor: false,
envColor: false,
clicolorIsSet: false,
clicolorForceIsSet: false,
},
// Output on terminal
{
name: "testcase2",
expectedResult: true,
isTerminal: true,
disableColor: false,
forceColor: false,
envColor: false,
clicolorIsSet: false,
clicolorForceIsSet: false,
},
// Output on terminal with color disabled
{
name: "testcase3",
expectedResult: false,
isTerminal: true,
disableColor: true,
forceColor: false,
envColor: false,
clicolorIsSet: false,
clicolorForceIsSet: false,
},
// Output not on terminal with color disabled
{
name: "testcase4",
expectedResult: false,
isTerminal: false,
disableColor: true,
forceColor: false,
envColor: false,
clicolorIsSet: false,
clicolorForceIsSet: false,
},
// Output not on terminal with color forced
{
name: "testcase5",
expectedResult: true,
isTerminal: false,
disableColor: false,
forceColor: true,
envColor: false,
clicolorIsSet: false,
clicolorForceIsSet: false,
},
// Output on terminal with clicolor set to "0"
{
name: "testcase6",
expectedResult: false,
isTerminal: true,
disableColor: false,
forceColor: false,
envColor: true,
clicolorIsSet: true,
clicolorForceIsSet: false,
clicolorVal: "0",
},
// Output on terminal with clicolor set to "1"
{
name: "testcase7",
expectedResult: true,
isTerminal: true,
disableColor: false,
forceColor: false,
envColor: true,
clicolorIsSet: true,
clicolorForceIsSet: false,
clicolorVal: "1",
},
// Output not on terminal with clicolor set to "0"
{
name: "testcase8",
expectedResult: false,
isTerminal: false,
disableColor: false,
forceColor: false,
envColor: true,
clicolorIsSet: true,
clicolorForceIsSet: false,
clicolorVal: "0",
},
// Output not on terminal with clicolor set to "1"
{
name: "testcase9",
expectedResult: false,
isTerminal: false,
disableColor: false,
forceColor: false,
envColor: true,
clicolorIsSet: true,
clicolorForceIsSet: false,
clicolorVal: "1",
},
// Output not on terminal with clicolor set to "1" and force color
{
name: "testcase10",
expectedResult: true,
isTerminal: false,
disableColor: false,
forceColor: true,
envColor: true,
clicolorIsSet: true,
clicolorForceIsSet: false,
clicolorVal: "1",
},
// Output not on terminal with clicolor set to "0" and force color
{
name: "testcase11",
expectedResult: false,
isTerminal: false,
disableColor: false,
forceColor: true,
envColor: true,
clicolorIsSet: true,
clicolorForceIsSet: false,
clicolorVal: "0",
},
// Output not on terminal with clicolor_force set to "1"
{
name: "testcase12",
expectedResult: true,
isTerminal: false,
disableColor: false,
forceColor: false,
envColor: true,
clicolorIsSet: false,
clicolorForceIsSet: true,
clicolorForceVal: "1",
},
// Output not on terminal with clicolor_force set to "0"
{
name: "testcase13",
expectedResult: false,
isTerminal: false,
disableColor: false,
forceColor: false,
envColor: true,
clicolorIsSet: false,
clicolorForceIsSet: true,
clicolorForceVal: "0",
},
// Output on terminal with clicolor_force set to "0"
{
name: "testcase14",
expectedResult: false,
isTerminal: true,
disableColor: false,
forceColor: false,
envColor: true,
clicolorIsSet: false,
clicolorForceIsSet: true,
clicolorForceVal: "0",
},
}
cleanenv := func() {
os.Unsetenv("CLICOLOR")
os.Unsetenv("CLICOLOR_FORCE")
}
defer cleanenv()
for _, val := range params {
t.Run("textformatter_"+val.name, func(subT *testing.T) {
tf := TextFormatter{
isTerminal: val.isTerminal,
DisableColors: val.disableColor,
ForceColors: val.forceColor,
EnvironmentOverrideColors: val.envColor,
}
cleanenv()
if val.clicolorIsSet {
os.Setenv("CLICOLOR", val.clicolorVal)
}
if val.clicolorForceIsSet {
os.Setenv("CLICOLOR_FORCE", val.clicolorForceVal)
}
res := tf.isColored()
assert.Equal(subT, val.expectedResult, res)
})
}
}
// TODO add tests for sorting etc., this requires a parser for the text // TODO add tests for sorting etc., this requires a parser for the text
// formatter output. // formatter output.