Skip to content

Commit

Permalink
ecslogs: round the timestamp
Browse files Browse the repository at this point in the history 
The last three digits of precision don't add very much value
timing-wise, and clutter up the log line.
  • Loading branch information
@kevinburkesegment
kevinburkesegment committed Sep 18, 2024
1 parent 9cd08ff commit 75cb1a9
Show file tree
Hide file tree
Showing 2 changed files with 15 additions and 13 deletions.
9 changes: 6 additions & 3 deletions ecslogs/handler.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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()
Expand Down
19 changes: 9 additions & 10 deletions ecslogs/handler_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,6 @@ package ecslogs
import (
"bytes"
"io"
"io/ioutil"
"testing"
"time"

Expand All @@ -18,23 +17,23 @@ 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,
}

for i := 0; i != 3; i++ {
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) {
Expand All @@ -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
Expand All @@ -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,
}

Expand Down

0 comments on commit 75cb1a9

Please sign in to comment.