feat(telemetry): implement secure telemetry logging with PII protection (#3948)

Signed-off-by: Kemal Akkoyun <[email protected]>

Author: kakkoyun

Makefile

@@ -32,6 +32,10 @@ generate: tools-install ## Run code generation
 lint: tools-install ## Run linting checks
 	$(BIN_PATH) ./scripts/lint.sh --all
 
+.PHONY: lint/go
+lint/go: tools-install ## Run Go linting checks
+	$(BIN_PATH) golangci-lint run ./...
+
 .PHONY: lint-fix
 lint-fix: tools-install ## Fix linting issues automatically
 	$(BIN_PATH) golangci-lint run --fix ./...

contrib/net/http/internal/wrap/roundtrip.go

@@ -52,7 +52,7 @@ func (t *httpTraceTimings) addTimingTags(span *tracer.Span) {
 	t.addDurationTag(span, "http.tls.duration_ms", t.tlsStart, t.tlsEnd)
 	t.addDurationTag(span, "http.get_conn.duration_ms", t.getConnStart, t.gotConn)
 	t.addDurationTag(span, "http.first_byte.duration_ms", t.wroteHeaders, t.gotFirstByte)
-	
+
 	// Add error information if present
 	if t.connectErr != nil {
 		span.SetTag("http.connect.error", t.connectErr.Error())

ddtrace/opentelemetry/tracer.go

@@ -9,12 +9,13 @@ import (
 	"context"
 	"encoding/binary"
 	"encoding/hex"
+	"log/slog"
 
 	"github.com/DataDog/dd-trace-go/v2/ddtrace/baggage"
 	"github.com/DataDog/dd-trace-go/v2/ddtrace/ext"
 	"github.com/DataDog/dd-trace-go/v2/ddtrace/tracer"
 	"github.com/DataDog/dd-trace-go/v2/internal/telemetry"
-	"github.com/DataDog/dd-trace-go/v2/internal/telemetry/log"
+	telemetrylog "github.com/DataDog/dd-trace-go/v2/internal/telemetry/log"
 
 	otelbaggage "go.opentelemetry.io/otel/baggage"
 	oteltrace "go.opentelemetry.io/otel/trace"
@@ -128,7 +129,7 @@ func mergeBaggageFromContext(ctx context.Context) otelbaggage.Baggage {
 				if err == nil {
 					otelBag = b
 				} else {
-					log.Debug("Error adding baggage member with key %s; dropping", key)
+					telemetrylog.Debug("Error adding baggage member; dropping", slog.String("key", key))
 				}
 			}
 		}

ddtrace/tracer/log.go

@@ -9,6 +9,7 @@ import (
 	"bytes"
 	"encoding/json"
 	"fmt"
+	"log/slog"
 	"math"
 	"net/http"
 	"runtime"
@@ -173,5 +174,5 @@ func logStartup(t *tracer) {
 		return
 	}
 	log.Info("DATADOG TRACER CONFIGURATION %s\n", string(bs))
-	telemetrylog.Debug("DATADOG TRACER CONFIGURATION %s\n", string(bs))
+	telemetrylog.Debug("DATADOG TRACER CONFIGURATION", slog.String("config", string(bs)))
 }

instrumentation/appsec/emitter/httpsec/http.go

@@ -177,7 +177,8 @@ func RouteMatched(ctx context.Context, route string, routeParams map[string]stri
 	op, ok := dyngo.FindOperation[HandlerOperation](ctx)
 	if !ok {
 		log.Debug("appsec: RouteMatched called without an active HandlerOperation in the context, ignoring")
-		telemetrylog.Warn("appsec: RouteMatched called without an active HandlerOperation in the context, ignoring", telemetry.WithTags([]string{"product:appsec"}))
+		telemetrylog.With(telemetry.WithTags([]string{"product:appsec"})).
+			Warn("appsec: RouteMatched called without an active HandlerOperation in the context, ignoring")
 		return nil
 	}
 

instrumentation/appsec/emitter/waf/actions/actions.go

@@ -6,6 +6,9 @@
 package actions
 
 import (
+	"fmt"
+	"log/slog"
+
 	"github.com/DataDog/dd-trace-go/v2/instrumentation/appsec/dyngo"
 	"github.com/DataDog/dd-trace-go/v2/internal/log"
 	telemetrylog "github.com/DataDog/dd-trace-go/v2/internal/telemetry/log"
@@ -42,15 +45,15 @@ func SendActionEvents(op dyngo.Operation, actions map[string]any) bool {
 		log.Debug("appsec: processing %q action with params %v", aType, params) //nolint:gocritic
 		params, ok := params.(map[string]any)
 		if !ok {
-			telemetrylog.Error("appsec: could not cast action params to map[string]any from %T", params)
+			telemetrylog.Error("appsec: could not cast action params to map[string]any", slog.String("actual_type", fmt.Sprintf("%T", params)))
 			continue
 		}
 
 		blocked = blocked || aType == "block_request"
 
 		actionHandler, ok := actionHandlers[aType]
 		if !ok {
-			telemetrylog.Error("appsec: unknown action type `%s`", aType)
+			telemetrylog.Error("appsec: unknown action type", slog.String("action_type", aType))
 			continue
 		}
 

instrumentation/instrumentation.go

@@ -17,6 +17,7 @@ import (
 	"github.com/DataDog/dd-trace-go/v2/internal/normalizer"
 	"github.com/DataDog/dd-trace-go/v2/internal/stableconfig"
 	"github.com/DataDog/dd-trace-go/v2/internal/telemetry"
+	telemetrylog "github.com/DataDog/dd-trace-go/v2/internal/telemetry/log"
 	"github.com/DataDog/dd-trace-go/v2/internal/version"
 )
 
@@ -35,9 +36,11 @@ func Load(pkg Package) *Instrumentation {
 	tracer.MarkIntegrationImported(info.TracedPackage)
 
 	return &Instrumentation{
-		pkg:    pkg,
-		logger: newLogger(pkg),
-		info:   info,
+		logger:       newLogger(pkg),
+		telemetrylog: telemetrylog.With(telemetry.WithTags([]string{"integration:" + string(pkg)})),
+
+		pkg:  pkg,
+		info: info,
 	}
 }
 
@@ -53,9 +56,11 @@ func Version() string {
 
 // Instrumentation represents instrumentation for a package.
 type Instrumentation struct {
-	pkg    Package
-	logger Logger
-	info   PackageInfo
+	logger       Logger
+	telemetrylog *telemetrylog.Logger
+
+	pkg  Package
+	info PackageInfo
 }
 
 // ServiceName returns the default service name to be set for the given instrumentation component.
@@ -93,6 +98,10 @@ func (i *Instrumentation) Logger() Logger {
 	return i.logger
 }
 
+func (i *Instrumentation) TelemetryLog() *telemetrylog.Logger {
+	return i.telemetrylog
+}
+
 func (i *Instrumentation) AnalyticsRate(defaultGlobal bool) float64 {
 	if internal.BoolEnv("DD_TRACE_"+i.info.EnvVarPrefix+"_ANALYTICS_ENABLED", false) {
 		return 1.0
@@ -145,9 +154,7 @@ type StatsdClient = internal.StatsdClient
 func (i *Instrumentation) StatsdClient(extraTags []string) (StatsdClient, error) {
 	addr := globalconfig.DogstatsdAddr()
 	tags := globalconfig.StatsTags()
-	for _, tag := range extraTags {
-		tags = append(tags, tag)
-	}
+	tags = append(tags, extraTags...)
 	return internal.NewStatsdClient(addr, tags)
 }
 

internal/appsec/appsec.go

@@ -7,6 +7,7 @@ package appsec
 
 import (
 	"fmt"
+	"log/slog"
 	"sync"
 
 	"github.com/DataDog/go-libddwaf/v4"
@@ -74,7 +75,7 @@ func Start(opts ...config.StartOption) {
 		} else {
 			// DD_APPSEC_ENABLED is not set so we cannot know what the intent is here, we must log a
 			// debug message instead to avoid showing an error to APM-tracing-only users.
-			telemetrylog.Error("appsec: remote activation of threats detection cannot be enabled for the following reasons: %s", err.Error())
+			telemetrylog.Error("appsec: remote activation of threats detection cannot be enabled", slog.Any("error", telemetrylog.NewSafeError(err)))
 		}
 		return
 	}
@@ -90,7 +91,7 @@ func Start(opts ...config.StartOption) {
 	// Start the remote configuration client
 	log.Debug("appsec: starting the remote configuration client")
 	if err := appsec.startRC(); err != nil {
-		telemetrylog.Error("appsec: Remote config: disabled due to an instanciation error: %s", err.Error())
+		telemetrylog.Error("appsec: Remote config: disabled due to an instantiation error", slog.Any("error", telemetrylog.NewSafeError(err)))
 	}
 
 	if mode == config.RCStandby {
@@ -119,7 +120,8 @@ func Start(opts ...config.StartOption) {
 // Implement the AppSec log message C1
 func logUnexpectedStartError(err error) {
 	log.Error("appsec: could not start because of an unexpected error: %s\nNo security activities will be collected. Please contact support at https://docs.datadoghq.com/help/ for help.", err.Error())
-	telemetry.Log(telemetry.LogError, fmt.Sprintf("appsec: could not start because of an unexpected error: %s", err.Error()), telemetry.WithTags([]string{"product:appsec"}))
+
+	telemetrylog.Error("appsec: could not start because of an unexpected error", slog.Any("error", telemetrylog.NewSafeError(err)))
 	telemetry.ProductStartError(telemetry.NamespaceAppSec, err)
 }
 

internal/appsec/config/config.go

@@ -7,13 +7,14 @@ package config
 
 import (
 	"fmt"
+	"log/slog"
 	"time"
 
 	sharedinternal "github.com/DataDog/dd-trace-go/v2/internal"
 	"github.com/DataDog/dd-trace-go/v2/internal/remoteconfig"
 	"github.com/DataDog/dd-trace-go/v2/internal/stableconfig"
 	"github.com/DataDog/dd-trace-go/v2/internal/telemetry"
-	"github.com/DataDog/dd-trace-go/v2/internal/telemetry/log"
+	telemetrylog "github.com/DataDog/dd-trace-go/v2/internal/telemetry/log"
 )
 
 func init() {
@@ -26,7 +27,7 @@ func init() {
 func registerSCAAppConfigTelemetry() {
 	_, _, err := stableconfig.Bool(EnvSCAEnabled, false)
 	if err != nil {
-		log.Error("appsec: %s", err.Error())
+		telemetrylog.Error("appsec: failed to get SCA config", slog.Any("error", telemetrylog.NewSafeError(err)))
 		return
 	}
 }

internal/appsec/config/config_test.go

@@ -6,10 +6,12 @@
 package config
 
 import (
+	"strings"
 	"testing"
 
 	"github.com/DataDog/dd-trace-go/v2/internal/telemetry"
 	"github.com/DataDog/dd-trace-go/v2/internal/telemetry/telemetrytest"
+	"github.com/stretchr/testify/mock"
 )
 
 func TestSCAEnabled(t *testing.T) {
@@ -42,7 +44,7 @@ func TestSCAEnabled(t *testing.T) {
 			name:              "parsing error",
 			envVarVal:         "not a boolean string representation [at {all!}]",
 			telemetryExpected: false,
-			telemetryLog:      "appsec: non-boolean value for DD_APPSEC_SCA_ENABLED: 'not a boolean string representation [at {all!}]' in env_var configuration, dropping",
+			telemetryLog:      "appsec: failed to get SCA config",
 			expectedValue:     false,
 		},
 	} {
@@ -54,8 +56,13 @@ func TestSCAEnabled(t *testing.T) {
 			telemetryClient := new(telemetrytest.MockClient)
 			telemetryClient.On("RegisterAppConfigs", []telemetry.Configuration{{Name: EnvSCAEnabled, Value: tc.expectedValue, Origin: telemetry.OriginEnvVar}}).Return()
 			telemetryClient.On("RegisterAppConfig", EnvSCAEnabled, tc.expectedValue, telemetry.OriginEnvVar).Return()
+
+			var logMatcher any
 			if tc.telemetryLog != "" {
-				telemetryClient.On("Log", telemetry.LogError, tc.telemetryLog, []telemetry.LogOption(nil)).Return()
+				logMatcher = mock.MatchedBy(func(record telemetry.Record) bool {
+					return strings.HasPrefix(record.Message, tc.telemetryLog)
+				})
+				telemetryClient.On("Log", logMatcher, []telemetry.LogOption(nil)).Return()
 			}
 			defer telemetry.MockClient(telemetryClient)()
 
@@ -68,7 +75,7 @@ func TestSCAEnabled(t *testing.T) {
 				telemetryClient.AssertNumberOfCalls(t, "RegisterAppConfigs", 0)
 			}
 			if tc.telemetryLog != "" {
-				telemetryClient.AssertCalled(t, "Log", telemetry.LogError, tc.telemetryLog, []telemetry.LogOption(nil))
+				telemetryClient.AssertCalled(t, "Log", logMatcher, []telemetry.LogOption(nil))
 			}
 		})
 	}