diff --git a/CHANGELOG.md b/CHANGELOG.md index 4bea3b8..f5c8c02 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,6 +1,7 @@ # 1.0.4 -* feature: Add optional logging of caller method +* Add optional logging of caller method + # 1.0.3 * Replace example files with testable examples diff --git a/README.md b/README.md index 6e99ad4..0ec45b8 100644 --- a/README.md +++ b/README.md @@ -66,6 +66,8 @@ To ensure this behaviour even if a TTY is attached, set your formatter as follow }) ``` +#### Logging Method Name + If you wish to add the calling method as a field, instruct the logger via: ```go log.SetReportCaller(true) @@ -73,14 +75,14 @@ log.SetReportCaller(true) This adds the caller as 'method' like so: ```json -{"animal":"penguin","level":"fatal","method":"arcticcreatures.migrate","msg":"a penguin swims by", +{"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=arcticcreatures.migrate msg="a penguin swims by" animal=penguin +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 of Go, but is +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: ``` diff --git a/entry.go b/entry.go index 6a8deb7..8ceab63 100644 --- a/entry.go +++ b/entry.go @@ -13,7 +13,7 @@ import ( var bufferPool *sync.Pool // qualified package name, cached at first use -var logrusPackage string +var LogrusPackage string // Positions in the call stack when tracing to report the calling method var minimumCallerDepth int @@ -126,8 +126,8 @@ func getCaller() (method string) { depth := runtime.Callers(minimumCallerDepth, pcs) // cache this package's fully-qualified name - if logrusPackage == "" { - logrusPackage = getPackageName(runtime.FuncForPC(pcs[0]).Name()) + if LogrusPackage == "" { + LogrusPackage = getPackageName(runtime.FuncForPC(pcs[0]).Name()) // now that we have the cache, we can skip a minimum count of known-logrus functions minimumCallerDepth = knownLogrusFrames @@ -138,7 +138,7 @@ func getCaller() (method string) { pkg := getPackageName(fullFuncName) // If the caller isn't part of this package, we're done - if pkg != logrusPackage { + if pkg != LogrusPackage { return fullFuncName } } diff --git a/formatter.go b/formatter.go index c430532..ba7b509 100644 --- a/formatter.go +++ b/formatter.go @@ -1,15 +1,9 @@ package logrus -import ( - "time" -) +import "time" -<<<<<<< HEAD -// DefaultTimestampFormat is YYYY-mm-DDTHH:MM:SS-TZ -const DefaultTimestampFormat = time.RFC3339 -======= +// defaultTimestampFormat is YYYY-mm-DDTHH:MM:SS-TZ const defaultTimestampFormat = time.RFC3339 ->>>>>>> 89742aefa4b206dcf400792f3bd35b542998eb3b // The Formatter interface is used to implement a custom Formatter. It takes an // `Entry`. It exposes all the fields, including the default ones: diff --git a/json_formatter.go b/json_formatter.go index 02e0a20..c9b0935 100644 --- a/json_formatter.go +++ b/json_formatter.go @@ -40,12 +40,10 @@ type JSONFormatter struct { // FieldMap: FieldMap{ // FieldKeyTime: "@timestamp", // FieldKeyLevel: "@level", -<<<<<<< HEAD // FieldKeyMsg: "@message", // FieldKeyFunc: "@caller", -======= - // FieldKeyMsg: "@message", ->>>>>>> 89742aefa4b206dcf400792f3bd35b542998eb3b + // FieldKeyMsg: "@message", + // FieldKeyFunc: "@caller", // }, // } FieldMap FieldMap diff --git a/logrus_test.go b/logrus_test.go index e724cc8..3fc68c9 100644 --- a/logrus_test.go +++ b/logrus_test.go @@ -59,7 +59,9 @@ func LogAndAssertText(t *testing.T, log func(*Logger), assertions func(fields ma // TestReportCaller verifies that when ReportCaller is set, the 'func' field // is added, and when it is unset it is not set or modified -func TestReportCaller(t *testing.T) { +// 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") @@ -79,6 +81,51 @@ func TestReportCaller(t *testing.T) { }) } +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 + + // override the filter to allow reporting of functions within the logrus package + LogrusPackage = "bogusForTesting" + + entry := logger.WithFields(Fields{ + "foo": "bar", + }) + + entry.Info(message) + + err := json.Unmarshal(buffer.Bytes(), &fields) + assert.Nil(t, err) + + // now clear the override so as not to mess with other usage + LogrusPackage = "" + return fields +} + +// TestReportCallerHelperDirect - verify reference when logging from a regular function +func TestReportCallerHelperDirect(t *testing.T) { + fields := logSomething(t, "direct") + + assert.Equal(t, "direct", fields["msg"]) + assert.Equal(t, "info", fields["level"]) + assert.Regexp(t, "github.com/.*/logrus.logSomething", fields["func"]) +} + +// TestReportCallerHelperDirect - verify reference when logging from a function called via pointer +func TestReportCallerHelperViaPointer(t *testing.T) { + fptr := logSomething + fields := fptr(t, "via pointer") + + assert.Equal(t, "via pointer", fields["msg"]) + assert.Equal(t, "info", fields["level"]) + assert.Regexp(t, "github.com/.*/logrus.logSomething", fields["func"]) +} + func TestPrint(t *testing.T) { LogAndAssertJSON(t, func(log *Logger) { log.Print("test") diff --git a/text_formatter.go b/text_formatter.go index cc22765..2537bf2 100644 --- a/text_formatter.go +++ b/text_formatter.go @@ -149,7 +149,7 @@ func (f *TextFormatter) printColored(b *bytes.Buffer, entry *Entry, keys []strin } 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]%s %-44s ", levelColor, levelText, int(entry.Time.Sub(baseTimestamp)/time.Second), caller, entry.Message) } else {