Opa: partial eval: remove impossible cases (?)

[srenatus]

Expected vs actual behaviour

When executing OPA 0.11.0, in a recent checkout of A2, say https://github.com/chef/automate/commit/f7212f8fc494dec6cb7702fdd18f313c894d92eb, the following commands, we find that the partial eval result contains lots of things that cannot happen:

$ cd components/authz-service/engine/opa/policy
$ opa run -w authz_v2.rego common.rego ../example_v2/store-pretty.json
OPA 0.11.1-dev (commit 55cede1e-dirty, built at 2019-05-21T08:53:59Z)

Run 'help' to see a list of commands.

> unknown input
> data.authz_v2.authorized
+-----------+--------------------------------------------------------------------------------------------+
| Query 1   | data.partial.authz_v2.authorized                                                           |
+-----------+--------------------------------------------------------------------------------------------+
| Support 1 | package partial                                                                            |
|           |                                                                                            |
|           | __not1_1__ {                                                                               |
|           |   "iam:roles:owner" = input.resource                                                       |
|           |   "iam:roles:update" = input.action                                                        |
|           |   _ = input.subjects[_]                                                                    |
|           | }           

--- 8< ---

+-----------+--------------------------------------------------------------------------------------------+
| Support 2 | package partial.authz_v2                                                                   |
|           |                                                                                            |
|           | authorized {                                                                               |
|           |   startswith(input.subjects[_], "user:")                                                   |
|           |   split(input.action, ":") = ["event", _, _]                                               |
|           |                                                                                            |
|           |   not data.partial.__not1_1__                                                              |
|           |   _ = input.resource                                                                       |
|           | }                                                                                          |
|           |                                                                                            |
|           | authorized {                                                                               |
|           |   "system:status" = input.resource                                                         |
|           |   "system:license:get" = input.action                                                      |
|           |                                                                                            |
|           |   not data.partial.__not1_1__                                                              |
|           |   _ = input.subjects[_]                                                                    |
|           | }            

--- >8 ---

Here, there's a not data.partial.__not1_1__ rule, although it _cannot happen_ for the existing data. (It could happen that there's a deny match with action: * and resource: *, but there currently isn't.) Also, there's irrelevant clauses, _ = input.resource and _ = input.subjects[_].

👉 The full output is here: https://gist.github.com/srenatus/f7993700cacaed49d9d7b8833c9d89b6

In general, I suppose I wouldn't care. However, we've found that updating a policy (or anything related, which causes data to be invalidated and the partial result recalculated) takes a bit too long to make it synchronous. Before we make it asynchronous, I wanted to reach out to ask if we're either doing something silly (authz_v2.rego lives here, or if you agree that making the update asynchronous is the way to go.

[tsandall]

@srenatus apologies for the delay.

EDIT: Let me know if my expectation around the results is wrong or if you're seeing different performance numbers.

Partial eval results

Here, there's a not data.partial.__not1_1__ rule, although it cannot happen for the existing data. (It could happen that there's a deny match with action: * and resource: *, but there currently isn't.)

The not data.partial.__not1_1__ expression (and supporting rules) are generated because of the not deny expression in the authorize rule.

As far as I can tell, these rules should be generated because there are policies (in the data) with "deny" effect that have to be included in the result. For example:

(detached*)torin:~/go/src/github.com/chef/automate/components/authz-service/engine/opa/policy$ docker run --rm -v $PWD/..:/src -w /src openpolicyagent/opa:0.10.7 eval -d policy/authz_v2.rego -d policy/common.rego -d example_v2/store-pretty.json -p 'data.authz_v2.match[["deny", pid, sid]]' -f pretty

(sorry for the ridiculously long line)

output:

8<
+----------+-----------------------------------------------------------------------------------+
| Query 2  | "team:local:admins" = input.subjects[_]                                           |
|          | "iam:policies:administrator-access" = input.resource                              |
|          | "iam:policies:delete" = input.action                                              |
|          | pid = "administrator-access"                                                      |
|          | sid = "e7db4f3c-80aa-491b-9842-4194c9326a2c"                                      |
+----------+-----------------------------------------------------------------------------------+
8<

I haven't dug into the reason for the _ = input.resource and _ = input.subjects[_] expressions.

Latency

The partial evaluation latency in v0.10.7 and v0.11.0 is roughly the same from what I can tell. Full output here.

v0.10.7:

|            METRIC            |   VALUE   |
+------------------------------+-----------+
| timer_rego_module_compile_ns | 11400778  |
| timer_rego_module_parse_ns   | 41277147  |
| timer_rego_partial_eval_ns   | 370921588 |
| timer_rego_query_compile_ns  | 82064     |
| timer_rego_query_parse_ns    | 265111    |
+------------------------------+-----------+

v0.11.0:

|            METRIC            |   VALUE   |
+------------------------------+-----------+
| timer_rego_input_parse_ns    | 657       |
| timer_rego_module_compile_ns | 13116993  |
| timer_rego_module_parse_ns   | 46489808  |
| timer_rego_partial_eval_ns   | 378955719 |
| timer_rego_query_compile_ns  | 107344    |
| timer_rego_query_parse_ns    | 326502    |
+------------------------------+-----------+

I ran a quick test to check how long it takes to compile the partial eval results and it's approximately the same in v0.10.7 and v0.11.0 (~500ms)

[srenatus]

@tsandall Thanks for looking into this! 😃

I can see how _the current rego_ leads to these results -- the not deny is overly broad. I was wondering if there's ways (or, well-known patterns) to "fix" this. I've been playing with the policy code, but haven't been able to address that in a way that wasn't much worse performing.

Thank you for comparing the latency numbers -- I'm afraid we've neglected our micro-benchmarks in the process of this iteration, so, I can't claim that it _had ever been better_. So, I realised that my request is a bit odd: _Would you see a way to change the policy code to improve the partial eval rebuild time?_

[tsandall]

@srenatus I'm actively looking into performance improvements for your use case. It's related to #1443.

One way to improve partial evaluation performance is to limit the amount of inlining that OPA performs. The problem is by default partial evaluation inlines as much possible. While this is good for returning policies that are as simple as possible it can be quite expensive. In your case (and in #1443) it means computing a cross-product of the data.policies collection.

I'm working on changes that would give you control to disable inlining of certain rules. In your case, you could disable inlining of data.authz_v2.deny. This would eliminate the cross-product. You can see the result here.

In the future, OPA could automatically decide whether to inline or not.

EDIT: to get that output I modified your policy slightly:

diff --git a/components/authz-service/engine/opa/policy/authz_v2.rego b/components/authz-service/engine/opa/policy/authz_v2.rego
index 22e52e25..5453fdcc 100644
--- a/components/authz-service/engine/opa/policy/authz_v2.rego
+++ b/components/authz-service/engine/opa/policy/authz_v2.rego
@@ -73,9 +73,9 @@ match[[effect, pol_id, statement_id]] {
        has_action[[pol_id, statement_id]]
 }

-allow = match[["allow", _, _]]
+allow { match[["allow", _, _]] }

-deny = match[["deny", _, _]]
+deny { match[["deny", _, _]] }

 authorized {
        allow

FWIW, you probably want to make this change anyway because OPA will generate a conflict error if you query for allow or deny without having run partial eval.

[srenatus]

This is great news, more than I could have hoped for. Staying tuned. 😉 Thanks again for looking into this.

[tsandall]

@srenatus with https://github.com/open-policy-agent/opa/pull/1475 you should be able to disable inlining like I described above. Can you give this a shot in the automate code base and let me know how it goes?

[srenatus]

@tsandall thank you so much. Indeed, it changes partial eval times _dramatically_:

name                                      old time/op    new time/op    delta
InitPartialResultV2/default_policies-8     1.87s ± 2%     0.39s ±12%  -79.33%  (p=0.000 n=10+10)

name                                     old alloc/op   new alloc/op   delta
InitPartialResultV2/default_policies-8     425MB ± 0%      50MB ± 0%  -88.19%  (p=0.000 n=10+8)

name                                    old allocs/op  new allocs/op  delta
InitPartialResultV2/default_policies-8     13.8M ± 0%      1.9M ± 0%  -86.24%  (p=0.000 n=10+10)

🎉 Thanks again! 😃 🎈