2014-11-06 01:39:35 +00:00
|
|
|
package logrus
|
|
|
|
|
|
|
|
import (
|
|
|
|
"bytes"
|
2019-03-11 10:47:03 +00:00
|
|
|
"context"
|
2014-11-06 01:39:35 +00:00
|
|
|
"fmt"
|
|
|
|
"testing"
|
2018-12-14 16:01:34 +00:00
|
|
|
"time"
|
2014-11-06 01:39:35 +00:00
|
|
|
|
|
|
|
"github.com/stretchr/testify/assert"
|
|
|
|
)
|
|
|
|
|
2015-05-13 11:35:03 +00:00
|
|
|
func TestEntryWithError(t *testing.T) {
|
|
|
|
|
2015-05-19 17:50:55 +00:00
|
|
|
assert := assert.New(t)
|
|
|
|
|
|
|
|
defer func() {
|
|
|
|
ErrorKey = "error"
|
|
|
|
}()
|
|
|
|
|
2015-09-08 00:47:46 +00:00
|
|
|
err := fmt.Errorf("kaboom at layer %d", 4711)
|
|
|
|
|
2015-05-19 17:50:55 +00:00
|
|
|
assert.Equal(err, WithError(err).Data["error"])
|
|
|
|
|
2015-05-13 11:35:03 +00:00
|
|
|
logger := New()
|
|
|
|
logger.Out = &bytes.Buffer{}
|
|
|
|
entry := NewEntry(logger)
|
|
|
|
|
2015-05-19 17:50:55 +00:00
|
|
|
assert.Equal(err, entry.WithError(err).Data["error"])
|
2015-05-13 11:35:03 +00:00
|
|
|
|
|
|
|
ErrorKey = "err"
|
2015-05-19 17:50:55 +00:00
|
|
|
|
|
|
|
assert.Equal(err, entry.WithError(err).Data["err"])
|
2015-05-13 11:35:03 +00:00
|
|
|
|
|
|
|
}
|
|
|
|
|
2019-03-11 10:47:03 +00:00
|
|
|
func TestEntryWithContext(t *testing.T) {
|
|
|
|
assert := assert.New(t)
|
|
|
|
ctx := context.WithValue(context.Background(), "foo", "bar")
|
|
|
|
|
|
|
|
assert.Equal(ctx, WithContext(ctx).Context)
|
|
|
|
|
|
|
|
logger := New()
|
|
|
|
logger.Out = &bytes.Buffer{}
|
|
|
|
entry := NewEntry(logger)
|
|
|
|
|
|
|
|
assert.Equal(ctx, entry.WithContext(ctx).Context)
|
|
|
|
}
|
|
|
|
|
2019-11-28 04:03:38 +00:00
|
|
|
func TestEntryWithContextCopiesData(t *testing.T) {
|
|
|
|
assert := assert.New(t)
|
|
|
|
|
2019-12-03 21:50:59 +00:00
|
|
|
// Initialize a parent Entry object with a key/value set in its Data map
|
2019-11-28 04:03:38 +00:00
|
|
|
logger := New()
|
|
|
|
logger.Out = &bytes.Buffer{}
|
|
|
|
parentEntry := NewEntry(logger).WithField("parentKey", "parentValue")
|
2019-12-03 21:50:59 +00:00
|
|
|
|
|
|
|
// Create two children Entry objects from the parent in different contexts
|
|
|
|
ctx1 := context.WithValue(context.Background(), "foo", "bar")
|
2019-11-28 04:03:38 +00:00
|
|
|
childEntry1 := parentEntry.WithContext(ctx1)
|
|
|
|
assert.Equal(ctx1, childEntry1.Context)
|
2019-12-03 21:50:59 +00:00
|
|
|
|
|
|
|
ctx2 := context.WithValue(context.Background(), "bar", "baz")
|
2019-11-28 04:03:38 +00:00
|
|
|
childEntry2 := parentEntry.WithContext(ctx2)
|
|
|
|
assert.Equal(ctx2, childEntry2.Context)
|
|
|
|
assert.NotEqual(ctx1, ctx2)
|
2019-12-03 21:50:59 +00:00
|
|
|
|
|
|
|
// Ensure that data set in the parent Entry are preserved to both children
|
2019-11-28 04:03:38 +00:00
|
|
|
assert.Equal("parentValue", childEntry1.Data["parentKey"])
|
|
|
|
assert.Equal("parentValue", childEntry2.Data["parentKey"])
|
|
|
|
|
2019-12-03 21:50:59 +00:00
|
|
|
// Modify data stored in the child entry
|
|
|
|
childEntry1.Data["childKey"] = "childValue"
|
2019-11-28 04:03:38 +00:00
|
|
|
|
2019-12-03 21:50:59 +00:00
|
|
|
// Verify that data is successfully stored in the child it was set on
|
|
|
|
val, exists := childEntry1.Data["childKey"]
|
2019-11-28 04:03:38 +00:00
|
|
|
assert.True(exists)
|
2019-12-03 21:50:59 +00:00
|
|
|
assert.Equal("childValue", val)
|
|
|
|
|
|
|
|
// Verify that the data change to child 1 has not affected its sibling
|
|
|
|
val, exists = childEntry2.Data["childKey"]
|
|
|
|
assert.False(exists)
|
|
|
|
assert.Empty(val)
|
|
|
|
|
|
|
|
// Verify that the data change to child 1 has not affected its parent
|
|
|
|
val, exists = parentEntry.Data["childKey"]
|
|
|
|
assert.False(exists)
|
|
|
|
assert.Empty(val)
|
|
|
|
}
|
|
|
|
|
|
|
|
func TestEntryWithTimeCopiesData(t *testing.T) {
|
|
|
|
assert := assert.New(t)
|
|
|
|
|
|
|
|
// Initialize a parent Entry object with a key/value set in its Data map
|
|
|
|
logger := New()
|
|
|
|
logger.Out = &bytes.Buffer{}
|
|
|
|
parentEntry := NewEntry(logger).WithField("parentKey", "parentValue")
|
|
|
|
|
|
|
|
// Create two children Entry objects from the parent with two different times
|
|
|
|
childEntry1 := parentEntry.WithTime(time.Now().AddDate(0, 0, 1))
|
|
|
|
childEntry2 := parentEntry.WithTime(time.Now().AddDate(0, 0, 2))
|
|
|
|
|
|
|
|
// Ensure that data set in the parent Entry are preserved to both children
|
|
|
|
assert.Equal("parentValue", childEntry1.Data["parentKey"])
|
|
|
|
assert.Equal("parentValue", childEntry2.Data["parentKey"])
|
|
|
|
|
|
|
|
// Modify data stored in the child entry
|
|
|
|
childEntry1.Data["childKey"] = "childValue"
|
|
|
|
|
|
|
|
// Verify that data is successfully stored in the child it was set on
|
|
|
|
val, exists := childEntry1.Data["childKey"]
|
|
|
|
assert.True(exists)
|
|
|
|
assert.Equal("childValue", val)
|
|
|
|
|
|
|
|
// Verify that the data change to child 1 has not affected its sibling
|
|
|
|
val, exists = childEntry2.Data["childKey"]
|
|
|
|
assert.False(exists)
|
|
|
|
assert.Empty(val)
|
2019-11-28 04:03:38 +00:00
|
|
|
|
2019-12-03 21:50:59 +00:00
|
|
|
// Verify that the data change to child 1 has not affected its parent
|
|
|
|
val, exists = parentEntry.Data["childKey"]
|
2019-11-28 04:03:38 +00:00
|
|
|
assert.False(exists)
|
|
|
|
assert.Empty(val)
|
|
|
|
}
|
|
|
|
|
2014-11-06 01:39:35 +00:00
|
|
|
func TestEntryPanicln(t *testing.T) {
|
|
|
|
errBoom := fmt.Errorf("boom time")
|
|
|
|
|
|
|
|
defer func() {
|
|
|
|
p := recover()
|
|
|
|
assert.NotNil(t, p)
|
|
|
|
|
|
|
|
switch pVal := p.(type) {
|
|
|
|
case *Entry:
|
|
|
|
assert.Equal(t, "kaboom", pVal.Message)
|
|
|
|
assert.Equal(t, errBoom, pVal.Data["err"])
|
|
|
|
default:
|
2014-11-06 13:42:52 +00:00
|
|
|
t.Fatalf("want type *Entry, got %T: %#v", pVal, pVal)
|
2014-11-06 01:39:35 +00:00
|
|
|
}
|
|
|
|
}()
|
|
|
|
|
|
|
|
logger := New()
|
|
|
|
logger.Out = &bytes.Buffer{}
|
|
|
|
entry := NewEntry(logger)
|
|
|
|
entry.WithField("err", errBoom).Panicln("kaboom")
|
|
|
|
}
|
|
|
|
|
|
|
|
func TestEntryPanicf(t *testing.T) {
|
|
|
|
errBoom := fmt.Errorf("boom again")
|
|
|
|
|
|
|
|
defer func() {
|
|
|
|
p := recover()
|
|
|
|
assert.NotNil(t, p)
|
|
|
|
|
|
|
|
switch pVal := p.(type) {
|
|
|
|
case *Entry:
|
|
|
|
assert.Equal(t, "kaboom true", pVal.Message)
|
|
|
|
assert.Equal(t, errBoom, pVal.Data["err"])
|
|
|
|
default:
|
2014-11-06 13:42:52 +00:00
|
|
|
t.Fatalf("want type *Entry, got %T: %#v", pVal, pVal)
|
2014-11-06 01:39:35 +00:00
|
|
|
}
|
|
|
|
}()
|
|
|
|
|
|
|
|
logger := New()
|
|
|
|
logger.Out = &bytes.Buffer{}
|
|
|
|
entry := NewEntry(logger)
|
|
|
|
entry.WithField("err", errBoom).Panicf("kaboom %v", true)
|
|
|
|
}
|
2018-01-22 15:35:26 +00:00
|
|
|
|
2020-12-15 23:25:34 +00:00
|
|
|
func TestEntryPanic(t *testing.T) {
|
|
|
|
errBoom := fmt.Errorf("boom again")
|
|
|
|
|
|
|
|
defer func() {
|
|
|
|
p := recover()
|
|
|
|
assert.NotNil(t, p)
|
|
|
|
|
|
|
|
switch pVal := p.(type) {
|
|
|
|
case *Entry:
|
|
|
|
assert.Equal(t, "kaboom", pVal.Message)
|
|
|
|
assert.Equal(t, errBoom, pVal.Data["err"])
|
|
|
|
default:
|
|
|
|
t.Fatalf("want type *Entry, got %T: %#v", pVal, pVal)
|
|
|
|
}
|
|
|
|
}()
|
|
|
|
|
|
|
|
logger := New()
|
|
|
|
logger.Out = &bytes.Buffer{}
|
|
|
|
entry := NewEntry(logger)
|
|
|
|
entry.WithField("err", errBoom).Panic("kaboom")
|
|
|
|
}
|
|
|
|
|
2018-01-22 15:35:26 +00:00
|
|
|
const (
|
|
|
|
badMessage = "this is going to panic"
|
|
|
|
panicMessage = "this is broken"
|
|
|
|
)
|
|
|
|
|
|
|
|
type panickyHook struct{}
|
|
|
|
|
|
|
|
func (p *panickyHook) Levels() []Level {
|
|
|
|
return []Level{InfoLevel}
|
|
|
|
}
|
|
|
|
|
|
|
|
func (p *panickyHook) Fire(entry *Entry) error {
|
|
|
|
if entry.Message == badMessage {
|
|
|
|
panic(panicMessage)
|
|
|
|
}
|
|
|
|
|
|
|
|
return nil
|
|
|
|
}
|
|
|
|
|
|
|
|
func TestEntryHooksPanic(t *testing.T) {
|
|
|
|
logger := New()
|
|
|
|
logger.Out = &bytes.Buffer{}
|
|
|
|
logger.Level = InfoLevel
|
|
|
|
logger.Hooks.Add(&panickyHook{})
|
|
|
|
|
|
|
|
defer func() {
|
|
|
|
p := recover()
|
|
|
|
assert.NotNil(t, p)
|
|
|
|
assert.Equal(t, panicMessage, p)
|
|
|
|
|
|
|
|
entry := NewEntry(logger)
|
|
|
|
entry.Info("another message")
|
|
|
|
}()
|
|
|
|
|
|
|
|
entry := NewEntry(logger)
|
|
|
|
entry.Info(badMessage)
|
|
|
|
}
|
2018-12-05 18:14:19 +00:00
|
|
|
|
|
|
|
func TestEntryWithIncorrectField(t *testing.T) {
|
|
|
|
assert := assert.New(t)
|
|
|
|
|
|
|
|
fn := func() {}
|
|
|
|
|
2021-02-16 09:29:37 +00:00
|
|
|
e := Entry{Logger: New()}
|
2018-12-05 18:14:19 +00:00
|
|
|
eWithFunc := e.WithFields(Fields{"func": fn})
|
|
|
|
eWithFuncPtr := e.WithFields(Fields{"funcPtr": &fn})
|
|
|
|
|
|
|
|
assert.Equal(eWithFunc.err, `can not add field "func"`)
|
|
|
|
assert.Equal(eWithFuncPtr.err, `can not add field "funcPtr"`)
|
2018-12-14 16:01:34 +00:00
|
|
|
|
|
|
|
eWithFunc = eWithFunc.WithField("not_a_func", "it is a string")
|
|
|
|
eWithFuncPtr = eWithFuncPtr.WithField("not_a_func", "it is a string")
|
|
|
|
|
|
|
|
assert.Equal(eWithFunc.err, `can not add field "func"`)
|
|
|
|
assert.Equal(eWithFuncPtr.err, `can not add field "funcPtr"`)
|
|
|
|
|
|
|
|
eWithFunc = eWithFunc.WithTime(time.Now())
|
|
|
|
eWithFuncPtr = eWithFuncPtr.WithTime(time.Now())
|
|
|
|
|
|
|
|
assert.Equal(eWithFunc.err, `can not add field "func"`)
|
|
|
|
assert.Equal(eWithFuncPtr.err, `can not add field "funcPtr"`)
|
2018-12-05 18:14:19 +00:00
|
|
|
}
|
2019-02-06 19:51:07 +00:00
|
|
|
|
|
|
|
func TestEntryLogfLevel(t *testing.T) {
|
|
|
|
logger := New()
|
|
|
|
buffer := &bytes.Buffer{}
|
|
|
|
logger.Out = buffer
|
|
|
|
logger.SetLevel(InfoLevel)
|
|
|
|
entry := NewEntry(logger)
|
|
|
|
|
|
|
|
entry.Logf(DebugLevel, "%s", "debug")
|
2019-10-23 17:43:07 +00:00
|
|
|
assert.NotContains(t, buffer.String(), "debug")
|
2019-02-06 19:51:07 +00:00
|
|
|
|
|
|
|
entry.Logf(WarnLevel, "%s", "warn")
|
2019-10-23 17:43:07 +00:00
|
|
|
assert.Contains(t, buffer.String(), "warn")
|
|
|
|
}
|
2020-03-19 09:29:19 +00:00
|
|
|
|
|
|
|
func TestEntryReportCallerRace(t *testing.T) {
|
|
|
|
logger := New()
|
|
|
|
entry := NewEntry(logger)
|
2021-06-16 09:54:39 +00:00
|
|
|
|
|
|
|
// logging before SetReportCaller has the highest chance of causing a race condition
|
|
|
|
// to be detected, but doing it twice just to increase the likelyhood of detecting the race
|
|
|
|
go func() {
|
|
|
|
entry.Info("should not race")
|
|
|
|
}()
|
2020-03-19 09:29:19 +00:00
|
|
|
go func() {
|
|
|
|
logger.SetReportCaller(true)
|
|
|
|
}()
|
|
|
|
go func() {
|
|
|
|
entry.Info("should not race")
|
|
|
|
}()
|
|
|
|
}
|
2021-06-16 09:54:39 +00:00
|
|
|
|
|
|
|
func TestEntryFormatterRace(t *testing.T) {
|
|
|
|
logger := New()
|
|
|
|
entry := NewEntry(logger)
|
|
|
|
|
|
|
|
// logging before SetReportCaller has the highest chance of causing a race condition
|
|
|
|
// to be detected, but doing it twice just to increase the likelyhood of detecting the race
|
|
|
|
go func() {
|
|
|
|
entry.Info("should not race")
|
|
|
|
}()
|
|
|
|
go func() {
|
|
|
|
logger.SetFormatter(&TextFormatter{})
|
|
|
|
}()
|
|
|
|
go func() {
|
|
|
|
entry.Info("should not race")
|
|
|
|
}()
|
|
|
|
}
|