internal/appsec/waf: add WAF metrics

contrib/gin-gonic/gin/appsec.go

@@ -9,6 +9,7 @@ import (
 	"net"
 
 	"gopkg.in/DataDog/dd-trace-go.v1/ddtrace/tracer"
+	"gopkg.in/DataDog/dd-trace-go.v1/internal/appsec/dyngo/instrumentation"
 	"gopkg.in/DataDog/dd-trace-go.v1/internal/appsec/dyngo/instrumentation/httpsec"
 
 	"github.com/gin-gonic/gin"
@@ -38,5 +39,6 @@ func useAppSec(c *gin.Context, span tracer.Span) func() {
 			}
 			httpsec.SetSecurityEventTags(span, events, remoteIP, args.Headers, c.Writer.Header())
 		}
+		instrumentation.SetTags(span, op.Tags())
 	}
 }

contrib/google.golang.org/grpc/appsec.go

@@ -10,6 +10,7 @@ import (
 	"net"
 
 	"gopkg.in/DataDog/dd-trace-go.v1/ddtrace"
+	"gopkg.in/DataDog/dd-trace-go.v1/internal/appsec/dyngo/instrumentation"
 	"gopkg.in/DataDog/dd-trace-go.v1/internal/appsec/dyngo/instrumentation/grpcsec"
 	"gopkg.in/DataDog/dd-trace-go.v1/internal/appsec/dyngo/instrumentation/httpsec"
 
@@ -27,6 +28,7 @@ func appsecUnaryHandlerMiddleware(span ddtrace.Span, handler grpc.UnaryHandler)
 		op := grpcsec.StartHandlerOperation(grpcsec.HandlerOperationArgs{Metadata: md}, nil)
 		defer func() {
 			events := op.Finish(grpcsec.HandlerOperationRes{})
+			instrumentation.SetTags(span, op.Tags())
 			if len(events) == 0 {
 				return
 			}
@@ -45,6 +47,7 @@ func appsecStreamHandlerMiddleware(span ddtrace.Span, handler grpc.StreamHandler
 		op := grpcsec.StartHandlerOperation(grpcsec.HandlerOperationArgs{Metadata: md}, nil)
 		defer func() {
 			events := op.Finish(grpcsec.HandlerOperationRes{})
+			instrumentation.SetTags(span, op.Tags())
 			if len(events) == 0 {
 				return
 			}

contrib/labstack/echo.v4/appsec.go

@@ -9,6 +9,7 @@ import (
 	"net"
 
 	"gopkg.in/DataDog/dd-trace-go.v1/ddtrace/tracer"
+	"gopkg.in/DataDog/dd-trace-go.v1/internal/appsec/dyngo/instrumentation"
 	"gopkg.in/DataDog/dd-trace-go.v1/internal/appsec/dyngo/instrumentation/httpsec"
 
 	"github.com/labstack/echo/v4"
@@ -33,5 +34,6 @@ func useAppSec(c echo.Context, span tracer.Span) func() {
 			}
 			httpsec.SetSecurityEventTags(span, events, remoteIP, args.Headers, c.Response().Writer.Header())
 		}
+		instrumentation.SetTags(span, op.Tags())
 	}
 }

internal/appsec/dyngo/instrumentation/common.go

@@ -0,0 +1,66 @@
+// 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 2022 Datadog, Inc.
+
+// Package instrumentation holds code commonly used between all instrumentation declinations (currently httpsec/grpcsec).
+package instrumentation
+
+import (
+	"encoding/json"
+	"sync"
+
+	"gopkg.in/DataDog/dd-trace-go.v1/ddtrace"
+)
+
+// TagsHolder wraps a map holding tags. The purpose of this struct is to be used by composition in an Operation
+// to allow said operation to handle tags addition/retrieval. See httpsec/http.go and grpcsec/grpc.go.
+type TagsHolder struct {
+	tags map[string]interface{}
+	mu   sync.Mutex
+}
+
+// NewTagsHolder returns a new instance of a TagsHolder struct.
+func NewTagsHolder() TagsHolder {
+	return TagsHolder{tags: map[string]interface{}{}}
+}
+
+// AddTag adds the key/value pair to the tags map
+func (m *TagsHolder) AddTag(k string, v interface{}) {
+	m.mu.Lock()
+	defer m.mu.Unlock()
+	m.tags[k] = v
+}
+
+// Tags returns the tags map
+func (m *TagsHolder) Tags() map[string]interface{} {
+	return m.tags
+}
+
+// SecurityEventsHolder is a wrapper around a thread safe security events slice. The purpose of this struct is to be
+// used by composition in an Operation to allow said operation to handle security events addition/retrieval.
+// See httpsec/http.go and grpcsec/grpc.go.
+type SecurityEventsHolder struct {
+	events []json.RawMessage
+	mu     sync.Mutex
+}
+
+// AddSecurityEvents adds the security events to the collected events list.
+// Thread safe.
+func (s *SecurityEventsHolder) AddSecurityEvents(events ...json.RawMessage) {
+	s.mu.Lock()
+	defer s.mu.Unlock()
+	s.events = append(s.events, events...)
+}
+
+// Events returns the list of stored events.
+func (s *SecurityEventsHolder) Events() []json.RawMessage {
+	return s.events
+}
+
+// SetTags fills the span tags using the key/value pairs found in `tags`
+func SetTags(span ddtrace.Span, tags map[string]interface{}) {
+	for k, v := range tags {
+		span.SetTag(k, v)
+	}
+}

internal/appsec/dyngo/instrumentation/grpcsec/grpc.go

@@ -12,9 +12,9 @@ package grpcsec
 import (
 	"encoding/json"
 	"reflect"
-	"sync"
 
 	"gopkg.in/DataDog/dd-trace-go.v1/internal/appsec/dyngo"
+	"gopkg.in/DataDog/dd-trace-go.v1/internal/appsec/dyngo/instrumentation"
 )
 
 // Abstract gRPC server handler operation definitions. It is based on two
@@ -37,9 +37,8 @@ type (
 	// to the operation using its AddSecurityEvent() method.
 	HandlerOperation struct {
 		dyngo.Operation
-
-		events []json.RawMessage
-		mu     sync.Mutex
+		instrumentation.TagsHolder
+		instrumentation.SecurityEventsHolder
 	}
 	// HandlerOperationArgs is the grpc handler arguments.
 	HandlerOperationArgs struct {
@@ -74,7 +73,10 @@ type (
 // operation stack. When parent is nil, the operation is linked to the global
 // root operation.
 func StartHandlerOperation(args HandlerOperationArgs, parent dyngo.Operation) *HandlerOperation {
-	op := &HandlerOperation{Operation: dyngo.NewOperation(parent)}
+	op := &HandlerOperation{
+		Operation:  dyngo.NewOperation(parent),
+		TagsHolder: instrumentation.NewTagsHolder(),
+	}
 	dyngo.StartOperation(op, args)
 	return op
 }
@@ -83,15 +85,7 @@ func StartHandlerOperation(args HandlerOperationArgs, parent dyngo.Operation) *H
 // finish event up in the operation stack.
 func (op *HandlerOperation) Finish(res HandlerOperationRes) []json.RawMessage {
 	dyngo.FinishOperation(op, res)
-	return op.events
-}
-
-// AddSecurityEvent adds the security event to the list of events observed
-// during the operation lifetime.
-func (op *HandlerOperation) AddSecurityEvent(events []json.RawMessage) {
-	op.mu.Lock()
-	defer op.mu.Unlock()
-	op.events = append(op.events, events...)
+	return op.Events()
 }
 
 // gRPC handler operation's start and finish event callback function types.

internal/appsec/dyngo/instrumentation/grpcsec/grpc_test.go

@@ -48,7 +48,7 @@ func TestUsage(t *testing.T) {
 						require.Equal(t, expectedMessage, res.Message)
 						recvFinished++
 
-						handlerOp.AddSecurityEvent([]json.RawMessage{json.RawMessage(expectedMessage)})
+						handlerOp.AddSecurityEvents(json.RawMessage(expectedMessage))
 					}))
 				}))
 

internal/appsec/dyngo/instrumentation/httpsec/http.go

@@ -20,6 +20,7 @@ import (
 
 	"gopkg.in/DataDog/dd-trace-go.v1/ddtrace"
 	"gopkg.in/DataDog/dd-trace-go.v1/internal/appsec/dyngo"
+	"gopkg.in/DataDog/dd-trace-go.v1/internal/appsec/dyngo/instrumentation"
 	"gopkg.in/DataDog/dd-trace-go.v1/internal/log"
 )
 
@@ -81,6 +82,7 @@ func WrapHandler(handler http.Handler, span ddtrace.Span, pathParams map[string]
 				status = mw.Status()
 			}
 			events := op.Finish(HandlerOperationRes{Status: status})
+			instrumentation.SetTags(span, op.Tags())
 			if len(events) == 0 {
 				return
 			}
@@ -129,7 +131,8 @@ func MakeHandlerOperationArgs(r *http.Request, pathParams map[string]string) Han
 type (
 	Operation struct {
 		dyngo.Operation
-		events json.RawMessage
+		instrumentation.TagsHolder
+		instrumentation.SecurityEventsHolder
 	}
 
 	// SDKBodyOperation type representing an SDK body. It must be created with
@@ -146,7 +149,10 @@ type (
 // The operation is linked to the global root operation since an HTTP operation
 // is always expected to be first in the operation stack.
 func StartOperation(ctx context.Context, args HandlerOperationArgs) (context.Context, *Operation) {
-	op := &Operation{Operation: dyngo.NewOperation(nil)}
+	op := &Operation{
+		Operation:  dyngo.NewOperation(nil),
+		TagsHolder: instrumentation.NewTagsHolder(),
+	}
 	newCtx := context.WithValue(ctx, contextKey{}, op)
 	dyngo.StartOperation(op, args)
 	return newCtx, op
@@ -162,7 +168,10 @@ func fromContext(ctx context.Context) *Operation {
 // finish event up in the operation stack.
 func (op *Operation) Finish(res HandlerOperationRes) json.RawMessage {
 	dyngo.FinishOperation(op, res)
-	return op.events
+	if events := op.Events(); len(events) > 0 {
+		return events[0]
+	}
+	return json.RawMessage{}
 }
 
 // StartSDKBodyOperation starts the SDKBody operation and emits a start event
@@ -177,15 +186,6 @@ func (op *SDKBodyOperation) Finish() {
 	dyngo.FinishOperation(op, SDKBodyOperationRes{})
 }
 
-// AddSecurityEvent adds the security event to the list of events observed
-// during the operation lifetime.
-func (op *Operation) AddSecurityEvent(event json.RawMessage) {
-	// TODO(Julio-Guerra): the current situation involves only one event per
-	//   operation. In the future, multiple events per operation will become
-	//   possible and the append operation should be made thread-safe.
-	op.events = event
-}
-
 // HTTP handler operation's start and finish event callback function types.
 type (
 	// OnHandlerOperationStart function type, called when an HTTP handler

internal/appsec/waf.go

@@ -17,13 +17,23 @@ import (
 	"sync/atomic"
 	"time"
 
+	"gopkg.in/DataDog/dd-trace-go.v1/ddtrace/ext"
 	"gopkg.in/DataDog/dd-trace-go.v1/internal/appsec/dyngo"
 	"gopkg.in/DataDog/dd-trace-go.v1/internal/appsec/dyngo/instrumentation/grpcsec"
 	"gopkg.in/DataDog/dd-trace-go.v1/internal/appsec/dyngo/instrumentation/httpsec"
 	"gopkg.in/DataDog/dd-trace-go.v1/internal/appsec/waf"
 	"gopkg.in/DataDog/dd-trace-go.v1/internal/log"
 )
 
+const (
+	eventRulesVersionTag = "_dd.appsec.event_rules.version"
+	eventRulesErrorsTag  = "_dd.appsec.event_rules.errors"
+	eventRulesLoadedTag  = "_dd.appsec.event_rules.loaded"
+	eventRulesFailedTag  = "_dd.appsec.event_rules.error_count"
+	wafDurationTag       = "_dd.appsec.waf.duration"
+	wafDurationExtTag    = "_dd.appsec.waf.duration_ext"
+)
+
 // Register the WAF event listener.
 func registerWAF(rules []byte, timeout time.Duration, limiter Limiter) (unreg dyngo.UnregisterFunc, err error) {
 	// Check the WAF is healthy
@@ -81,6 +91,7 @@ func registerWAF(rules []byte, timeout time.Duration, limiter Limiter) (unreg dy
 
 // newWAFEventListener returns the WAF event listener to register in order to enable it.
 func newHTTPWAFEventListener(handle *waf.Handle, addresses []string, timeout time.Duration, limiter Limiter) dyngo.EventListener {
+	var once sync.Once
 	return httpsec.OnHandlerOperationStart(func(op *httpsec.Operation, args httpsec.HandlerOperationArgs) {
 		var body interface{}
 		op.On(httpsec.OnSDKBodyOperationStart(func(op *httpsec.SDKBodyOperation, args httpsec.SDKBodyOperationArgs) {
@@ -126,15 +137,30 @@ func newHTTPWAFEventListener(handle *waf.Handle, addresses []string, timeout tim
 					values[serverResponseStatusAddr] = res.Status
 				}
 			}
+			wafRunStartTime := time.Now()
 			matches := runWAF(wafCtx, values, timeout)
+			overallWAFRunDuration := time.Since(wafRunStartTime)
+
+			// Log WAF metrics.
+			// time.Duration.Microseconds() is only as of go1.13, so we do it manually here
+			op.AddTag(wafDurationTag, float64(wafCtx.TotalRuntime()/1e3))
+			op.AddTag(wafDurationExtTag, float64(overallWAFRunDuration.Nanoseconds()/1e3))
+			once.Do(func() {
+				rInfo := handle.RulesetInfo()
+				op.AddTag(eventRulesVersionTag, rInfo.Version)
+				op.AddTag(eventRulesErrorsTag, rInfo.Errors)
+				op.AddTag(eventRulesLoadedTag, float64(rInfo.Loaded))
+				op.AddTag(eventRulesFailedTag, float64(rInfo.Failed))
+				op.AddTag(ext.ManualKeep, true)
+			})
 
 			// Log the attacks if any
 			if len(matches) == 0 {
 				return
 			}
 			log.Debug("appsec: attack detected by the waf")
 			if limiter.Allow() {
-				op.AddSecurityEvent(matches)
+				op.AddSecurityEvents(matches)
 			}
 		}))
 
@@ -149,8 +175,11 @@ func newGRPCWAFEventListener(handle *waf.Handle, _ []string, timeout time.Durati
 		// receive unlimited number of messages where we could find security events
 		const maxWAFEventsPerRequest = 10
 		var (
-			nbEvents uint32
-			logOnce  sync.Once
+			nbEvents               uint32
+			logOnce                sync.Once
+			metricsOnce            sync.Once
+			wafRunDuration         waf.AtomicDuration
+			wafBindingsRunDuration waf.AtomicDuration
 
 			events []json.RawMessage
 			mu     sync.Mutex
@@ -184,7 +213,13 @@ func newGRPCWAFEventListener(handle *waf.Handle, _ []string, timeout time.Durati
 			if md := handlerArgs.Metadata; len(md) > 0 {
 				values[grpcServerRequestMetadata] = md
 			}
+			now := time.Now()
 			event := runWAF(wafCtx, values, timeout)
+			// WAF run durations are WAF context bound. As of now we need to keep track of those externally since
+			// we use a new WAF context for each callback. When we are able to re-use the same WAF context across
+			// callbacks, we can get rid of these variables and simply use the WAF bindings in OnHandlerOperationFinish.
+			wafBindingsRunDuration.Add(uint64(time.Since(now).Nanoseconds()))
+			wafRunDuration.Add(wafCtx.TotalRuntime())
 			if len(event) == 0 {
 				return
 			}
@@ -195,8 +230,19 @@ func newGRPCWAFEventListener(handle *waf.Handle, _ []string, timeout time.Durati
 			mu.Unlock()
 		}))
 		op.On(grpcsec.OnHandlerOperationFinish(func(op *grpcsec.HandlerOperation, _ grpcsec.HandlerOperationRes) {
+			op.AddTag(wafDurationTag, float64(wafRunDuration/1e3))
+			op.AddTag(wafDurationExtTag, float64(wafBindingsRunDuration/1e3))
+
+			metricsOnce.Do(func() {
+				rInfo := handle.RulesetInfo()
+				op.AddTag(eventRulesVersionTag, rInfo.Version)
+				op.AddTag(eventRulesErrorsTag, rInfo.Errors)
+				op.AddTag(eventRulesLoadedTag, float64(rInfo.Loaded))
+				op.AddTag(eventRulesFailedTag, float64(rInfo.Failed))
+				op.AddTag(ext.ManualKeep, true)
+			})
 			if len(events) > 0 && limiter.Allow() {
-				op.AddSecurityEvent(events)
+				op.AddSecurityEvents(events...)
 			}
 		}))
 	})