From cd495faacbebbbe002caf0cbaa68be6cebebb545 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?V=C3=ADctor=20Rold=C3=A1n=20Betancort?= Date: Wed, 15 Nov 2023 16:50:21 +0000 Subject: [PATCH 1/6] log messages for possibly loop on singleflight dispatch --- internal/dispatch/singleflight/singleflight.go | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/internal/dispatch/singleflight/singleflight.go b/internal/dispatch/singleflight/singleflight.go index fbcc1224f9..d49dc45d06 100644 --- a/internal/dispatch/singleflight/singleflight.go +++ b/internal/dispatch/singleflight/singleflight.go @@ -12,6 +12,8 @@ import ( "google.golang.org/grpc/status" "resenje.org/singleflight" + log "github.com/authzed/spicedb/internal/logging" + "github.com/authzed/spicedb/internal/dispatch" "github.com/authzed/spicedb/internal/dispatch/keys" v1 "github.com/authzed/spicedb/pkg/proto/dispatch/v1" @@ -73,6 +75,7 @@ func (d *Dispatcher) DispatchCheck(ctx context.Context, req *v1.DispatchCheckReq if err != nil { return &v1.DispatchCheckResponse{Metadata: &v1.ResponseMeta{DispatchCount: 1}}, err } else if possiblyLoop { + log.Warn().Object("DispatchCheckRequest", req).Msg("potential loop detect on SingleFlight Dispatcher") singleFlightCount.WithLabelValues("DispatchCheck", "loop").Inc() return d.delegate.DispatchCheck(ctx, req) } @@ -117,6 +120,7 @@ func (d *Dispatcher) DispatchExpand(ctx context.Context, req *v1.DispatchExpandR return &v1.DispatchExpandResponse{Metadata: &v1.ResponseMeta{DispatchCount: 1}}, err } else if possiblyLoop { singleFlightCount.WithLabelValues("DispatchExpand", "loop").Inc() + log.Warn().Object("DispatchExpand", req).Msg("potential loop detect on SingleFlight Dispatcher") return d.delegate.DispatchExpand(ctx, req) } From 4a148d1ac1e94854ef893adde8217f5e1e370290 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?V=C3=ADctor=20Rold=C3=A1n=20Betancort?= Date: Wed, 15 Nov 2023 18:24:20 +0000 Subject: [PATCH 2/6] return error if traversal key is empty --- pkg/proto/dispatch/v1/02_resolvermeta.go | 8 ++++++-- 1 file changed, 6 insertions(+), 2 deletions(-) diff --git a/pkg/proto/dispatch/v1/02_resolvermeta.go b/pkg/proto/dispatch/v1/02_resolvermeta.go index 4e5b248adf..2a43a3f9d0 100644 --- a/pkg/proto/dispatch/v1/02_resolvermeta.go +++ b/pkg/proto/dispatch/v1/02_resolvermeta.go @@ -11,6 +11,10 @@ import ( ) func (x *ResolverMeta) RecordTraversal(key string) (possiblyLoop bool, err error) { + if key == "" { + return false, status.Error(codes.Internal, fmt.Errorf("missing key to be recorded in traversal").Error()) + } + if x == nil || len(x.TraversalBloom) == 0 { return false, status.Error(codes.Internal, fmt.Errorf("required traversal bloom filter is missing").Error()) } @@ -39,12 +43,12 @@ const defaultFalsePositiveRate = 0.001 func NewTraversalBloomFilter(numElements uint) ([]byte, error) { bf := bloom.NewWithEstimates(numElements, defaultFalsePositiveRate) - modifiedBloomFilter, err := bf.MarshalBinary() + emptyBloomFilter, err := bf.MarshalBinary() if err != nil { return nil, spiceerrors.MustBugf("unexpected error while serializing empty bloom filter: %s", err.Error()) } - return modifiedBloomFilter, nil + return emptyBloomFilter, nil } // MustNewTraversalBloomFilter creates a new bloom filter sized to the provided number of elements and From 3a7645f2b74f29029ef5445a745d2dcebd7087d2 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?V=C3=ADctor=20Rold=C3=A1n=20Betancort?= Date: Wed, 15 Nov 2023 18:24:43 +0000 Subject: [PATCH 3/6] do not panic on these execution paths --- internal/services/v1/permissions.go | 21 ++++++++++++++++++--- 1 file changed, 18 insertions(+), 3 deletions(-) diff --git a/internal/services/v1/permissions.go b/internal/services/v1/permissions.go index 952fe7660b..1f17f710f2 100644 --- a/internal/services/v1/permissions.go +++ b/internal/services/v1/permissions.go @@ -155,11 +155,16 @@ func (ps *permissionServer) ExpandPermissionTree(ctx context.Context, req *v1.Ex return nil, ps.rewriteError(ctx, err) } + bf, err := dispatch.NewTraversalBloomFilter(uint(ps.config.MaximumAPIDepth)) + if err != nil { + return nil, err + } + resp, err := ps.dispatch.DispatchExpand(ctx, &dispatch.DispatchExpandRequest{ Metadata: &dispatch.ResolverMeta{ AtRevision: atRevision.String(), DepthRemaining: ps.config.MaximumAPIDepth, - TraversalBloom: dispatch.MustNewTraversalBloomFilter(uint(ps.config.MaximumAPIDepth)), + TraversalBloom: bf, }, ResourceAndRelation: &core.ObjectAndRelation{ Namespace: req.Resource.ObjectType, @@ -417,12 +422,17 @@ func (ps *permissionServer) LookupResources(req *v1.LookupResourcesRequest, resp return nil }) + bf, err := dispatch.NewTraversalBloomFilter(uint(ps.config.MaximumAPIDepth)) + if err != nil { + return err + } + err = ps.dispatch.DispatchLookupResources( &dispatch.DispatchLookupResourcesRequest{ Metadata: &dispatch.ResolverMeta{ AtRevision: atRevision.String(), DepthRemaining: ps.config.MaximumAPIDepth, - TraversalBloom: dispatch.MustNewTraversalBloomFilter(uint(ps.config.MaximumAPIDepth)), + TraversalBloom: bf, }, ObjectRelation: &core.RelationReference{ Namespace: req.ResourceObjectType, @@ -537,12 +547,17 @@ func (ps *permissionServer) LookupSubjects(req *v1.LookupSubjectsRequest, resp v return nil }) + bf, err := dispatch.NewTraversalBloomFilter(uint(ps.config.MaximumAPIDepth)) + if err != nil { + return err + } + err = ps.dispatch.DispatchLookupSubjects( &dispatch.DispatchLookupSubjectsRequest{ Metadata: &dispatch.ResolverMeta{ AtRevision: atRevision.String(), DepthRemaining: ps.config.MaximumAPIDepth, - TraversalBloom: dispatch.MustNewTraversalBloomFilter(uint(ps.config.MaximumAPIDepth)), + TraversalBloom: bf, }, ResourceRelation: &core.RelationReference{ Namespace: req.Resource.ObjectType, From 55d1a7f83f506f921cddbcff6460a9c9e6e22cf6 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?V=C3=ADctor=20Rold=C3=A1n=20Betancort?= Date: Wed, 15 Nov 2023 18:25:10 +0000 Subject: [PATCH 4/6] do not double singleflight cluster dispatches this would have been caused increase in false-positives in the bloom filter --- internal/dispatch/cluster/cluster.go | 2 -- 1 file changed, 2 deletions(-) diff --git a/internal/dispatch/cluster/cluster.go b/internal/dispatch/cluster/cluster.go index b00728a851..edc69952ff 100644 --- a/internal/dispatch/cluster/cluster.go +++ b/internal/dispatch/cluster/cluster.go @@ -7,7 +7,6 @@ import ( "github.com/authzed/spicedb/internal/dispatch/caching" "github.com/authzed/spicedb/internal/dispatch/graph" "github.com/authzed/spicedb/internal/dispatch/keys" - "github.com/authzed/spicedb/internal/dispatch/singleflight" "github.com/authzed/spicedb/pkg/cache" ) @@ -68,7 +67,6 @@ func NewClusterDispatcher(dispatch dispatch.Dispatcher, options ...Option) (disp } clusterDispatch := graph.NewDispatcher(dispatch, opts.concurrencyLimits) - clusterDispatch = singleflight.New(clusterDispatch, &keys.CanonicalKeyHandler{}) if opts.prometheusSubsystem == "" { opts.prometheusSubsystem = "dispatch" From 8518a93fffcbe6bc387b2986bc4b736cde049ff6 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?V=C3=ADctor=20Rold=C3=A1n=20Betancort?= Date: Wed, 15 Nov 2023 18:26:24 +0000 Subject: [PATCH 5/6] log as debug possible loops, and log key --- internal/dispatch/singleflight/singleflight.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/internal/dispatch/singleflight/singleflight.go b/internal/dispatch/singleflight/singleflight.go index d49dc45d06..6a01a386bb 100644 --- a/internal/dispatch/singleflight/singleflight.go +++ b/internal/dispatch/singleflight/singleflight.go @@ -75,7 +75,7 @@ func (d *Dispatcher) DispatchCheck(ctx context.Context, req *v1.DispatchCheckReq if err != nil { return &v1.DispatchCheckResponse{Metadata: &v1.ResponseMeta{DispatchCount: 1}}, err } else if possiblyLoop { - log.Warn().Object("DispatchCheckRequest", req).Msg("potential loop detect on SingleFlight Dispatcher") + log.Debug().Object("DispatchCheckRequest", req).Str("key", keyString).Msg("potential DispatchCheckRequest loop detected") singleFlightCount.WithLabelValues("DispatchCheck", "loop").Inc() return d.delegate.DispatchCheck(ctx, req) } @@ -119,8 +119,8 @@ func (d *Dispatcher) DispatchExpand(ctx context.Context, req *v1.DispatchExpandR if err != nil { return &v1.DispatchExpandResponse{Metadata: &v1.ResponseMeta{DispatchCount: 1}}, err } else if possiblyLoop { + log.Debug().Object("DispatchExpand", req).Str("key", keyString).Msg("potential DispatchExpand loop detected") singleFlightCount.WithLabelValues("DispatchExpand", "loop").Inc() - log.Warn().Object("DispatchExpand", req).Msg("potential loop detect on SingleFlight Dispatcher") return d.delegate.DispatchExpand(ctx, req) } From 4a20f13d474027f303f6ff806639be60ceff4461 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?V=C3=ADctor=20Rold=C3=A1n=20Betancort?= Date: Wed, 15 Nov 2023 18:49:56 +0000 Subject: [PATCH 6/6] this is an unexpected error so use MustBugf --- pkg/proto/dispatch/v1/02_resolvermeta.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pkg/proto/dispatch/v1/02_resolvermeta.go b/pkg/proto/dispatch/v1/02_resolvermeta.go index 2a43a3f9d0..93742e06a7 100644 --- a/pkg/proto/dispatch/v1/02_resolvermeta.go +++ b/pkg/proto/dispatch/v1/02_resolvermeta.go @@ -12,7 +12,7 @@ import ( func (x *ResolverMeta) RecordTraversal(key string) (possiblyLoop bool, err error) { if key == "" { - return false, status.Error(codes.Internal, fmt.Errorf("missing key to be recorded in traversal").Error()) + return false, spiceerrors.MustBugf("missing key to be recorded in traversal") } if x == nil || len(x.TraversalBloom) == 0 {