Skip to content

Commit

Permalink
Merge pull request #2017 from josephschorr/check-recurse-error
Browse files Browse the repository at this point in the history
Ensure debug information is returned for recursive checks that dispatch
  • Loading branch information
josephschorr authored Aug 12, 2024
2 parents 8bcfb32 + 103663e commit 5ee5c8e
Show file tree
Hide file tree
Showing 13 changed files with 192 additions and 30 deletions.
20 changes: 19 additions & 1 deletion internal/dispatch/errors.go
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,12 @@ package dispatch

import (
"fmt"

v1 "github.com/authzed/authzed-go/proto/authzed/api/v1"
"google.golang.org/grpc/codes"
"google.golang.org/grpc/status"

"github.com/authzed/spicedb/pkg/spiceerrors"
)

// MaxDepthExceededError is an error returned when the maximum depth for dispatching has been exceeded.
Expand All @@ -15,7 +21,19 @@ type MaxDepthExceededError struct {
// NewMaxDepthExceededError creates a new MaxDepthExceededError.
func NewMaxDepthExceededError(req DispatchableRequest) error {
return MaxDepthExceededError{
fmt.Errorf("max depth exceeded: this usually indicates a recursive or too deep data dependency"),
fmt.Errorf("max depth exceeded: this usually indicates a recursive or too deep data dependency. See: https://spicedb.dev/d/debug-max-depth"),
req,
}
}

// GRPCStatus implements retrieving the gRPC status for the error.
func (err MaxDepthExceededError) GRPCStatus() *status.Status {
return spiceerrors.WithCodeAndDetails(
err,
codes.ResourceExhausted,
spiceerrors.ForReason(
v1.ErrorReason_ERROR_REASON_MAXIMUM_DEPTH_EXCEEDED,
map[string]string{},
),
)
}
22 changes: 19 additions & 3 deletions internal/graph/check.go
Original file line number Diff line number Diff line change
Expand Up @@ -122,7 +122,12 @@ func (cc *ConcurrentChecker) Check(ctx context.Context, req ValidatedCheckReques
}
}

debugInfo.Check.Request = req.DispatchCheckRequest
// Remove the traversal bloom from the debug request to save some data over the
// wire.
clonedRequest := req.DispatchCheckRequest.CloneVT()
clonedRequest.Metadata.TraversalBloom = nil

debugInfo.Check.Request = clonedRequest
debugInfo.Check.Duration = durationpb.New(time.Since(*startTime))

if nspkg.GetRelationKind(relation) == iv1.RelationMetadata_PERMISSION {
Expand All @@ -138,10 +143,21 @@ func (cc *ConcurrentChecker) Check(ctx context.Context, req ValidatedCheckReques
results[resourceID] = found
}
}

debugInfo.Check.Results = results

// If there is existing debug information in the error, then place it as the subproblem of the current
// debug information.
if existingDebugInfo, ok := spiceerrors.GetDetails[*v1.DebugInformation](resolved.Err); ok {
debugInfo.Check.SubProblems = []*v1.CheckDebugTrace{existingDebugInfo.Check}
}

resolved.Resp.Metadata.DebugInfo = debugInfo
return resolved.Resp, resolved.Err

// If there is an error and it is already a gRPC error, add the debug information
// into the details portion of the payload. This allows the client to see the debug
// information, as gRPC will only return the error.
updatedErr := spiceerrors.WithReplacedDetails(resolved.Err, debugInfo)
return resolved.Resp, updatedErr
}

func (cc *ConcurrentChecker) checkInternal(ctx context.Context, req ValidatedCheckRequest, relation *core.Relation) CheckResult {
Expand Down
6 changes: 1 addition & 5 deletions internal/services/shared/errors.go
Original file line number Diff line number Diff line change
Expand Up @@ -119,18 +119,14 @@ type ConfigForErrors struct {
DebugTrace *v1.DebugInformation
}

// DebugTraceErrorDetailsKey is the key used to store the debug trace in the error details.
// The value is expected to be a string containing the proto text of a DebugInformation message.
const DebugTraceErrorDetailsKey = "debug_trace_proto_text"

func RewriteErrorWithoutConfig(ctx context.Context, err error) error {
return rewriteError(ctx, err, nil)
}

func RewriteError(ctx context.Context, err error, config *ConfigForErrors) error {
rerr := rewriteError(ctx, err, config)
if config != nil && config.DebugTrace != nil {
spiceerrors.WithAdditionalDetails(rerr, DebugTraceErrorDetailsKey, config.DebugTrace.String())
spiceerrors.WithAdditionalDetails(rerr, spiceerrors.DebugTraceErrorDetailsKey, config.DebugTrace.String())
}
return rerr
}
Expand Down
10 changes: 0 additions & 10 deletions internal/services/shared/errors_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,6 @@ import (
"google.golang.org/grpc/codes"

"github.com/authzed/spicedb/internal/dispatch"
dispatchv1 "github.com/authzed/spicedb/pkg/proto/dispatch/v1"
)

func TestRewriteCanceledError(t *testing.T) {
Expand All @@ -34,12 +33,3 @@ func TestRewriteMaximumDepthExceededError(t *testing.T) {
require.ErrorContains(t, errorRewritten, "See: https://spicedb.dev/d/debug-max-depth")
grpcutil.RequireStatus(t, codes.ResourceExhausted, errorRewritten)
}

func TestRewriteMaximumDepthExceededErrorForCheck(t *testing.T) {
errorRewritten := RewriteError(context.Background(), dispatch.NewMaxDepthExceededError(&dispatchv1.DispatchCheckRequest{}), &ConfigForErrors{
MaximumAPIDepth: 50,
})
require.ErrorContains(t, errorRewritten, "See: https://spicedb.dev/d/debug-max-depth-check")
require.ErrorContains(t, errorRewritten, "--explain")
grpcutil.RequireStatus(t, codes.ResourceExhausted, errorRewritten)
}
3 changes: 1 addition & 2 deletions internal/services/v1/debug.go
Original file line number Diff line number Diff line change
Expand Up @@ -21,10 +21,9 @@ import (
func ConvertCheckDispatchDebugInformation(
ctx context.Context,
caveatContext map[string]any,
metadata *dispatch.ResponseMeta,
debugInfo *dispatch.DebugInformation,
reader datastore.Reader,
) (*v1.DebugInformation, error) {
debugInfo := metadata.DebugInfo
if debugInfo == nil {
return nil, nil
}
Expand Down
3 changes: 2 additions & 1 deletion internal/services/v1/debug_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@ import (
"sort"
"strings"
"testing"
"time"

"github.com/authzed/authzed-go/pkg/requestmeta"
"github.com/authzed/authzed-go/pkg/responsemeta"
Expand Down Expand Up @@ -484,7 +485,7 @@ func TestCheckPermissionWithDebug(t *testing.T) {
tc := tc
t.Run(tc.name, func(t *testing.T) {
req := require.New(t)
conn, cleanup, _, revision := testserver.NewTestServer(req, testTimedeltas[0], memdb.DisableGC, true,
conn, cleanup, _, revision := testserver.NewTestServer(req, 5*time.Second, memdb.DisableGC, true,
func(ds datastore.Datastore, require *require.Assertions) (datastore.Datastore, datastore.Revision) {
return tf.DatastoreFromSchemaAndTestRelationships(ds, tc.schema, tc.relationships, req)
})
Expand Down
17 changes: 16 additions & 1 deletion internal/services/v1/permissions.go
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,7 @@ import (
"github.com/authzed/spicedb/pkg/middleware/consistency"
core "github.com/authzed/spicedb/pkg/proto/core/v1"
dispatch "github.com/authzed/spicedb/pkg/proto/dispatch/v1"
"github.com/authzed/spicedb/pkg/spiceerrors"
"github.com/authzed/spicedb/pkg/tuple"
)

Expand Down Expand Up @@ -108,14 +109,28 @@ func (ps *permissionServer) CheckPermission(ctx context.Context, req *v1.CheckPe
var debugTrace *v1.DebugInformation
if debugOption != computed.NoDebugging && metadata.DebugInfo != nil {
// Convert the dispatch debug information into API debug information.
converted, cerr := ConvertCheckDispatchDebugInformation(ctx, caveatContext, metadata, ds)
converted, cerr := ConvertCheckDispatchDebugInformation(ctx, caveatContext, metadata.DebugInfo, ds)
if cerr != nil {
return nil, ps.rewriteError(ctx, cerr)
}
debugTrace = converted
}

if err != nil {
// If the error already contains debug information, rewrite it. This can happen if
// a dispatch error occurs and debug was requested.
if dispatchDebugInfo, ok := spiceerrors.GetDetails[*dispatch.DebugInformation](err); ok {
// Convert the dispatch debug information into API debug information.
converted, cerr := ConvertCheckDispatchDebugInformation(ctx, caveatContext, dispatchDebugInfo, ds)
if cerr != nil {
return nil, ps.rewriteError(ctx, cerr)
}

if converted != nil {
return nil, spiceerrors.AppendDetailsMetadata(err, spiceerrors.DebugTraceErrorDetailsKey, converted.String())
}
}

return nil, ps.rewriteErrorWithOptionalDebugTrace(ctx, err, debugTrace)
}

Expand Down
7 changes: 4 additions & 3 deletions internal/services/v1/permissions_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -38,6 +38,7 @@ import (
core "github.com/authzed/spicedb/pkg/proto/core/v1"
"github.com/authzed/spicedb/pkg/schemadsl/compiler"
"github.com/authzed/spicedb/pkg/schemadsl/input"
"github.com/authzed/spicedb/pkg/spiceerrors"
"github.com/authzed/spicedb/pkg/testutil"
"github.com/authzed/spicedb/pkg/tuple"
"github.com/authzed/spicedb/pkg/zedtoken"
Expand Down Expand Up @@ -435,11 +436,11 @@ func TestCheckPermissionWithDebugInfoInError(t *testing.T) {
for _, d := range s.Details() {
if errInfo, ok := d.(*errdetails.ErrorInfo); ok {
req.NotNil(errInfo.Metadata)
req.NotNil(errInfo.Metadata[shared.DebugTraceErrorDetailsKey])
req.NotEmpty(errInfo.Metadata[shared.DebugTraceErrorDetailsKey])
req.NotNil(errInfo.Metadata[string(spiceerrors.DebugTraceErrorDetailsKey)])
req.NotEmpty(errInfo.Metadata[string(spiceerrors.DebugTraceErrorDetailsKey)])

debugInfo := &v1.DebugInformation{}
err = prototext.Unmarshal([]byte(errInfo.Metadata[shared.DebugTraceErrorDetailsKey]), debugInfo)
err = prototext.Unmarshal([]byte(errInfo.Metadata[string(spiceerrors.DebugTraceErrorDetailsKey)]), debugInfo)
req.NoError(err)

req.Equal(1, len(debugInfo.Check.GetSubProblems().Traces))
Expand Down
2 changes: 1 addition & 1 deletion pkg/development/check.go
Original file line number Diff line number Diff line change
Expand Up @@ -45,7 +45,7 @@ func RunCheck(devContext *DevContext, resource *core.ObjectAndRelation, subject
}

reader := devContext.Datastore.SnapshotReader(devContext.Revision)
converted, err := v1.ConvertCheckDispatchDebugInformation(ctx, caveatContext, meta, reader)
converted, err := v1.ConvertCheckDispatchDebugInformation(ctx, caveatContext, meta.DebugInfo, reader)
if err != nil {
return CheckResult{v1dispatch.ResourceCheckResult_NOT_MEMBER, nil, nil, nil}, err
}
Expand Down
14 changes: 14 additions & 0 deletions pkg/development/devcontext.go
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@ import (

v1 "github.com/authzed/authzed-go/proto/authzed/api/v1"
humanize "github.com/dustin/go-humanize"
"google.golang.org/genproto/googleapis/rpc/errdetails"
"google.golang.org/grpc"
"google.golang.org/grpc/codes"
"google.golang.org/grpc/credentials/insecure"
Expand Down Expand Up @@ -340,6 +341,19 @@ func distinguishGraphError(ctx context.Context, dispatchError error, source devi
}, nil
}

details, ok := spiceerrors.GetDetails[*errdetails.ErrorInfo](dispatchError)
if ok && details.Reason == "ERROR_REASON_MAXIMUM_DEPTH_EXCEEDED" {
status, _ := status.FromError(dispatchError)
return &devinterface.DeveloperError{
Message: status.Message(),
Source: source,
Kind: devinterface.DeveloperError_MAXIMUM_RECURSION,
Line: line,
Column: column,
Context: context,
}, nil
}

if errors.As(dispatchError, &invalidRelError) {
return &devinterface.DeveloperError{
Message: dispatchError.Error(),
Expand Down
2 changes: 1 addition & 1 deletion pkg/development/wasm/operations_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -274,7 +274,7 @@ func TestCheckOperation(t *testing.T) {
&editCheckResult{
Relationship: tuple.MustParse("document:someobj#viewer@user:foo"),
Error: &devinterface.DeveloperError{
Message: "max depth exceeded: this usually indicates a recursive or too deep data dependency",
Message: "max depth exceeded: this usually indicates a recursive or too deep data dependency. See: https://spicedb.dev/d/debug-max-depth",
Kind: devinterface.DeveloperError_MAXIMUM_RECURSION,
Source: devinterface.DeveloperError_CHECK_WATCH,
Context: "document:someobj#viewer@user:foo",
Expand Down
112 changes: 112 additions & 0 deletions pkg/spiceerrors/details_metadata.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,112 @@
package spiceerrors

import (
"fmt"

"google.golang.org/genproto/googleapis/rpc/errdetails"
"google.golang.org/grpc/status"
"google.golang.org/protobuf/runtime/protoiface"
)

// MetadataKey is the type used to represent the keys of the metadata map in
// the error details.
type MetadataKey string

// DebugTraceErrorDetailsKey is the key used to store the debug trace in the error details.
// The value is expected to be a string containing the proto text of a DebugInformation message.
const DebugTraceErrorDetailsKey MetadataKey = "debug_trace_proto_text"

// AppendDetailsMetadata appends the key-value pair to the error details metadata.
// If the error is nil or is not a status error, it is returned as is.
func AppendDetailsMetadata(err error, key MetadataKey, value string) error {
if err == nil {
return nil
}

s, ok := status.FromError(err)
if !ok {
return err
}

var foundErrDetails *errdetails.ErrorInfo
var otherDetails []protoiface.MessageV1
for _, details := range s.Details() {
if errInfo, ok := details.(*errdetails.ErrorInfo); ok {
foundErrDetails = errInfo
} else if cast, ok := details.(protoiface.MessageV1); ok {
otherDetails = append(otherDetails, cast)
}
}

if foundErrDetails != nil {
if foundErrDetails.Metadata == nil {
foundErrDetails.Metadata = make(map[string]string, 1)
}

foundErrDetails.Metadata[string(key)] = value
}

return WithCodeAndDetailsAsError(
fmt.Errorf("%s", s.Message()),
s.Code(),
append(otherDetails, foundErrDetails)...,
)
}

// WithReplacedDetails replaces the details of the error with the provided details.
// If the error is nil or is not a status error, it is returned as is.
// If the error does not have the details to replace, the provided details are appended.
func WithReplacedDetails[T protoiface.MessageV1](err error, toReplace T) error {
if err == nil {
return nil
}

s, ok := status.FromError(err)
if !ok {
return err
}

details := make([]protoiface.MessageV1, 0, len(s.Details()))
wasReplaced := false
for _, current := range s.Details() {
if _, ok := current.(T); ok {
details = append(details, toReplace)
wasReplaced = true
continue
}

if cast, ok := current.(protoiface.MessageV1); ok {
details = append(details, cast)
}
}

if !wasReplaced {
details = append(details, toReplace)
}

return WithCodeAndDetailsAsError(
fmt.Errorf("%s", s.Message()),
s.Code(),
details...,
)
}

// GetDetails returns the details of the error if they are of the provided type, if any.
func GetDetails[T protoiface.MessageV1](err error) (T, bool) {
if err == nil {
return *new(T), false
}

s, ok := status.FromError(err)
if !ok {
return *new(T), false
}

for _, details := range s.Details() {
if cast, ok := details.(T); ok {
return cast, true
}
}

return *new(T), false
}
4 changes: 2 additions & 2 deletions pkg/spiceerrors/withstatus.go
Original file line number Diff line number Diff line change
Expand Up @@ -58,11 +58,11 @@ func WithCodeAndReason(err error, code codes.Code, reason v1.ErrorReason) error
}

type SupportsAdditionalMetadata interface {
WithAdditionalDetails(key string, value string)
WithAdditionalDetails(key MetadataKey, value string)
}

// WithAdditionalDetails adds an additional details field to the error if it is possible.
func WithAdditionalDetails(err error, key string, value string) bool {
func WithAdditionalDetails(err error, key MetadataKey, value string) bool {
var supportsAdditionalDetails SupportsAdditionalMetadata
if ok := errors.As(err, &supportsAdditionalDetails); ok {
supportsAdditionalDetails.WithAdditionalDetails(key, value)
Expand Down

0 comments on commit 5ee5c8e

Please sign in to comment.