diff --git a/internal/internal.go b/internal/internal.go index e31ea240f..ef75fb163 100644 --- a/internal/internal.go +++ b/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 { diff --git a/internal/internal_test.go b/internal/internal_test.go index 342748819..4e9b3bed8 100644 --- a/internal/internal_test.go +++ b/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", diff --git a/test/e2e/distributedtracing/distributedtracing_test.go b/test/e2e/distributedtracing/distributedtracing_test.go index 4e7fa0288..bea819e77 100644 --- a/test/e2e/distributedtracing/distributedtracing_test.go +++ b/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) + } + } }) } diff --git a/test/e2e/testing.go b/test/e2e/testing.go index 166a84e6c..a2b6f19a2 100644 --- a/test/e2e/testing.go +++ b/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 }