Skip to content

Commit ffc24dc

Browse files
authored
feat: create tracing.SlogSink for storing logs as span events (#4962)
1 parent 0ae8d5e commit ffc24dc

File tree

7 files changed

+344
-1
lines changed

7 files changed

+344
-1
lines changed

cli/deployment/config.go

+5
Original file line numberDiff line numberDiff line change
@@ -295,6 +295,11 @@ func newConfig() *codersdk.DeploymentConfig {
295295
Flag: "trace-honeycomb-api-key",
296296
Secret: true,
297297
},
298+
CaptureLogs: &codersdk.DeploymentConfigField[bool]{
299+
Name: "Capture Logs in Traces",
300+
Usage: "Enables capturing of logs as events in traces. This is useful for debugging, but may result in a very large amount of events being sent to the tracing backend which may incur significant costs. If the verbose flag was supplied, debug-level logs will be included.",
301+
Flag: "trace-logs",
302+
},
298303
},
299304
SecureAuthCookie: &codersdk.DeploymentConfigField[bool]{
300305
Name: "Secure Auth Cookie",

cli/server.go

+4-1
Original file line numberDiff line numberDiff line change
@@ -88,6 +88,9 @@ func Server(vip *viper.Viper, newAPI func(context.Context, *coderd.Options) (*co
8888
if ok, _ := cmd.Flags().GetBool(varVerbose); ok {
8989
logger = logger.Leveled(slog.LevelDebug)
9090
}
91+
if cfg.Trace.CaptureLogs.Value {
92+
logger = logger.AppendSinks(tracing.SlogSink{})
93+
}
9194

9295
// Main command context for managing cancellation
9396
// of running services.
@@ -126,7 +129,7 @@ func Server(vip *viper.Viper, newAPI func(context.Context, *coderd.Options) (*co
126129
shouldCoderTrace = cfg.Telemetry.Trace.Value
127130
}
128131

129-
if cfg.Trace.Enable.Value || shouldCoderTrace {
132+
if cfg.Trace.Enable.Value || shouldCoderTrace || cfg.Trace.HoneycombAPIKey.Value != "" {
130133
sdkTracerProvider, closeTracing, err := tracing.TracerProvider(ctx, "coderd", tracing.TracerOpts{
131134
Default: cfg.Trace.Enable.Value,
132135
Coder: shouldCoderTrace,

cli/testdata/coder_server_--help.golden

+8
Original file line numberDiff line numberDiff line change
@@ -188,6 +188,14 @@ Flags:
188188
--trace-honeycomb-api-key string Enables trace exporting to Honeycomb.io
189189
using the provided API Key.
190190
Consumes $CODER_TRACE_HONEYCOMB_API_KEY
191+
--trace-logs Enables capturing of logs as events in
192+
traces. This is useful for debugging, but
193+
may result in a very large amount of
194+
events being sent to the tracing backend
195+
which may incur significant costs. If the
196+
verbose flag was supplied, debug-level
197+
logs will be included.
198+
Consumes $CODER_TRACE_CAPTURE_LOGS
191199
--wildcard-access-url string Specifies the wildcard hostname to use
192200
for workspace applications in the form
193201
"*.example.com".

coderd/tracing/slog.go

+116
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,116 @@
1+
package tracing
2+
3+
import (
4+
"context"
5+
"fmt"
6+
"strings"
7+
"time"
8+
9+
"go.opentelemetry.io/otel/attribute"
10+
"go.opentelemetry.io/otel/trace"
11+
12+
"cdr.dev/slog"
13+
)
14+
15+
type SlogSink struct{}
16+
17+
var _ slog.Sink = SlogSink{}
18+
19+
// LogEntry implements slog.Sink. All entries are added as events to the span
20+
// in the context. If no span is present, the entry is dropped.
21+
func (SlogSink) LogEntry(ctx context.Context, e slog.SinkEntry) {
22+
span := trace.SpanFromContext(ctx)
23+
if !span.IsRecording() {
24+
// If the span is a noopSpan or isn't recording, we don't want to
25+
// compute the attributes (which is expensive) below.
26+
return
27+
}
28+
29+
attributes := []attribute.KeyValue{
30+
attribute.String("slog.time", e.Time.Format(time.RFC3339Nano)),
31+
attribute.String("slog.logger", strings.Join(e.LoggerNames, ".")),
32+
attribute.String("slog.level", e.Level.String()),
33+
attribute.String("slog.message", e.Message),
34+
attribute.String("slog.func", e.Func),
35+
attribute.String("slog.file", e.File),
36+
attribute.Int64("slog.line", int64(e.Line)),
37+
}
38+
attributes = append(attributes, slogFieldsToAttributes(e.Fields)...)
39+
40+
name := fmt.Sprintf("log: %s: %s", e.Level, e.Message)
41+
span.AddEvent(name, trace.WithAttributes(attributes...))
42+
}
43+
44+
// Sync implements slog.Sink. No-op as syncing is handled externally by otel.
45+
func (SlogSink) Sync() {}
46+
47+
func slogFieldsToAttributes(m slog.Map) []attribute.KeyValue {
48+
attrs := make([]attribute.KeyValue, 0, len(m))
49+
for _, f := range m {
50+
var value attribute.Value
51+
switch v := f.Value.(type) {
52+
case bool:
53+
value = attribute.BoolValue(v)
54+
case []bool:
55+
value = attribute.BoolSliceValue(v)
56+
case float32:
57+
value = attribute.Float64Value(float64(v))
58+
// no float32 slice method
59+
case float64:
60+
value = attribute.Float64Value(v)
61+
case []float64:
62+
value = attribute.Float64SliceValue(v)
63+
case int:
64+
value = attribute.Int64Value(int64(v))
65+
case []int:
66+
value = attribute.IntSliceValue(v)
67+
case int8:
68+
value = attribute.Int64Value(int64(v))
69+
// no int8 slice method
70+
case int16:
71+
value = attribute.Int64Value(int64(v))
72+
// no int16 slice method
73+
case int32:
74+
value = attribute.Int64Value(int64(v))
75+
// no int32 slice method
76+
case int64:
77+
value = attribute.Int64Value(v)
78+
case []int64:
79+
value = attribute.Int64SliceValue(v)
80+
case uint:
81+
value = attribute.Int64Value(int64(v))
82+
// no uint slice method
83+
case uint8:
84+
value = attribute.Int64Value(int64(v))
85+
// no uint8 slice method
86+
case uint16:
87+
value = attribute.Int64Value(int64(v))
88+
// no uint16 slice method
89+
case uint32:
90+
value = attribute.Int64Value(int64(v))
91+
// no uint32 slice method
92+
case uint64:
93+
value = attribute.Int64Value(int64(v))
94+
// no uint64 slice method
95+
case string:
96+
value = attribute.StringValue(v)
97+
case []string:
98+
value = attribute.StringSliceValue(v)
99+
case time.Duration:
100+
value = attribute.StringValue(v.String())
101+
case time.Time:
102+
value = attribute.StringValue(v.Format(time.RFC3339Nano))
103+
case fmt.Stringer:
104+
value = attribute.StringValue(v.String())
105+
}
106+
107+
if value.Type() != attribute.INVALID {
108+
attrs = append(attrs, attribute.KeyValue{
109+
Key: attribute.Key(f.Name),
110+
Value: value,
111+
})
112+
}
113+
}
114+
115+
return attrs
116+
}

coderd/tracing/slog_test.go

+209
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,209 @@
1+
package tracing_test
2+
3+
import (
4+
"context"
5+
"fmt"
6+
"strings"
7+
"testing"
8+
"time"
9+
10+
"go.opentelemetry.io/otel/attribute"
11+
"go.opentelemetry.io/otel/trace"
12+
13+
"github.com/stretchr/testify/require"
14+
15+
"cdr.dev/slog"
16+
"github.com/coder/coder/coderd/tracing"
17+
)
18+
19+
type stringer string
20+
21+
var _ fmt.Stringer = stringer("")
22+
23+
func (s stringer) String() string {
24+
return string(s)
25+
}
26+
27+
type traceEvent struct {
28+
name string
29+
attributes []attribute.KeyValue
30+
}
31+
32+
type slogFakeSpan struct {
33+
trace.Span // always nil
34+
35+
isRecording bool
36+
events []traceEvent
37+
}
38+
39+
// We overwrite some methods below.
40+
var _ trace.Span = &slogFakeSpan{}
41+
42+
// IsRecording implements trace.Span.
43+
func (s *slogFakeSpan) IsRecording() bool {
44+
return s.isRecording
45+
}
46+
47+
// AddEvent implements trace.Span.
48+
func (s *slogFakeSpan) AddEvent(name string, options ...trace.EventOption) {
49+
cfg := trace.NewEventConfig(options...)
50+
51+
s.events = append(s.events, traceEvent{
52+
name: name,
53+
attributes: cfg.Attributes(),
54+
})
55+
}
56+
57+
func Test_SlogSink(t *testing.T) {
58+
t.Parallel()
59+
60+
fieldsMap := map[string]interface{}{
61+
"test_bool": true,
62+
"test_[]bool": []bool{true, false},
63+
"test_float32": float32(1.1),
64+
"test_float64": float64(1.1),
65+
"test_[]float64": []float64{1.1, 2.2},
66+
"test_int": int(1),
67+
"test_[]int": []int{1, 2},
68+
"test_int8": int8(1),
69+
"test_int16": int16(1),
70+
"test_int32": int32(1),
71+
"test_int64": int64(1),
72+
"test_[]int64": []int64{1, 2},
73+
"test_uint": uint(1),
74+
"test_uint8": uint8(1),
75+
"test_uint16": uint16(1),
76+
"test_uint32": uint32(1),
77+
"test_uint64": uint64(1),
78+
"test_string": "test",
79+
"test_[]string": []string{"test1", "test2"},
80+
"test_duration": time.Second,
81+
"test_time": time.Now(),
82+
"test_stringer": stringer("test"),
83+
"test_struct": struct {
84+
Field string `json:"field"`
85+
}{
86+
Field: "test",
87+
},
88+
}
89+
90+
entry := slog.SinkEntry{
91+
Time: time.Now(),
92+
Level: slog.LevelInfo,
93+
Message: "hello",
94+
LoggerNames: []string{"foo", "bar"},
95+
Func: "hello",
96+
File: "hello.go",
97+
Line: 42,
98+
Fields: mapToSlogFields(fieldsMap),
99+
}
100+
101+
t.Run("NotRecording", func(t *testing.T) {
102+
t.Parallel()
103+
104+
sink := tracing.SlogSink{}
105+
span := &slogFakeSpan{
106+
isRecording: false,
107+
}
108+
ctx := trace.ContextWithSpan(context.Background(), span)
109+
110+
sink.LogEntry(ctx, entry)
111+
require.Len(t, span.events, 0)
112+
})
113+
114+
t.Run("OK", func(t *testing.T) {
115+
t.Parallel()
116+
117+
sink := tracing.SlogSink{}
118+
sink.Sync()
119+
120+
span := &slogFakeSpan{
121+
isRecording: true,
122+
}
123+
ctx := trace.ContextWithSpan(context.Background(), span)
124+
125+
sink.LogEntry(ctx, entry)
126+
require.Len(t, span.events, 1)
127+
128+
sink.LogEntry(ctx, entry)
129+
require.Len(t, span.events, 2)
130+
131+
e := span.events[0]
132+
require.Equal(t, "log: INFO: hello", e.name)
133+
134+
expectedAttributes := mapToBasicMap(fieldsMap)
135+
delete(expectedAttributes, "test_struct")
136+
expectedAttributes["slog.time"] = entry.Time.Format(time.RFC3339Nano)
137+
expectedAttributes["slog.logger"] = strings.Join(entry.LoggerNames, ".")
138+
expectedAttributes["slog.level"] = entry.Level.String()
139+
expectedAttributes["slog.message"] = entry.Message
140+
expectedAttributes["slog.func"] = entry.Func
141+
expectedAttributes["slog.file"] = entry.File
142+
expectedAttributes["slog.line"] = int64(entry.Line)
143+
144+
require.Equal(t, expectedAttributes, attributesToMap(e.attributes))
145+
})
146+
}
147+
148+
func mapToSlogFields(m map[string]interface{}) slog.Map {
149+
fields := make(slog.Map, 0, len(m))
150+
for k, v := range m {
151+
fields = append(fields, slog.F(k, v))
152+
}
153+
154+
return fields
155+
}
156+
157+
func mapToBasicMap(m map[string]interface{}) map[string]interface{} {
158+
basic := make(map[string]interface{}, len(m))
159+
for k, v := range m {
160+
var val interface{} = v
161+
switch v := v.(type) {
162+
case float32:
163+
val = float64(v)
164+
case int:
165+
val = int64(v)
166+
case []int:
167+
i64Slice := make([]int64, len(v))
168+
for i, v := range v {
169+
i64Slice[i] = int64(v)
170+
}
171+
val = i64Slice
172+
case int8:
173+
val = int64(v)
174+
case int16:
175+
val = int64(v)
176+
case int32:
177+
val = int64(v)
178+
case uint:
179+
val = int64(v)
180+
case uint8:
181+
val = int64(v)
182+
case uint16:
183+
val = int64(v)
184+
case uint32:
185+
val = int64(v)
186+
case uint64:
187+
val = int64(v)
188+
case time.Duration:
189+
val = v.String()
190+
case time.Time:
191+
val = v.Format(time.RFC3339Nano)
192+
case fmt.Stringer:
193+
val = v.String()
194+
}
195+
196+
basic[k] = val
197+
}
198+
199+
return basic
200+
}
201+
202+
func attributesToMap(attrs []attribute.KeyValue) map[string]interface{} {
203+
m := make(map[string]interface{}, len(attrs))
204+
for _, attr := range attrs {
205+
m[string(attr.Key)] = attr.Value.AsInterface()
206+
}
207+
208+
return m
209+
}

codersdk/deploymentconfig.go

+1
Original file line numberDiff line numberDiff line change
@@ -111,6 +111,7 @@ type TLSConfig struct {
111111
type TraceConfig struct {
112112
Enable *DeploymentConfigField[bool] `json:"enable" typescript:",notnull"`
113113
HoneycombAPIKey *DeploymentConfigField[string] `json:"honeycomb_api_key" typescript:",notnull"`
114+
CaptureLogs *DeploymentConfigField[bool] `json:"capture_logs" typescript:",notnull"`
114115
}
115116

116117
type GitAuthConfig struct {

site/src/api/typesGenerated.ts

+1
Original file line numberDiff line numberDiff line change
@@ -676,6 +676,7 @@ export interface TemplateVersionsByTemplateRequest extends Pagination {
676676
export interface TraceConfig {
677677
readonly enable: DeploymentConfigField<boolean>
678678
readonly honeycomb_api_key: DeploymentConfigField<string>
679+
readonly capture_logs: DeploymentConfigField<boolean>
679680
}
680681

681682
// From codersdk/templates.go

0 commit comments

Comments
 (0)