Merge pull request #1139 from zregvart/pr/trace-print

Print traces and debug messages from OPA

acceptance/examples/trace_debug.rego

@@ -0,0 +1,19 @@
+package main
+
+import future.keywords.contains
+import future.keywords.if
+
+# METADATA
+# title: Debug
+# description: This rule print to debug log
+# custom:
+#   short_name: debuggy
+#   failure_msg: Prints and succeeds
+deny contains result if {
+	print("here we are")
+	false
+	result := {
+		"code": "acceptance.debuggy",
+		"msg": "This should not happen",
+	}
+}

features/validate_image.feature

@@ -896,3 +896,35 @@ Feature: evaluate enterprise contract
     When ec command is run with "validate image --image ${REGISTRY}/acceptance/fetch-oci-blob --policy acceptance/ec-policy --public-key ${known_PUBLIC_KEY} --rekor-url ${REKOR}  --show-successes"
     Then the exit status should be 0
     Then the output should match the snapshot
+
+  Scenario: tracing and debug logging
+    Given a key pair named "trace_debug"
+      And an image named "acceptance/trace-debug"
+      And a valid image signature of "acceptance/trace-debug" image signed by the "trace_debug" key
+      And a valid Rekor entry for image signature of "acceptance/trace-debug"
+      And a valid attestation of "acceptance/trace-debug" signed by the "trace_debug" key
+      And a valid Rekor entry for attestation of "acceptance/trace-debug"
+      And a git repository named "trace-debug" with
+      | main.rego | examples/trace_debug.rego |
+      And policy configuration named "ec-policy" with specification
+      """
+      {
+        "sources": [
+          {
+            "policy": [
+              "git::https://${GITHOST}/git/trace-debug.git"
+            ]
+          }
+        ]
+      }
+      """
+    When ec command is run with "validate image --image ${REGISTRY}/acceptance/trace-debug --policy acceptance/ec-policy --public-key ${trace_debug_PUBLIC_KEY} --rekor-url ${REKOR}  --show-successes --trace"
+    Then the exit status should be 0
+     And the standard error should contain
+      """
+      level=trace msg="\[data.main.deny\] Enter data.main.deny
+      """
+     And the standard error should contain
+      """
+      level=debug msg="\[data.main.deny\] .*/main.rego:13: here we are
+      """

internal/evaluator/conftest_evaluator.go

@@ -163,23 +163,42 @@ type conftestRunner struct {
 }
 
 func (r conftestRunner) Run(ctx context.Context, fileList []string) (result []Outcome, data Data, err error) {
+	if log.IsLevelEnabled(log.TraceLevel) {
+		r.Trace = true
+	}
+
 	var conftestResult []output.CheckResult
 	conftestResult, err = r.TestRunner.Run(ctx, fileList)
 	if err != nil {
 		return
 	}
 
-	for _, r := range conftestResult {
+	for _, res := range conftestResult {
+		if log.IsLevelEnabled(log.TraceLevel) {
+			for _, q := range res.Queries {
+				for _, t := range q.Traces {
+					log.Tracef("[%s] %s", q.Query, t)
+				}
+			}
+		}
+		if log.IsLevelEnabled(log.DebugLevel) {
+			for _, q := range res.Queries {
+				for _, o := range q.Outputs {
+					log.Debugf("[%s] %s", q.Query, o)
+				}
+			}
+		}
+
 		result = append(result, Outcome{
-			FileName:  r.FileName,
-			Namespace: r.Namespace,
+			FileName:  res.FileName,
+			Namespace: res.Namespace,
 			// Conftest doesn't give us a list of successes, just a count. Here we turn that count
 			// into a placeholder slice of that size to make processing easier later on.
-			Successes:  make([]Result, r.Successes),
-			Skipped:    toRules(r.Skipped),
-			Warnings:   toRules(r.Warnings),
-			Failures:   toRules(r.Failures),
-			Exceptions: toRules(r.Exceptions),
+			Successes:  make([]Result, res.Successes),
+			Skipped:    toRules(res.Skipped),
+			Warnings:   toRules(res.Warnings),
+			Failures:   toRules(res.Failures),
+			Exceptions: toRules(res.Exceptions),
 		})
 	}
 

internal/logging/logging.go

@@ -47,7 +47,7 @@ func InitLogging(verbose, quiet, debug, trace bool) {
 	var v string
 	switch {
 	case trace:
-		level = log.DebugLevel
+		level = log.TraceLevel
 		setupDebugMode()
 		v = "9"
 	case debug: