diff --git a/cli/deployment/config.go b/cli/deployment/config.go index 1887fbac71..4c8c72c135 100644 --- a/cli/deployment/config.go +++ b/cli/deployment/config.go @@ -295,6 +295,11 @@ func newConfig() *codersdk.DeploymentConfig { Flag: "trace-honeycomb-api-key", Secret: true, }, + CaptureLogs: &codersdk.DeploymentConfigField[bool]{ + Name: "Capture Logs in Traces", + 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.", + Flag: "trace-logs", + }, }, SecureAuthCookie: &codersdk.DeploymentConfigField[bool]{ Name: "Secure Auth Cookie", diff --git a/cli/server.go b/cli/server.go index 2ec1374a25..bc4ccad533 100644 --- a/cli/server.go +++ b/cli/server.go @@ -88,6 +88,9 @@ func Server(vip *viper.Viper, newAPI func(context.Context, *coderd.Options) (*co if ok, _ := cmd.Flags().GetBool(varVerbose); ok { logger = logger.Leveled(slog.LevelDebug) } + if cfg.Trace.CaptureLogs.Value { + logger = logger.AppendSinks(tracing.SlogSink{}) + } // Main command context for managing cancellation // of running services. @@ -126,7 +129,7 @@ func Server(vip *viper.Viper, newAPI func(context.Context, *coderd.Options) (*co shouldCoderTrace = cfg.Telemetry.Trace.Value } - if cfg.Trace.Enable.Value || shouldCoderTrace { + if cfg.Trace.Enable.Value || shouldCoderTrace || cfg.Trace.HoneycombAPIKey.Value != "" { sdkTracerProvider, closeTracing, err := tracing.TracerProvider(ctx, "coderd", tracing.TracerOpts{ Default: cfg.Trace.Enable.Value, Coder: shouldCoderTrace, diff --git a/cli/testdata/coder_server_--help.golden b/cli/testdata/coder_server_--help.golden index 40016c3efc..2033e4c63d 100644 --- a/cli/testdata/coder_server_--help.golden +++ b/cli/testdata/coder_server_--help.golden @@ -188,6 +188,14 @@ Flags: --trace-honeycomb-api-key string Enables trace exporting to Honeycomb.io using the provided API Key. Consumes $CODER_TRACE_HONEYCOMB_API_KEY + --trace-logs 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. + Consumes $CODER_TRACE_CAPTURE_LOGS --wildcard-access-url string Specifies the wildcard hostname to use for workspace applications in the form "*.example.com". diff --git a/coderd/tracing/slog.go b/coderd/tracing/slog.go new file mode 100644 index 0000000000..ad60f6895e --- /dev/null +++ b/coderd/tracing/slog.go @@ -0,0 +1,116 @@ +package tracing + +import ( + "context" + "fmt" + "strings" + "time" + + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/trace" + + "cdr.dev/slog" +) + +type SlogSink struct{} + +var _ slog.Sink = SlogSink{} + +// LogEntry implements slog.Sink. All entries are added as events to the span +// in the context. If no span is present, the entry is dropped. +func (SlogSink) LogEntry(ctx context.Context, e slog.SinkEntry) { + span := trace.SpanFromContext(ctx) + if !span.IsRecording() { + // If the span is a noopSpan or isn't recording, we don't want to + // compute the attributes (which is expensive) below. + return + } + + attributes := []attribute.KeyValue{ + attribute.String("slog.time", e.Time.Format(time.RFC3339Nano)), + attribute.String("slog.logger", strings.Join(e.LoggerNames, ".")), + attribute.String("slog.level", e.Level.String()), + attribute.String("slog.message", e.Message), + attribute.String("slog.func", e.Func), + attribute.String("slog.file", e.File), + attribute.Int64("slog.line", int64(e.Line)), + } + attributes = append(attributes, slogFieldsToAttributes(e.Fields)...) + + name := fmt.Sprintf("log: %s: %s", e.Level, e.Message) + span.AddEvent(name, trace.WithAttributes(attributes...)) +} + +// Sync implements slog.Sink. No-op as syncing is handled externally by otel. +func (SlogSink) Sync() {} + +func slogFieldsToAttributes(m slog.Map) []attribute.KeyValue { + attrs := make([]attribute.KeyValue, 0, len(m)) + for _, f := range m { + var value attribute.Value + switch v := f.Value.(type) { + case bool: + value = attribute.BoolValue(v) + case []bool: + value = attribute.BoolSliceValue(v) + case float32: + value = attribute.Float64Value(float64(v)) + // no float32 slice method + case float64: + value = attribute.Float64Value(v) + case []float64: + value = attribute.Float64SliceValue(v) + case int: + value = attribute.Int64Value(int64(v)) + case []int: + value = attribute.IntSliceValue(v) + case int8: + value = attribute.Int64Value(int64(v)) + // no int8 slice method + case int16: + value = attribute.Int64Value(int64(v)) + // no int16 slice method + case int32: + value = attribute.Int64Value(int64(v)) + // no int32 slice method + case int64: + value = attribute.Int64Value(v) + case []int64: + value = attribute.Int64SliceValue(v) + case uint: + value = attribute.Int64Value(int64(v)) + // no uint slice method + case uint8: + value = attribute.Int64Value(int64(v)) + // no uint8 slice method + case uint16: + value = attribute.Int64Value(int64(v)) + // no uint16 slice method + case uint32: + value = attribute.Int64Value(int64(v)) + // no uint32 slice method + case uint64: + value = attribute.Int64Value(int64(v)) + // no uint64 slice method + case string: + value = attribute.StringValue(v) + case []string: + value = attribute.StringSliceValue(v) + case time.Duration: + value = attribute.StringValue(v.String()) + case time.Time: + value = attribute.StringValue(v.Format(time.RFC3339Nano)) + case fmt.Stringer: + value = attribute.StringValue(v.String()) + } + + if value.Type() != attribute.INVALID { + attrs = append(attrs, attribute.KeyValue{ + Key: attribute.Key(f.Name), + Value: value, + }) + } + } + + return attrs +} diff --git a/coderd/tracing/slog_test.go b/coderd/tracing/slog_test.go new file mode 100644 index 0000000000..2db0013d20 --- /dev/null +++ b/coderd/tracing/slog_test.go @@ -0,0 +1,209 @@ +package tracing_test + +import ( + "context" + "fmt" + "strings" + "testing" + "time" + + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/trace" + + "github.com/stretchr/testify/require" + + "cdr.dev/slog" + "github.com/coder/coder/coderd/tracing" +) + +type stringer string + +var _ fmt.Stringer = stringer("") + +func (s stringer) String() string { + return string(s) +} + +type traceEvent struct { + name string + attributes []attribute.KeyValue +} + +type slogFakeSpan struct { + trace.Span // always nil + + isRecording bool + events []traceEvent +} + +// We overwrite some methods below. +var _ trace.Span = &slogFakeSpan{} + +// IsRecording implements trace.Span. +func (s *slogFakeSpan) IsRecording() bool { + return s.isRecording +} + +// AddEvent implements trace.Span. +func (s *slogFakeSpan) AddEvent(name string, options ...trace.EventOption) { + cfg := trace.NewEventConfig(options...) + + s.events = append(s.events, traceEvent{ + name: name, + attributes: cfg.Attributes(), + }) +} + +func Test_SlogSink(t *testing.T) { + t.Parallel() + + fieldsMap := map[string]interface{}{ + "test_bool": true, + "test_[]bool": []bool{true, false}, + "test_float32": float32(1.1), + "test_float64": float64(1.1), + "test_[]float64": []float64{1.1, 2.2}, + "test_int": int(1), + "test_[]int": []int{1, 2}, + "test_int8": int8(1), + "test_int16": int16(1), + "test_int32": int32(1), + "test_int64": int64(1), + "test_[]int64": []int64{1, 2}, + "test_uint": uint(1), + "test_uint8": uint8(1), + "test_uint16": uint16(1), + "test_uint32": uint32(1), + "test_uint64": uint64(1), + "test_string": "test", + "test_[]string": []string{"test1", "test2"}, + "test_duration": time.Second, + "test_time": time.Now(), + "test_stringer": stringer("test"), + "test_struct": struct { + Field string `json:"field"` + }{ + Field: "test", + }, + } + + entry := slog.SinkEntry{ + Time: time.Now(), + Level: slog.LevelInfo, + Message: "hello", + LoggerNames: []string{"foo", "bar"}, + Func: "hello", + File: "hello.go", + Line: 42, + Fields: mapToSlogFields(fieldsMap), + } + + t.Run("NotRecording", func(t *testing.T) { + t.Parallel() + + sink := tracing.SlogSink{} + span := &slogFakeSpan{ + isRecording: false, + } + ctx := trace.ContextWithSpan(context.Background(), span) + + sink.LogEntry(ctx, entry) + require.Len(t, span.events, 0) + }) + + t.Run("OK", func(t *testing.T) { + t.Parallel() + + sink := tracing.SlogSink{} + sink.Sync() + + span := &slogFakeSpan{ + isRecording: true, + } + ctx := trace.ContextWithSpan(context.Background(), span) + + sink.LogEntry(ctx, entry) + require.Len(t, span.events, 1) + + sink.LogEntry(ctx, entry) + require.Len(t, span.events, 2) + + e := span.events[0] + require.Equal(t, "log: INFO: hello", e.name) + + expectedAttributes := mapToBasicMap(fieldsMap) + delete(expectedAttributes, "test_struct") + expectedAttributes["slog.time"] = entry.Time.Format(time.RFC3339Nano) + expectedAttributes["slog.logger"] = strings.Join(entry.LoggerNames, ".") + expectedAttributes["slog.level"] = entry.Level.String() + expectedAttributes["slog.message"] = entry.Message + expectedAttributes["slog.func"] = entry.Func + expectedAttributes["slog.file"] = entry.File + expectedAttributes["slog.line"] = int64(entry.Line) + + require.Equal(t, expectedAttributes, attributesToMap(e.attributes)) + }) +} + +func mapToSlogFields(m map[string]interface{}) slog.Map { + fields := make(slog.Map, 0, len(m)) + for k, v := range m { + fields = append(fields, slog.F(k, v)) + } + + return fields +} + +func mapToBasicMap(m map[string]interface{}) map[string]interface{} { + basic := make(map[string]interface{}, len(m)) + for k, v := range m { + var val interface{} = v + switch v := v.(type) { + case float32: + val = float64(v) + case int: + val = int64(v) + case []int: + i64Slice := make([]int64, len(v)) + for i, v := range v { + i64Slice[i] = int64(v) + } + val = i64Slice + case int8: + val = int64(v) + case int16: + val = int64(v) + case int32: + val = int64(v) + case uint: + val = int64(v) + case uint8: + val = int64(v) + case uint16: + val = int64(v) + case uint32: + val = int64(v) + case uint64: + val = int64(v) + case time.Duration: + val = v.String() + case time.Time: + val = v.Format(time.RFC3339Nano) + case fmt.Stringer: + val = v.String() + } + + basic[k] = val + } + + return basic +} + +func attributesToMap(attrs []attribute.KeyValue) map[string]interface{} { + m := make(map[string]interface{}, len(attrs)) + for _, attr := range attrs { + m[string(attr.Key)] = attr.Value.AsInterface() + } + + return m +} diff --git a/codersdk/deploymentconfig.go b/codersdk/deploymentconfig.go index 7d6ed987f8..bc51fd806a 100644 --- a/codersdk/deploymentconfig.go +++ b/codersdk/deploymentconfig.go @@ -111,6 +111,7 @@ type TLSConfig struct { type TraceConfig struct { Enable *DeploymentConfigField[bool] `json:"enable" typescript:",notnull"` HoneycombAPIKey *DeploymentConfigField[string] `json:"honeycomb_api_key" typescript:",notnull"` + CaptureLogs *DeploymentConfigField[bool] `json:"capture_logs" typescript:",notnull"` } type GitAuthConfig struct { diff --git a/site/src/api/typesGenerated.ts b/site/src/api/typesGenerated.ts index b0055a2be5..b38ed2ea6c 100644 --- a/site/src/api/typesGenerated.ts +++ b/site/src/api/typesGenerated.ts @@ -676,6 +676,7 @@ export interface TemplateVersionsByTemplateRequest extends Pagination { export interface TraceConfig { readonly enable: DeploymentConfigField readonly honeycomb_api_key: DeploymentConfigField + readonly capture_logs: DeploymentConfigField } // From codersdk/templates.go