ewilliams28/releases
1
0
Fork 0
mirror of https://github.com/open-policy-agent/opa.git synced 2026-08-13 03:42:35 -06:00
Code Issues Packages Projects Releases Wiki Activity

topdown: Improve wasm resolver traces

Browse Source 
We now trace once for each call to Eval() on a resolver and can
include a ref with the trace events.

Signed-off-by: Patrick East <east.patrick@gmail.com>
This commit is contained in:
Patrick East
2020-11-04 12:30:24 -08:00
committed by Torin Sandall
parent 4085c4d6b9
commit 89be02aaa7
6 changed files with 175 additions and 161 deletions
Download Patch File Download Diff File Expand all files Collapse all files
cmd/test_test.go
+4 -4
View File
@@ -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"
tester/reporter_test.go
+112 -108
View File
@@ -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
}
]
}
]
`))
topdown/eval.go
+15 -16
View File
@@ -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 {
topdown/resolver.go
+9 -9
View File
@@ -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
}
topdown/trace.go
+22 -11
View File
@@ -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 {
topdown/trace_test.go
+13 -13
View File
@@ -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