diff --git a/cmd/test_test.go b/cmd/test_test.go index 8bf47173b6..1b601b8f25 100644 --- a/cmd/test_test.go +++ b/cmd/test_test.go @@ -83,10 +83,10 @@ func TestFilterTraceExplainFull(t *testing.T) { p.explain.Set(explainModeFull) expected := `Enter data.testing.test_p = _ | Eval data.testing.test_p = _ -| Index data.testing.test_p = _ (matched 1 rule) +| Index data.testing.test_p (matched 1 rule) | Enter data.testing.test_p | | Eval data.testing.p with data.x as "bar" -| | Index data.testing.p with data.x as "bar" (matched 1 rule) +| | Index data.testing.p (matched 1 rule) | | Enter data.testing.p | | | Eval data.testing.x | | | Index data.testing.x (matched 1 rule) @@ -100,12 +100,12 @@ func TestFilterTraceExplainFull(t *testing.T) { | | | Eval trace("test test") | | | Note "test test" | | | Eval data.testing.q.foo -| | | Index data.testing.q.foo (matched 1 rule) +| | | Index data.testing.q (matched 1 rule) | | | Enter data.testing.q | | | | Eval trace("got this far") | | | | Note "got this far" | | | | Eval data.testing.r[x] -| | | | Index data.testing.r[__local0__] (matched 1 rule) +| | | | Index data.testing.r (matched 1 rule) | | | | Enter data.testing.r | | | | | Eval trace("got this far2") | | | | | Note "got this far2" diff --git a/tester/reporter_test.go b/tester/reporter_test.go index 565c211a28..b45508c98e 100644 --- a/tester/reporter_test.go +++ b/tester/reporter_test.go @@ -171,42 +171,43 @@ func TestJSONReporter(t *testing.T) { "name": "test_baz", "duration": 0, "trace": [ - { - "Op": "Fail", - "Node": { - "index": 0, - "terms": [ - { - "type": "ref", - "value": [ - { - "type": "var", - "value": "eq" - } - ] - }, - { - "type": "boolean", - "value": true - }, - { - "type": "boolean", - "value": false - } - ] - }, - "Location": { - "row": 1, - "col": 1, - "file": "" - }, - "QueryID": 0, - "ParentID": 0, - "Locals": null, - "LocalMetadata": null, - "Message": "" - } - ] + { + "Op": "Fail", + "Node": { + "index": 0, + "terms": [ + { + "type": "ref", + "value": [ + { + "type": "var", + "value": "eq" + } + ] + }, + { + "type": "boolean", + "value": true + }, + { + "type": "boolean", + "value": false + } + ] + }, + "Location": { + "file": "", + "row": 1, + "col": 1 + }, + "QueryID": 0, + "ParentID": 0, + "Locals": null, + "LocalMetadata": null, + "Message": "", + "Ref": null + } + ] }, { "location": null, @@ -215,42 +216,43 @@ func TestJSONReporter(t *testing.T) { "error": {}, "duration": 0, "trace": [ - { - "Op": "Fail", - "Node": { - "index": 0, - "terms": [ - { - "type": "ref", - "value": [ - { - "type": "var", - "value": "eq" - } - ] - }, - { - "type": "boolean", - "value": true - }, - { - "type": "boolean", - "value": false - } - ] - }, - "Location": { - "row": 1, - "col": 1, - "file": "" - }, - "QueryID": 0, - "ParentID": 0, - "Locals": null, - "LocalMetadata": null, - "Message": "" - } - ] + { + "Op": "Fail", + "Node": { + "index": 0, + "terms": [ + { + "type": "ref", + "value": [ + { + "type": "var", + "value": "eq" + } + ] + }, + { + "type": "boolean", + "value": true + }, + { + "type": "boolean", + "value": false + } + ] + }, + "Location": { + "file": "", + "row": 1, + "col": 1 + }, + "QueryID": 0, + "ParentID": 0, + "Locals": null, + "LocalMetadata": null, + "Message": "", + "Ref": null + } + ] }, { "location": null, @@ -259,42 +261,44 @@ func TestJSONReporter(t *testing.T) { "fail": true, "duration": 0, "trace": [ - { - "Op": "Fail", - "Node": { - "index": 0, - "terms": [ - { - "type": "ref", - "value": [ - { - "type": "var", - "value": "eq" - } - ] - }, - { - "type": "boolean", - "value": true - }, - { - "type": "boolean", - "value": false - } - ] - }, - "Location": { - "row": 1, - "col": 1, - "file": "" - }, - "QueryID": 0, - "ParentID": 0, - "Locals": null, - "LocalMetadata": null, - "Message": "" - } - ] } + { + "Op": "Fail", + "Node": { + "index": 0, + "terms": [ + { + "type": "ref", + "value": [ + { + "type": "var", + "value": "eq" + } + ] + }, + { + "type": "boolean", + "value": true + }, + { + "type": "boolean", + "value": false + } + ] + }, + "Location": { + "file": "", + "row": 1, + "col": 1 + }, + "QueryID": 0, + "ParentID": 0, + "Locals": null, + "LocalMetadata": null, + "Message": "", + "Ref": null + } + ] + } ] `)) diff --git a/topdown/eval.go b/topdown/eval.go index 024011093d..50f2d30196 100644 --- a/topdown/eval.go +++ b/topdown/eval.go @@ -151,38 +151,38 @@ func (e *eval) unknown(x interface{}, b *bindings) bool { } func (e *eval) traceEnter(x ast.Node) { - e.traceEvent(EnterOp, x, "") + e.traceEvent(EnterOp, x, "", nil) } func (e *eval) traceExit(x ast.Node) { - e.traceEvent(ExitOp, x, "") + e.traceEvent(ExitOp, x, "", nil) } func (e *eval) traceEval(x ast.Node) { - e.traceEvent(EvalOp, x, "") + e.traceEvent(EvalOp, x, "", nil) } func (e *eval) traceFail(x ast.Node) { - e.traceEvent(FailOp, x, "") + e.traceEvent(FailOp, x, "", nil) } func (e *eval) traceRedo(x ast.Node) { - e.traceEvent(RedoOp, x, "") + e.traceEvent(RedoOp, x, "", nil) } func (e *eval) traceSave(x ast.Node) { - e.traceEvent(SaveOp, x, "") + e.traceEvent(SaveOp, x, "", nil) } -func (e *eval) traceIndex(x ast.Node, msg string) { - e.traceEvent(IndexOp, x, msg) +func (e *eval) traceIndex(x ast.Node, msg string, target *ast.Ref) { + e.traceEvent(IndexOp, x, msg, target) } -func (e *eval) traceExternalResolve(x ast.Node) { - e.traceEvent(ExternalResolveOp, x, "") +func (e *eval) traceWasm(x ast.Node, target *ast.Ref) { + e.traceEvent(WasmOp, x, "", target) } -func (e *eval) traceEvent(op Op, x ast.Node, msg string) { +func (e *eval) traceEvent(op Op, x ast.Node, msg string, target *ast.Ref) { if !e.traceEnabled { return @@ -200,6 +200,7 @@ func (e *eval) traceEvent(op Op, x ast.Node, msg string) { Node: x, Location: x.Loc(), Message: msg, + Ref: target, } // Skip plugging the local variables, unless any of the tracers @@ -1253,7 +1254,7 @@ func (e *eval) getRules(ref ast.Ref) (*ast.IndexResult, error) { b.WriteString(" rules)") msg = b.String() } - e.traceIndex(e.query[e.index], msg) + e.traceIndex(e.query[e.index], msg, &ref) return result, err } @@ -1330,13 +1331,11 @@ func (e *eval) resolveReadFromStorage(ref ast.Ref, a ast.Value) (ast.Value, erro return a, nil } - v, err := e.external.Resolve(e.ctx, ref, e.input) + v, err := e.external.Resolve(e, ref) if err != nil { return nil, err - } else if v != nil { - e.traceExternalResolve(e.query[e.index]) - } else { + } else if v == nil { path, err := storage.NewPathForRef(ref) if err != nil { diff --git a/topdown/resolver.go b/topdown/resolver.go index 0671a56f57..47af4cfd63 100644 --- a/topdown/resolver.go +++ b/topdown/resolver.go @@ -5,8 +5,6 @@ package topdown import ( - "context" - "github.com/open-policy-agent/opa/ast" "github.com/open-policy-agent/opa/resolver" ) @@ -33,10 +31,10 @@ func (t *resolverTrie) Put(ref ast.Ref, r resolver.Resolver) { node.r = r } -func (t *resolverTrie) Resolve(ctx context.Context, ref ast.Ref, input *ast.Term) (ast.Value, error) { +func (t *resolverTrie) Resolve(e *eval, ref ast.Ref) (ast.Value, error) { in := resolver.Input{ Ref: ref, - Input: input, + Input: e.input, } node := t for i, t := range ref { @@ -46,7 +44,8 @@ func (t *resolverTrie) Resolve(ctx context.Context, ref ast.Ref, input *ast.Term } node = child if node.r != nil { - result, err := node.r.Eval(ctx, in) + e.traceWasm(e.query[e.index], &in.Ref) + result, err := node.r.Eval(e.ctx, in) if err != nil { return nil, err } @@ -56,12 +55,13 @@ func (t *resolverTrie) Resolve(ctx context.Context, ref ast.Ref, input *ast.Term return result.Value.Find(ref[i+1:]) } } - return node.mktree(ctx, in) + return node.mktree(e, in) } -func (t *resolverTrie) mktree(ctx context.Context, in resolver.Input) (ast.Value, error) { +func (t *resolverTrie) mktree(e *eval, in resolver.Input) (ast.Value, error) { if t.r != nil { - result, err := t.r.Eval(ctx, in) + e.traceWasm(e.query[e.index], &in.Ref) + result, err := t.r.Eval(e.ctx, in) if err != nil { return nil, err } @@ -72,7 +72,7 @@ func (t *resolverTrie) mktree(ctx context.Context, in resolver.Input) (ast.Value } obj := ast.NewObject() for k, child := range t.children { - v, err := child.mktree(ctx, resolver.Input{Ref: append(in.Ref, ast.NewTerm(k)), Input: in.Input}) + v, err := child.mktree(e, resolver.Input{Ref: append(in.Ref, ast.NewTerm(k)), Input: in.Input}) if err != nil { return nil, err } diff --git a/topdown/trace.go b/topdown/trace.go index 906ba92143..2d4d5b76ee 100644 --- a/topdown/trace.go +++ b/topdown/trace.go @@ -51,9 +51,9 @@ const ( // matches. IndexOp Op = "Index" - // ExternalResolveOp is emitted when resolving a ref using an external + // WasmOp is emitted when resolving a ref using an external // Resolver. - ExternalResolveOp Op = "ExternalResolve" + WasmOp Op = "Wasm" ) // VarMetadata provides some user facing information about @@ -73,6 +73,7 @@ type Event struct { Locals *ast.ValueMap // Contains local variable bindings from the query context. Nil if variables were not included in the trace event. LocalMetadata map[ast.Var]VarMetadata // Contains metadata for the local variable bindings. Nil if variables were not included in the trace event. Message string // Contains message for Note events. + Ref *ast.Ref // Identifies the subject ref for the event. Only applies to Index and Wasm operations. } // HasRule returns true if the Event contains an ast.Rule. @@ -242,16 +243,26 @@ func formatEvent(event *Event, depth int) string { padding := formatEventPadding(event, depth) if event.Op == NoteOp { return fmt.Sprintf("%v%v %q", padding, event.Op, event.Message) - } else if event.Message != "" { - return fmt.Sprintf("%v%v %v %v", padding, event.Op, event.Node, event.Message) - } else { - switch node := event.Node.(type) { - case *ast.Rule: - return fmt.Sprintf("%v%v %v", padding, event.Op, node.Path()) - default: - return fmt.Sprintf("%v%v %v", padding, event.Op, rewrite(event).Node) - } } + + var details interface{} + if node, ok := event.Node.(*ast.Rule); ok { + details = node.Path() + } else if event.Ref != nil { + details = event.Ref + } else { + details = rewrite(event).Node + } + + template := "%v%v %v" + opts := []interface{}{padding, event.Op, details} + + if event.Message != "" { + template += " %v" + opts = append(opts, event.Message) + } + + return fmt.Sprintf(template, opts...) } func formatEventPadding(event *Event, depth int) string { diff --git a/topdown/trace_test.go b/topdown/trace_test.go index 651f040099..8a803b7baa 100644 --- a/topdown/trace_test.go +++ b/topdown/trace_test.go @@ -80,10 +80,10 @@ func TestPrettyTrace(t *testing.T) { expected := `Enter data.test.p = _ | Eval data.test.p = _ -| Index data.test.p = _ (matched 1 rule) +| Index data.test.p (matched 1 rule) | Enter data.test.p | | Eval data.test.q[x] -| | Index data.test.q[x] (matched 1 rule) +| | Index data.test.q (matched 1 rule) | | Enter data.test.q | | | Eval x = data.a[_] | | | Exit data.test.q @@ -173,10 +173,10 @@ func TestPrettyTraceWithLocation(t *testing.T) { expected := `query:1 Enter data.test.p = _ query:1 | Eval data.test.p = _ -query:1 | Index data.test.p = _ (matched 1 rule) +query:1 | Index data.test.p (matched 1 rule) query:3 | Enter data.test.p query:3 | | Eval data.test.q[x] -query:3 | | Index data.test.q[x] (matched 1 rule) +query:3 | | Index data.test.q (matched 1 rule) query:4 | | Enter data.test.q query:4 | | | Eval x = data.a[_] query:4 | | | Exit data.test.q @@ -275,10 +275,10 @@ func TestPrettyTraceWithLocationTruncatedPaths(t *testing.T) { expected := `query:1 Enter data.test.p = _ query:1 | Eval data.test.p = _ -query:1 | Index data.test.p = _ (matched 1 rule) +query:1 | Index data.test.p (matched 1 rule) authz_bundle/...ternal/authz/policies/abac/v1/beta/policy.rego:6 | Enter data.test.p authz_bundle/...ternal/authz/policies/abac/v1/beta/policy.rego:6 | | Eval data.utils.q[x] -authz_bundle/...ternal/authz/policies/abac/v1/beta/policy.rego:6 | | Index data.utils.q[x] (matched 1 rule) +authz_bundle/...ternal/authz/policies/abac/v1/beta/policy.rego:6 | | Index data.utils.q (matched 1 rule) authz_bundle/...ternal/authz/policies/utils/utils.rego:4 | | Enter data.utils.q authz_bundle/...ternal/authz/policies/utils/utils.rego:4 | | | Eval x = data.a[_] authz_bundle/...ternal/authz/policies/utils/utils.rego:4 | | | Exit data.utils.q @@ -426,7 +426,7 @@ query:1 | Eval data query:1 | Index data.example_rbac.allow (matched 1 rule) authz_bundle/...ternal/authz/policies/rbac/v1/beta/policy.rego:6 | Enter data.example_rbac.allow authz_bundle/...ternal/authz/policies/rbac/v1/beta/policy.rego:7 | | Eval data.utils.user_has_role[role_name] -authz_bundle/...ternal/authz/policies/rbac/v1/beta/policy.rego:7 | | Index data.utils.user_has_role[role_name] (matched 1 rule) +authz_bundle/...ternal/authz/policies/rbac/v1/beta/policy.rego:7 | | Index data.utils.user_has_role (matched 1 rule) authz_bundle/...ternal/authz/policies/utils/user.rego:4 | | Enter data.utils.user_has_role authz_bundle/...ternal/authz/policies/utils/user.rego:5 | | | Eval role_binding = data.bindings[_] authz_bundle/...ternal/authz/policies/utils/user.rego:6 | | | Eval role_binding.role = role_name @@ -434,7 +434,7 @@ authz_bundle/...ternal/authz/policies/utils/user.rego:7 | | | Eval authz_bundle/...ternal/authz/policies/utils/user.rego:7 | | | Save "inspector-alice" = input.subject.user authz_bundle/...ternal/authz/policies/utils/user.rego:4 | | | Exit data.utils.user_has_role authz_bundle/...ternal/authz/policies/rbac/v1/beta/policy.rego:9 | | Eval data.utils.role_has_permission[role_name] -authz_bundle/...ternal/authz/policies/rbac/v1/beta/policy.rego:9 | | Index data.utils.role_has_permission[role_name] (matched 1 rule) +authz_bundle/...ternal/authz/policies/rbac/v1/beta/policy.rego:9 | | Index data.utils.role_has_permission (matched 1 rule) authz_bundle/...ternal/authz/policies/utils/user.rego:10 | | Enter data.utils.role_has_permission authz_bundle/...ternal/authz/policies/utils/user.rego:11 | | | Eval role = data.roles[_] authz_bundle/...ternal/authz/policies/utils/user.rego:12 | | | Eval role.name = role_name @@ -464,7 +464,7 @@ authz_bundle/...ternal/authz/policies/utils/user.rego:7 | | | Eval authz_bundle/...ternal/authz/policies/utils/user.rego:7 | | | Save "maker-bob" = input.subject.user authz_bundle/...ternal/authz/policies/utils/user.rego:4 | | | Exit data.utils.user_has_role authz_bundle/...ternal/authz/policies/rbac/v1/beta/policy.rego:9 | | Eval data.utils.role_has_permission[role_name] -authz_bundle/...ternal/authz/policies/rbac/v1/beta/policy.rego:9 | | Index data.utils.role_has_permission[role_name] (matched 1 rule) +authz_bundle/...ternal/authz/policies/rbac/v1/beta/policy.rego:9 | | Index data.utils.role_has_permission (matched 1 rule) authz_bundle/...ternal/authz/policies/utils/user.rego:10 | | Enter data.utils.role_has_permission authz_bundle/...ternal/authz/policies/utils/user.rego:11 | | | Eval role = data.roles[_] authz_bundle/...ternal/authz/policies/utils/user.rego:12 | | | Eval role.name = role_name @@ -556,10 +556,10 @@ func TestTraceNote(t *testing.T) { expected := `Enter data.test.p = _ | Eval data.test.p = _ -| Index data.test.p = _ (matched 1 rule) +| Index data.test.p (matched 1 rule) | Enter data.test.p | | Eval data.test.q[x] -| | Index data.test.q[x] (matched 1 rule) +| | Index data.test.q (matched 1 rule) | | Enter data.test.q | | | Eval x = data.a[_] | | | Exit data.test.q @@ -669,10 +669,10 @@ func TestTraceNoteWithLocation(t *testing.T) { expected := `query:1 Enter data.test.p = _ query:1 | Eval data.test.p = _ -query:1 | Index data.test.p = _ (matched 1 rule) +query:1 | Index data.test.p (matched 1 rule) query:3 | Enter data.test.p query:3 | | Eval data.test.q[x] -query:3 | | Index data.test.q[x] (matched 1 rule) +query:3 | | Index data.test.q (matched 1 rule) query:4 | | Enter data.test.q query:4 | | | Eval x = data.a[_] query:4 | | | Exit data.test.q