Traces

Sentinel provides execution traces to better understand the execution of a policy.

When using the Sentinel CLI, traces are shown on policy failure during apply or test, or when the -trace flag is explicitly specified. For Sentinel-enabled applications, traces are optional and may require special configuration to enable. Most Sentinel-enabled applications log traces on failure.

Analyzing a Trace

To show traces, let's use the example policy below with the CLI:

is_weekday = rule { day not in ["saturday", "sunday"] }
is_open_hours = rule { hour > 8 and hour < 17 }
main = rule { is_open_hours and is_weekday }

Let's cause the policy to fail so the trace is more interesting. If you're on a terminal that supports it, the trace output will be colored so you can more clearly see passes, failures, and rules.

$ sentinel apply -global 'day=sunday' -global 'hour=14' policy.sentinel
Fail
 
FALSE - policy.sentinel:6:1 - Rule "main"
  TRUE - policy.sentinel:6:15 - is_open_hours
    TRUE - policy.sentinel:5:24 - hour > 8 and hour < 17
      TRUE - policy.sentinel:5:24 - hour > 8
      TRUE - policy.sentinel:5:37 - hour < 17
  FALSE - policy.sentinel:6:33 - is_weekday
    FALSE - policy.sentinel:4:21 - day not in ["saturday", "sunday"]
 
TRUE - policy.sentinel:5:1 - Rule "is_open_hours"
  TRUE - policy.sentinel:5:24 - hour > 8
  TRUE - policy.sentinel:5:37 - hour < 17
 
FALSE - policy.sentinel:4:1 - Rule "is_weekday"

The least-nested values are all rules. It begins with the value of that rule (TRUE or FALSE) followed by the location and name of the rule. Notice that the main rule is false, the is_open_hours rule is true, and the is_weekday rule is false.

We know that main requires both is_open_hours and is_weekday to be true, so based on the trace, we can tell that main failed because is_weekday was false. We can then go to the definition of is_weekday in the source and determine the logical failure.

The trace also breaks down more complex logical expressions. Notice that is_open_hours is split into the two sides of the and, but is_weekday has no values under it. Because is_weekday is itself a single boolean expression, the failure isn't repeated. But for is_open_hours, you can also see the result of each side of the boolean expression.

Missing Rules or Expressions

The Sentinel runtime sometimes optimizes away executions completely. This can result in a trace being incomplete. If you don't see a rule or boolean expression within the trace, it means the runtime didn't execute it at all.

Consider the example policy:

main = rule { 42 > 40 or 10 < 5 }

If we run it with trace:

$ sentinel apply -trace policy.sentinel
TRUE - policy.sentinel:1:1 - Rule "main"
  TRUE - policy.sentinel:1:15 - 42 > 40

Notice that the expression 10 < 5 is not present in the trace. Since 42 > 40 is true, the entire or can be short-circuited and the result is known to be true. Remaining parts of the expression are not executed and are therefore not present in the trace.

Policy Description

An additional feature that can be utilised within a trace is the output of a policy description. By placing a comment at the top of a policy file, ensuring that there is a space between itself and any following content, a description will be added to the trace output.

The following policy:

// Ensure 42 is greater than 40, or 10 is less than 5

main = rule { 42 > 40 or 10 < 5 }

Will output:

$ sentinel apply -trace policy.sentinel
Description:
  Ensure 42 is greater than 40, or 10 is less than 5
 
TRUE - policy.sentinel:1:1 - Rule "main"
  TRUE - policy.sentinel:1:15 - 42 > 40