Merge pull request #13 from fujiwara/add-tests

refactoring

.github/workflows/test.yml

@@ -5,8 +5,9 @@ jobs:
     strategy:
       matrix:
         go:
-          - "1.19"
-          - "1.20"
+          - "1.21"
+          - "1.22"
+          - "1.23"
     name: Build
     runs-on: ubuntu-latest
     steps:
@@ -17,7 +18,7 @@ jobs:
         id: go
 
       - name: Check out code into the Go module directory
-        uses: actions/checkout@v3
+        uses: actions/checkout@v4
 
       - name: Build & Test
         run: |

Makefile

@@ -3,3 +3,6 @@ tracer: *.go *.go cmd/tracer/*
 
 install:
 	go install github.com/fujiwara/tracer/cmd/tracer
+
+test:
+	go test -v ./...

export_test.go

@@ -0,0 +1,6 @@
+package tracer
+
+var (
+	ExtractTaskID      = extractTaskID
+	ExtractClusterName = extractClusterName
+)

go.mod

@@ -1,6 +1,6 @@
 module github.com/fujiwara/tracer
 
-go 1.17
+go 1.21
 
 require (
 	github.com/aws/aws-lambda-go v1.28.0
@@ -9,7 +9,6 @@ require (
 	github.com/aws/aws-sdk-go-v2/service/cloudwatchlogs v1.15.11
 	github.com/aws/aws-sdk-go-v2/service/ecs v1.18.12
 	github.com/aws/aws-sdk-go-v2/service/sns v1.17.10
-	github.com/stretchr/testify v1.6.1
 )
 
 require (
@@ -22,8 +21,6 @@ require (
 	github.com/aws/aws-sdk-go-v2/service/sso v1.11.13 // indirect
 	github.com/aws/aws-sdk-go-v2/service/sts v1.16.10 // indirect
 	github.com/aws/smithy-go v1.12.0 // indirect
-	github.com/davecgh/go-spew v1.1.1 // indirect
 	github.com/jmespath/go-jmespath v0.4.0 // indirect
-	github.com/pmezard/go-difflib v1.0.0 // indirect
 	gopkg.in/yaml.v3 v3.0.0-20210107192922-496545a6307b // indirect
 )

go.sum

@@ -48,7 +48,6 @@ github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+
 github.com/stretchr/testify v1.6.1 h1:hDPOHmpOpP40lSULcqw7IrRb/u7w6RpDC9399XyoNd0=
 github.com/stretchr/testify v1.6.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
 github.com/urfave/cli/v2 v2.2.0/go.mod h1:SE9GqnLQmjVa0iPEY0f1w3ygNIYcIJ0OKPMoW2caLfQ=
-gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM=
 gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
 gopkg.in/yaml.v2 v2.2.2/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI=
 gopkg.in/yaml.v2 v2.2.8 h1:obN1ZagJSUGI0Ek/LBmuj4SNLPfIny3KsKFopxRdj10=

lambda_test.go

@@ -1,9 +1,9 @@
-package tracer
+package tracer_test
 
 import (
 	"testing"
 
-	"github.com/stretchr/testify/require"
+	"github.com/fujiwara/tracer"
 )
 
 func TestExtractClusterName(t *testing.T) {
@@ -23,8 +23,10 @@ func TestExtractClusterName(t *testing.T) {
 
 	for _, c := range cases {
 		t.Run(c.input, func(t *testing.T) {
-			actual := extractClusterName(c.input)
-			require.Equal(t, c.expected, actual)
+			actual := tracer.ExtractClusterName(c.input)
+			if c.expected != actual {
+				t.Errorf("expected: %s, actual: %s", c.expected, actual)
+			}
 		})
 	}
 }
@@ -49,8 +51,10 @@ func TestExtractTaskID(t *testing.T) {
 
 	for _, c := range cases {
 		t.Run(c.input, func(t *testing.T) {
-			actual := extractTaskID(c.cluster, c.input)
-			require.Equal(t, c.expected, actual)
+			actual := tracer.ExtractTaskID(c.cluster, c.input)
+			if c.expected != actual {
+				t.Errorf("expected: %s, actual: %s", c.expected, actual)
+			}
 		})
 	}
 }

tracer.go

@@ -46,52 +46,62 @@ type Tracer struct {
 	option *RunOption
 }
 
-func (t *Tracer) AddEvent(ts *time.Time, source, message string) {
+func (t *Tracer) AddEvent(ts time.Time, source, message string) {
 	t.timeline.Add(newEvent(ts, source, message))
 }
 
+func NewTimeline() *Timeline {
+	return &Timeline{
+		seen: make(map[string]bool),
+	}
+}
+
 type Timeline struct {
-	events []*TimeLineEvent
+	events []*TimelineEvent
 	seen   map[string]bool
 	mu     sync.Mutex
 }
 
-func (tl *Timeline) Add(event *TimeLineEvent) {
+func (tl *Timeline) Add(event *TimelineEvent) {
+	if event.Timestamp.IsZero() { // ignore zero time event
+		return
+	}
 	tl.mu.Lock()
 	defer tl.mu.Unlock()
 	tl.events = append(tl.events, event)
 }
 
-func (tl *Timeline) Print(w io.Writer) {
+func (tl *Timeline) Print(w io.Writer) (int, error) {
 	tl.mu.Lock()
 	defer tl.mu.Unlock()
 
-	tls := make([]*TimeLineEvent, 0, len(tl.events))
-	for _, e := range tl.events {
-		if e.Timestamp == nil {
-			continue
-		}
-		tls = append(tls, e)
-	}
+	tls := make([]*TimelineEvent, 0, len(tl.events))
+	tls = append(tls, tl.events...)
 	sort.SliceStable(tls, func(i, j int) bool {
-		return (*tls[i].Timestamp).Before(*tls[j].Timestamp)
+		return tls[i].Timestamp.Before(tls[j].Timestamp)
 	})
+	n := 0
 	for _, e := range tls {
 		s := e.String()
 		if !tl.seen[s] {
-			fmt.Fprint(w, e.String())
+			l, err := fmt.Fprint(w, e.String())
+			if err != nil {
+				return n, err
+			}
+			n += l
 			tl.seen[s] = true
 		}
 	}
+	return n, nil
 }
 
-type TimeLineEvent struct {
-	Timestamp *time.Time
+type TimelineEvent struct {
+	Timestamp time.Time
 	Source    string
 	Message   string
 }
 
-func (e *TimeLineEvent) String() string {
+func (e *TimelineEvent) String() string {
 	ts := e.Timestamp.In(time.Local)
 	return fmt.Sprintf("%s\t%s\t%s\n", ts.Format(TimeFormat), e.Source, e.Message)
 }
@@ -107,19 +117,17 @@ func New(ctx context.Context) (*Tracer, error) {
 
 func NewWithConfig(config aws.Config) (*Tracer, error) {
 	return &Tracer{
-		ecs:  ecs.NewFromConfig(config),
-		logs: cloudwatchlogs.NewFromConfig(config),
-		sns:  sns.NewFromConfig(config),
-		timeline: &Timeline{
-			seen: make(map[string]bool),
-		},
-		buf: new(bytes.Buffer),
-		w:   os.Stdout,
+		ecs:      ecs.NewFromConfig(config),
+		logs:     cloudwatchlogs.NewFromConfig(config),
+		sns:      sns.NewFromConfig(config),
+		timeline: NewTimeline(),
+		buf:      new(bytes.Buffer),
+		w:        os.Stdout,
 	}, nil
 }
 
-func newEvent(ts *time.Time, src, msg string) *TimeLineEvent {
-	return &TimeLineEvent{
+func newEvent(ts time.Time, src, msg string) *TimelineEvent {
+	return &TimelineEvent{
 		Timestamp: ts,
 		Source:    src,
 		Message:   msg,
@@ -239,18 +247,18 @@ func (t *Tracer) traceTask(ctx context.Context, cluster string, taskID string) (
 		t.fetchServiceEvents(ctx, cluster, taskGroup[1])
 	}
 
-	t.AddEvent(task.CreatedAt, "TASK", "Created")
-	t.AddEvent(task.ConnectivityAt, "TASK", "Connected")
-	t.AddEvent(task.StartedAt, "TASK", "Started")
-	t.AddEvent(task.PullStartedAt, "TASK", "Pull started")
-	t.AddEvent(task.PullStoppedAt, "TASK", "Pull stopped")
-	t.AddEvent(task.StoppedAt, "TASK", "Stopped")
-	t.AddEvent(task.StoppingAt, "TASK", "Stopping")
+	t.AddEvent(aws.ToTime(task.CreatedAt), "TASK", "Created")
+	t.AddEvent(aws.ToTime(task.ConnectivityAt), "TASK", "Connected")
+	t.AddEvent(aws.ToTime(task.StartedAt), "TASK", "Started")
+	t.AddEvent(aws.ToTime(task.PullStartedAt), "TASK", "Pull started")
+	t.AddEvent(aws.ToTime(task.PullStoppedAt), "TASK", "Pull stopped")
+	t.AddEvent(aws.ToTime(task.StoppedAt), "TASK", "Stopped")
+	t.AddEvent(aws.ToTime(task.StoppingAt), "TASK", "Stopping")
 	if task.StoppedReason != nil {
-		t.AddEvent(task.StoppingAt, "TASK", "StoppedReason:"+*task.StoppedReason)
+		t.AddEvent(aws.ToTime(task.StoppingAt), "TASK", "StoppedReason:"+aws.ToString(task.StoppedReason))
 	}
-	t.AddEvent(task.StoppingAt, "TASK", "StoppedCode:"+string(task.StopCode))
-	t.AddEvent(task.ExecutionStoppedAt, "TASK", "Execution stopped")
+	t.AddEvent(aws.ToTime(task.StoppingAt), "TASK", "StoppedCode:"+string(task.StopCode))
+	t.AddEvent(aws.ToTime(task.ExecutionStoppedAt), "TASK", "Execution stopped")
 
 	for _, c := range task.Containers {
 		containerName := *c.Name
@@ -261,10 +269,10 @@ func (t *Tracer) traceTask(ctx context.Context, cluster string, taskID string) (
 		if c.Reason != nil {
 			msg += fmt.Sprintf(" (reason: %s)", *c.Reason)
 		}
-		t.AddEvent(&t.now, "CONTAINER:"+containerName, msg)
+		t.AddEvent(t.now, "CONTAINER:"+containerName, msg)
 	}
 
-	t.AddEvent(&t.now, "TASK", "LastStatus:"+aws.ToString(task.LastStatus))
+	t.AddEvent(t.now, "TASK", "LastStatus:"+aws.ToString(task.LastStatus))
 
 	return &task, nil
 }
@@ -321,9 +329,9 @@ func (t *Tracer) fetchServiceEvents(ctx context.Context, cluster, service string
 		return fmt.Errorf("no services found: %w", err)
 	}
 	for _, e := range res.Services[0].Events {
-		ts := *e.CreatedAt
+		ts := aws.ToTime(e.CreatedAt)
 		if ts.After(t.headBegin) && ts.Before(t.headEnd) || ts.After(t.tailBegin) && ts.Before(t.tailEnd) {
-			t.AddEvent(e.CreatedAt, "SERVICE", *e.Message)
+			t.AddEvent(ts, "SERVICE", aws.ToString(e.Message))
 		}
 	}
 	return nil
@@ -358,7 +366,7 @@ func (t *Tracer) fetchLogs(ctx context.Context, containerName, group, stream str
 		fetched++
 		for _, e := range res.Events {
 			ts := msecToTime(aws.ToInt64(e.Timestamp))
-			t.AddEvent(&ts, "CONTAINER:"+containerName, aws.ToString(e.Message))
+			t.AddEvent(ts, "CONTAINER:"+containerName, aws.ToString(e.Message))
 		}
 		if aws.ToString(nextToken) == aws.ToString(res.NextForwardToken) {
 			break

tracer_test.go

@@ -0,0 +1,85 @@
+package tracer_test
+
+import (
+	"strings"
+	"testing"
+	"time"
+
+	"github.com/aws/aws-sdk-go-v2/aws"
+	"github.com/fujiwara/tracer"
+)
+
+var (
+	testEvents = []tracer.TimelineEvent{
+		{
+			Timestamp: time.Date(2021, 1, 2, 3, 4, 5, 123_999_000, time.UTC),
+			Message:   "test message 1",
+			Source:    "test_source 1",
+		},
+		{
+			Timestamp: time.Date(2021, 1, 2, 3, 4, 5, 123_999_999, time.UTC),
+			Message:   "test message 5",
+			Source:    "test_source 5",
+		},
+		{
+			Timestamp: time.Date(2021, 1, 2, 3, 4, 6, 123_999_000, time.UTC),
+			Message:   "test message 2",
+			Source:    "test_source 2",
+		},
+		{
+			// same timestamp to test sort stable
+			Timestamp: time.Date(2021, 1, 2, 3, 4, 5, 123_999_000, time.UTC),
+			Message:   "test message 3",
+			Source:    "test_source 3",
+		},
+		{
+			// duplicate event
+			Timestamp: time.Date(2021, 1, 2, 3, 4, 5, 123_999_000, time.UTC),
+			Message:   "test message 3",
+			Source:    "test_source 3",
+		},
+		{
+			Timestamp: aws.ToTime(nil),
+			Message:   "test message ignored",
+			Source:    "test_source ignored",
+		},
+	}
+	expectedOutput = `2021-01-02T03:04:05.123Z	test_source 1	test message 1
+2021-01-02T03:04:05.123Z	test_source 3	test message 3
+2021-01-02T03:04:05.123Z	test_source 5	test message 5
+2021-01-02T03:04:06.123Z	test_source 2	test message 2
+`
+)
+
+func TestTimelineEvent(t *testing.T) {
+	t.Setenv("TZ", "UTC")
+	now := time.Date(2021, 1, 2, 3, 4, 5, 123_999_000, time.UTC)
+	ev := tracer.TimelineEvent{
+		Timestamp: now,
+		Message:   "test message",
+		Source:    "test_source",
+	}
+	if ev.String() != "2021-01-02T03:04:05.123Z\ttest_source\ttest message\n" {
+		t.Errorf("unexpected string: %s", ev.String())
+	}
+}
+
+func TestTimeline(t *testing.T) {
+	t.Setenv("TZ", "UTC")
+	tl := tracer.NewTimeline()
+	for _, ev := range testEvents {
+		ev := ev
+		tl.Add(&ev)
+	}
+	b := new(strings.Builder)
+	n, err := tl.Print(b)
+	if err != nil {
+		t.Errorf("unexpected error: %v", err)
+	}
+	if n != len(expectedOutput) {
+		t.Errorf("unexpected length: %d", n)
+	}
+	if b.String() != expectedOutput {
+		t.Errorf("unexpected output: %s", b.String())
+	}
+}