Issue 5230

internal/internal.go

@@ -44,6 +44,8 @@ import (
 	"github.com/open-policy-agent/opa/tracing"
 	"github.com/open-policy-agent/opa/util"
 
+	"go.opentelemetry.io/otel/trace"
+
 	"github.com/open-policy-agent/opa-envoy-plugin/envoyauth"
 	internal_util "github.com/open-policy-agent/opa-envoy-plugin/internal/util"
 	"github.com/open-policy-agent/opa-envoy-plugin/opa/decisionlog"
@@ -519,6 +521,12 @@ func (p *envoyExtAuthzGrpcServer) log(ctx context.Context, input interface{}, re
 		info.Path = p.cfg.Path
 	}
 
+	sctx := trace.SpanFromContext(ctx).SpanContext()
+	if sctx.IsValid() {
+		info.TraceID = sctx.TraceID().String()
+		info.SpanID = sctx.SpanID().String()
+	}
+
 	if result.NDBuiltinCache != nil {
 		x, err := ast.JSON(result.NDBuiltinCache.AsValue())
 		if err != nil {

internal/internal_test.go

@@ -49,6 +49,8 @@ const exampleAllowedRequest = `{
 			"x-b3-sampled": "1",
 			"x-b3-spanid": "537f473f27475073",
 			"x-b3-traceid": "537f473f27475073",
+			"traceparent" : "00-0000000000000000f7bea0490c3cb268-b9543a567b0289f8-01",
+			"tracestate" : "rojo=00f067aa0ba902b7",
 			"x-envoy-internal": "true",
 			"x-forwarded-for": "172.17.0.1",
 			"x-forwarded-proto": "http",

test/e2e/distributedtracing/distributedtracing_test.go

@@ -12,6 +12,7 @@ import (
 
 	ext_authz "github.com/envoyproxy/go-control-plane/envoy/service/auth/v3"
 	"github.com/open-policy-agent/opa-envoy-plugin/test/e2e"
+	"github.com/open-policy-agent/opa/logging/test"
 	"github.com/open-policy-agent/opa/plugins"
 	"github.com/open-policy-agent/opa/tracing"
 	"github.com/open-policy-agent/opa/util"
@@ -24,6 +25,7 @@ import (
 )
 
 var spanExporter *tracetest.InMemoryExporter
+var consoleLogger *test.Logger
 
 const exampleRequest = `{
 	"attributes": {
@@ -70,6 +72,8 @@ func TestMain(m *testing.M) {
 	tracing.RegisterHTTPTracing(&factory{})
 	spanExporter = tracetest.NewInMemoryExporter()
 	tracerProvider := trace.NewTracerProvider(trace.WithSpanProcessor(trace.NewSimpleSpanProcessor(spanExporter)))
+	consoleLogger = test.New()
+
 	count := 0
 	countMutex := sync.Mutex{}
 	ts := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
@@ -88,7 +92,7 @@ func TestMain(m *testing.M) {
 		resp.body.count == 1
 	}`
 	module := fmt.Sprintf(moduleFmt, ts.URL)
-	pluginsManager, err := e2e.TestAuthzServerWithWithOpts(module, "envoy/authz/allow", ":9191", plugins.WithTracerProvider(tracerProvider))
+	pluginsManager, err := e2e.TestAuthzServerWithWithOpts(module, "envoy/authz/allow", ":9191", plugins.WithTracerProvider(tracerProvider), plugins.ConsoleLogger(consoleLogger))
 	if err != nil {
 		log.Fatal(err)
 	}
@@ -98,10 +102,7 @@ func TestMain(m *testing.M) {
 	os.Exit(m.Run())
 }
 
-// TestServerSpan exemplarily asserts that the server handlers emit OpenTelemetry spans
-// with the correct attributes. It does NOT exercise all handlers, but contains one test
-// with a GET and one with a POST.
-func TestServerSpan(t *testing.T) {
+func TestServerSpanAndTraceIdInDecisionLog(t *testing.T) {
 	spanExporter.Reset()
 
 	t.Run("envoy.service.auth.v3.Authorization Check", func(t *testing.T) {
@@ -147,5 +148,52 @@ func TestServerSpan(t *testing.T) {
 		if got, expected := spans[0].Parent.SpanID(), parentSpanID; got != expected {
 			t.Errorf("expected span to be child of %v, got parent %v", expected, got)
 		}
+
+		var entry test.LogEntry
+		var found bool
+
+		for _, entry = range consoleLogger.Entries() {
+			//t.Log(entry.Message)
+			if entry.Message == "Decision Log" {
+				found = true
+			}
+		}
+
+		if !found {
+			t.Fatalf("Did not find 'Decision Log' event in captured log entries")
+		}
+		// Check for some important fields
+		expectedFields := map[string]*struct {
+			found bool
+			match func(*testing.T, string)
+		}{
+			"labels":      {},
+			"decision_id": {},
+			"trace_id":    {},
+			"span_id":     {},
+			"result":      {},
+			"timestamp":   {},
+			"type": {match: func(t *testing.T, actual string) {
+				if actual != "openpolicyagent.org/decision_logs" {
+					t.Fatalf("Expected field 'type' to be 'openpolicyagent.org/decision_logs'")
+				}
+			}},
+		}
+
+		// Ensure expected fields exist
+		for fieldName, rawField := range entry.Fields {
+			if fd, ok := expectedFields[fieldName]; ok {
+				if fieldValue, ok := rawField.(string); ok && fd.match != nil {
+					fd.match(t, fieldValue)
+				}
+				fd.found = true
+			}
+		}
+
+		for field, fd := range expectedFields {
+			if !fd.found {
+				t.Errorf("Missing expected field in decision log: %s\n\nEntry: %+v\n\n", field, entry)
+			}
+		}
 	})
 }

test/e2e/testing.go

@@ -8,10 +8,30 @@ import (
 	"github.com/open-policy-agent/opa-envoy-plugin/internal"
 	"github.com/open-policy-agent/opa-envoy-plugin/plugin"
 	"github.com/open-policy-agent/opa/plugins"
+	"github.com/open-policy-agent/opa/plugins/logs"
 	"github.com/open-policy-agent/opa/storage"
 	"github.com/open-policy-agent/opa/storage/inmem"
 )
 
+type testPlugin struct {
+	events []logs.EventV1
+}
+
+func (*testPlugin) Start(context.Context) error {
+	return nil
+}
+
+func (*testPlugin) Stop(context.Context) {
+}
+
+func (*testPlugin) Reconfigure(context.Context, interface{}) {
+}
+
+func (p *testPlugin) Log(_ context.Context, event logs.EventV1) error {
+	p.events = append(p.events, event)
+	return nil
+}
+
 // TestAuthzServerWithWithOpts creates a new AuthzServer
 // that implements the Envoy ext_authz API. Options for
 // plugins.Manager can/should be customized for the test case.
@@ -37,6 +57,18 @@ func TestAuthzServerWithWithOpts(module string, path string, addr string, opts .
 		return nil, err
 	}
 	m.Register(plugin.PluginName, internal.New(m, cfg))
+
+	m.Register("test_plugin", &testPlugin{})
+	config, err := logs.ParseConfig([]byte(`{"plugin": "test_plugin"}`), nil, []string{"test_plugin"})
+
+	if err != nil {
+		return nil, err
+	}
+	config.ConsoleLogs = true
+
+	logPlugin := logs.New(config, m)
+	m.Register(logs.Name, logPlugin)
+
 	if err := m.Start(ctx); err != nil {
 		return nil, err
 	}