From a7e5c8d3666fa305f947a750de5f65514a3f17a8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Felix=20Geisend=C3=B6rfer?= Date: Fri, 5 Jul 2024 10:39:36 +0200 Subject: [PATCH] ddtrace/tracer: runtime metrics v2 --- ddtrace/tracer/option.go | 4 ++ ddtrace/tracer/slog.go | 64 +++++++++++++++++++++++++++++++ ddtrace/tracer/slog_test.go | 33 ++++++++++++++++ ddtrace/tracer/telemetry.go | 1 + ddtrace/tracer/tracer.go | 10 +++++ go.mod | 11 +++--- go.sum | 22 ++++++----- internal/apps/apps.go | 5 +++ internal/statsd.go | 2 + internal/statsdtest/statsdtest.go | 8 ++++ 10 files changed, 145 insertions(+), 15 deletions(-) create mode 100644 ddtrace/tracer/slog.go create mode 100644 ddtrace/tracer/slog_test.go diff --git a/ddtrace/tracer/option.go b/ddtrace/tracer/option.go index d8ce6843a2..e07d775d74 100644 --- a/ddtrace/tracer/option.go +++ b/ddtrace/tracer/option.go @@ -188,6 +188,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. @@ -377,6 +380,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.BoolVal("DD_RUNTIME_METRICS_V2_ENABLED", false) c.debug = internal.BoolVal(getDDorOtelConfig("debugMode"), false) c.enabled = newDynamicConfig("tracing_enabled", internal.BoolVal(getDDorOtelConfig("enabled"), true), func(b bool) bool { return true }, equal[bool]) if _, ok := os.LookupEnv("DD_TRACE_ENABLED"); ok { diff --git a/ddtrace/tracer/slog.go b/ddtrace/tracer/slog.go new file mode 100644 index 0000000000..09015eb14f --- /dev/null +++ b/ddtrace/tracer/slog.go @@ -0,0 +1,64 @@ +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()), ".") +} diff --git a/ddtrace/tracer/slog_test.go b/ddtrace/tracer/slog_test.go new file mode 100644 index 0000000000..c04c028760 --- /dev/null +++ b/ddtrace/tracer/slog_test.go @@ -0,0 +1,33 @@ +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)() + + // 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") +} diff --git a/ddtrace/tracer/telemetry.go b/ddtrace/tracer/telemetry.go index 7fec111383..31ddeddfb2 100644 --- a/ddtrace/tracer/telemetry.go +++ b/ddtrace/tracer/telemetry.go @@ -47,6 +47,7 @@ func startTelemetry(c *config) { {Name: "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}, {Name: "dogstatsd_addr", Value: c.dogstatsdAddr}, {Name: "trace_debug_enabled", Value: !c.noDebugStack}, {Name: "profiling_hotspots_enabled", Value: c.profilerHotspots}, diff --git a/ddtrace/tracer/tracer.go b/ddtrace/tracer/tracer.go index 35e3f2ce43..3d8711ef9a 100644 --- a/ddtrace/tracer/tracer.go +++ b/ddtrace/tracer/tracer.go @@ -8,6 +8,7 @@ package tracer import ( gocontext "context" "encoding/binary" + "log/slog" "math" "os" "runtime/pprof" @@ -32,6 +33,7 @@ import ( "gopkg.in/DataDog/dd-trace-go.v1/internal/traceprof" "github.com/DataDog/datadog-agent/pkg/obfuscate" + "github.com/DataDog/go-runtime-metrics-internal/pkg/runtimemetrics" ) var _ ddtrace.Tracer = (*tracer)(nil) @@ -307,6 +309,14 @@ func newTracer(opts ...StartOption) *tracer { t.reportRuntimeMetrics(defaultMetricsReportInterval) }() } + if c.runtimeMetricsV2 { + l := slog.New(slogHandler{}) + if err := runtimemetrics.Start(t.statsd, l); err == nil { + l.Debug("Runtime metrics v2 enabled.") + } else { + l.Error("Failed to enable runtime metrics v2", "err", err.Error()) + } + } if c.debugAbandonedSpans { log.Info("Abandoned spans logs enabled.") t.abandonedSpansDebugger = newAbandonedSpansDebugger() diff --git a/go.mod b/go.mod index c879e8440f..82660e73aa 100644 --- a/go.mod +++ b/go.mod @@ -8,8 +8,9 @@ require ( github.com/DataDog/appsec-internal-go v1.6.0 github.com/DataDog/datadog-agent/pkg/obfuscate v0.48.0 github.com/DataDog/datadog-agent/pkg/remoteconfig/state v0.48.1 - github.com/DataDog/datadog-go/v5 v5.3.0 + github.com/DataDog/datadog-go/v5 v5.5.0 github.com/DataDog/go-libddwaf/v3 v3.2.1 + github.com/DataDog/go-runtime-metrics-internal v0.0.0-20240703170703-20739ceb6063 github.com/DataDog/gostackparse v0.7.0 github.com/DataDog/sketches-go v1.4.5 github.com/IBM/sarama v1.40.0 @@ -255,12 +256,12 @@ require ( go.opentelemetry.io/otel/metric v1.20.0 // indirect golang.org/x/arch v0.4.0 // indirect golang.org/x/crypto v0.21.0 // indirect - golang.org/x/exp v0.0.0-20230321023759-10a507213a29 // indirect - golang.org/x/mod v0.14.0 // indirect - golang.org/x/sync v0.5.0 // indirect + golang.org/x/exp v0.0.0-20240213143201-ec583247a57a // indirect + golang.org/x/mod v0.16.0 // indirect + golang.org/x/sync v0.6.0 // indirect golang.org/x/term v0.18.0 // indirect golang.org/x/text v0.14.0 // indirect - golang.org/x/tools v0.16.1 // indirect + golang.org/x/tools v0.19.0 // indirect google.golang.org/appengine v1.6.7 // indirect google.golang.org/genproto v0.0.0-20230530153820-e85fd2cbaebc // indirect google.golang.org/genproto/googleapis/api v0.0.0-20230530153820-e85fd2cbaebc // indirect diff --git a/go.sum b/go.sum index dde9e28268..0b1d602c48 100644 --- a/go.sum +++ b/go.sum @@ -632,10 +632,12 @@ github.com/DataDog/datadog-agent/pkg/obfuscate v0.48.0/go.mod h1:HzySONXnAgSmIQf github.com/DataDog/datadog-agent/pkg/remoteconfig/state v0.48.1 h1:5nE6N3JSs2IG3xzMthNFhXfOaXlrsdgqmJ73lndFf8c= github.com/DataDog/datadog-agent/pkg/remoteconfig/state v0.48.1/go.mod h1:Vc+snp0Bey4MrrJyiV2tVxxJb6BmLomPvN1RgAvjGaQ= github.com/DataDog/datadog-go v3.2.0+incompatible/go.mod h1:LButxg5PwREeZtORoXG3tL4fMGNddJ+vMq1mwgfaqoQ= -github.com/DataDog/datadog-go/v5 v5.3.0 h1:2q2qjFOb3RwAZNU+ez27ZVDwErJv5/VpbBPprz7Z+s8= -github.com/DataDog/datadog-go/v5 v5.3.0/go.mod h1:XRDJk1pTc00gm+ZDiBKsjh7oOOtJfYfglVCmFb8C2+Q= +github.com/DataDog/datadog-go/v5 v5.5.0 h1:G5KHeB8pWBNXT4Jtw0zAkhdxEAWSpWH00geHI6LDrKU= +github.com/DataDog/datadog-go/v5 v5.5.0/go.mod h1:K9kcYBlxkcPP8tvvjZZKs/m1edNAUFzBbdpTUKfCsuw= github.com/DataDog/go-libddwaf/v3 v3.2.1 h1:lZPc6UxCOwioHc++nsldKR50FpIrRh1uGnGLuryqnE8= github.com/DataDog/go-libddwaf/v3 v3.2.1/go.mod h1:AP+7Atb8ftSsrha35wht7+K3R+xuzfVSQhabSO4w6CY= +github.com/DataDog/go-runtime-metrics-internal v0.0.0-20240703170703-20739ceb6063 h1:vGv1wZc9ztE0pV0SNVit5w7PSgnzs8wndArZpra7yfQ= +github.com/DataDog/go-runtime-metrics-internal v0.0.0-20240703170703-20739ceb6063/go.mod h1:zDQhUvRGwpo8egskalchVK7yoU+09H16wtMIG/aG3Hw= github.com/DataDog/go-tuf v1.0.2-0.5.2 h1:EeZr937eKAWPxJ26IykAdWA4A0jQXJgkhUjqEI/w7+I= github.com/DataDog/go-tuf v1.0.2-0.5.2/go.mod h1:zBcq6f654iVqmkk8n2Cx81E1JnNTMOAx1UEO/wZR+P0= github.com/DataDog/gostackparse v0.7.0 h1:i7dLkXHvYzHV308hnkvVGDL3BR4FWl7IsXNPz/IGQh4= @@ -2236,8 +2238,8 @@ golang.org/x/exp v0.0.0-20200119233911-0405dc783f0a/go.mod h1:2RIsYlXP63K8oxa1u0 golang.org/x/exp v0.0.0-20200207192155-f17229e696bd/go.mod h1:J/WKrq2StrnmMY6+EHIKF9dgMWnmCNThgcyBT1FY9mM= golang.org/x/exp v0.0.0-20200224162631-6cc2880d07d6/go.mod h1:3jZMyOhIsHpP37uCMkUooju7aAi5cS1Q23tOzKc+0MU= golang.org/x/exp v0.0.0-20220827204233-334a2380cb91/go.mod h1:cyybsKvd6eL0RnXn6p/Grxp8F5bW7iYuBgsNCOHpMYE= -golang.org/x/exp v0.0.0-20230321023759-10a507213a29 h1:ooxPy7fPvB4kwsA2h+iBNHkAbp/4JxTSwCmvdjEYmug= -golang.org/x/exp v0.0.0-20230321023759-10a507213a29/go.mod h1:CxIveKay+FTh1D0yPZemJVgC/95VzuuOLq5Qi4xnoYc= +golang.org/x/exp v0.0.0-20240213143201-ec583247a57a h1:HinSgX1tJRX3KsL//Gxynpw5CTOAIPhgL4W8PNiIpVE= +golang.org/x/exp v0.0.0-20240213143201-ec583247a57a/go.mod h1:CxmFvTBINI24O/j8iY7H1xHzx2i4OsyguNBmN/uPtqc= golang.org/x/image v0.0.0-20180708004352-c73c2afc3b81/go.mod h1:ux5Hcp/YLpHSI86hEcLt0YII63i6oz57MZXIpbrjZUs= golang.org/x/image v0.0.0-20190227222117-0694c2d4d067/go.mod h1:kZ7UVZpmo3dzQBMxlp+ypCbDeSB+sBbTgSJuh5dn5js= golang.org/x/image v0.0.0-20190802002840-cff245a6509b/go.mod h1:FeLwcggjj3mMvU+oOTbSwawSJRM1uh48EjtB4UJZlP0= @@ -2279,8 +2281,8 @@ golang.org/x/mod v0.5.1/go.mod h1:5OXOZSfqPIIbmVBIIKWRFfZjPR0E5r58TLhUjH0a2Ro= golang.org/x/mod v0.6.0-dev.0.20220419223038-86c51ed26bb4/go.mod h1:jJ57K6gSWd91VN4djpZkiMVwK6gcyfeH4XE8wZrZaV4= golang.org/x/mod v0.7.0/go.mod h1:iBbtSCu2XBx23ZKBPSOrRkjjQPZFPuis4dIYUhu/chs= golang.org/x/mod v0.8.0/go.mod h1:iBbtSCu2XBx23ZKBPSOrRkjjQPZFPuis4dIYUhu/chs= -golang.org/x/mod v0.14.0 h1:dGoOF9QVLYng8IHTm7BAyWqCqSheQ5pYWGhzW00YJr0= -golang.org/x/mod v0.14.0/go.mod h1:hTbmBsO62+eylJbnUtE2MGJUyE7QWk4xUqPFrRgJ+7c= +golang.org/x/mod v0.16.0 h1:QX4fJ0Rr5cPQCF7O9lh9Se4pmwfwskqZfq5moyldzic= +golang.org/x/mod v0.16.0/go.mod h1:hTbmBsO62+eylJbnUtE2MGJUyE7QWk4xUqPFrRgJ+7c= golang.org/x/net v0.0.0-20180218175443-cbe0f9307d01/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4= golang.org/x/net v0.0.0-20180724234803-3673e40ba225/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4= golang.org/x/net v0.0.0-20180826012351-8a410e7b638d/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4= @@ -2415,8 +2417,8 @@ golang.org/x/sync v0.0.0-20220819030929-7fc1605a5dde/go.mod h1:RxMgew5VJxzue5/jJ golang.org/x/sync v0.0.0-20220923202941-7f9b1623fab7/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= golang.org/x/sync v0.0.0-20220929204114-8fcdb60fdcc0/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= golang.org/x/sync v0.1.0/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= -golang.org/x/sync v0.5.0 h1:60k92dhOjHxJkrqnwsfl8KuaHbn/5dl0lUPUklKo3qE= -golang.org/x/sync v0.5.0/go.mod h1:Czt+wKu1gCyEFDUtn0jG5QVvpJ6rzVqr5aXyt9drQfk= +golang.org/x/sync v0.6.0 h1:5BMeUDZ7vkXGfEr1x9B4bRcTH4lpkTkpdh0T/J+qjbQ= +golang.org/x/sync v0.6.0/go.mod h1:Czt+wKu1gCyEFDUtn0jG5QVvpJ6rzVqr5aXyt9drQfk= golang.org/x/sys v0.0.0-20180823144017-11551d06cbcc/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= golang.org/x/sys v0.0.0-20180830151530-49385e6e1522/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= golang.org/x/sys v0.0.0-20180905080454-ebe1bf3edb33/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= @@ -2688,8 +2690,8 @@ golang.org/x/tools v0.1.12/go.mod h1:hNGJHUnrk76NpqgfD5Aqm5Crs+Hm0VOH/i9J2+nxYbc golang.org/x/tools v0.3.0/go.mod h1:/rWhSS2+zyEVwoJf8YAX6L2f0ntZ7Kn/mGgAWcipA5k= golang.org/x/tools v0.4.0/go.mod h1:UE5sM2OK9E/d67R0ANs2xJizIymRP5gJU295PvKXxjQ= golang.org/x/tools v0.6.0/go.mod h1:Xwgl3UAJ/d3gWutnCtw505GrjyAbvKui8lOU390QaIU= -golang.org/x/tools v0.16.1 h1:TLyB3WofjdOEepBHAU20JdNC1Zbg87elYofWYAY5oZA= -golang.org/x/tools v0.16.1/go.mod h1:kYVVN6I1mBNoB1OX+noeBjbRk4IUEPa7JJ+TJMEooJ0= +golang.org/x/tools v0.19.0 h1:tfGCXNR1OsFG+sVdLAitlpjAvD/I6dHDKnYrpEZUHkw= +golang.org/x/tools v0.19.0/go.mod h1:qoJWxmGSIBmAeriMx19ogtrEPrGtDbPK634QFIcLAhc= golang.org/x/xerrors v0.0.0-20190717185122-a985d3407aa7/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= golang.org/x/xerrors v0.0.0-20191011141410-1b5146add898/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= golang.org/x/xerrors v0.0.0-20191204190536-9bdfabe68543/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= diff --git a/internal/apps/apps.go b/internal/apps/apps.go index 27518f478e..4ac7a6e205 100644 --- a/internal/apps/apps.go +++ b/internal/apps/apps.go @@ -40,6 +40,11 @@ func (c Config) RunHTTP(handler func() http.Handler) { os.Setenv("DD_PROFILING_EXECUTION_TRACE_PERIOD", "1s") } + // Enabled runtime metrics v2 by default + if v := os.Getenv("DD_RUNTIME_METRICS_V2_ENABLED"); v == "" { + os.Setenv("DD_RUNTIME_METRICS_V2_ENABLED", "true") + } + // Setup context that gets canceled on receiving SIGINT ctx, stop := signal.NotifyContext(context.Background(), os.Interrupt) defer stop() diff --git a/internal/statsd.go b/internal/statsd.go index a901759f27..df1d18a307 100644 --- a/internal/statsd.go +++ b/internal/statsd.go @@ -16,7 +16,9 @@ const DefaultDogstatsdAddr = "localhost:8125" type StatsdClient interface { Incr(name string, tags []string, rate float64) error Count(name string, value int64, tags []string, rate float64) error + CountWithTimestamp(name string, value int64, tags []string, rate float64, timestamp time.Time) error Gauge(name string, value float64, tags []string, rate float64) error + GaugeWithTimestamp(name string, value float64, tags []string, rate float64, timestamp time.Time) error Timing(name string, value time.Duration, tags []string, rate float64) error Flush() error Close() error diff --git a/internal/statsdtest/statsdtest.go b/internal/statsdtest/statsdtest.go index b48e3b753a..2e6e676731 100644 --- a/internal/statsdtest/statsdtest.go +++ b/internal/statsdtest/statsdtest.go @@ -62,6 +62,10 @@ func (tg *TestStatsdClient) Gauge(name string, value float64, tags []string, rat }) } +func (tg *TestStatsdClient) GaugeWithTimestamp(name string, value float64, tags []string, rate float64, timestamp time.Time) error { + panic("not implemented yet") +} + func (tg *TestStatsdClient) Incr(name string, tags []string, rate float64) error { tg.addCount(name, 1) return tg.addMetric(callTypeIncr, tags, TestStatsdCall{ @@ -81,6 +85,10 @@ func (tg *TestStatsdClient) Count(name string, value int64, tags []string, rate }) } +func (tg *TestStatsdClient) CountWithTimestamp(name string, value int64, tags []string, rate float64, timestamp time.Time) error { + panic("not implemented yet") +} + func (tg *TestStatsdClient) Timing(name string, value time.Duration, tags []string, rate float64) error { return tg.addMetric(callTypeTiming, tags, TestStatsdCall{ name: name,