mirror
/
logrus
mirror of https://github.com/sirupsen/logrus.git
1
0
Fork 1
Code Issues Packages Projects Releases Wiki Activity

1. merge

This commit is contained in:
xiachengjia 2018-11-13 15:49:03 +08:00
parent 344530d269 44067abb19
commit 804b9126c5
37 changed files with 1704 additions and 236 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

1
.gitignore vendored
View File

@ -1 +1,2 @@
logrus
vendor

60
.travis.yml
View File

@ -1,15 +1,51 @@
language: go
go:
- 1.8.x
- 1.9.x
- 1.10.x
- tip
env:
- GOMAXPROCS=4 GORACE=halt_on_error=1
install:
- go get github.com/stretchr/testify/assert
- go get gopkg.in/gemnasium/logrus-airbrake-hook.v2
- go get golang.org/x/sys/unix
- go get golang.org/x/sys/windows
script:
- go test -race -v ./...
matrix:
include:
- go: 1.10.x
install:
- go get github.com/stretchr/testify/assert
- go get golang.org/x/crypto/ssh/terminal
- go get golang.org/x/sys/unix
- go get golang.org/x/sys/windows
script:
- go test -race -v ./...
- go: 1.11.x
env: GO111MODULE=on
install:
- go mod download
script:
- go test -race -v ./...
- go: 1.11.x
env: GO111MODULE=off
install:
- go get github.com/stretchr/testify/assert
- go get golang.org/x/crypto/ssh/terminal
- go get golang.org/x/sys/unix
- go get golang.org/x/sys/windows
script:
- go test -race -v ./...
- go: 1.10.x
install:
- go get github.com/stretchr/testify/assert
- go get golang.org/x/crypto/ssh/terminal
- go get golang.org/x/sys/unix
- go get golang.org/x/sys/windows
script:
- go test -race -v -tags appengine ./...
- go: 1.11.x
env: GO111MODULE=on
install:
- go mod download
script:
- go test -race -v -tags appengine ./...
- go: 1.11.x
env: GO111MODULE=off
install:
- go get github.com/stretchr/testify/assert
- go get golang.org/x/crypto/ssh/terminal
- go get golang.org/x/sys/unix
- go get golang.org/x/sys/windows
script:
- go test -race -v -tags appengine ./...

42
CHANGELOG.md
View File

@ -1,3 +1,45 @@
# 1.2.0
This new release introduces:
* A new method `SetReportCaller` in the `Logger` to enable the file, line and calling function from which the trace has been issued
* A new trace level named `Trace` whose level is below `Debug`
* A configurable exit function to be called upon a Fatal trace
* The `Level` object now implements `encoding.TextUnmarshaler` interface
# 1.1.1
This is a bug fix release.
* fix the build break on Solaris
* don't drop a whole trace in JSONFormatter when a field param is a function pointer which can not be serialized
# 1.1.0
This new release introduces:
* several fixes:
* a fix for a race condition on entry formatting
* proper cleanup of previously used entries before putting them back in the pool
* the extra new line at the end of message in text formatter has been removed
* a new global public API to check if a level is activated: IsLevelEnabled
* the following methods have been added to the Logger object
* IsLevelEnabled
* SetFormatter
* SetOutput
* ReplaceHooks
* introduction of go module
* an indent configuration for the json formatter
* output colour support for windows
* the field sort function is now configurable for text formatter
* the CLICOLOR and CLICOLOR\_FORCE environment variable support in text formater
# 1.0.6
This new release introduces:
* a new api WithTime which allows to easily force the time of the log entry
which is mostly useful for logger wrapper
* a fix reverting the immutability of the entry given as parameter to the hooks
a new configuration field of the json formatter in order to put all the fields
in a nested dictionnary
* a new SetOutput method in the Logger
* a new configuration of the textformatter to configure the name of the default keys
* a new configuration of the text formatter to disable the level truncation
# 1.0.5
* Fix hooks race (#707)

37
README.md
View File

@ -56,8 +56,39 @@ time="2015-03-26T01:27:38-04:00" level=warning msg="The group's number increased
time="2015-03-26T01:27:38-04:00" level=debug msg="Temperature changes" temperature=-4
time="2015-03-26T01:27:38-04:00" level=panic msg="It's over 9000!" animal=orca size=9009
time="2015-03-26T01:27:38-04:00" level=fatal msg="The ice breaks!" err=&{0x2082280c0 map[animal:orca size:9009] 2015-03-26 01:27:38.441574009 -0400 EDT panic It's over 9000!} number=100 omg=true
exit status 1
```
To ensure this behaviour even if a TTY is attached, set your formatter as follows:
```go
log.SetFormatter(&log.TextFormatter{
DisableColors: true,
FullTimestamp: true,
})
```
#### Logging Method Name
If you wish to add the calling method as a field, instruct the logger via:
```go
log.SetReportCaller(true)
```
This adds the caller as 'method' like so:
```json
{"animal":"penguin","level":"fatal","method":"github.com/sirupsen/arcticcreatures.migrate","msg":"a penguin swims by",
"time":"2014-03-10 19:57:38.562543129 -0400 EDT"}
```
```text
time="2015-03-26T01:27:38-04:00" level=fatal method=github.com/sirupsen/arcticcreatures.migrate msg="a penguin swims by" animal=penguin
```
Note that this does add measurable overhead - the cost will depend on the version of Go, but is
between 20 and 40% in recent tests with 1.6 and 1.7. You can validate this in your
environment via benchmarks:
```
go test -bench=.*CallerTracing
```
#### Case-sensitivity
@ -246,9 +277,10 @@ A list of currently known of service hook can be found in this wiki [page](https
#### Level logging
Logrus has six logging levels: Debug, Info, Warning, Error, Fatal and Panic.
Logrus has seven logging levels: Trace, Debug, Info, Warning, Error, Fatal and Panic.
```go
log.Trace("Something very low level.")
log.Debug("Useful debugging information.")
log.Info("Something noteworthy happened!")
log.Warn("You should probably take a look at this.")
@ -329,6 +361,7 @@ The built-in logging formatters are:
Third party logging formatters:
* [`FluentdFormatter`](https://github.com/joonix/log). Formats entries that can be parsed by Kubernetes and Google Container Engine.
* [`GELF`](https://github.com/fabienm/go-logrus-formatters). Formats entries so they comply to Graylog's [GELF 1.1 specification](http://docs.graylog.org/en/2.4/pages/gelf.html).
* [`logstash`](https://github.com/bshuster-repo/logrus-logstash-hook). Logs fields as [Logstash](http://logstash.net) Events.
* [`prefixed`](https://github.com/x-cray/logrus-prefixed-formatter). Displays log entry source along with alternative layout.
* [`zalgo`](https://github.com/aybabtme/logzalgo). Invoking the P͉̫o̳̼̊w̖͈̰͎e̬͔̭͂r͚̼̹̲ ̫͓͉̳͈ō̠͕͖̚f̝͍̠ ͕̲̞͖͑Z̖̫̤̫ͪa͉̬͈̗l͖͎g̳̥o̰̥̅!̣͔̲̻͊̄ ̙̘̦̹̦.

20
alt_exit_test.go
View File

@ -6,6 +6,8 @@ import (
"os"
"os/exec"
"path/filepath"
"runtime"
"strings"
"testing"
"time"
)
@ -19,6 +21,9 @@ func TestRegister(t *testing.T) {
}
func TestHandler(t *testing.T) {
testprog := testprogleader
testprog = append(testprog, getPackage()...)
testprog = append(testprog, testprogtrailer...)
tempDir, err := ioutil.TempDir("", "test_handler")
if err != nil {
log.Fatalf("can't create temp dir. %q", err)
@ -47,13 +52,24 @@ func TestHandler(t *testing.T) {
}
}
var testprog = []byte(`
// getPackage returns the name of the current package, which makes running this
// test in a fork simpler
func getPackage() []byte {
pc, _, _, _ := runtime.Caller(0)
fullFuncName := runtime.FuncForPC(pc).Name()
idx := strings.LastIndex(fullFuncName, ".")
return []byte(fullFuncName[:idx]) // trim off function details
}
var testprogleader = []byte(`
// Test program for atexit, gets output file and data as arguments and writes
// data to output file in atexit handler.
package main
import (
"github.com/sirupsen/logrus"
"`)
var testprogtrailer = []byte(
`"
"flag"
"fmt"
"io/ioutil"

196
entry.go
View File

@ -4,11 +4,30 @@ import (
"bytes"
"fmt"
"os"
"reflect"
"runtime"
"strings"
"sync"
"time"
)
var bufferPool *sync.Pool
var (
bufferPool *sync.Pool
// qualified package name, cached at first use
logrusPackage string
// Positions in the call stack when tracing to report the calling method
minimumCallerDepth int
// Used for caller information initialisation
callerInitOnce sync.Once
)
const (
maximumCallerDepth int = 25
knownLogrusFrames int = 4
)
func init() {
bufferPool = &sync.Pool{
@ -16,15 +35,18 @@ func init() {
return new(bytes.Buffer)
},
}
// start at the bottom of the stack before the package-name cache is primed
minimumCallerDepth = 1
}
// Defines the key when adding errors using WithError.
var ErrorKey = "error"
// An entry is the final or intermediate Logrus logging entry. It contains all
// the fields passed with WithField{,s}. It's finally logged when Debug, Info,
// Warn, Error, Fatal or Panic is called on it. These objects can be reused and
// passed around as much as you wish to avoid field duplication.
// the fields passed with WithField{,s}. It's finally logged when Trace, Debug,
// Info, Warn, Error, Fatal or Panic is called on it. These objects can be
// reused and passed around as much as you wish to avoid field duplication.
type Entry struct {
Logger *Logger
@ -34,22 +56,28 @@ type Entry struct {
// Time at which the log entry was created
Time time.Time
// Level the log entry was logged at: Debug, Info, Warn, Error, Fatal or Panic
// Level the log entry was logged at: Trace, Debug, Info, Warn, Error, Fatal or Panic
// This field will be set on entry firing and the value will be equal to the one in Logger struct field.
Level Level
// Message passed to Debug, Info, Warn, Error, Fatal or Panic
// Calling method, with package name
Caller *runtime.Frame
// Message passed to Trace, Debug, Info, Warn, Error, Fatal or Panic
Message string
// When formatter is called in entry.log(), an Buffer may be set to entry
// When formatter is called in entry.log(), a Buffer may be set to entry
Buffer *bytes.Buffer
// err may contain a field formatting error
err string
}
func NewEntry(logger *Logger) *Entry {
return &Entry{
Logger: logger,
// Default is five fields, give a little extra room
Data: make(Fields, 5),
// Default is three fields, plus one optional. Give a little extra room.
Data: make(Fields, 6),
}
}
@ -80,19 +108,95 @@ func (entry *Entry) WithFields(fields Fields) *Entry {
for k, v := range entry.Data {
data[k] = v
}
var field_err string
for k, v := range fields {
data[k] = v
if t := reflect.TypeOf(v); t != nil && t.Kind() == reflect.Func {
field_err = fmt.Sprintf("can not add field %q", k)
if entry.err != "" {
field_err = entry.err + ", " + field_err
}
} else {
data[k] = v
}
}
return &Entry{Logger: entry.Logger, Data: data}
return &Entry{Logger: entry.Logger, Data: data, Time: entry.Time, err: field_err}
}
// Overrides the time of the Entry.
func (entry *Entry) WithTime(t time.Time) *Entry {
return &Entry{Logger: entry.Logger, Data: entry.Data, Time: t}
}
// getPackageName reduces a fully qualified function name to the package name
// There really ought to be to be a better way...
func getPackageName(f string) string {
for {
lastPeriod := strings.LastIndex(f, ".")
lastSlash := strings.LastIndex(f, "/")
if lastPeriod > lastSlash {
f = f[:lastPeriod]
} else {
break
}
}
return f
}
// getCaller retrieves the name of the first non-logrus calling function
func getCaller() *runtime.Frame {
// Restrict the lookback frames to avoid runaway lookups
pcs := make([]uintptr, maximumCallerDepth)
depth := runtime.Callers(minimumCallerDepth, pcs)
frames := runtime.CallersFrames(pcs[:depth])
// cache this package's fully-qualified name
callerInitOnce.Do(func() {
logrusPackage = getPackageName(runtime.FuncForPC(pcs[0]).Name())
// now that we have the cache, we can skip a minimum count of known-logrus functions
// XXX this is dubious, the number of frames may vary store an entry in a logger interface
minimumCallerDepth = knownLogrusFrames
})
for f, again := frames.Next(); again; f, again = frames.Next() {
pkg := getPackageName(f.Function)
// If the caller isn't part of this package, we're done
if pkg != logrusPackage {
return &f
}
}
// if we got here, we failed to find the caller's context
return nil
}
func (entry Entry) HasCaller() (has bool) {
return entry.Logger != nil &&
entry.Logger.ReportCaller &&
entry.Caller != nil
}
// This function is not declared with a pointer value because otherwise
// race conditions will occur when using multiple goroutines
func (entry Entry) log(level Level, msg string) {
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.Message = msg
if entry.Logger.ReportCaller {
entry.Caller = getCaller()
}
entry.fireHooks()
@ -113,21 +217,19 @@ func (entry Entry) log(level Level, msg string) {
}
}
// This function is not declared with a pointer value because otherwise
// race conditions will occur when using multiple goroutines
func (entry Entry) fireHooks() {
func (entry *Entry) fireHooks() {
entry.Logger.mu.Lock()
defer entry.Logger.mu.Unlock()
err := entry.Logger.Hooks.Fire(entry.Level, &entry)
err := entry.Logger.Hooks.Fire(entry.Level, entry)
if err != nil {
fmt.Fprintf(os.Stderr, "Failed to fire hook: %v\n", err)
}
}
func (entry *Entry) write() {
serialized, err := entry.Logger.Formatter.Format(entry)
entry.Logger.mu.Lock()
defer entry.Logger.mu.Unlock()
serialized, err := entry.Logger.Formatter.Format(entry)
if err != nil {
fmt.Fprintf(os.Stderr, "Failed to obtain reader, %v\n", err)
} else {
@ -138,8 +240,14 @@ func (entry *Entry) write() {
}
}
func (entry *Entry) Trace(args ...interface{}) {
if entry.Logger.IsLevelEnabled(TraceLevel) {
entry.log(TraceLevel, fmt.Sprint(args...))
}
}
func (entry *Entry) Debug(args ...interface{}) {
if entry.Logger.level() >= DebugLevel {
if entry.Logger.IsLevelEnabled(DebugLevel) {
entry.log(DebugLevel, fmt.Sprint(args...))
}
}
@ -149,13 +257,13 @@ func (entry *Entry) Print(args ...interface{}) {
}
func (entry *Entry) Info(args ...interface{}) {
if entry.Logger.level() >= InfoLevel {
if entry.Logger.IsLevelEnabled(InfoLevel) {
entry.log(InfoLevel, fmt.Sprint(args...))
}
}
func (entry *Entry) Warn(args ...interface{}) {
if entry.Logger.level() >= WarnLevel {
if entry.Logger.IsLevelEnabled(WarnLevel) {
entry.log(WarnLevel, fmt.Sprint(args...))
}
}
@ -165,20 +273,20 @@ func (entry *Entry) Warning(args ...interface{}) {
}
func (entry *Entry) Error(args ...interface{}) {
if entry.Logger.level() >= ErrorLevel {
if entry.Logger.IsLevelEnabled(ErrorLevel) {
entry.log(ErrorLevel, fmt.Sprint(args...))
}
}
func (entry *Entry) Fatal(args ...interface{}) {
if entry.Logger.level() >= FatalLevel {
if entry.Logger.IsLevelEnabled(FatalLevel) {
entry.log(FatalLevel, fmt.Sprint(args...))
}
Exit(1)
entry.Logger.Exit(1)
}
func (entry *Entry) Panic(args ...interface{}) {
if entry.Logger.level() >= PanicLevel {
if entry.Logger.IsLevelEnabled(PanicLevel) {
entry.log(PanicLevel, fmt.Sprint(args...))
}
panic(fmt.Sprint(args...))
@ -186,14 +294,20 @@ func (entry *Entry) Panic(args ...interface{}) {
// Entry Printf family functions
func (entry *Entry) Tracef(format string, args ...interface{}) {
if entry.Logger.IsLevelEnabled(TraceLevel) {
entry.Trace(fmt.Sprintf(format, args...))
}
}
func (entry *Entry) Debugf(format string, args ...interface{}) {
if entry.Logger.level() >= DebugLevel {
if entry.Logger.IsLevelEnabled(DebugLevel) {
entry.Debug(fmt.Sprintf(format, args...))
}
}
func (entry *Entry) Infof(format string, args ...interface{}) {
if entry.Logger.level() >= InfoLevel {
if entry.Logger.IsLevelEnabled(InfoLevel) {
entry.Info(fmt.Sprintf(format, args...))
}
}
@ -203,7 +317,7 @@ func (entry *Entry) Printf(format string, args ...interface{}) {
}
func (entry *Entry) Warnf(format string, args ...interface{}) {
if entry.Logger.level() >= WarnLevel {
if entry.Logger.IsLevelEnabled(WarnLevel) {
entry.Warn(fmt.Sprintf(format, args...))
}
}
@ -213,34 +327,40 @@ func (entry *Entry) Warningf(format string, args ...interface{}) {
}
func (entry *Entry) Errorf(format string, args ...interface{}) {
if entry.Logger.level() >= ErrorLevel {
if entry.Logger.IsLevelEnabled(ErrorLevel) {
entry.Error(fmt.Sprintf(format, args...))
}
}
func (entry *Entry) Fatalf(format string, args ...interface{}) {
if entry.Logger.level() >= FatalLevel {
if entry.Logger.IsLevelEnabled(FatalLevel) {
entry.Fatal(fmt.Sprintf(format, args...))
}
Exit(1)
entry.Logger.Exit(1)
}
func (entry *Entry) Panicf(format string, args ...interface{}) {
if entry.Logger.level() >= PanicLevel {
if entry.Logger.IsLevelEnabled(PanicLevel) {
entry.Panic(fmt.Sprintf(format, args...))
}
}
// Entry Println family functions
func (entry *Entry) Traceln(args ...interface{}) {
if entry.Logger.IsLevelEnabled(TraceLevel) {
entry.Trace(entry.sprintlnn(args...))
}
}
func (entry *Entry) Debugln(args ...interface{}) {
if entry.Logger.level() >= DebugLevel {
if entry.Logger.IsLevelEnabled(DebugLevel) {
entry.Debug(entry.sprintlnn(args...))
}
}
func (entry *Entry) Infoln(args ...interface{}) {
if entry.Logger.level() >= InfoLevel {
if entry.Logger.IsLevelEnabled(InfoLevel) {
entry.Info(entry.sprintlnn(args...))
}
}
@ -250,7 +370,7 @@ func (entry *Entry) Println(args ...interface{}) {
}
func (entry *Entry) Warnln(args ...interface{}) {
if entry.Logger.level() >= WarnLevel {
if entry.Logger.IsLevelEnabled(WarnLevel) {
entry.Warn(entry.sprintlnn(args...))
}
}
@ -260,20 +380,20 @@ func (entry *Entry) Warningln(args ...interface{}) {
}
func (entry *Entry) Errorln(args ...interface{}) {
if entry.Logger.level() >= ErrorLevel {
if entry.Logger.IsLevelEnabled(ErrorLevel) {
entry.Error(entry.sprintlnn(args...))
}
}
func (entry *Entry) Fatalln(args ...interface{}) {
if entry.Logger.level() >= FatalLevel {
if entry.Logger.IsLevelEnabled(FatalLevel) {
entry.Fatal(entry.sprintlnn(args...))
}
Exit(1)
entry.Logger.Exit(1)
}
func (entry *Entry) Panicln(args ...interface{}) {
if entry.Logger.level() >= PanicLevel {
if entry.Logger.IsLevelEnabled(PanicLevel) {
entry.Panic(entry.sprintlnn(args...))
}
}

12
example_basic_test.go
View File

@ -1,16 +1,18 @@
package logrus_test
import (
"github.com/sirupsen/logrus"
"os"
"github.com/sirupsen/logrus"
)
func Example_basic() {
var log = logrus.New()
log.Formatter = new(logrus.JSONFormatter)
log.Formatter = new(logrus.TextFormatter) //default
log.Formatter.(*logrus.TextFormatter).DisableColors = true // remove colors
log.Formatter.(*logrus.TextFormatter).DisableTimestamp = true // remove timestamp from test output
log.Level = logrus.DebugLevel
log.Level = logrus.TraceLevel
log.Out = os.Stdout
// file, err := os.OpenFile("logrus.log", os.O_CREATE|os.O_WRONLY, 0666)
@ -35,6 +37,11 @@ func Example_basic() {
}
}()
log.WithFields(logrus.Fields{
"animal": "walrus",
"number": 0,
}).Trace("Went to the beach")
log.WithFields(logrus.Fields{
"animal": "walrus",
"number": 8,
@ -60,6 +67,7 @@ func Example_basic() {
}).Panic("It's over 9000!")
// Output:
// level=trace msg="Went to the beach" animal=walrus number=0
// level=debug msg="Started observing beach" animal=walrus number=8
// level=info msg="A group of walrus emerges from the ocean" animal=walrus size=10
// level=warning msg="The group's number increased tremendously!" number=122 omg=true

36
example_global_hook_test.go Normal file
View File

@ -0,0 +1,36 @@
package logrus_test
import (
"github.com/sirupsen/logrus"
"os"
)
var (
mystring string
)
type GlobalHook struct {
}
func (h *GlobalHook) Levels() []logrus.Level {
return logrus.AllLevels
}
func (h *GlobalHook) Fire(e *logrus.Entry) error {
e.Data["mystring"] = mystring
return nil
}
func Example() {
l := logrus.New()
l.Out = os.Stdout
l.Formatter = &logrus.TextFormatter{DisableTimestamp: true, DisableColors: true}
l.AddHook(&GlobalHook{})
mystring = "first value"
l.Info("first log")
mystring = "another value"
l.Info("second log")
// Output:
// level=info msg="first log" mystring="first value"
// level=info msg="second log" mystring="another value"
}

14
example_hook_test.go
View File

@ -1,16 +1,24 @@
// +build !windows
package logrus_test
import (
"github.com/sirupsen/logrus"
"gopkg.in/gemnasium/logrus-airbrake-hook.v2"
"log/syslog"
"os"
"github.com/sirupsen/logrus"
slhooks "github.com/sirupsen/logrus/hooks/syslog"
)
// An example on how to use a hook
func Example_hook() {
var log = logrus.New()
log.Formatter = new(logrus.TextFormatter) // default
log.Formatter.(*logrus.TextFormatter).DisableColors = true // remove colors
log.Formatter.(*logrus.TextFormatter).DisableTimestamp = true // remove timestamp from test output
log.Hooks.Add(airbrake.NewHook(123, "xyz", "development"))
if sl, err := slhooks.NewSyslogHook("udp", "localhost:514", syslog.LOG_INFO, ""); err != nil {
log.Hooks.Add(sl)
}
log.Out = os.Stdout
log.WithFields(logrus.Fields{

50
exported.go
View File

@ -2,6 +2,7 @@ package logrus
import (
"io"
"time"
)
var (
@ -20,30 +21,33 @@ func SetOutput(out io.Writer) {
// SetFormatter sets the standard logger formatter.
func SetFormatter(formatter Formatter) {
std.mu.Lock()
defer std.mu.Unlock()
std.Formatter = formatter
std.SetFormatter(formatter)
}
// SetReportCaller sets whether the standard logger will include the calling
// method as a field.
func SetReportCaller(include bool) {
std.SetReportCaller(include)
}
// SetLevel sets the standard logger level.
func SetLevel(level Level) {
std.mu.Lock()
defer std.mu.Unlock()
std.SetLevel(level)
}
// GetLevel returns the standard logger level.
func GetLevel() Level {
std.mu.Lock()
defer std.mu.Unlock()
return std.level()
return std.GetLevel()
}
// IsLevelEnabled checks if the log level of the standard logger is greater than the level param
func IsLevelEnabled(level Level) bool {
return std.IsLevelEnabled(level)
}
// AddHook adds a hook to the standard logger hooks.
func AddHook(hook Hook) {
std.mu.Lock()
defer std.mu.Unlock()
std.Hooks.Add(hook)
std.AddHook(hook)
}
// WithError creates an entry from the standard logger and adds an error to it, using the value defined in ErrorKey as key.
@ -70,6 +74,20 @@ func WithFields(fields Fields) *Entry {
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)
}
// Trace logs a message at level Trace on the standard logger.
func Trace(args ...interface{}) {
std.Trace(args...)
}
// Debug logs a message at level Debug on the standard logger.
func Debug(args ...interface{}) {
std.Debug(args...)
@ -110,6 +128,11 @@ func Fatal(args ...interface{}) {
std.Fatal(args...)
}
// Tracef logs a message at level Trace on the standard logger.
func Tracef(format string, args ...interface{}) {
std.Tracef(format, args...)
}
// Debugf logs a message at level Debug on the standard logger.
func Debugf(format string, args ...interface{}) {
std.Debugf(format, args...)
@ -150,6 +173,11 @@ func Fatalf(format string, args ...interface{}) {
std.Fatalf(format, args...)
}
// Traceln logs a message at level Trace on the standard logger.
func Traceln(args ...interface{}) {
std.Traceln(args...)
}
// Debugln logs a message at level Debug on the standard logger.
func Debugln(args ...interface{}) {
std.Debugln(args...)

33
formatter.go
View File

@ -2,7 +2,16 @@ package logrus
import "time"
const defaultTimestampFormat = time.RFC3339
// Default key names for the default fields
const (
defaultTimestampFormat = time.RFC3339
FieldKeyMsg = "msg"
FieldKeyLevel = "level"
FieldKeyTime = "time"
FieldKeyLogrusError = "logrus_error"
FieldKeyFunc = "func"
FieldKeyFile = "file"
)
// The Formatter interface is used to implement a custom Formatter. It takes an
// `Entry`. It exposes all the fields, including the default ones:
@ -18,7 +27,7 @@ type Formatter interface {
Format(*Entry) ([]byte, error)
}
// This is to not silently overwrite `time`, `msg` and `level` fields when
// This is to not silently overwrite `time`, `msg`, `func` and `level` fields when
// dumping it. If this code wasn't there doing:
//
// logrus.WithField("level", 1).Info("hello")
@ -30,7 +39,7 @@ type Formatter interface {
//
// It's not exported because it's still using Data in an opinionated way. It's to
// avoid code duplication between the two default formatters.
func prefixFieldClashes(data Fields, fieldMap FieldMap) {
func prefixFieldClashes(data Fields, fieldMap FieldMap, reportCaller bool) {
timeKey := fieldMap.resolve(FieldKeyTime)
if t, ok := data[timeKey]; ok {
data["fields."+timeKey] = t
@ -48,4 +57,22 @@ func prefixFieldClashes(data Fields, fieldMap FieldMap) {
data["fields."+levelKey] = l
delete(data, levelKey)
}
logrusErrKey := fieldMap.resolve(FieldKeyLogrusError)
if l, ok := data[logrusErrKey]; ok {
data["fields."+logrusErrKey] = l
delete(data, logrusErrKey)
}
// If reportCaller is not set, 'func' will not conflict.
if reportCaller {
funcKey := fieldMap.resolve(FieldKeyFunc)
if l, ok := data[funcKey]; ok {
data["fields."+funcKey] = l
}
fileKey := fieldMap.resolve(FieldKeyFile)
if l, ok := data[fileKey]; ok {
data["fields."+fileKey] = l
}
}
}

11
go.mod Normal file
View File

@ -0,0 +1,11 @@
module github.com/sirupsen/logrus
require (
github.com/davecgh/go-spew v1.1.1 // indirect
github.com/konsorten/go-windows-terminal-sequences v1.0.1
github.com/pmezard/go-difflib v1.0.0 // indirect
github.com/stretchr/objx v0.1.1 // indirect
github.com/stretchr/testify v1.2.2
golang.org/x/crypto v0.0.0-20180904163835-0709b304e793
golang.org/x/sys v0.0.0-20180905080454-ebe1bf3edb33
)

15
go.sum Normal file
View File

@ -0,0 +1,15 @@
github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
github.com/konsorten/go-windows-terminal-sequences v0.0.0-20180402223658-b729f2633dfe h1:CHRGQ8V7OlCYtwaKPJi3iA7J+YdNKdo8j7nG5IgDhjs=
github.com/konsorten/go-windows-terminal-sequences v0.0.0-20180402223658-b729f2633dfe/go.mod h1:T0+1ngSBFLxvqU3pZ+m/2kptfBszLMUkC4ZK/EgS/cQ=
github.com/konsorten/go-windows-terminal-sequences v1.0.1/go.mod h1:T0+1ngSBFLxvqU3pZ+m/2kptfBszLMUkC4ZK/EgS/cQ=
github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
github.com/stretchr/objx v0.1.1 h1:2vfRuCMp5sSVIDSqO8oNnWJq7mPa6KVP3iPIwFBuy8A=
github.com/stretchr/objx v0.1.1/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
github.com/stretchr/testify v1.2.2 h1:bSDNvY7ZPG5RlJ8otE/7V6gMiyenm9RtJ7IUVIAoJ1w=
github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs=
golang.org/x/crypto v0.0.0-20180904163835-0709b304e793 h1:u+LnwYTOOW7Ukr/fppxEb1Nwz0AtPflrblfvUudpo+I=
golang.org/x/crypto v0.0.0-20180904163835-0709b304e793/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4=
golang.org/x/sys v0.0.0-20180905080454-ebe1bf3edb33 h1:I6FyU15t786LL7oL/hn43zqTuEGr4PN7F4XJ1p4E3Y8=
golang.org/x/sys v0.0.0-20180905080454-ebe1bf3edb33/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY=

50
hook_test.go
View File

@ -1,10 +1,16 @@
package logrus
package logrus_test
import (
"bytes"
"encoding/json"
"sync"
"testing"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
. "github.com/sirupsen/logrus"
. "github.com/sirupsen/logrus/internal/testutils"
)
type TestHook struct {
@ -18,6 +24,7 @@ func (hook *TestHook) Fire(entry *Entry) error {
func (hook *TestHook) Levels() []Level {
return []Level{
TraceLevel,
DebugLevel,
InfoLevel,
WarnLevel,
@ -50,6 +57,7 @@ func (hook *ModifyHook) Fire(entry *Entry) error {
func (hook *ModifyHook) Levels() []Level {
return []Level{
TraceLevel,
DebugLevel,
InfoLevel,
WarnLevel,
@ -85,6 +93,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 {
Fired bool
}

2
hooks/syslog/syslog.go
View File

@ -43,7 +43,7 @@ func (hook *SyslogHook) Fire(entry *logrus.Entry) error {
return hook.Writer.Warning(line)
case logrus.InfoLevel:
return hook.Writer.Info(line)
case logrus.DebugLevel:
case logrus.DebugLevel, logrus.TraceLevel:
return hook.Writer.Debug(line)
default:
return nil

2
hooks/syslog/syslog_test.go
View File

@ -1,3 +1,5 @@
// +build !windows,!nacl,!plan9
package syslog
import (

15
hooks/test/test.go
View File

@ -15,7 +15,7 @@ type Hook struct {
// 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
// value directly.
Entries []*logrus.Entry
Entries []logrus.Entry
mu sync.RWMutex
}
@ -52,7 +52,7 @@ func NewNullLogger() (*logrus.Logger, *Hook) {
func (t *Hook) Fire(e *logrus.Entry) error {
t.mu.Lock()
defer t.mu.Unlock()
t.Entries = append(t.Entries, e)
t.Entries = append(t.Entries, *e)
return nil
}
@ -68,9 +68,7 @@ func (t *Hook) LastEntry() *logrus.Entry {
if i < 0 {
return nil
}
// Make a copy, for safety
e := *t.Entries[i]
return &e
return &t.Entries[i]
}
// AllEntries returns all entries that were logged.
@ -79,10 +77,9 @@ func (t *Hook) AllEntries() []*logrus.Entry {
defer t.mu.RUnlock()
// Make a copy so the returned value won't race with future log requests
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
e := *entry
entries[i] = &e
entries[i] = &t.Entries[i]
}
return entries
}
@ -91,5 +88,5 @@ func (t *Hook) AllEntries() []*logrus.Entry {
func (t *Hook) Reset() {
t.mu.Lock()
defer t.mu.Unlock()
t.Entries = make([]*logrus.Entry, 0)
t.Entries = make([]logrus.Entry, 0)
}

36
hooks/test/test_test.go
View File

@ -1,8 +1,10 @@
package test
import (
"math/rand"
"sync"
"testing"
"time"
"github.com/sirupsen/logrus"
"github.com/stretchr/testify/assert"
@ -38,24 +40,46 @@ func TestAllHooks(t *testing.T) {
}
func TestLoggingWithHooksRace(t *testing.T) {
rand.Seed(time.Now().Unix())
unlocker := rand.Int() % 100
assert := assert.New(t)
logger, hook := NewNullLogger()
var wg sync.WaitGroup
wg.Add(100)
var wgOne, wgAll sync.WaitGroup
wgOne.Add(1)
wgAll.Add(100)
for i := 0; i < 100; i++ {
go func() {
go func(i int) {
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("info", hook.LastEntry().Message)
wgAll.Wait()
entries := hook.AllEntries()
assert.Equal(100, len(entries))
}
func TestFatalWithAlternateExit(t *testing.T) {
assert := assert.New(t)
logger, hook := NewNullLogger()
logger.ExitFunc = func(code int) {}
logger.Fatal("something went very wrong")
assert.Equal(logrus.FatalLevel, hook.LastEntry().Level)
assert.Equal("something went very wrong", hook.LastEntry().Message)
assert.Equal(1, len(hook.Entries))
}

58
internal/testutils/testutils.go Normal file
View File

@ -0,0 +1,58 @@
package testutils
import (
"bytes"
"encoding/json"
"strconv"
"strings"
"testing"
. "github.com/sirupsen/logrus"
"github.com/stretchr/testify/require"
)
func LogAndAssertJSON(t *testing.T, log func(*Logger), assertions func(fields Fields)) {
var buffer bytes.Buffer
var fields Fields
logger := New()
logger.Out = &buffer
logger.Formatter = new(JSONFormatter)
log(logger)
err := json.Unmarshal(buffer.Bytes(), &fields)
require.Nil(t, err)
assertions(fields)
}
func LogAndAssertText(t *testing.T, log func(*Logger), assertions func(fields map[string]string)) {
var buffer bytes.Buffer
logger := New()
logger.Out = &buffer
logger.Formatter = &TextFormatter{
DisableColors: true,
}
log(logger)
fields := make(map[string]string)
for _, kv := range strings.Split(buffer.String(), " ") {
if !strings.Contains(kv, "=") {
continue
}
kvArr := strings.Split(kv, "=")
key := strings.TrimSpace(kvArr[0])
val := kvArr[1]
if kvArr[1][0] == '"' {
var err error
val, err = strconv.Unquote(val)
require.NoError(t, err)
}
fields[key] = val
}
assertions(fields)
}

44
json_formatter.go
View File

@ -1,6 +1,7 @@
package logrus
import (
"bytes"
"encoding/json"
"fmt"
)
@ -10,13 +11,6 @@ type fieldKey string
// FieldMap allows customization of the key names for default fields.
type FieldMap map[fieldKey]string
// Default key names for the default fields
const (
FieldKeyMsg = "msg"
FieldKeyLevel = "level"
FieldKeyTime = "time"
)
func (f FieldMap) resolve(key fieldKey) string {
if k, ok := f[key]; ok {
return k
@ -40,17 +34,21 @@ type JSONFormatter struct {
// As an example:
// formatter := &JSONFormatter{
// FieldMap: FieldMap{
// FieldKeyTime: "@timestamp",
// FieldKeyTime: "@timestamp",
// FieldKeyLevel: "@level",
// FieldKeyMsg: "@message",
// FieldKeyMsg: "@message",
// FieldKeyFunc: "@caller",
// },
// }
FieldMap FieldMap
// PrettyPrint will indent all json logs
PrettyPrint bool
}
// Format renders a single log entry
func (f *JSONFormatter) Format(entry *Entry) ([]byte, error) {
data := make(Fields, len(entry.Data)+3)
data := make(Fields, len(entry.Data)+4)
for k, v := range entry.Data {
switch v := v.(type) {
case error:
@ -68,22 +66,40 @@ func (f *JSONFormatter) Format(entry *Entry) ([]byte, error) {
data = newData
}
prefixFieldClashes(data, f.FieldMap)
prefixFieldClashes(data, f.FieldMap, entry.HasCaller())
timestampFormat := f.TimestampFormat
if timestampFormat == "" {
timestampFormat = defaultTimestampFormat
}
if entry.err != "" {
data[f.FieldMap.resolve(FieldKeyLogrusError)] = entry.err
}
if !f.DisableTimestamp {
data[f.FieldMap.resolve(FieldKeyTime)] = entry.Time.Format(timestampFormat)
}
data[f.FieldMap.resolve(FieldKeyMsg)] = entry.Message
data[f.FieldMap.resolve(FieldKeyLevel)] = entry.Level.String()
if entry.HasCaller() {
data[f.FieldMap.resolve(FieldKeyFunc)] = entry.Caller.Function
data[f.FieldMap.resolve(FieldKeyFile)] = fmt.Sprintf("%s:%d", entry.Caller.File, entry.Caller.Line)
}
serialized, err := json.Marshal(data)
if err != nil {
var b *bytes.Buffer
if entry.Buffer != nil {
b = entry.Buffer
} else {
b = &bytes.Buffer{}
}
encoder := json.NewEncoder(b)
if f.PrettyPrint {
encoder.SetIndent("", " ")
}
if err := encoder.Encode(data); err != nil {
return nil, fmt.Errorf("Failed to marshal fields to JSON, %v", err)
}
return append(serialized, '\n'), nil
return b.Bytes(), nil
}

54
json_formatter_test.go
View File

@ -4,6 +4,7 @@ import (
"encoding/json"
"errors"
"fmt"
"runtime"
"strings"
"testing"
)
@ -167,8 +168,8 @@ func TestFieldsInNestedDictionary(t *testing.T) {
}
logEntry := WithFields(Fields{
"level": "level",
"test": "test",
"level": "level",
"test": "test",
})
logEntry.Level = InfoLevel
@ -267,6 +268,55 @@ func TestJSONTimeKey(t *testing.T) {
}
}
func TestFieldDoesNotClashWithCaller(t *testing.T) {
SetReportCaller(false)
formatter := &JSONFormatter{}
b, err := formatter.Format(WithField("func", "howdy pardner"))
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)
}
if entry["func"] != "howdy pardner" {
t.Fatal("func field replaced when ReportCaller=false")
}
}
func TestFieldClashWithCaller(t *testing.T) {
SetReportCaller(true)
formatter := &JSONFormatter{}
e := WithField("func", "howdy pardner")
e.Caller = &runtime.Frame{Function: "somefunc"}
b, err := formatter.Format(e)
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)
}
if entry["fields.func"] != "howdy pardner" {
t.Fatalf("fields.func not set to original func field when ReportCaller=true (got '%s')",
entry["fields.func"])
}
if entry["func"] != "somefunc" {
t.Fatalf("func not set as expected when ReportCaller=true (got '%s')",
entry["func"])
}
SetReportCaller(false) // return to default value
}
func TestJSONDisableTimestamp(t *testing.T) {
formatter := &JSONFormatter{
DisableTimestamp: true,

150
logger.go
View File

@ -5,12 +5,13 @@ import (
"os"
"sync"
"sync/atomic"
"time"
)
type Logger struct {
// 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
// something more adventorous, such as logging to Kafka.
// something more adventurous, such as logging to Kafka.
Out io.Writer
// 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
@ -23,6 +24,10 @@ type Logger struct {
// own that implements the `Formatter` interface, see the `README` or included
// formatters for examples.
Formatter Formatter
// Flag for whether to log caller info (off by default)
ReportCaller bool
// The logging level the logger should log at. This is typically (and defaults
// to) `logrus.Info`, which allows Info(), Warn(), Error() and Fatal() to be
// logged.
@ -31,8 +36,12 @@ type Logger struct {
mu MutexWrap
// Reusable empty entry
entryPool sync.Pool
// Function to exit the application, defaults to `os.Exit()`
ExitFunc exitFunc
}
type exitFunc func(int)
type MutexWrap struct {
lock sync.Mutex
disabled bool
@ -68,10 +77,12 @@ func (mw *MutexWrap) Disable() {
// It's recommended to make this a global instance called `log`.
func New() *Logger {
return &Logger{
Out: os.Stderr,
Formatter: new(TextFormatter),
Hooks: make(LevelHooks),
Level: InfoLevel,
Out: os.Stderr,
Formatter: new(TextFormatter),
Hooks: make(LevelHooks),
Level: InfoLevel,
ExitFunc: os.Exit,
ReportCaller: false,
}
}
@ -84,6 +95,7 @@ func (logger *Logger) newEntry() *Entry {
}
func (logger *Logger) releaseEntry(entry *Entry) {
entry.Data = map[string]interface{}{}
logger.entryPool.Put(entry)
}
@ -112,8 +124,23 @@ func (logger *Logger) WithError(err error) *Entry {
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) Tracef(format string, args ...interface{}) {
if logger.IsLevelEnabled(TraceLevel) {
entry := logger.newEntry()
entry.Tracef(format, args...)
logger.releaseEntry(entry)
}
}
func (logger *Logger) Debugf(format string, args ...interface{}) {
if logger.level() >= DebugLevel {
if logger.IsLevelEnabled(DebugLevel) {
entry := logger.newEntry()
entry.Debugf(format, args...)
logger.releaseEntry(entry)
@ -121,7 +148,7 @@ func (logger *Logger) Debugf(format string, args ...interface{}) {
}
func (logger *Logger) Infof(format string, args ...interface{}) {
if logger.level() >= InfoLevel {
if logger.IsLevelEnabled(InfoLevel) {
entry := logger.newEntry()
entry.Infof(format, args...)
logger.releaseEntry(entry)
@ -135,7 +162,7 @@ func (logger *Logger) Printf(format string, args ...interface{}) {
}
func (logger *Logger) Warnf(format string, args ...interface{}) {
if logger.level() >= WarnLevel {
if logger.IsLevelEnabled(WarnLevel) {
entry := logger.newEntry()
entry.Warnf(format, args...)
logger.releaseEntry(entry)
@ -143,7 +170,7 @@ func (logger *Logger) Warnf(format string, args ...interface{}) {
}
func (logger *Logger) Warningf(format string, args ...interface{}) {
if logger.level() >= WarnLevel {
if logger.IsLevelEnabled(WarnLevel) {
entry := logger.newEntry()
entry.Warnf(format, args...)
logger.releaseEntry(entry)
@ -151,7 +178,7 @@ func (logger *Logger) Warningf(format string, args ...interface{}) {
}
func (logger *Logger) Errorf(format string, args ...interface{}) {
if logger.level() >= ErrorLevel {
if logger.IsLevelEnabled(ErrorLevel) {
entry := logger.newEntry()
entry.Errorf(format, args...)
logger.releaseEntry(entry)
@ -159,24 +186,32 @@ func (logger *Logger) Errorf(format string, args ...interface{}) {
}
func (logger *Logger) Fatalf(format string, args ...interface{}) {
if logger.level() >= FatalLevel {
if logger.IsLevelEnabled(FatalLevel) {
entry := logger.newEntry()
entry.Fatalf(format, args...)
logger.releaseEntry(entry)
}
Exit(1)
logger.Exit(1)
}
func (logger *Logger) Panicf(format string, args ...interface{}) {
if logger.level() >= PanicLevel {
if logger.IsLevelEnabled(PanicLevel) {
entry := logger.newEntry()
entry.Panicf(format, args...)
logger.releaseEntry(entry)
}
}
func (logger *Logger) Trace(args ...interface{}) {
if logger.IsLevelEnabled(TraceLevel) {
entry := logger.newEntry()
entry.Trace(args...)
logger.releaseEntry(entry)
}
}
func (logger *Logger) Debug(args ...interface{}) {
if logger.level() >= DebugLevel {
if logger.IsLevelEnabled(DebugLevel) {
entry := logger.newEntry()
entry.Debug(args...)
logger.releaseEntry(entry)
@ -184,7 +219,7 @@ func (logger *Logger) Debug(args ...interface{}) {
}
func (logger *Logger) Info(args ...interface{}) {
if logger.level() >= InfoLevel {
if logger.IsLevelEnabled(InfoLevel) {
entry := logger.newEntry()
entry.Info(args...)
logger.releaseEntry(entry)
@ -198,7 +233,7 @@ func (logger *Logger) Print(args ...interface{}) {
}
func (logger *Logger) Warn(args ...interface{}) {
if logger.level() >= WarnLevel {
if logger.IsLevelEnabled(WarnLevel) {
entry := logger.newEntry()
entry.Warn(args...)
logger.releaseEntry(entry)
@ -206,7 +241,7 @@ func (logger *Logger) Warn(args ...interface{}) {
}
func (logger *Logger) Warning(args ...interface{}) {
if logger.level() >= WarnLevel {
if logger.IsLevelEnabled(WarnLevel) {
entry := logger.newEntry()
entry.Warn(args...)
logger.releaseEntry(entry)
@ -214,7 +249,7 @@ func (logger *Logger) Warning(args ...interface{}) {
}
func (logger *Logger) Error(args ...interface{}) {
if logger.level() >= ErrorLevel {
if logger.IsLevelEnabled(ErrorLevel) {
entry := logger.newEntry()
entry.Error(args...)
logger.releaseEntry(entry)
@ -222,24 +257,32 @@ func (logger *Logger) Error(args ...interface{}) {
}
func (logger *Logger) Fatal(args ...interface{}) {
if logger.level() >= FatalLevel {
if logger.IsLevelEnabled(FatalLevel) {
entry := logger.newEntry()
entry.Fatal(args...)
logger.releaseEntry(entry)
}
Exit(1)
logger.Exit(1)
}
func (logger *Logger) Panic(args ...interface{}) {
if logger.level() >= PanicLevel {
if logger.IsLevelEnabled(PanicLevel) {
entry := logger.newEntry()
entry.Panic(args...)
logger.releaseEntry(entry)
}
}
func (logger *Logger) Traceln(args ...interface{}) {
if logger.IsLevelEnabled(TraceLevel) {
entry := logger.newEntry()
entry.Traceln(args...)
logger.releaseEntry(entry)
}
}
func (logger *Logger) Debugln(args ...interface{}) {
if logger.level() >= DebugLevel {
if logger.IsLevelEnabled(DebugLevel) {
entry := logger.newEntry()
entry.Debugln(args...)
logger.releaseEntry(entry)
@ -247,7 +290,7 @@ func (logger *Logger) Debugln(args ...interface{}) {
}
func (logger *Logger) Infoln(args ...interface{}) {
if logger.level() >= InfoLevel {
if logger.IsLevelEnabled(InfoLevel) {
entry := logger.newEntry()
entry.Infoln(args...)
logger.releaseEntry(entry)
@ -261,7 +304,7 @@ func (logger *Logger) Println(args ...interface{}) {
}
func (logger *Logger) Warnln(args ...interface{}) {
if logger.level() >= WarnLevel {
if logger.IsLevelEnabled(WarnLevel) {
entry := logger.newEntry()
entry.Warnln(args...)
logger.releaseEntry(entry)
@ -269,7 +312,7 @@ func (logger *Logger) Warnln(args ...interface{}) {
}
func (logger *Logger) Warningln(args ...interface{}) {
if logger.level() >= WarnLevel {
if logger.IsLevelEnabled(WarnLevel) {
entry := logger.newEntry()
entry.Warnln(args...)
logger.releaseEntry(entry)
@ -277,7 +320,7 @@ func (logger *Logger) Warningln(args ...interface{}) {
}
func (logger *Logger) Errorln(args ...interface{}) {
if logger.level() >= ErrorLevel {
if logger.IsLevelEnabled(ErrorLevel) {
entry := logger.newEntry()
entry.Errorln(args...)
logger.releaseEntry(entry)
@ -285,22 +328,30 @@ func (logger *Logger) Errorln(args ...interface{}) {
}
func (logger *Logger) Fatalln(args ...interface{}) {
if logger.level() >= FatalLevel {
if logger.IsLevelEnabled(FatalLevel) {
entry := logger.newEntry()
entry.Fatalln(args...)
logger.releaseEntry(entry)
}
Exit(1)
logger.Exit(1)
}
func (logger *Logger) Panicln(args ...interface{}) {
if logger.level() >= PanicLevel {
if logger.IsLevelEnabled(PanicLevel) {
entry := logger.newEntry()
entry.Panicln(args...)
logger.releaseEntry(entry)
}
}
func (logger *Logger) Exit(code int) {
runHandlers()
if logger.ExitFunc == nil {
logger.ExitFunc = os.Exit
}
logger.ExitFunc(code)
}
//When file is opened with appending mode, it's safe to
//write concurrently to a file (within 4k message on Linux).
//In these cases user can choose to disable the lock.
@ -312,6 +363,7 @@ func (logger *Logger) level() Level {
return Level(atomic.LoadUint32((*uint32)(&logger.Level)))
}
// SetLevel sets the logger level.
func (logger *Logger) SetLevel(level Level) {
atomic.StoreUint32((*uint32)(&logger.Level), uint32(level))
}
@ -331,8 +383,48 @@ func (logger *Logger) SetOutput(out io.Writer) {
logger.Out = out
}
// 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) {
logger.mu.Lock()
defer logger.mu.Unlock()
logger.Hooks.Add(hook)
}
// IsLevelEnabled checks if the log level of the logger is greater than the level param
func (logger *Logger) IsLevelEnabled(level Level) bool {
return logger.level() >= level
}
// 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
}
func (logger *Logger) SetReportCaller(reportCaller bool) {
logger.mu.Lock()
defer logger.mu.Unlock()
logger.ReportCaller = reportCaller
}
// 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
}

24
logger_bench_test.go
View File

@ -1,6 +1,7 @@
package logrus
import (
"io/ioutil"
"os"
"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")
}
})
}

42
logger_test.go Normal file
View File

@ -0,0 +1,42 @@
package logrus
import (
"bytes"
"encoding/json"
"fmt"
"testing"
"github.com/stretchr/testify/require"
)
func TestFieldValueError(t *testing.T) {
buf := &bytes.Buffer{}
l := &Logger{
Out: buf,
Formatter: new(JSONFormatter),
Hooks: make(LevelHooks),
Level: DebugLevel,
}
l.WithField("func", func() {}).Info("test")
fmt.Println(buf.String())
var data map[string]interface{}
json.Unmarshal(buf.Bytes(), &data)
_, ok := data[FieldKeyLogrusError]
require.True(t, ok)
}
func TestNoFieldValueError(t *testing.T) {
buf := &bytes.Buffer{}
l := &Logger{
Out: buf,
Formatter: new(JSONFormatter),
Hooks: make(LevelHooks),
Level: DebugLevel,
}
l.WithField("str", "str").Info("test")
fmt.Println(buf.String())
var data map[string]interface{}
json.Unmarshal(buf.Bytes(), &data)
_, ok := data[FieldKeyLogrusError]
require.False(t, ok)
}

37
logrus.go
View File

@ -15,6 +15,8 @@ type Level uint32
// Convert the Level to a string. E.g. PanicLevel becomes "panic".
func (level Level) String() string {
switch level {
case TraceLevel:
return "trace"
case DebugLevel:
return "debug"
case InfoLevel:
@ -47,12 +49,26 @@ func ParseLevel(lvl string) (Level, error) {
return InfoLevel, nil
case "debug":
return DebugLevel, nil
case "trace":
return TraceLevel, nil
}
var l Level
return l, fmt.Errorf("not a valid logrus Level: %q", lvl)
}
// UnmarshalText implements encoding.TextUnmarshaler.
func (level *Level) UnmarshalText(text []byte) error {
l, err := ParseLevel(string(text))
if err != nil {
return err
}
*level = Level(l)
return nil
}
// A constant exposing all logging levels
var AllLevels = []Level{
PanicLevel,
@ -61,6 +77,7 @@ var AllLevels = []Level{
WarnLevel,
InfoLevel,
DebugLevel,
TraceLevel,
}
// These are the different logging levels. You can set the logging level to log
@ -69,7 +86,7 @@ const (
// PanicLevel level, highest level of severity. Logs and then calls panic with the
// message passed to Debug, Info, ...
PanicLevel Level = iota
// FatalLevel level. Logs and then calls `os.Exit(1)`. It will exit even if the
// FatalLevel level. Logs and then calls `logger.Exit(1)`. It will exit even if the
// logging level is set to Panic.
FatalLevel
// ErrorLevel level. Logs. Used for errors that should definitely be noted.
@ -82,6 +99,8 @@ const (
InfoLevel
// DebugLevel level. Usually only enabled when debugging. Very verbose logging.
DebugLevel
// TraceLevel level. Designates finer-grained informational events than the Debug.
TraceLevel
)
// Won't compile if StdLogger can't be realized by a log.Logger
@ -140,4 +159,20 @@ type FieldLogger interface {
Errorln(args ...interface{})
Fatalln(args ...interface{})
Panicln(args ...interface{})
// IsDebugEnabled() bool
// IsInfoEnabled() bool
// IsWarnEnabled() bool
// IsErrorEnabled() bool
// IsFatalEnabled() bool
// IsPanicEnabled() bool
}
// Ext1FieldLogger (the first extension to FieldLogger) is superfluous, it is
// here for consistancy. Do not use. Use Logger or Entry instead.
type Ext1FieldLogger interface {
FieldLogger
Tracef(format string, args ...interface{})
Trace(args ...interface{})
Traceln(args ...interface{})
}

434
logrus_test.go
View File

@ -1,67 +1,93 @@
package logrus
package logrus_test
import (
"bytes"
"encoding/json"
"strconv"
"strings"
"io/ioutil"
"os"
"path/filepath"
"sync"
"testing"
"time"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
. "github.com/sirupsen/logrus"
. "github.com/sirupsen/logrus/internal/testutils"
)
func LogAndAssertJSON(t *testing.T, log func(*Logger), assertions func(fields Fields)) {
// TestReportCaller verifies that when ReportCaller is set, the 'func' field
// is added, and when it is unset it is not set or modified
// Verify that functions within the Logrus package aren't considered when
// discovering the caller.
func TestReportCallerWhenConfigured(t *testing.T) {
LogAndAssertJSON(t, func(log *Logger) {
log.ReportCaller = false
log.Print("testNoCaller")
}, func(fields Fields) {
assert.Equal(t, "testNoCaller", fields["msg"])
assert.Equal(t, "info", fields["level"])
assert.Equal(t, nil, fields["func"])
})
LogAndAssertJSON(t, func(log *Logger) {
log.ReportCaller = true
log.Print("testWithCaller")
}, func(fields Fields) {
assert.Equal(t, "testWithCaller", fields["msg"])
assert.Equal(t, "info", fields["level"])
assert.Equal(t,
"github.com/sirupsen/logrus_test.TestReportCallerWhenConfigured.func3", fields["func"])
})
}
func logSomething(t *testing.T, message string) Fields {
var buffer bytes.Buffer
var fields Fields
logger := New()
logger.Out = &buffer
logger.Formatter = new(JSONFormatter)
logger.ReportCaller = true
log(logger)
entry := logger.WithFields(Fields{
"foo": "bar",
})
entry.Info(message)
err := json.Unmarshal(buffer.Bytes(), &fields)
assert.Nil(t, err)
assertions(fields)
return fields
}
func LogAndAssertText(t *testing.T, log func(*Logger), assertions func(fields map[string]string)) {
var buffer bytes.Buffer
// TestReportCallerHelperDirect - verify reference when logging from a regular function
func TestReportCallerHelperDirect(t *testing.T) {
fields := logSomething(t, "direct")
logger := New()
logger.Out = &buffer
logger.Formatter = &TextFormatter{
DisableColors: true,
}
assert.Equal(t, "direct", fields["msg"])
assert.Equal(t, "info", fields["level"])
assert.Regexp(t, "github.com/.*/logrus_test.logSomething", fields["func"])
}
log(logger)
// TestReportCallerHelperDirect - verify reference when logging from a function called via pointer
func TestReportCallerHelperViaPointer(t *testing.T) {
fptr := logSomething
fields := fptr(t, "via pointer")
fields := make(map[string]string)
for _, kv := range strings.Split(buffer.String(), " ") {
if !strings.Contains(kv, "=") {
continue
}
kvArr := strings.Split(kv, "=")
key := strings.TrimSpace(kvArr[0])
val := kvArr[1]
if kvArr[1][0] == '"' {
var err error
val, err = strconv.Unquote(val)
assert.NoError(t, err)
}
fields[key] = val
}
assertions(fields)
assert.Equal(t, "via pointer", fields["msg"])
assert.Equal(t, "info", fields["level"])
assert.Regexp(t, "github.com/.*/logrus_test.logSomething", fields["func"])
}
func TestPrint(t *testing.T) {
LogAndAssertJSON(t, func(log *Logger) {
log.Print("test")
}, func(fields Fields) {
assert.Equal(t, fields["msg"], "test")
assert.Equal(t, fields["level"], "info")
assert.Equal(t, "test", fields["msg"])
assert.Equal(t, "info", fields["level"])
})
}
@ -69,8 +95,8 @@ func TestInfo(t *testing.T) {
LogAndAssertJSON(t, func(log *Logger) {
log.Info("test")
}, func(fields Fields) {
assert.Equal(t, fields["msg"], "test")
assert.Equal(t, fields["level"], "info")
assert.Equal(t, "test", fields["msg"])
assert.Equal(t, "info", fields["level"])
})
}
@ -78,8 +104,8 @@ func TestWarn(t *testing.T) {
LogAndAssertJSON(t, func(log *Logger) {
log.Warn("test")
}, func(fields Fields) {
assert.Equal(t, fields["msg"], "test")
assert.Equal(t, fields["level"], "warning")
assert.Equal(t, "test", fields["msg"])
assert.Equal(t, "warning", fields["level"])
})
}
@ -87,7 +113,7 @@ func TestInfolnShouldAddSpacesBetweenStrings(t *testing.T) {
LogAndAssertJSON(t, func(log *Logger) {
log.Infoln("test", "test")
}, func(fields Fields) {
assert.Equal(t, fields["msg"], "test test")
assert.Equal(t, "test test", fields["msg"])
})
}
@ -95,7 +121,7 @@ func TestInfolnShouldAddSpacesBetweenStringAndNonstring(t *testing.T) {
LogAndAssertJSON(t, func(log *Logger) {
log.Infoln("test", 10)
}, func(fields Fields) {
assert.Equal(t, fields["msg"], "test 10")
assert.Equal(t, "test 10", fields["msg"])
})
}
@ -103,7 +129,7 @@ func TestInfolnShouldAddSpacesBetweenTwoNonStrings(t *testing.T) {
LogAndAssertJSON(t, func(log *Logger) {
log.Infoln(10, 10)
}, func(fields Fields) {
assert.Equal(t, fields["msg"], "10 10")
assert.Equal(t, "10 10", fields["msg"])
})
}
@ -111,7 +137,7 @@ func TestInfoShouldAddSpacesBetweenTwoNonStrings(t *testing.T) {
LogAndAssertJSON(t, func(log *Logger) {
log.Infoln(10, 10)
}, func(fields Fields) {
assert.Equal(t, fields["msg"], "10 10")
assert.Equal(t, "10 10", fields["msg"])
})
}
@ -119,7 +145,7 @@ func TestInfoShouldNotAddSpacesBetweenStringAndNonstring(t *testing.T) {
LogAndAssertJSON(t, func(log *Logger) {
log.Info("test", 10)
}, func(fields Fields) {
assert.Equal(t, fields["msg"], "test10")
assert.Equal(t, "test10", fields["msg"])
})
}
@ -127,7 +153,7 @@ func TestInfoShouldNotAddSpacesBetweenStrings(t *testing.T) {
LogAndAssertJSON(t, func(log *Logger) {
log.Info("test", "test")
}, func(fields Fields) {
assert.Equal(t, fields["msg"], "testtest")
assert.Equal(t, "testtest", fields["msg"])
})
}
@ -165,7 +191,7 @@ func TestUserSuppliedFieldDoesNotOverwriteDefaults(t *testing.T) {
LogAndAssertJSON(t, func(log *Logger) {
log.WithField("msg", "hello").Info("test")
}, func(fields Fields) {
assert.Equal(t, fields["msg"], "test")
assert.Equal(t, "test", fields["msg"])
})
}
@ -173,8 +199,8 @@ func TestUserSuppliedMsgFieldHasPrefix(t *testing.T) {
LogAndAssertJSON(t, func(log *Logger) {
log.WithField("msg", "hello").Info("test")
}, func(fields Fields) {
assert.Equal(t, fields["msg"], "test")
assert.Equal(t, fields["fields.msg"], "hello")
assert.Equal(t, "test", fields["msg"])
assert.Equal(t, "hello", fields["fields.msg"])
})
}
@ -182,7 +208,7 @@ func TestUserSuppliedTimeFieldHasPrefix(t *testing.T) {
LogAndAssertJSON(t, func(log *Logger) {
log.WithField("time", "hello").Info("test")
}, func(fields Fields) {
assert.Equal(t, fields["fields.time"], "hello")
assert.Equal(t, "hello", fields["fields.time"])
})
}
@ -190,8 +216,8 @@ func TestUserSuppliedLevelFieldHasPrefix(t *testing.T) {
LogAndAssertJSON(t, func(log *Logger) {
log.WithField("level", 1).Info("test")
}, func(fields Fields) {
assert.Equal(t, fields["level"], "info")
assert.Equal(t, fields["fields.level"], 1.0) // JSON has floats only
assert.Equal(t, "info", fields["level"])
assert.Equal(t, 1.0, fields["fields.level"]) // JSON has floats only
})
}
@ -209,6 +235,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(time.RFC3339))
})
}
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(time.RFC3339))
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(time.RFC3339))
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) {
var buffer bytes.Buffer
@ -235,13 +320,117 @@ func TestDoubleLoggingDoesntPrefixPreviousFields(t *testing.T) {
err = json.Unmarshal(buffer.Bytes(), &fields)
assert.NoError(t, err, "should have decoded second message")
assert.Equal(t, len(fields), 4, "should only have msg/time/level/context fields")
assert.Equal(t, fields["msg"], "omg it is!")
assert.Equal(t, fields["context"], "eating raw fish")
assert.Equal(t, "omg it is!", fields["msg"])
assert.Equal(t, "eating raw fish", fields["context"])
assert.Nil(t, fields["fields.msg"], "should not have prefixed previous `msg` entry")
}
func TestNestedLoggingReportsCorrectCaller(t *testing.T) {
var buffer bytes.Buffer
var fields Fields
logger := New()
logger.Out = &buffer
logger.Formatter = new(JSONFormatter)
logger.ReportCaller = true
llog := logger.WithField("context", "eating raw fish")
llog.Info("looks delicious")
err := json.Unmarshal(buffer.Bytes(), &fields)
require.NoError(t, err, "should have decoded first message")
assert.Equal(t, 6, len(fields), "should have msg/time/level/func/context fields")
assert.Equal(t, "looks delicious", fields["msg"])
assert.Equal(t, "eating raw fish", fields["context"])
assert.Equal(t,
"github.com/sirupsen/logrus_test.TestNestedLoggingReportsCorrectCaller", fields["func"])
cwd, err := os.Getwd()
require.NoError(t, err)
assert.Equal(t, filepath.ToSlash(cwd+"/logrus_test.go:340"), filepath.ToSlash(fields["file"].(string)))
buffer.Reset()
logger.WithFields(Fields{
"Clyde": "Stubblefield",
}).WithFields(Fields{
"Jab'o": "Starks",
}).WithFields(Fields{
"uri": "https://www.youtube.com/watch?v=V5DTznu-9v0",
}).WithFields(Fields{
"func": "y drummer",
}).WithFields(Fields{
"James": "Brown",
}).Print("The hardest workin' man in show business")
err = json.Unmarshal(buffer.Bytes(), &fields)
assert.NoError(t, err, "should have decoded second message")
assert.Equal(t, 11, len(fields), "should have all builtin fields plus foo,bar,baz,...")
assert.Equal(t, "Stubblefield", fields["Clyde"])
assert.Equal(t, "Starks", fields["Jab'o"])
assert.Equal(t, "https://www.youtube.com/watch?v=V5DTznu-9v0", fields["uri"])
assert.Equal(t, "y drummer", fields["fields.func"])
assert.Equal(t, "Brown", fields["James"])
assert.Equal(t, "The hardest workin' man in show business", fields["msg"])
assert.Nil(t, fields["fields.msg"], "should not have prefixed previous `msg` entry")
assert.Equal(t,
"github.com/sirupsen/logrus_test.TestNestedLoggingReportsCorrectCaller", fields["func"])
require.NoError(t, err)
assert.Equal(t, filepath.ToSlash(cwd+"/logrus_test.go:365"), filepath.ToSlash(fields["file"].(string)))
logger.ReportCaller = false // return to default value
}
func logLoop(iterations int, reportCaller bool) {
var buffer bytes.Buffer
logger := New()
logger.Out = &buffer
logger.Formatter = new(JSONFormatter)
logger.ReportCaller = reportCaller
for i := 0; i < iterations; i++ {
logger.Infof("round %d of %d", i, iterations)
}
}
// Assertions for upper bounds to reporting overhead
func TestCallerReportingOverhead(t *testing.T) {
iterations := 5000
before := time.Now()
logLoop(iterations, false)
during := time.Now()
logLoop(iterations, true)
after := time.Now()
elapsedNotReporting := during.Sub(before).Nanoseconds()
elapsedReporting := after.Sub(during).Nanoseconds()
maxDelta := 1 * time.Second
assert.WithinDuration(t, during, before, maxDelta,
"%d log calls without caller name lookup takes less than %d second(s) (was %d nanoseconds)",
iterations, maxDelta.Seconds(), elapsedNotReporting)
assert.WithinDuration(t, after, during, maxDelta,
"%d log calls without caller name lookup takes less than %d second(s) (was %d nanoseconds)",
iterations, maxDelta.Seconds(), elapsedReporting)
}
// benchmarks for both with and without caller-function reporting
func BenchmarkWithoutCallerTracing(b *testing.B) {
for i := 0; i < b.N; i++ {
logLoop(1000, false)
}
}
func BenchmarkWithCallerTracing(b *testing.B) {
for i := 0; i < b.N; i++ {
logLoop(1000, true)
}
}
func TestConvertLevelToString(t *testing.T) {
assert.Equal(t, "trace", TraceLevel.String())
assert.Equal(t, "debug", DebugLevel.String())
assert.Equal(t, "info", InfoLevel.String())
assert.Equal(t, "warning", WarnLevel.String())
@ -307,10 +496,31 @@ func TestParseLevel(t *testing.T) {
assert.Nil(t, err)
assert.Equal(t, DebugLevel, l)
l, err = ParseLevel("trace")
assert.Nil(t, err)
assert.Equal(t, TraceLevel, l)
l, err = ParseLevel("TRACE")
assert.Nil(t, err)
assert.Equal(t, TraceLevel, l)
l, err = ParseLevel("invalid")
assert.Equal(t, "not a valid logrus Level: \"invalid\"", err.Error())
}
func TestUnmarshalText(t *testing.T) {
var u Level
for _, level := range AllLevels {
t.Run(level.String(), func(t *testing.T) {
assert.NoError(t, u.UnmarshalText([]byte(level.String())))
assert.Equal(t, level, u)
})
}
t.Run("invalid", func(t *testing.T) {
assert.Error(t, u.UnmarshalText([]byte("invalid")))
})
}
func TestGetSetLevelRace(t *testing.T) {
wg := sync.WaitGroup{}
for i := 0; i < 100; i++ {
@ -343,10 +553,52 @@ func TestLoggingRace(t *testing.T) {
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
func TestLogrusInterface(t *testing.T) {
func TestLogrusInterfaces(t *testing.T) {
var buffer bytes.Buffer
fn := func(l FieldLogger) {
// This verifies FieldLogger and Ext1FieldLogger work as designed.
// Please don't use them. Use Logger and Entry directly.
fn := func(xl Ext1FieldLogger) {
var l FieldLogger = xl
b := l.WithField("key", "value")
b.Debug("Test")
}
@ -384,3 +636,81 @@ func TestEntryWriter(t *testing.T) {
assert.Equal(t, fields["foo"], "bar")
assert.Equal(t, fields["level"], "warning")
}
func TestLogLevelEnabled(t *testing.T) {
log := New()
log.SetLevel(PanicLevel)
assert.Equal(t, true, log.IsLevelEnabled(PanicLevel))
assert.Equal(t, false, log.IsLevelEnabled(FatalLevel))
assert.Equal(t, false, log.IsLevelEnabled(ErrorLevel))
assert.Equal(t, false, log.IsLevelEnabled(WarnLevel))
assert.Equal(t, false, log.IsLevelEnabled(InfoLevel))
assert.Equal(t, false, log.IsLevelEnabled(DebugLevel))
assert.Equal(t, false, log.IsLevelEnabled(TraceLevel))
log.SetLevel(FatalLevel)
assert.Equal(t, true, log.IsLevelEnabled(PanicLevel))
assert.Equal(t, true, log.IsLevelEnabled(FatalLevel))
assert.Equal(t, false, log.IsLevelEnabled(ErrorLevel))
assert.Equal(t, false, log.IsLevelEnabled(WarnLevel))
assert.Equal(t, false, log.IsLevelEnabled(InfoLevel))
assert.Equal(t, false, log.IsLevelEnabled(DebugLevel))
assert.Equal(t, false, log.IsLevelEnabled(TraceLevel))
log.SetLevel(ErrorLevel)
assert.Equal(t, true, log.IsLevelEnabled(PanicLevel))
assert.Equal(t, true, log.IsLevelEnabled(FatalLevel))
assert.Equal(t, true, log.IsLevelEnabled(ErrorLevel))
assert.Equal(t, false, log.IsLevelEnabled(WarnLevel))
assert.Equal(t, false, log.IsLevelEnabled(InfoLevel))
assert.Equal(t, false, log.IsLevelEnabled(DebugLevel))
assert.Equal(t, false, log.IsLevelEnabled(TraceLevel))
log.SetLevel(WarnLevel)
assert.Equal(t, true, log.IsLevelEnabled(PanicLevel))
assert.Equal(t, true, log.IsLevelEnabled(FatalLevel))
assert.Equal(t, true, log.IsLevelEnabled(ErrorLevel))
assert.Equal(t, true, log.IsLevelEnabled(WarnLevel))
assert.Equal(t, false, log.IsLevelEnabled(InfoLevel))
assert.Equal(t, false, log.IsLevelEnabled(DebugLevel))
assert.Equal(t, false, log.IsLevelEnabled(TraceLevel))
log.SetLevel(InfoLevel)
assert.Equal(t, true, log.IsLevelEnabled(PanicLevel))
assert.Equal(t, true, log.IsLevelEnabled(FatalLevel))
assert.Equal(t, true, log.IsLevelEnabled(ErrorLevel))
assert.Equal(t, true, log.IsLevelEnabled(WarnLevel))
assert.Equal(t, true, log.IsLevelEnabled(InfoLevel))
assert.Equal(t, false, log.IsLevelEnabled(DebugLevel))
assert.Equal(t, false, log.IsLevelEnabled(TraceLevel))
log.SetLevel(DebugLevel)
assert.Equal(t, true, log.IsLevelEnabled(PanicLevel))
assert.Equal(t, true, log.IsLevelEnabled(FatalLevel))
assert.Equal(t, true, log.IsLevelEnabled(ErrorLevel))
assert.Equal(t, true, log.IsLevelEnabled(WarnLevel))
assert.Equal(t, true, log.IsLevelEnabled(InfoLevel))
assert.Equal(t, true, log.IsLevelEnabled(DebugLevel))
assert.Equal(t, false, log.IsLevelEnabled(TraceLevel))
log.SetLevel(TraceLevel)
assert.Equal(t, true, log.IsLevelEnabled(PanicLevel))
assert.Equal(t, true, log.IsLevelEnabled(FatalLevel))
assert.Equal(t, true, log.IsLevelEnabled(ErrorLevel))
assert.Equal(t, true, log.IsLevelEnabled(WarnLevel))
assert.Equal(t, true, log.IsLevelEnabled(InfoLevel))
assert.Equal(t, true, log.IsLevelEnabled(DebugLevel))
assert.Equal(t, true, log.IsLevelEnabled(TraceLevel))
}
func TestReportCallerOnTextFormatter(t *testing.T) {
l := New()
l.Formatter.(*TextFormatter).ForceColors = true
l.Formatter.(*TextFormatter).DisableColors = false
l.WithFields(Fields{"func": "func", "file": "file"}).Info("test")
l.Formatter.(*TextFormatter).ForceColors = false
l.Formatter.(*TextFormatter).DisableColors = true
l.WithFields(Fields{"func": "func", "file": "file"}).Info("test")
}

10
terminal_bsd.go
View File

@ -1,10 +0,0 @@
// +build darwin freebsd openbsd netbsd dragonfly
// +build !appengine,!gopherjs
package logrus
import "golang.org/x/sys/unix"
const ioctlReadTermios = unix.TIOCGETA
type Termios unix.Termios

2
terminal_check_appengine.go
View File

@ -1,4 +1,4 @@
// +build appengine gopherjs
// +build appengine
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
}

2
terminal_check_notappengine.go
View File

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

20
terminal_check_windows.go Normal file
View File

@ -0,0 +1,20 @@
// +build !appengine,!js,windows
package logrus
import (
"io"
"os"
"syscall"
)
func checkIfTerminal(w io.Writer) bool {
switch v := w.(type) {
case *os.File:
var mode uint32
err := syscall.GetConsoleMode(syscall.Handle(v.Fd()), &mode)
return err == nil
default:
return false
}
}

14
terminal_linux.go
View File

@ -1,14 +0,0 @@
// Based on ssh/terminal:
// Copyright 2013 The Go Authors. All rights reserved.
// Use of this source code is governed by a BSD-style
// license that can be found in the LICENSE file.
// +build !appengine,!gopherjs
package logrus
import "golang.org/x/sys/unix"
const ioctlReadTermios = unix.TCGETS
type Termios unix.Termios

8
terminal_notwindows.go Normal file
View File

@ -0,0 +1,8 @@
// +build !windows
package logrus
import "io"
func initTerminal(w io.Writer) {
}

18
terminal_windows.go Normal file
View File

@ -0,0 +1,18 @@
// +build !appengine,!js,windows
package logrus
import (
"io"
"os"
"syscall"
sequences "github.com/konsorten/go-windows-terminal-sequences"
)
func initTerminal(w io.Writer) {
switch v := w.(type) {
case *os.File:
sequences.EnableVirtualTerminalProcessing(syscall.Handle(v.Fd()), true)
}
}

114
text_formatter.go
View File

@ -3,6 +3,7 @@ package logrus
import (
"bytes"
"fmt"
"os"
"sort"
"strings"
"sync"
@ -35,6 +36,9 @@ type TextFormatter struct {
// Force disabling colors.
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
// system that already adds timestamps.
DisableTimestamp bool
@ -51,6 +55,9 @@ type TextFormatter struct {
// be desired.
DisableSorting bool
// The keys sorting function, when uninitialized it uses sort.Strings.
SortingFunc func([]string)
// Disables the truncation of the level text to 4 characters.
DisableLevelTruncation bool
@ -69,26 +76,74 @@ type TextFormatter struct {
// FieldKeyMsg: "@message"}}
FieldMap FieldMap
sync.Once
terminalInitOnce sync.Once
}
func (f *TextFormatter) init(entry *Entry) {
if entry.Logger != nil {
f.isTerminal = checkIfTerminal(entry.Logger.Out)
if f.isTerminal {
initTerminal(entry.Logger.Out)
}
}
}
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
func (f *TextFormatter) Format(entry *Entry) ([]byte, error) {
prefixFieldClashes(entry.Data, f.FieldMap)
prefixFieldClashes(entry.Data, f.FieldMap, entry.HasCaller())
keys := make([]string, 0, len(entry.Data))
for k := range entry.Data {
keys = append(keys, k)
}
fixedKeys := make([]string, 0, 4+len(entry.Data))
if !f.DisableTimestamp {
fixedKeys = append(fixedKeys, f.FieldMap.resolve(FieldKeyTime))
}
fixedKeys = append(fixedKeys, f.FieldMap.resolve(FieldKeyLevel))
if entry.Message != "" {
fixedKeys = append(fixedKeys, f.FieldMap.resolve(FieldKeyMsg))
}
if entry.err != "" {
fixedKeys = append(fixedKeys, f.FieldMap.resolve(FieldKeyLogrusError))
}
if entry.HasCaller() {
fixedKeys = append(fixedKeys,
f.FieldMap.resolve(FieldKeyFunc), f.FieldMap.resolve(FieldKeyFile))
}
if !f.DisableSorting {
sort.Strings(keys)
if f.SortingFunc == nil {
sort.Strings(keys)
fixedKeys = append(fixedKeys, keys...)
} else {
if !f.isColored() {
fixedKeys = append(fixedKeys, keys...)
f.SortingFunc(fixedKeys)
} else {
f.SortingFunc(keys)
}
}
} else {
fixedKeys = append(fixedKeys, keys...)
}
var b *bytes.Buffer
@ -98,26 +153,34 @@ func (f *TextFormatter) Format(entry *Entry) ([]byte, error) {
b = &bytes.Buffer{}
}
f.Do(func() { f.init(entry) })
isColored := (f.ForceColors || f.isTerminal) && !f.DisableColors
f.terminalInitOnce.Do(func() { f.init(entry) })
timestampFormat := f.TimestampFormat
if timestampFormat == "" {
timestampFormat = defaultTimestampFormat
}
if isColored {
if f.isColored() {
f.printColored(b, entry, keys, timestampFormat)
} else {
if !f.DisableTimestamp {
f.appendKeyValue(b, f.FieldMap.resolve(FieldKeyTime), entry.Time.Format(timestampFormat))
}
f.appendKeyValue(b, f.FieldMap.resolve(FieldKeyLevel), entry.Level.String())
if entry.Message != "" {
f.appendKeyValue(b, f.FieldMap.resolve(FieldKeyMsg), entry.Message)
}
for _, key := range keys {
f.appendKeyValue(b, key, entry.Data[key])
for _, key := range fixedKeys {
var value interface{}
switch {
case key == f.FieldMap.resolve(FieldKeyTime):
value = entry.Time.Format(timestampFormat)
case key == f.FieldMap.resolve(FieldKeyLevel):
value = entry.Level.String()
case key == f.FieldMap.resolve(FieldKeyMsg):
value = entry.Message
case key == f.FieldMap.resolve(FieldKeyLogrusError):
value = entry.err
case key == f.FieldMap.resolve(FieldKeyFunc) && entry.HasCaller():
value = entry.Caller.Function
case key == f.FieldMap.resolve(FieldKeyFile) && entry.HasCaller():
value = fmt.Sprintf("%s:%d", entry.Caller.File, entry.Caller.Line)
default:
value = entry.Data[key]
}
f.appendKeyValue(b, key, value)
}
}
@ -128,7 +191,7 @@ func (f *TextFormatter) Format(entry *Entry) ([]byte, error) {
func (f *TextFormatter) printColored(b *bytes.Buffer, entry *Entry, keys []string, timestampFormat string) {
var levelColor int
switch entry.Level {
case DebugLevel:
case DebugLevel, TraceLevel:
levelColor = gray
case WarnLevel:
levelColor = yellow
@ -143,12 +206,23 @@ func (f *TextFormatter) printColored(b *bytes.Buffer, entry *Entry, keys []strin
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")
caller := ""
if entry.HasCaller() {
caller = fmt.Sprintf("%s:%d %s()",
entry.Caller.File, entry.Caller.Line, entry.Caller.Function)
}
if f.DisableTimestamp {
fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m %-44s ", levelColor, levelText, entry.Message)
fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m%s %-44s ", levelColor, levelText, caller, entry.Message)
} else if !f.FullTimestamp {
fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%04d] %-44s ", levelColor, levelText, int(entry.Time.Sub(baseTimestamp)/time.Second), entry.Message)
fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%04d]%s %-44s ", levelColor, levelText, int(entry.Time.Sub(baseTimestamp)/time.Second), caller, entry.Message)
} else {
fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%s] %-44s ", levelColor, levelText, entry.Time.Format(timestampFormat), entry.Message)
fmt.Fprintf(b, "\x1b[%dm%s\x1b[0m[%s]%s %-44s ", levelColor, levelText, entry.Time.Format(timestampFormat), caller, entry.Message)
}
for _, k := range keys {
v := entry.Data[k]

264
text_formatter_test.go
View File

@ -4,11 +4,14 @@ import (
"bytes"
"errors"
"fmt"
"os"
"sort"
"strings"
"testing"
"time"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
)
func TestFormatting(t *testing.T) {
@ -177,6 +180,29 @@ 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,
@ -216,5 +242,239 @@ func TestTextFormatterFieldMap(t *testing.T) {
"Formatted output doesn't respect FieldMap")
}
// TODO add tests for sorting etc., this requires a parser for the text
// formatter output.
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)
})
}
}
func TestCustomSorting(t *testing.T) {
formatter := &TextFormatter{
DisableColors: true,
SortingFunc: func(keys []string) {
sort.Slice(keys, func(i, j int) bool {
if keys[j] == "prefix" {
return false
}
if keys[i] == "prefix" {
return true
}
return strings.Compare(keys[i], keys[j]) == -1
})
},
}
entry := &Entry{
Message: "Testing custom sort function",
Time: time.Now(),
Level: InfoLevel,
Data: Fields{
"test": "testvalue",
"prefix": "the application prefix",
"blablabla": "blablabla",
},
}
b, err := formatter.Format(entry)
require.NoError(t, err)
require.True(t, strings.HasPrefix(string(b), "prefix="), "format output is %q", string(b))
}

2
writer.go
View File

@ -24,6 +24,8 @@ func (entry *Entry) WriterLevel(level Level) *io.PipeWriter {
var printFunc func(args ...interface{})
switch level {
case TraceLevel:
printFunc = entry.Trace
case DebugLevel:
printFunc = entry.Debug
case InfoLevel: