Improve tracing for permissions checks (#156)

* Enable OTLP for Jaeger, start using it Signed-off-by: John Schaeffer <[email protected]> * Provide better spans for allow/deny events This commit updates permissions checks to provide better spans for surfacing allow/deny events. In particular, it tries to enforce the following conventions: * Allow and deny are explicitly conveyed using permissions.outcome * Denials are not errors These two conventions combined help us differentiate between allows, denials, and problems communicating with SpiceDB. Signed-off-by: John Schaeffer <[email protected]> * Fix bad SpiceDB PSK in dev container Signed-off-by: John Schaeffer <[email protected]> * Remove spurious audience in OIDC config Signed-off-by: John Schaeffer <[email protected]> * Fix linting issues Signed-off-by: John Schaeffer <[email protected]> --------- Signed-off-by: John Schaeffer <[email protected]>
infratographer · Aug 9, 2023 · bbd541c · bbd541c
1 parent b886dff
commit bbd541c
Show file tree

Hide file tree

Showing 7 changed files with 85 additions and 11 deletions.
diff --git a/.devcontainer/.env b/.devcontainer/.env
@@ -20,10 +20,11 @@ IDENTITYAPI_TRACING_JAEGER_ENDPOINT=http://localhost:14268/api/traces
 IDENTITYAPI_CRDB_URI="postgresql://root@crdb:26257/identityapi_dev?sslmode=disable"
 
 PERMISSIONSAPI_TRACING_ENABLED=true
-PERMISSIONSAPI_TRACING_PROVIDER=jaeger
-PERMISSIONSAPI_TRACING_JAEGER_ENDPOINT=http://localhost:14268/api/traces
+PERMISSIONSAPI_TRACING_PROVIDER=otlpgrpc
+PERMISSIONSAPI_TRACING_OTLP_ENDPOINT=jaeger:4317
+PERMISSIONSAPI_TRACING_OTLP_INSECURE=true
 PERMISSIONSAPI_SPICEDB_ENDPOINT=spicedb:50051
-PERMISSIONSAPI_SPICEDB_KEY=$SPICEDB_GRPC_PRESHARED_KEY
+PERMISSIONSAPI_SPICEDB_KEY=infradev
 PERMISSIONSAPI_SPICEDB_INSECURE=true
 
 PERMISSIONSAPI_PUBSUB_NAME=permissionsapi

diff --git a/.devcontainer/docker-compose.yml b/.devcontainer/docker-compose.yml
@@ -117,7 +117,12 @@ services:
 
   jaeger:
     image: jaegertracing/all-in-one:1.47.0
-    network_mode: service:app
+    environment:
+      - COLLECTOR_OTLP_ENABLED=true
+    ports:
+      - 16688:16686
+    networks:
+      - infradev
 
   mock-oauth2-server:
     image: ghcr.io/navikt/mock-oauth2-server:1.0.0

diff --git a/internal/api/permissions.go b/internal/api/permissions.go
@@ -11,6 +11,7 @@ import (
 	"go.infratographer.com/permissions-api/internal/query"
 	"go.infratographer.com/permissions-api/internal/types"
 	"go.infratographer.com/x/gidx"
+	"go.opentelemetry.io/otel/codes"
 	"go.uber.org/multierr"
 )
 
@@ -246,7 +247,10 @@ func (r *Router) checkAllActions(c echo.Context) error {
 	}
 
 	if internalErrors != 0 {
-		return echo.NewHTTPError(http.StatusInternalServerError, "an error occurred checking permissions").SetInternal(multierr.Combine(allErrors...))
+		combined := multierr.Combine(allErrors...)
+		span.SetStatus(codes.Error, combined.Error())
+
+		return echo.NewHTTPError(http.StatusInternalServerError, "an error occurred checking permissions").SetInternal(combined)
 	}
 
 	if unauthorizedErrors != 0 {

diff --git a/internal/query/relations.go b/internal/query/relations.go
@@ -2,6 +2,7 @@ package query
 
 import (
 	"context"
+	"errors"
 	"fmt"
 	"io"
 	"strings"
@@ -65,6 +66,27 @@ func resourceToSpiceDBRef(namespace string, r types.Resource) *pb.ObjectReferenc
 
 // SubjectHasPermission checks if the given subject can do the given action on the given resource
 func (e *engine) SubjectHasPermission(ctx context.Context, subject types.Resource, action string, resource types.Resource) error {
+	ctx, span := e.tracer.Start(
+		ctx,
+		"SubjectHasPermission",
+		trace.WithAttributes(
+			attribute.Stringer(
+				"permissions.actor",
+				subject.ID,
+			),
+			attribute.String(
+				"permissions.action",
+				action,
+			),
+			attribute.Stringer(
+				"permissions.resource",
+				resource.ID,
+			),
+		),
+	)
+
+	defer span.End()
+
 	req := &pb.CheckPermissionRequest{
 		Consistency: &pb.Consistency{
 			Requirement: &pb.Consistency_FullyConsistent{
@@ -78,7 +100,28 @@ func (e *engine) SubjectHasPermission(ctx context.Context, subject types.Resourc
 		},
 	}
 
-	return e.checkPermission(ctx, req)
+	err := e.checkPermission(ctx, req)
+
+	switch {
+	case err == nil:
+		span.SetAttributes(
+			attribute.String(
+				"permissions.outcome",
+				outcomeAllowed,
+			),
+		)
+	case errors.Is(err, ErrActionNotAssigned):
+		span.SetAttributes(
+			attribute.String(
+				"permissions.outcome",
+				outcomeDenied,
+			),
+		)
+	default:
+		span.SetStatus(codes.Error, err.Error())
+	}
+
+	return err
 }
 
 // AssignSubjectRole assigns the given role to the given subject.
@@ -194,7 +237,7 @@ func (e *engine) checkPermission(ctx context.Context, req *pb.CheckPermissionReq
 
 // CreateRelationships atomically creates the given relationships in SpiceDB.
 func (e *engine) CreateRelationships(ctx context.Context, rels []types.Relationship) (string, error) {
-	ctx, span := tracer.Start(ctx, "engine.CreateRelationships", trace.WithAttributes(attribute.Int("relationships", len(rels))))
+	ctx, span := e.tracer.Start(ctx, "engine.CreateRelationships", trace.WithAttributes(attribute.Int("relationships", len(rels))))
 
 	defer span.End()
 
@@ -347,7 +390,7 @@ func (e *engine) readRelationships(ctx context.Context, filter *pb.RelationshipF
 // DeleteRelationships removes the specified relationships.
 // If any relationships fails to be deleted, all completed deletions are re-created.
 func (e *engine) DeleteRelationships(ctx context.Context, relationships ...types.Relationship) (string, error) {
-	ctx, span := tracer.Start(ctx, "engine.DeleteRelationships", trace.WithAttributes(attribute.Int("relationships", len(relationships))))
+	ctx, span := e.tracer.Start(ctx, "engine.DeleteRelationships", trace.WithAttributes(attribute.Int("relationships", len(relationships))))
 
 	defer span.End()
 

diff --git a/internal/query/service.go b/internal/query/service.go
@@ -6,14 +6,16 @@ import (
 	"github.com/authzed/authzed-go/v1"
 	"go.infratographer.com/x/gidx"
 	"go.opentelemetry.io/otel"
+	"go.opentelemetry.io/otel/trace"
 	"go.uber.org/zap"
 
 	"go.infratographer.com/permissions-api/internal/iapl"
 	"go.infratographer.com/permissions-api/internal/types"
 )
 
-var (
-	tracer = otel.GetTracerProvider().Tracer("go.infratographer.com/permissions-api/internal/query")
+const (
+	outcomeAllowed = "allowed"
+	outcomeDenied  = "denied"
 )
 
 // Engine represents a client for making permissions queries.
@@ -37,6 +39,7 @@ type Engine interface {
 }
 
 type engine struct {
+	tracer                   trace.Tracer
 	logger                   *zap.SugaredLogger
 	namespace                string
 	client                   *authzed.Client
@@ -87,10 +90,13 @@ func resourceHasRoleBindings(resType types.ResourceType) bool {
 
 // NewEngine returns a new client for making permissions queries.
 func NewEngine(namespace string, client *authzed.Client, options ...Option) Engine {
+	tracer := otel.GetTracerProvider().Tracer("go.infratographer.com/permissions-api/internal/query")
+
 	e := &engine{
 		logger:    zap.NewNop().Sugar(),
 		namespace: namespace,
 		client:    client,
+		tracer:    tracer,
 	}
 
 	for _, fn := range options {

diff --git a/permissions-api.example.yaml b/permissions-api.example.yaml
@@ -1,3 +1,3 @@
 oidc:
   issuer: http://mock-oauth2-server:8081/default
-  audience: permissions-api
+
diff --git a/pkg/permissions/permissions.go b/pkg/permissions/permissions.go
@@ -27,6 +27,9 @@ const (
 	bearerPrefix = "Bearer "
 
 	defaultClientTimeout = 5 * time.Second
+
+	outcomeAllowed = "allowed"
+	outcomeDenied  = "denied"
 )
 
 var (
@@ -153,6 +156,12 @@ func (p *Permissions) checker(c echo.Context, actor, token string) Checker {
 			case errors.Is(err, ErrPermissionDenied):
 				logger.Warnw("unauthorized access to resource")
 				span.AddEvent("permission denied")
+				span.SetAttributes(
+					attribute.String(
+						"permissions.outcome",
+						outcomeDenied,
+					),
+				)
 			case errors.Is(err, ErrBadResponse):
 				logger.Errorw("bad response from server", "error", err, "response.status_code", resp.StatusCode, "response.body", string(body))
 				span.SetStatus(codes.Error, errors.WithStack(err).Error())
@@ -161,6 +170,12 @@ func (p *Permissions) checker(c echo.Context, actor, token string) Checker {
 			return err
 		}
 
+		span.SetAttributes(
+			attribute.String(
+				"permissions.outcome",
+				outcomeAllowed,
+			),
+		)
 		logger.Debug("access granted to resource")
 
 		return nil