Merge pull request #18980 from hashicorp/f-policy-output

backend/remote: only show the full policy output when it fails

backend/remote/backend_apply.go

@@ -7,6 +7,7 @@ import (
 	"fmt"
 	"log"
 	"strings"
+	"time"
 
 	tfe "github.com/hashicorp/go-tfe"
 	"github.com/hashicorp/terraform/backend"
@@ -146,23 +147,32 @@ func (b *Remote) opApply(stopCtx, cancelCtx context.Context, op *backend.Operati
 	return r, nil
 }
 
-func (b *Remote) checkPolicy(stopCtx, cancelCtx context.Context, op *backend.Operation, r *tfe.Run) error {
+func (b *Remote) checkPolicy(stopCtx, cancelCtx context.Context, op *backend.Operation, r *tfe.Run) (err error) {
 	if b.CLI != nil {
 		b.CLI.Output("\n------------------------------------------------------------------------\n")
 	}
 	for _, pc := range r.PolicyChecks {
-		logs, err := b.client.PolicyChecks.Logs(stopCtx, pc.ID)
+		// Loop until the context is canceled or the policy check is finished.
-		if err != nil {
+		for {
-			return generalError("error retrieving policy check logs", err)
+			pc, err = b.client.PolicyChecks.Read(stopCtx, pc.ID)
-		}
-		scanner := bufio.NewScanner(logs)
-
-		// Retrieve the policy check to get its current status.
-		pc, err := b.client.PolicyChecks.Read(stopCtx, pc.ID)
 			if err != nil {
 				return generalError("error retrieving policy check", err)
 			}
 
+			switch pc.Status {
+			case tfe.PolicyPending, tfe.PolicyQueued:
+				select {
+				case <-stopCtx.Done():
+					return generalError("error retrieving policy check", stopCtx.Err())
+				case <-time.After(500 * time.Millisecond):
+					continue
+				}
+			}
+
+			// Break if the policy check is finished.
+			break
+		}
+
 		var msgPrefix string
 		switch pc.Scope {
 		case tfe.PolicyScopeOrganization:
@@ -173,10 +183,25 @@ func (b *Remote) checkPolicy(stopCtx, cancelCtx context.Context, op *backend.Ope
 			msgPrefix = fmt.Sprintf("Unknown policy check (%s)", pc.Scope)
 		}
 
+		// Don't show the full policy output if the policy passed.
+		if pc.Status == tfe.PolicyPasses {
+			if b.CLI != nil {
+				b.CLI.Output(b.Colorize().Color(msgPrefix + ": passed\n"))
+				b.CLI.Output("------------------------------------------------------------------------")
+			}
+			continue
+		}
+
 		if b.CLI != nil {
 			b.CLI.Output(b.Colorize().Color(msgPrefix + ":\n"))
 		}
 
+		logs, err := b.client.PolicyChecks.Logs(stopCtx, pc.ID)
+		if err != nil {
+			return generalError("error retrieving policy check logs", err)
+		}
+		scanner := bufio.NewScanner(logs)
+
 		for scanner.Scan() {
 			if b.CLI != nil {
 				b.CLI.Output(b.Colorize().Color(scanner.Text()))
@@ -187,11 +212,6 @@ func (b *Remote) checkPolicy(stopCtx, cancelCtx context.Context, op *backend.Ope
 		}
 
 		switch pc.Status {
-		case tfe.PolicyPasses:
-			if b.CLI != nil {
-				b.CLI.Output("\n------------------------------------------------------------------------")
-			}
-			continue
 		case tfe.PolicyErrored:
 			return fmt.Errorf(msgPrefix + " errored.")
 		case tfe.PolicyHardFailed:
@@ -215,13 +235,13 @@ func (b *Remote) checkPolicy(stopCtx, cancelCtx context.Context, op *backend.Ope
 			return err
 		}
 
-		if b.CLI != nil {
-			b.CLI.Output("------------------------------------------------------------------------")
-		}
-
 		if _, err = b.client.PolicyChecks.Override(stopCtx, pc.ID); err != nil {
 			return generalError("error overriding policy check", err)
 		}
+
+		if b.CLI != nil {
+			b.CLI.Output("------------------------------------------------------------------------")
+		}
 	}
 
 	return nil

backend/remote/backend_apply_test.go

@@ -442,8 +442,8 @@ func TestRemote_applyPolicyPass(t *testing.T) {
 	if !strings.Contains(output, "1 to add, 0 to change, 0 to destroy") {
 		t.Fatalf("missing plan summery in output: %s", output)
 	}
-	if !strings.Contains(output, "Sentinel Result: true") {
+	if !strings.Contains(output, "policy check: passed") {
-		t.Fatalf("missing Sentinel result in output: %s", output)
+		t.Fatalf("missing polic check result in output: %s", output)
 	}
 	if !strings.Contains(output, "1 added, 0 changed, 0 destroyed") {
 		t.Fatalf("missing apply summery in output: %s", output)
@@ -487,7 +487,7 @@ func TestRemote_applyPolicyHardFail(t *testing.T) {
 		t.Fatalf("missing plan summery in output: %s", output)
 	}
 	if !strings.Contains(output, "Sentinel Result: false") {
-		t.Fatalf("missing Sentinel result in output: %s", output)
+		t.Fatalf("missing policy check result in output: %s", output)
 	}
 	if strings.Contains(output, "1 added, 0 changed, 0 destroyed") {
 		t.Fatalf("unexpected apply summery in output: %s", output)
@@ -530,7 +530,7 @@ func TestRemote_applyPolicySoftFail(t *testing.T) {
 		t.Fatalf("missing plan summery in output: %s", output)
 	}
 	if !strings.Contains(output, "Sentinel Result: false") {
-		t.Fatalf("missing Sentinel result in output: %s", output)
+		t.Fatalf("missing policy check result in output: %s", output)
 	}
 	if !strings.Contains(output, "1 added, 0 changed, 0 destroyed") {
 		t.Fatalf("missing apply summery in output: %s", output)
@@ -573,7 +573,7 @@ func TestRemote_applyPolicySoftFailAutoApprove(t *testing.T) {
 		t.Fatalf("missing plan summery in output: %s", output)
 	}
 	if !strings.Contains(output, "Sentinel Result: false") {
-		t.Fatalf("missing Sentinel result in output: %s", output)
+		t.Fatalf("missing policy check result in output: %s", output)
 	}
 	if !strings.Contains(output, "1 added, 0 changed, 0 destroyed") {
 		t.Fatalf("missing apply summery in output: %s", output)

backend/remote/backend_mock.go

@@ -471,6 +471,38 @@ func (m *mockPolicyChecks) Read(ctx context.Context, policyCheckID string) (*tfe
 	if !ok {
 		return nil, tfe.ErrResourceNotFound
 	}
+
+	logfile, ok := m.logs[pc.ID]
+	if !ok {
+		return nil, tfe.ErrResourceNotFound
+	}
+
+	if _, err := os.Stat(logfile); os.IsNotExist(err) {
+		return nil, fmt.Errorf("logfile does not exist")
+	}
+
+	logs, err := ioutil.ReadFile(logfile)
+	if err != nil {
+		return nil, err
+	}
+
+	switch {
+	case bytes.Contains(logs, []byte("Sentinel Result: true")):
+		pc.Status = tfe.PolicyPasses
+	case bytes.Contains(logs, []byte("Sentinel Result: false")):
+		switch {
+		case bytes.Contains(logs, []byte("hard-mandatory")):
+			pc.Status = tfe.PolicyHardFailed
+		case bytes.Contains(logs, []byte("soft-mandatory")):
+			pc.Actions.IsOverridable = true
+			pc.Permissions.CanOverride = true
+			pc.Status = tfe.PolicySoftFailed
+		}
+	default:
+		// As this is an unexpected state, we say the policy errored.
+		pc.Status = tfe.PolicyErrored
+	}
+
 	return pc, nil
 }
 
@@ -495,7 +527,7 @@ func (m *mockPolicyChecks) Logs(ctx context.Context, policyCheckID string) (io.R
 	}
 
 	if _, err := os.Stat(logfile); os.IsNotExist(err) {
-		return bytes.NewBufferString("logfile does not exist"), nil
+		return nil, fmt.Errorf("logfile does not exist")
 	}
 
 	logs, err := ioutil.ReadFile(logfile)
@@ -503,23 +535,6 @@ func (m *mockPolicyChecks) Logs(ctx context.Context, policyCheckID string) (io.R
 		return nil, err
 	}
 
-	switch {
-	case bytes.Contains(logs, []byte("Sentinel Result: true")):
-		pc.Status = tfe.PolicyPasses
-	case bytes.Contains(logs, []byte("Sentinel Result: false")):
-		switch {
-		case bytes.Contains(logs, []byte("hard-mandatory")):
-			pc.Status = tfe.PolicyHardFailed
-		case bytes.Contains(logs, []byte("soft-mandatory")):
-			pc.Actions.IsOverridable = true
-			pc.Permissions.CanOverride = true
-			pc.Status = tfe.PolicySoftFailed
-		}
-	default:
-		// As this is an unexpected state, we say the policy errored.
-		pc.Status = tfe.PolicyErrored
-	}
-
 	return bytes.NewBuffer(logs), nil
 }
 

backend/remote/test-fixtures/apply-policy-passed/policy.log

@@ -1,12 +1,2 @@
+# This line is here only for the mock!
 Sentinel Result: true
-
-This result means that Sentinel policies returned true and the protected
-behavior is allowed by Sentinel policies.
-
-1 policies evaluated.
-
-## Policy 1: Passthrough.sentinel (soft-mandatory)
-
-Result: true
-
-TRUE - Passthrough.sentinel:1:1 - Rule "main"