diff --git a/gelf_writer.go b/gelf_writer.go index 7a56d8d..30ffb61 100644 --- a/gelf_writer.go +++ b/gelf_writer.go @@ -266,9 +266,6 @@ func (w *Writer) Warning(m string) (err error) // the server specified in New(). func (w *Writer) Write(p []byte) (n int, err error) { - // 1 for the function that called us. - file, line := getCallerIgnoringLogMulti(1) - // remove trailing and leading whitespace p = bytes.TrimSpace(p) @@ -291,8 +288,6 @@ func (w *Writer) Write(p []byte) (n int, err error) { TimeUnix: float64(time.Now().UnixNano()/1000000) / 1000., Level: 6, // info Facility: w.Facility, - File: file, - Line: line, Extra: map[string]interface{}{}, } diff --git a/graylog_hook.go b/graylog_hook.go index 8dcda5d..83c2900 100644 --- a/graylog_hook.go +++ b/graylog_hook.go @@ -6,8 +6,6 @@ import ( "errors" "fmt" "os" - "runtime" - "strings" "sync" "time" @@ -95,9 +93,13 @@ func (hook *GraylogHook) Fire(entry *logrus.Entry) error { hook.mu.RLock() // Claim the mutex as a RLock - allowing multiple go routines to log simultaneously defer hook.mu.RUnlock() - // get caller file and line here, it won't be available inside the goroutine - // 1 for the function that called us. - file, line := getCallerIgnoringLogMulti(1) + var file string + var line int + + if entry.Caller != nil { + file = entry.Caller.File + line = entry.Caller.Line + } newData := make(map[string]interface{}) for k, v := range entry.Data { @@ -109,6 +111,7 @@ func (hook *GraylogHook) Fire(entry *logrus.Entry) error { Data: newData, Time: entry.Time, Level: entry.Level, + Caller: entry.Caller, Message: entry.Message, } gEntry := graylogEntry{newEntry, file, line} @@ -182,6 +185,13 @@ func (hook *GraylogHook) sendEntry(entry graylogEntry) { k = fmt.Sprintf("_%s", k) // "[...] every field you send and prefix with a _ (underscore) will be treated as an additional field." extra[k] = v } + + if entry.Caller != nil { + extra["_file"] = entry.Caller.File + extra["_line"] = entry.Caller.Line + extra["_function"] = entry.Caller.Function + } + for k, v := range entry.Data { if !hook.blacklist[k] { extraK := fmt.Sprintf("_%s", k) // "[...] every field you send and prefix with a _ (underscore) will be treated as an additional field." @@ -258,38 +268,3 @@ func (hook *GraylogHook) SetWriter(w *Writer) error { func (hook *GraylogHook) Writer() *Writer { return hook.gelfLogger } - -// getCaller returns the filename and the line info of a function -// further down in the call stack. Passing 0 in as callDepth would -// return info on the function calling getCallerIgnoringLog, 1 the -// parent function, and so on. Any suffixes passed to getCaller are -// path fragments like "/pkg/log/log.go", and functions in the call -// stack from that file are ignored. -func getCaller(callDepth int, suffixesToIgnore ...string) (file string, line int) { - // bump by 1 to ignore the getCaller (this) stackframe - callDepth++ -outer: - for { - var ok bool - _, file, line, ok = runtime.Caller(callDepth) - if !ok { - file = "???" - line = 0 - break - } - - for _, s := range suffixesToIgnore { - if strings.HasSuffix(file, s) { - callDepth++ - continue outer - } - } - break - } - return -} - -func getCallerIgnoringLogMulti(callDepth int) (string, int) { - // the +1 is to ignore this (getCallerIgnoringLogMulti) frame - return getCaller(callDepth+1, "logrus/hooks.go", "logrus/entry.go", "logrus/logger.go", "logrus/exported.go", "asm_amd64.s") -} diff --git a/graylog_hook_test.go b/graylog_hook_test.go index eaed6f4..5665f10 100644 --- a/graylog_hook_test.go +++ b/graylog_hook_test.go @@ -29,6 +29,7 @@ func TestWritingToUDP(t *testing.T) { msgData := "test message\nsecond line" log := logrus.New() + log.SetReportCaller(true) log.Out = ioutil.Discard log.Hooks.Add(hook) log.WithFields(logrus.Fields{"withField": "1", "filterMe": "1"}).Info(msgData) @@ -55,8 +56,8 @@ func TestWritingToUDP(t *testing.T) { t.Errorf("Host should match (exp: testing.local, got: %s)", msg.Host) } - if len(msg.Extra) != 2 { - t.Errorf("wrong number of extra fields (exp: %d, got %d) in %v", 2, len(msg.Extra), msg.Extra) + if len(msg.Extra) != 5 { + t.Errorf("wrong number of extra fields (exp: %d, got %d) in %v", 5, len(msg.Extra), msg.Extra) } fileExpected := "graylog_hook_test.go" @@ -65,12 +66,12 @@ func TestWritingToUDP(t *testing.T) { msg.File) } - lineExpected := 34 // Update this if code is updated above + lineExpected := 35 // Update this if code is updated above if msg.Line != lineExpected { t.Errorf("msg.Line: expected %d, got %d", lineExpected, msg.Line) } - if len(msg.Extra) != 2 { + if len(msg.Extra) != 5 { t.Errorf("wrong number of extra fields (exp: %d, got %d) in %v", 2, len(msg.Extra), msg.Extra) } @@ -251,6 +252,7 @@ func TestStackTracer(t *testing.T) { hook := NewGraylogHook(r.Addr(), map[string]interface{}{}) log := logrus.New() + log.SetReportCaller(true) log.Out = ioutil.Discard log.Hooks.Add(hook) @@ -269,7 +271,7 @@ func TestStackTracer(t *testing.T) { msg.File) } - lineExpected := 257 // Update this if code is updated above + lineExpected := 259 // Update this if code is updated above if msg.Line != lineExpected { t.Errorf("msg.Line: expected %d, got %d", lineExpected, msg.Line) } @@ -331,3 +333,127 @@ func TestLogrusLevelToSylog(t *testing.T) { t.Error("logrusLevelToSylog(PanicLevel) != LOG_ALERT") } } + +func TestReportCallerEnabled(t *testing.T) { + r, err := NewReader("127.0.0.1:0") + if err != nil { + t.Fatalf("NewReader: %s", err) + } + hook := NewGraylogHook(r.Addr(), map[string]interface{}{}) + hook.Host = "testing.local" + msgData := "test message\nsecond line" + + log := logrus.New() + log.SetReportCaller(true) + log.Out = ioutil.Discard + log.Hooks.Add(hook) + log.Info(msgData) + + msg, err := r.ReadMessage() + + if err != nil { + t.Errorf("ReadMessage: %s", err) + } + + fileField, ok := msg.Extra["_file"] + if !ok { + t.Error("_file field not present in extra fields") + } + + fileGot, ok := fileField.(string) + if !ok { + t.Error("_file field is not a string") + } + + fileExpected := "graylog_hook_test.go" + if !strings.HasSuffix(fileGot, fileExpected) { + t.Errorf("msg.Extra[\"_file\"]: expected %s, got %s", fileExpected, fileGot) + } + + lineField, ok := msg.Extra["_line"] + if !ok { + t.Error("_line field not present in extra fields") + } + + lineGot, ok := lineField.(float64) + if !ok { + t.Error("_line dowes not have the correct type") + } + + lineExpected := 350 // Update this if code is updated above + if msg.Line != lineExpected { + t.Errorf("msg.Extra[\"_line\"]: expected %d, got %d", lineExpected, int(lineGot)) + } + + functionField, ok := msg.Extra["_function"] + if !ok { + t.Error("_function field not present in extra fields") + } + + functionGot, ok := functionField.(string) + if !ok { + t.Error("_function field is not a string") + } + + functionExpected := "TestReportCallerEnabled" + if !strings.HasSuffix(functionGot, functionExpected) { + t.Errorf("msg.Extra[\"_function\"]: expected %s, got %s", functionExpected, functionGot) + } + + gelfFileExpected := "graylog_hook_test.go" + if !strings.HasSuffix(msg.File, gelfFileExpected) { + t.Errorf("msg.File: expected %s, got %s", gelfFileExpected, + msg.File) + } + + gelfLineExpected := 259 // Update this if code is updated above + if msg.Line != lineExpected { + t.Errorf("msg.Line: expected %d, got %d", gelfLineExpected, msg.Line) + } +} + +func TestReportCallerDisabled(t *testing.T) { + r, err := NewReader("127.0.0.1:0") + if err != nil { + t.Fatalf("NewReader: %s", err) + } + hook := NewGraylogHook(r.Addr(), map[string]interface{}{}) + hook.Host = "testing.local" + msgData := "test message\nsecond line" + + log := logrus.New() + log.SetReportCaller(false) + log.Out = ioutil.Discard + log.Hooks.Add(hook) + log.Info(msgData) + + msg, err := r.ReadMessage() + + if err != nil { + t.Errorf("ReadMessage: %s", err) + } + + if _, ok := msg.Extra["_file"]; ok { + t.Error("_file field should not present in extra fields") + } + + if _, ok := msg.Extra["_line"]; ok { + t.Error("_line field should not present in extra fields") + } + + if _, ok := msg.Extra["_function"]; ok { + t.Error("_function field should not present in extra fields") + } + + // if reportCaller is disabled (this is the default setting) the File and Line field should have the default values + // corresponding to the types. "" and 0 respectively. + gelfFileExpected := "" + if msg.File != gelfFileExpected { + t.Errorf("msg.File: expected %s, got %s", gelfFileExpected, msg.File) + } + + gelfLineExpected := 0 + if msg.Line != gelfLineExpected { + t.Errorf("msg.Line: expected %d, got %d", gelfLineExpected, msg.Line) + } +}