diff --git a/ecslogs/handler.go b/ecslogs/handler.go index 8fed235..4b79fb0 100644 --- a/ecslogs/handler.go +++ b/ecslogs/handler.go @@ -42,7 +42,10 @@ func (h *Handler) HandleEvent(e *events.Event) { f.buffer.Reset() f.level = "INFO" - f.time = e.Time + // It's not super realistic to expect more precise timestamps on a Unix + // server, and the additional fidelity doesn't help much either vs. + // cluttering up the log line + f.time = e.Time.Round(time.Microsecond) f.message = e.Message f.data.args = e.Args f.info.Source = e.Source @@ -180,14 +183,14 @@ func (st stackTrace) MarshalJSON() ([]byte, error) { pc := uintptr(frame) file, line := events.SourceForPC(pc) i++ - fmt.Fprintf(b, `"%s:%d:%s"`, file, line, funcName(file, pc)) + fmt.Fprintf(b, `"%s:%d:%s"`, file, line, funcName(pc)) } b.WriteByte(']') return b.Bytes(), nil } -func funcName(file string, pc uintptr) string { +func funcName(pc uintptr) string { callers := [1]uintptr{pc} frames := runtime.CallersFrames(callers[:]) f, _ := frames.Next() diff --git a/ecslogs/handler_test.go b/ecslogs/handler_test.go index dce4118..e455f36 100644 --- a/ecslogs/handler_test.go +++ b/ecslogs/handler_test.go @@ -3,7 +3,6 @@ package ecslogs import ( "bytes" "io" - "io/ioutil" "testing" "time" @@ -18,7 +17,7 @@ func TestHandler(t *testing.T) { Message: "Hello Luke!", Source: "github.com/segmentio/events/ecslogs/handler_test.go:19", Args: events.Args{{Name: "name", Value: "Luke"}, {Name: "from", Value: "Han"}, {Name: "error", Value: io.EOF}}, - Time: time.Date(2017, 1, 1, 23, 42, 0, 123000000, time.UTC), + Time: time.Date(2017, 1, 1, 23, 42, 0, 123456789, time.UTC), Debug: true, } @@ -26,15 +25,15 @@ func TestHandler(t *testing.T) { h.HandleEvent(e) } - const ref = `{"level":"ERROR","time":"2017-01-01T23:42:00.123Z","info":{"source":"github.com/segmentio/events/ecslogs/handler_test.go:19","errors":[{"type":"*errors.errorString","error":"EOF"}]},"data":{"name":"Luke","from":"Han"},"message":"Hello Luke!"} -{"level":"ERROR","time":"2017-01-01T23:42:00.123Z","info":{"source":"github.com/segmentio/events/ecslogs/handler_test.go:19","errors":[{"type":"*errors.errorString","error":"EOF"}]},"data":{"name":"Luke","from":"Han"},"message":"Hello Luke!"} -{"level":"ERROR","time":"2017-01-01T23:42:00.123Z","info":{"source":"github.com/segmentio/events/ecslogs/handler_test.go:19","errors":[{"type":"*errors.errorString","error":"EOF"}]},"data":{"name":"Luke","from":"Han"},"message":"Hello Luke!"} + const ref = `{"level":"ERROR","time":"2017-01-01T23:42:00.123457Z","info":{"source":"github.com/segmentio/events/ecslogs/handler_test.go:19","errors":[{"type":"*errors.errorString","error":"EOF"}]},"data":{"name":"Luke","from":"Han"},"message":"Hello Luke!"} +{"level":"ERROR","time":"2017-01-01T23:42:00.123457Z","info":{"source":"github.com/segmentio/events/ecslogs/handler_test.go:19","errors":[{"type":"*errors.errorString","error":"EOF"}]},"data":{"name":"Luke","from":"Han"},"message":"Hello Luke!"} +{"level":"ERROR","time":"2017-01-01T23:42:00.123457Z","info":{"source":"github.com/segmentio/events/ecslogs/handler_test.go:19","errors":[{"type":"*errors.errorString","error":"EOF"}]},"data":{"name":"Luke","from":"Han"},"message":"Hello Luke!"} ` if s := b.String(); s != ref { t.Error("bad event:") - t.Log("expected:", ref) - t.Log("found: ", s) + t.Logf("expected:%q", ref) + t.Logf("found :%q", s) } t.Run("stack", func(t *testing.T) { @@ -43,7 +42,7 @@ func TestHandler(t *testing.T) { b.Reset() h.HandleEvent(e) - if s := b.String(); s != `{"level":"ERROR","time":"2017-01-01T23:42:00.123Z","info":{"source":"github.com/segmentio/events/ecslogs/handler_test.go:19","errors":[{"type":"*errors.errorString","error":"EOF","stack":["github.com/segmentio/events/ecslogs/handler_test.go:41:ecslogs.TestHandler.func1","testing/testing.go:746:testing.tRunner","runtime/asm_amd64.s:2337:runtime.goexit"]}]},"data":{"name":"Luke","from":"Han"},"message":"Hello Luke!"} + if s := b.String(); s != `{"level":"ERROR","time":"2017-01-01T23:42:00.123457Z","info":{"source":"github.com/segmentio/events/ecslogs/handler_test.go:19","errors":[{"type":"*errors.errorString","error":"EOF","stack":["github.com/segmentio/events/ecslogs/handler_test.go:41:ecslogs.TestHandler.func1","testing/testing.go:746:testing.tRunner","runtime/asm_amd64.s:2337:runtime.goexit"]}]},"data":{"name":"Luke","from":"Han"},"message":"Hello Luke!"} ` { // This test is sensitive, it may break if the Go version changes or // if this file is edited (because the number of lines may not be @@ -55,12 +54,12 @@ func TestHandler(t *testing.T) { } func BenchmarkHandler(b *testing.B) { - h := NewHandler(ioutil.Discard) + h := NewHandler(io.Discard) e := &events.Event{ Message: "Hello Luke!", Source: "github.com/segmentio/events/ecslogs/handler_test.go:19", Args: events.Args{{Name: "name", Value: "Luke"}, {Name: "from", Value: "Han"}}, - Time: time.Date(2017, 1, 1, 23, 42, 0, 123000000, time.UTC), + Time: time.Date(2017, 1, 1, 23, 42, 0, 123456789, time.UTC), Debug: true, }