Fixed allowing action & HAProxy logging (#74)

* Fixed allowing action & HAProxy logging

* Added tests

docker-compose.e2e.yaml

@@ -15,6 +15,12 @@ services:
       - coraza
       - httpbin
     image: ${HAPROXY_IMAGE:-haproxy:2.7-alpine}
+    command:
+      [
+        "sh",
+        "-c",
+        "haproxy -f /usr/local/etc/haproxy/haproxy.cfg | tee /var/lib/haproxy/hap.log"
+      ]
     ports: [ "4000:80" ]
     links:
       - "coraza:coraza"
@@ -23,6 +29,7 @@ services:
       - type: bind
         source: ./docker/haproxy
         target: /usr/local/etc/haproxy
+      - hap:/var/lib/haproxy
   tests:
     depends_on:
       - haproxy
@@ -33,3 +40,7 @@ services:
     build:
       context: docker/e2e
       dockerfile: ./Dockerfile.curl
+    volumes:
+      - hap:/haproxy
+volumes:
+  hap:

docker/e2e/Dockerfile.curl

@@ -13,4 +13,4 @@ COPY ./e2e.sh /workspace/e2e.sh
 ENV HAPROXY_HOST=haproxy:80
 ENV HTTPBIN_HOST=httpbin:8080
 
-CMD ["bash","-c", "/workspace/e2e.sh"]
+CMD ["bash", "/workspace/e2e.sh"]

docker/e2e/e2e.sh

@@ -7,6 +7,7 @@
 
 HAPROXY_HOST=${HAPROXY_HOST:-"localhost:4000"}
 HTTPBIN_HOST=${HTTPBIN_HOST:-"localhost:8080"}
+HAPROXY_LOGS='/haproxy/hap.log'
 
 [[ "${DEBUG}" == "true" ]] && set -x
 
@@ -82,8 +83,19 @@ function check_body() {
     echo "[Ok] Got response with an expected body (empty=${empty})"
 }
 
+# check_hap_logs checks HAProxy logs for the given regexp.
+# $1: The regexp to check logs aginst.
+function check_hap_logs() {
+    local regex=${1}
+    if [[ $(grep -q -e "$regex" "$HAPROXY_LOGS") ]]; then
+      echo -e "[Fail] No log lines matches pattern '$regex'"
+      exit 1
+    fi
+    echo "[Ok] Got logs with an expected pattern '$regex'"
+}
+
 step=1
-total_steps=12
+total_steps=17
 
 ## Testing that basic coraza phases are working
 
@@ -159,4 +171,29 @@ check_status "${url_echo}" 403 --user-agent "Grabber/0.1 (X11; U; Linux i686; en
 echo "[${step}/${total_steps}] True negative GET request with user-agent"
 check_status "${url_echo}" 200 --user-agent "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/105.0.0.0 Safari/537.36"
 
+# Find Allow action
+((step+=1))
+echo "[${step}/${total_steps}] HAP log format (waf-action: allow)"
+check_hap_logs "waf-action: allow"
+
+# Find Deny action
+((step+=1))
+echo "[${step}/${total_steps}] HAP log format (waf-action: deny)"
+check_hap_logs "waf-action: deny"
+
+# Find Drop action
+((step+=1))
+echo "[${step}/${total_steps}] HAP log format (waf-action: drop)"
+check_hap_logs "waf-action: drop"
+
+# Find Redirect action
+((step+=1))
+echo "[${step}/${total_steps}] HAP log format (waf-action: redirect)"
+check_hap_logs "waf-action: redirect"
+
+# Find no error
+((step+=1))
+echo "[${step}/${total_steps}] HAP log format (spoa-error: -)"
+check_hap_logs "spoa-error: -"
+
 echo "[Done] All tests passed"

docker/haproxy/haproxy.cfg

@@ -26,7 +26,7 @@ frontend test_frontend
     bind *:443 ssl crt /usr/local/etc/haproxy/example.com.pem alpn h2,http/1.1
     unique-id-format %[uuid()]
     unique-id-header X-Unique-ID
-    log-format "%ci:%cp\ [%t]\ %ft\ %b/%s\ %Th/%Ti/%TR/%Tq/%Tw/%Tc/%Tr/%Tt\ %ST\ %B\ %CC\ %CS\ %tsc\ %ac/%fc/%bc/%sc/%rc\ %sq/%bq\ %hr\ %hs\ %{+Q}r\ %ID\ spoa-error:\ %[var(txn.coraza.error)]\ waf-hit:\ %[var(txn.coraza.fail)]"
+    log-format "%ci:%cp\ [%t]\ %ft\ %b/%s\ %Th/%Ti/%TR/%Tq/%Tw/%Tc/%Tr/%Tt\ %ST\ %B\ %CC\ %CS\ %tsc\ %ac/%fc/%bc/%sc/%rc\ %sq/%bq\ %hr\ %hs\ %{+Q}r\ %ID\ spoa-error:\ %[var(txn.coraza.error)]\ waf-action:\ %[var(txn.coraza.action)]"
 
     filter spoe engine coraza config /usr/local/etc/haproxy/coraza.cfg
 

internal/spoa.go

@@ -19,13 +19,6 @@ import (
 	"go.uber.org/zap/zapcore"
 )
 
-const (
-	// miss sets the detection result to safe.
-	miss = iota
-	// hit opposite to Miss.
-	hit
-)
-
 // TODO - in coraza v3 ErrorLogCallback is currently in the internal package
 type ErrorLogCallback = func(rule types.MatchedRule)
 
@@ -67,14 +60,7 @@ func (s *SPOA) Start(bind string) error {
 	return nil
 }
 
-func (s *SPOA) processInterruption(it *types.Interruption, code int) []spoe.Action {
-	//if it.Status == 0 {
-	//  tx.variables.responseStatus.Set("", []string{"403"})
-	//} else {
-	//  status := strconv.Itoa(int(it.Status))
-	//  tx.variables.responseStatus.Set("", []string{status})
-	//}
-
+func (s *SPOA) processInterruption(it *types.Interruption) []spoe.Action {
 	return []spoe.Action{
 		spoe.ActionSetVar{
 			Name:  "status",
@@ -99,14 +85,15 @@ func (s *SPOA) processInterruption(it *types.Interruption, code int) []spoe.Acti
 	}
 }
 
-func (s *SPOA) message(code int) []spoe.Action {
-	return []spoe.Action{
+func (s *SPOA) allowAction() []spoe.Action {
+	act := []spoe.Action{
 		spoe.ActionSetVar{
-			Name:  "fail",
+			Name:  "action",
 			Scope: spoe.VarScopeTransaction,
-			Value: code,
+			Value: "allow",
 		},
 	}
+	return act
 }
 
 func (s *SPOA) readHeaders(headers string) (http.Header, error) {
@@ -292,7 +279,7 @@ func (s *SPOA) processRequest(spoeMsg *spoe.Message) ([]spoe.Action, error) {
 	tx = app.waf.NewTransactionWithID(req.id)
 	if tx.IsRuleEngineOff() {
 		app.logger.Warn("Rule engine is Off, Coraza is not going to process any rule")
-		return s.message(miss), nil
+		return s.allowAction(), nil
 	}
 
 	err = req.init()
@@ -315,26 +302,26 @@ func (s *SPOA) processRequest(spoeMsg *spoe.Message) ([]spoe.Action, error) {
 		return nil, err
 	}
 	if it != nil {
-		return s.processInterruption(it, hit), nil
+		return s.processInterruption(it), nil
 	}
 
 	tx.ProcessConnection(req.srcIp.String(), req.srcPort, req.dstIp.String(), req.dstPort)
 	tx.ProcessURI(req.path+"?"+req.query, req.method, "HTTP/"+req.version)
 
 	it = tx.ProcessRequestHeaders()
 	if it != nil {
-		return s.processInterruption(it, hit), nil
+		return s.processInterruption(it), nil
 	}
 
 	it, err = tx.ProcessRequestBody()
 	if err != nil {
 		return nil, err
 	}
 	if it != nil {
-		return s.processInterruption(it, hit), nil
+		return s.processInterruption(it), nil
 	}
 
-	return s.message(miss), nil
+	return s.allowAction(), nil
 }
 
 func (s *SPOA) processResponse(spoeMsg *spoe.Message) ([]spoe.Action, error) {
@@ -387,21 +374,21 @@ func (s *SPOA) processResponse(spoeMsg *spoe.Message) ([]spoe.Action, error) {
 		return nil, err
 	}
 	if it != nil {
-		return s.processInterruption(it, hit), nil
+		return s.processInterruption(it), nil
 	}
 
 	it = tx.ProcessResponseHeaders(resp.status, "HTTP/"+resp.version)
 	if it != nil {
-		return s.processInterruption(it, hit), nil
+		return s.processInterruption(it), nil
 	}
 
 	it, err = tx.ProcessResponseBody()
 	if err != nil {
 		return nil, err
 	}
 	if it != nil {
-		return s.processInterruption(it, hit), nil
+		return s.processInterruption(it), nil
 	}
 
-	return s.message(miss), nil
+	return s.allowAction(), nil
 }