Merge pull request #803 from Pix4D/pci-3852-policy-checker-add-logging

pci-3852: policy checker handler: add logging

atc/api/policychecker/handler.go

@@ -34,10 +34,15 @@ type policyCheckingHandler struct {
 func (h policyCheckingHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 	acc := accessor.GetAccessor(r)
 
+	logger := h.logger.Session("policy-checker")
 	result, err := h.policyChecker.Check(h.action, acc, r)
 	if err != nil {
 		w.WriteHeader(http.StatusBadRequest)
-		fmt.Fprintf(w, "policy check error: %s", err.Error())
+		userMsg := "policy-checker: unreachable or misconfigured"
+		// error should be logged and meaningful to the Concourse operator/maintainer
+		logger.Error("policy-checker", err, lager.Data{"user-msg": userMsg})
+		// actual error is not useful and can be confusing to Concourse user
+		fmt.Fprint(w, userMsg)
 		return
 	}
 

atc/api/policychecker/handler_test.go

@@ -117,7 +117,7 @@ var _ = Describe("Handler", func() {
 
 			msg, err := io.ReadAll(responseWriter.Body)
 			Expect(err).ToNot(HaveOccurred())
-			Expect(string(msg)).To(Equal("policy check error: some-error"))
+			Expect(string(msg)).To(Equal("policy-checker: unreachable or misconfigured"))
 		})
 
 		It("not call the inner handler", func() {

atc/policy/opa/opa.go

@@ -60,23 +60,23 @@ func (c opa) Check(input policy.PolicyCheckInput) (policy.PolicyCheckResult, err
 	client.Timeout = c.config.Timeout
 	resp, err := client.Do(req)
 	if err != nil {
-		return nil, err
+		return nil, fmt.Errorf("OPA server: connecting: %w", err)
 	}
 	defer resp.Body.Close()
 
 	statusCode := resp.StatusCode
 	if statusCode != http.StatusOK {
-		return nil, fmt.Errorf("opa returned status: %d", statusCode)
+		return nil, fmt.Errorf("OPA server returned status: %d", statusCode)
 	}
 
 	body, err := io.ReadAll(resp.Body)
 	if err != nil {
-		return nil, fmt.Errorf("opa returned no response: %s", err.Error())
+		return nil, fmt.Errorf("OPA server: reading response body: %s", err.Error())
 	}
 
 	result, err := ParseOpaResult(body, c.config)
 	if err != nil {
-		return nil, fmt.Errorf("parsing opa results: %w", err)
+		return nil, fmt.Errorf("parsing OPA results: %w", err)
 	}
 
 	return result, nil

atc/policy/opa/opa_test.go

@@ -177,7 +177,7 @@ var _ = Describe("OPA Policy Checker", func() {
 		It("should return error", func() {
 			result, err := agent.Check(policy.PolicyCheckInput{})
 			Expect(err).To(HaveOccurred())
-			Expect(err.Error()).To(MatchRegexp("connection refused"))
+			Expect(err.Error()).To(MatchRegexp("OPA server: connecting: .* connection refused"))
 			Expect(result).To(BeNil())
 		})
 	})
@@ -190,7 +190,7 @@ var _ = Describe("OPA Policy Checker", func() {
 		It("should return error", func() {
 			result, err := agent.Check(policy.PolicyCheckInput{})
 			Expect(err).To(HaveOccurred())
-			Expect(err.Error()).To(Equal("opa returned status: 404"))
+			Expect(err.Error()).To(Equal("OPA server returned status: 404"))
 			Expect(result).To(BeNil())
 		})
 	})
@@ -205,7 +205,7 @@ var _ = Describe("OPA Policy Checker", func() {
 		It("should return error", func() {
 			result, err := agent.Check(policy.PolicyCheckInput{})
 			Expect(err).To(HaveOccurred())
-			Expect(err.Error()).To(ContainSubstring("invalid character 'h' looking for beginning of value"))
+			Expect(err.Error()).To(ContainSubstring("parsing JSON: invalid character 'h' looking for beginning of value"))
 			Expect(result).To(BeNil())
 		})
 	})

atc/policy/opa/result.go

@@ -30,7 +30,7 @@ func ParseOpaResult(bytesResult []byte, opaConfig OpaConfig) (opaResult, error)
 	var results vars.StaticVariables
 	err := json.Unmarshal(bytesResult, &results)
 	if err != nil {
-		return opaResult{}, err
+		return opaResult{}, fmt.Errorf("parsing JSON: %w", err)
 	}
 
 	var allowed, shouldBlock, ok bool