phos/example_test.go at main · johan-st/phos · GitHub

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
package phos

import (
	"context"
	"errors"
	"log/slog"
	"strings"
	"testing"
	"time"
)

// TestExample_TraceVisualization builds a realistic trace with overlapping
// spans and prints a CLI timeline showing how spans relate to each other.
//
// Run with: go test -v -run Example_Trace ./phos/...
func TestExample_TraceVisualization(t *testing.T) {
	exp := &captureExporter{}
	getSpans := withExporter(t, exp)

	rootCtx, root := NewSpan(context.Background(), "http.request",
		WithAttrs(
			slog.String("method", "GET"),
			slog.String("path", "/api/users"),
		),
	)
	Event(rootCtx, "received")
	time.Sleep(2 * time.Millisecond)

	authCtx, auth := NewSpan(rootCtx, "auth")
	Event(authCtx, "lookup")
	time.Sleep(time.Millisecond)
	Event(authCtx, "granted")

	_, tokenVerify := NewSpan(authCtx, "token.verify")
	time.Sleep(3 * time.Millisecond)
	tokenVerify.End()

	Attrs(authCtx, slog.String("user", "alice"))
	time.Sleep(time.Millisecond)
	auth.End()

	dbCtx, dbQuery := NewSpan(rootCtx, "db.query",
		WithAttrs(slog.String("table", "users")),
	)
	cacheCtx, cacheCheck := NewSpan(rootCtx, "cache.check",
		WithAttrs(slog.String("key", "users:list")),
	)

	Event(dbCtx, "rows", slog.Int("count", 42))
	Event(cacheCtx, "miss")
	time.Sleep(3 * time.Millisecond)
	cacheCheck.End()

	time.Sleep(4 * time.Millisecond)
	Error(dbCtx, errors.New("slow query"),
		slog.Duration("threshold", 100*time.Millisecond),
	)
	dbQuery.End()

	time.Sleep(time.Millisecond)

	serializeCtx, serialize := NewSpan(rootCtx, "serialize")
	time.Sleep(time.Millisecond)

	_, compress := NewSpan(serializeCtx, "compress")
	time.Sleep(2 * time.Millisecond)
	compress.End()

	Event(serializeCtx, "done")
	time.Sleep(time.Millisecond)
	serialize.End()

	Event(rootCtx, "complete")
	root.End()

	t.Logf("\n%s", RenderTraces(getSpans()))
}

func TestRenderTraceEndpointMarkers(t *testing.T) {
	start := time.Unix(0, 0)
	end := start.Add(time.Second)
	for _, marker := range []Snapshot{
		{Events: []SnapshotEvent{{Time: end, Name: "endpoint"}}},
		{Errors: []SnapshotError{{Err: errors.New("endpoint")}}},
	} {
		marker.ID = "child"
		marker.Name = "child"
		marker.ParentID = "root"
		marker.TimeStart = end
		marker.TimeEnd = end
		out := RenderTrace([]Snapshot{{ID: "root", Name: "root", TimeStart: start, TimeEnd: end}, marker})
		if !strings.Contains(out, strings.Repeat("·", 49)+"1") || !strings.Contains(out, "endpoint") {
			t.Fatalf("endpoint marker missing from final column or legend:\n%s", out)
		}
	}
}