Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ddtrace/tracer: runtime metrics v2 (exclude from release notes) #2772

Merged
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 2 additions & 0 deletions ddtrace/tracer/log.go
Original file line number Diff line number Diff line change
Expand Up @@ -43,6 +43,7 @@ type startupInfo struct {
ServiceMappings map[string]string `json:"service_mappings"` // Service Mappings
Tags map[string]string `json:"tags"` // Global tags
RuntimeMetricsEnabled bool `json:"runtime_metrics_enabled"` // Whether runtime metrics are enabled
RuntimeMetricsV2Enabled bool `json:"runtime_metrics_v2_enabled"` // Whether runtime metrics v2 are enabled
HealthMetricsEnabled bool `json:"health_metrics_enabled"` // Whether health metrics are enabled
ProfilerCodeHotspotsEnabled bool `json:"profiler_code_hotspots_enabled"` // Whether profiler code hotspots are enabled
ProfilerEndpointsEnabled bool `json:"profiler_endpoints_enabled"` // Whether profiler endpoints are enabled
Expand Down Expand Up @@ -124,6 +125,7 @@ func logStartup(t *tracer) {
ServiceMappings: t.config.serviceMappings,
Tags: tags,
RuntimeMetricsEnabled: t.config.runtimeMetrics,
RuntimeMetricsV2Enabled: t.config.runtimeMetricsV2,
HealthMetricsEnabled: t.config.runtimeMetrics,
ApplicationVersion: t.config.version,
ProfilerCodeHotspotsEnabled: t.config.profilerHotspots,
Expand Down
15 changes: 8 additions & 7 deletions ddtrace/tracer/log_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -32,7 +32,7 @@ func TestStartupLog(t *testing.T) {
tp.Ignore("appsec: ", telemetry.LogPrefix)
logStartup(tracer)
require.Len(t, tp.Logs(), 2)
assert.Regexp(logPrefixRegexp+` INFO: DATADOG TRACER CONFIGURATION {"date":"[^"]*","os_name":"[^"]*","os_version":"[^"]*","version":"[^"]*","lang":"Go","lang_version":"[^"]*","env":"","service":"tracer\.test(\.exe)?","agent_url":"http://localhost:9/v0.4/traces","agent_error":"Post .*","debug":false,"analytics_enabled":false,"sample_rate":"NaN","sample_rate_limit":"disabled","trace_sampling_rules":null,"span_sampling_rules":null,"sampling_rules_error":"","service_mappings":null,"tags":{"runtime-id":"[^"]*"},"runtime_metrics_enabled":false,"health_metrics_enabled":false,"profiler_code_hotspots_enabled":((false)|(true)),"profiler_endpoints_enabled":((false)|(true)),"dd_version":"","architecture":"[^"]*","global_service":"","lambda_mode":"false","appsec":((true)|(false)),"agent_features":{"DropP0s":((true)|(false)),"Stats":((true)|(false)),"StatsdPort":0},"integrations":{.*},"partial_flush_enabled":false,"partial_flush_min_spans":1000,"orchestrion":{"enabled":false},"feature_flags":\[\],"propagation_style_inject":"datadog,tracecontext","propagation_style_extract":"datadog,tracecontext"}`, tp.Logs()[1])
assert.Regexp(logPrefixRegexp+` INFO: DATADOG TRACER CONFIGURATION {"date":"[^"]*","os_name":"[^"]*","os_version":"[^"]*","version":"[^"]*","lang":"Go","lang_version":"[^"]*","env":"","service":"tracer\.test(\.exe)?","agent_url":"http://localhost:9/v0.4/traces","agent_error":"Post .*","debug":false,"analytics_enabled":false,"sample_rate":"NaN","sample_rate_limit":"disabled","trace_sampling_rules":null,"span_sampling_rules":null,"sampling_rules_error":"","service_mappings":null,"tags":{"runtime-id":"[^"]*"},"runtime_metrics_enabled":false,"runtime_metrics_v2_enabled":false,"health_metrics_enabled":false,"profiler_code_hotspots_enabled":((false)|(true)),"profiler_endpoints_enabled":((false)|(true)),"dd_version":"","architecture":"[^"]*","global_service":"","lambda_mode":"false","appsec":((true)|(false)),"agent_features":{"DropP0s":((true)|(false)),"Stats":((true)|(false)),"StatsdPort":0},"integrations":{.*},"partial_flush_enabled":false,"partial_flush_min_spans":1000,"orchestrion":{"enabled":false},"feature_flags":\[\],"propagation_style_inject":"datadog,tracecontext","propagation_style_extract":"datadog,tracecontext"}`, tp.Logs()[1])
})

t.Run("configured", func(t *testing.T) {
Expand Down Expand Up @@ -64,7 +64,7 @@ func TestStartupLog(t *testing.T) {
tp.Ignore("appsec: ", telemetry.LogPrefix)
logStartup(tracer)
require.Len(t, tp.Logs(), 2)
assert.Regexp(logPrefixRegexp+` INFO: DATADOG TRACER CONFIGURATION {"date":"[^"]*","os_name":"[^"]*","os_version":"[^"]*","version":"[^"]*","lang":"Go","lang_version":"[^"]*","env":"configuredEnv","service":"configured.service","agent_url":"http://localhost:9/v0.4/traces","agent_error":"Post .*","debug":true,"analytics_enabled":true,"sample_rate":"0\.123000","sample_rate_limit":"100","trace_sampling_rules":\[{"service":"mysql","sample_rate":0\.75}\],"span_sampling_rules":null,"sampling_rules_error":"","service_mappings":{"initial_service":"new_service"},"tags":{"runtime-id":"[^"]*","tag":"value","tag2":"NaN"},"runtime_metrics_enabled":true,"health_metrics_enabled":true,"profiler_code_hotspots_enabled":((false)|(true)),"profiler_endpoints_enabled":((false)|(true)),"dd_version":"2.3.4","architecture":"[^"]*","global_service":"configured.service","lambda_mode":"false","appsec":((true)|(false)),"agent_features":{"DropP0s":false,"Stats":false,"StatsdPort":0},"integrations":{.*},"partial_flush_enabled":false,"partial_flush_min_spans":1000,"orchestrion":{"enabled":true,"metadata":{"version":"v1"}},"feature_flags":\["discovery"\],"propagation_style_inject":"datadog,tracecontext","propagation_style_extract":"datadog,tracecontext"}`, tp.Logs()[1])
assert.Regexp(logPrefixRegexp+` INFO: DATADOG TRACER CONFIGURATION {"date":"[^"]*","os_name":"[^"]*","os_version":"[^"]*","version":"[^"]*","lang":"Go","lang_version":"[^"]*","env":"configuredEnv","service":"configured.service","agent_url":"http://localhost:9/v0.4/traces","agent_error":"Post .*","debug":true,"analytics_enabled":true,"sample_rate":"0\.123000","sample_rate_limit":"100","trace_sampling_rules":\[{"service":"mysql","sample_rate":0\.75}\],"span_sampling_rules":null,"sampling_rules_error":"","service_mappings":{"initial_service":"new_service"},"tags":{"runtime-id":"[^"]*","tag":"value","tag2":"NaN"},"runtime_metrics_enabled":true,"runtime_metrics_v2_enabled":false,"health_metrics_enabled":true,"profiler_code_hotspots_enabled":((false)|(true)),"profiler_endpoints_enabled":((false)|(true)),"dd_version":"2.3.4","architecture":"[^"]*","global_service":"configured.service","lambda_mode":"false","appsec":((true)|(false)),"agent_features":{"DropP0s":false,"Stats":false,"StatsdPort":0},"integrations":{.*},"partial_flush_enabled":false,"partial_flush_min_spans":1000,"orchestrion":{"enabled":true,"metadata":{"version":"v1"}},"feature_flags":\["discovery"\],"propagation_style_inject":"datadog,tracecontext","propagation_style_extract":"datadog,tracecontext"}`, tp.Logs()[1])
})

t.Run("limit", func(t *testing.T) {
Expand Down Expand Up @@ -94,7 +94,7 @@ func TestStartupLog(t *testing.T) {
tp.Ignore("appsec: ", telemetry.LogPrefix)
logStartup(tracer)
require.Len(t, tp.Logs(), 2)
assert.Regexp(logPrefixRegexp+` INFO: DATADOG TRACER CONFIGURATION {"date":"[^"]*","os_name":"[^"]*","os_version":"[^"]*","version":"[^"]*","lang":"Go","lang_version":"[^"]*","env":"configuredEnv","service":"configured.service","agent_url":"http://localhost:9/v0.4/traces","agent_error":"Post .*","debug":true,"analytics_enabled":true,"sample_rate":"0\.123000","sample_rate_limit":"1000.001","trace_sampling_rules":\[{"service":"mysql","sample_rate":0\.75}\],"span_sampling_rules":null,"sampling_rules_error":"","service_mappings":{"initial_service":"new_service"},"tags":{"runtime-id":"[^"]*","tag":"value","tag2":"NaN"},"runtime_metrics_enabled":true,"health_metrics_enabled":true,"profiler_code_hotspots_enabled":((false)|(true)),"profiler_endpoints_enabled":((false)|(true)),"dd_version":"2.3.4","architecture":"[^"]*","global_service":"configured.service","lambda_mode":"false","appsec":((true)|(false)),"agent_features":{"DropP0s":false,"Stats":false,"StatsdPort":0},"integrations":{.*},"partial_flush_enabled":false,"partial_flush_min_spans":1000,"orchestrion":{"enabled":false},"feature_flags":\[\],"propagation_style_inject":"datadog,tracecontext","propagation_style_extract":"datadog,tracecontext"}`, tp.Logs()[1])
assert.Regexp(logPrefixRegexp+` INFO: DATADOG TRACER CONFIGURATION {"date":"[^"]*","os_name":"[^"]*","os_version":"[^"]*","version":"[^"]*","lang":"Go","lang_version":"[^"]*","env":"configuredEnv","service":"configured.service","agent_url":"http://localhost:9/v0.4/traces","agent_error":"Post .*","debug":true,"analytics_enabled":true,"sample_rate":"0\.123000","sample_rate_limit":"1000.001","trace_sampling_rules":\[{"service":"mysql","sample_rate":0\.75}\],"span_sampling_rules":null,"sampling_rules_error":"","service_mappings":{"initial_service":"new_service"},"tags":{"runtime-id":"[^"]*","tag":"value","tag2":"NaN"},"runtime_metrics_enabled":true,"runtime_metrics_v2_enabled":false,"health_metrics_enabled":true,"profiler_code_hotspots_enabled":((false)|(true)),"profiler_endpoints_enabled":((false)|(true)),"dd_version":"2.3.4","architecture":"[^"]*","global_service":"configured.service","lambda_mode":"false","appsec":((true)|(false)),"agent_features":{"DropP0s":false,"Stats":false,"StatsdPort":0},"integrations":{.*},"partial_flush_enabled":false,"partial_flush_min_spans":1000,"orchestrion":{"enabled":false},"feature_flags":\[\],"propagation_style_inject":"datadog,tracecontext","propagation_style_extract":"datadog,tracecontext"}`, tp.Logs()[1])
})

t.Run("errors", func(t *testing.T) {
Expand All @@ -108,7 +108,7 @@ func TestStartupLog(t *testing.T) {
tp.Ignore("appsec: ", telemetry.LogPrefix)
logStartup(tracer)
require.Len(t, tp.Logs(), 2)
assert.Regexp(logPrefixRegexp+` INFO: DATADOG TRACER CONFIGURATION {"date":"[^"]*","os_name":"[^"]*","os_version":"[^"]*","version":"[^"]*","lang":"Go","lang_version":"[^"]*","env":"","service":"tracer\.test(\.exe)?","agent_url":"http://localhost:9/v0.4/traces","agent_error":"Post .*","debug":false,"analytics_enabled":false,"sample_rate":"NaN","sample_rate_limit":"100","trace_sampling_rules":\[{"service":"some\.service","sample_rate":0\.234}\],"span_sampling_rules":null,"sampling_rules_error":"\\n\\tat index 1: ignoring rule {Service:other.service Rate:2}: rate is out of \[0\.0, 1\.0] range","service_mappings":null,"tags":{"runtime-id":"[^"]*"},"runtime_metrics_enabled":false,"health_metrics_enabled":false,"profiler_code_hotspots_enabled":((false)|(true)),"profiler_endpoints_enabled":((false)|(true)),"dd_version":"","architecture":"[^"]*","global_service":"","lambda_mode":"false","appsec":((true)|(false)),"agent_features":{"DropP0s":((true)|(false)),"Stats":((true)|(false)),"StatsdPort":0},"integrations":{.*},"partial_flush_enabled":false,"partial_flush_min_spans":1000,"orchestrion":{"enabled":false},"feature_flags":\[\],"propagation_style_inject":"datadog,tracecontext","propagation_style_extract":"datadog,tracecontext"}`, tp.Logs()[1])
assert.Regexp(logPrefixRegexp+` INFO: DATADOG TRACER CONFIGURATION {"date":"[^"]*","os_name":"[^"]*","os_version":"[^"]*","version":"[^"]*","lang":"Go","lang_version":"[^"]*","env":"","service":"tracer\.test(\.exe)?","agent_url":"http://localhost:9/v0.4/traces","agent_error":"Post .*","debug":false,"analytics_enabled":false,"sample_rate":"NaN","sample_rate_limit":"100","trace_sampling_rules":\[{"service":"some\.service","sample_rate":0\.234}\],"span_sampling_rules":null,"sampling_rules_error":"\\n\\tat index 1: ignoring rule {Service:other.service Rate:2}: rate is out of \[0\.0, 1\.0] range","service_mappings":null,"tags":{"runtime-id":"[^"]*"},"runtime_metrics_enabled":false,"runtime_metrics_v2_enabled":false,"health_metrics_enabled":false,"profiler_code_hotspots_enabled":((false)|(true)),"profiler_endpoints_enabled":((false)|(true)),"dd_version":"","architecture":"[^"]*","global_service":"","lambda_mode":"false","appsec":((true)|(false)),"agent_features":{"DropP0s":((true)|(false)),"Stats":((true)|(false)),"StatsdPort":0},"integrations":{.*},"partial_flush_enabled":false,"partial_flush_min_spans":1000,"orchestrion":{"enabled":false},"feature_flags":\[\],"propagation_style_inject":"datadog,tracecontext","propagation_style_extract":"datadog,tracecontext"}`, tp.Logs()[1])
})

t.Run("lambda", func(t *testing.T) {
Expand All @@ -121,7 +121,7 @@ func TestStartupLog(t *testing.T) {
tp.Ignore("appsec: ", telemetry.LogPrefix)
logStartup(tracer)
assert.Len(tp.Logs(), 1)
assert.Regexp(logPrefixRegexp+` INFO: DATADOG TRACER CONFIGURATION {"date":"[^"]*","os_name":"[^"]*","os_version":"[^"]*","version":"[^"]*","lang":"Go","lang_version":"[^"]*","env":"","service":"tracer\.test(\.exe)?","agent_url":"http://localhost:9/v0.4/traces","agent_error":"","debug":false,"analytics_enabled":false,"sample_rate":"NaN","sample_rate_limit":"disabled","trace_sampling_rules":null,"span_sampling_rules":null,"sampling_rules_error":"","service_mappings":null,"tags":{"runtime-id":"[^"]*"},"runtime_metrics_enabled":false,"health_metrics_enabled":false,"profiler_code_hotspots_enabled":((false)|(true)),"profiler_endpoints_enabled":((false)|(true)),"dd_version":"","architecture":"[^"]*","global_service":"","lambda_mode":"true","appsec":((true)|(false)),"agent_features":{"DropP0s":false,"Stats":false,"StatsdPort":0},"integrations":{.*},"partial_flush_enabled":false,"partial_flush_min_spans":1000,"orchestrion":{"enabled":false},"feature_flags":\[\],"propagation_style_inject":"datadog,tracecontext","propagation_style_extract":"datadog,tracecontext"}`, tp.Logs()[0])
assert.Regexp(logPrefixRegexp+` INFO: DATADOG TRACER CONFIGURATION {"date":"[^"]*","os_name":"[^"]*","os_version":"[^"]*","version":"[^"]*","lang":"Go","lang_version":"[^"]*","env":"","service":"tracer\.test(\.exe)?","agent_url":"http://localhost:9/v0.4/traces","agent_error":"","debug":false,"analytics_enabled":false,"sample_rate":"NaN","sample_rate_limit":"disabled","trace_sampling_rules":null,"span_sampling_rules":null,"sampling_rules_error":"","service_mappings":null,"tags":{"runtime-id":"[^"]*"},"runtime_metrics_enabled":false,"runtime_metrics_v2_enabled":false,"health_metrics_enabled":false,"profiler_code_hotspots_enabled":((false)|(true)),"profiler_endpoints_enabled":((false)|(true)),"dd_version":"","architecture":"[^"]*","global_service":"","lambda_mode":"true","appsec":((true)|(false)),"agent_features":{"DropP0s":false,"Stats":false,"StatsdPort":0},"integrations":{.*},"partial_flush_enabled":false,"partial_flush_min_spans":1000,"orchestrion":{"enabled":false},"feature_flags":\[\],"propagation_style_inject":"datadog,tracecontext","propagation_style_extract":"datadog,tracecontext"}`, tp.Logs()[0])
})

t.Run("integrations", func(t *testing.T) {
Expand Down Expand Up @@ -180,8 +180,9 @@ func TestLogAgentReachable(t *testing.T) {
func TestLogFormat(t *testing.T) {
assert := assert.New(t)
tp := new(log.RecordLogger)
tracer := newTracer(WithLogger(tp), WithRuntimeMetrics(), WithDebugMode(true))
defer tracer.Stop()

tracer, _, _, stop := startTestTracer(t, WithLogger(tp), WithRuntimeMetrics(), WithDebugMode(true))
defer stop()
tp.Reset()
tp.Ignore("appsec: ", telemetry.LogPrefix)
tracer.StartSpan("test", ServiceName("test-service"), ResourceName("/"), WithSpanID(12345))
Expand Down
4 changes: 4 additions & 0 deletions ddtrace/tracer/option.go
Original file line number Diff line number Diff line change
Expand Up @@ -190,6 +190,9 @@ type config struct {
// runtimeMetrics specifies whether collection of runtime metrics is enabled.
runtimeMetrics bool

// runtimeMetricsV2 specifies whether collection of runtime metrics v2 is enabled.
runtimeMetricsV2 bool

// dogstatsdAddr specifies the address to connect for sending metrics to the
// Datadog Agent. If not set, it defaults to "localhost:8125" or to the
// combination of the environment variables DD_AGENT_HOST and DD_DOGSTATSD_PORT.
Expand Down Expand Up @@ -385,6 +388,7 @@ func newConfig(opts ...StartOption) *config {
}
c.logStartup = internal.BoolEnv("DD_TRACE_STARTUP_LOGS", true)
c.runtimeMetrics = internal.BoolVal(getDDorOtelConfig("metrics"), false)
c.runtimeMetricsV2 = internal.BoolEnv("DD_RUNTIME_METRICS_V2_ENABLED", false)
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

NIT from @Gandem: We should consider adding a test for this.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Resolution: Will probably add one in a follow-up PR.

c.debug = internal.BoolVal(getDDorOtelConfig("debugMode"), false)
c.logDirectory = os.Getenv("DD_TRACE_LOG_DIRECTORY")
c.enabled = newDynamicConfig("tracing_enabled", internal.BoolVal(getDDorOtelConfig("enabled"), true), func(b bool) bool { return true }, equal[bool])
Expand Down
69 changes: 69 additions & 0 deletions ddtrace/tracer/slog.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,69 @@
// Unless explicitly stated otherwise all files in this repository are licensed
// under the Apache License Version 2.0.
// This product includes software developed at Datadog (https://www.datadoghq.com/).
// Copyright 2024 Datadog, Inc.

package tracer

import (
"context"
"log/slog"
"strings"

"gopkg.in/DataDog/dd-trace-go.v1/internal/log"
)

// slogHandler implements the slog.Handler interface to dispatch messages to our
// internal logger.
type slogHandler struct {
attrs []string
groups []string
}

func (h slogHandler) Enabled(ctx context.Context, lvl slog.Level) bool {
if lvl <= slog.LevelDebug {
return log.DebugEnabled()
}
// TODO(fg): Implement generic log level checking in the internal logger.
// But we're we're not concerned with slog perf, so this is okay for now.
return true
}

func (h slogHandler) Handle(ctx context.Context, r slog.Record) error {
parts := make([]string, 0, 1+len(h.attrs)+r.NumAttrs())
parts = append(parts, r.Message)
parts = append(parts, h.attrs...)
r.Attrs(func(a slog.Attr) bool {
parts = append(parts, formatAttr(a, h.groups))
return true
})

msg := strings.Join(parts, " ")
switch r.Level {
case slog.LevelDebug:
log.Debug(msg)
case slog.LevelInfo:
log.Info(msg)
case slog.LevelWarn:
log.Warn(msg)
case slog.LevelError:
log.Error(msg)
}
return nil
}

func (h slogHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
for _, a := range attrs {
h.attrs = append(h.attrs, formatAttr(a, h.groups))
}
return h
}

func (h slogHandler) WithGroup(name string) slog.Handler {
h.groups = append(h.groups, name)
return h
}

func formatAttr(a slog.Attr, groups []string) string {
return strings.Join(append(groups, a.String()), ".")
}
45 changes: 45 additions & 0 deletions ddtrace/tracer/slog_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,45 @@
// Unless explicitly stated otherwise all files in this repository are licensed
// under the Apache License Version 2.0.
// This product includes software developed at Datadog (https://www.datadoghq.com/).
// Copyright 2024 Datadog, Inc.

package tracer

import (
"log/slog"
"testing"

"github.com/stretchr/testify/require"
"gopkg.in/DataDog/dd-trace-go.v1/internal/log"
)

func Test_slogHandler(t *testing.T) {
// Create a record logger to capture the logs and restore the original
// logger at the end.
rl := &log.RecordLogger{}
defer log.UseLogger(rl)()

// Ensure the logger is set to the default level. This may not be the case
// when previous tests pollute the global state. We leave the logger in the
// state we found it to not contribute to this pollution ourselves.
oldLevel := log.GetLevel()
log.SetLevel(log.LevelWarn)
defer log.SetLevel(oldLevel)

// Log a few messages at different levels. The debug message gets discarded
// because the internal logger does not have debug enabled by default.
l := slog.New(slogHandler{})
l = l.With("foo", "bar")
l = l.WithGroup("a").WithGroup("b")
l.Debug("debug test", "n", 0)
l.Info("info test", "n", 1)
l.Warn("warn test", "n", 2)
l.Error("error test", "n", 3)
log.Flush() // needed to get the error log flushed

// Check that the logs were written correctly.
require.Len(t, rl.Logs(), 3)
require.Contains(t, rl.Logs()[0], "info test foo=bar a.b.n=1")
require.Contains(t, rl.Logs()[1], "warn test foo=bar a.b.n=2")
require.Contains(t, rl.Logs()[2], "error test foo=bar a.b.n=3")
}
1 change: 1 addition & 0 deletions ddtrace/tracer/telemetry.go
Original file line number Diff line number Diff line change
Expand Up @@ -54,6 +54,7 @@ func startTelemetry(c *config) {
{Name: "trace_agent_url", Value: c.agentURL.String()},
{Name: "agent_hostname", Value: c.hostname},
{Name: "runtime_metrics_enabled", Value: c.runtimeMetrics},
{Name: "runtime_metrics_v2_enabled", Value: c.runtimeMetricsV2},
felixge marked this conversation as resolved.
Show resolved Hide resolved
{Name: "dogstatsd_addr", Value: c.dogstatsdAddr},
{Name: "debug_stack_enabled", Value: !c.noDebugStack},
{Name: "profiling_hotspots_enabled", Value: c.profilerHotspots},
Expand Down
Loading
Loading