Incomplete Anomaly Score Log: Missing Value for 'msg' Field with Rule ID 980170

[Barnoux]

1. The problem I'm having:

Hello,

We don't have the value of the msg field in the anomaly score log wich have the rule id 980170.
this was already reported and fix in #684

2. Expected behavior :

We should have a log like this one.

{
  "level": "error",
  "ts": 1685797070.7382822,
  "logger": "http.handlers.waf",
  "msg": "[client \"192.168.1.1\"] Coraza: Warning. Anomaly Scores: (Inbound Scores: blocking=25, detection=25, per_pl=15-0-0-10, threshold=1000) - (Outbound Scores: blocking=0, detection=0, per_pl=0-0-0-0, threshold=1000) - (SQLI=0, XSS=0, RFI=0, LFI= [file \"/ruleset/coreruleset/rules/RESPONSE-980-CORRELATION.conf\"] [line \"11046\"] [id \"980170\"] [rev \"\"] [msg \"Anomaly Scores: (Inbound Scores: blocking=25, detection=25, per_pl=15-0-0-10, threshold=1000) - (Outbound Scores: blocking=0, detection=0, per_pl=0-0-0-0, threshold=1000) - (SQLI=0, XSS=0, RFI=0, LFI=\"] [data \"\"] [severity \"emergency\"] [ver \"OWASP_CRS/4.0.0-rc1\"] [maturity \"0\"] [accuracy \"0\"] [tag \"reporting\"] [hostname \"\"] [uri \"/?foo=/etc/passwd&bar=/bin/sh\"] [unique_id \"DyldtRcMRMBWPrdM\"]\n"
}

3. Actual behavior - Error messages and/or full log output:

Actually the rule 980170 is trigerred but we have no msg.

{
    "level": "error",
    "ts": 1711207475.5746813,
    "logger": "http.handlers.waf",
    "msg": "[client \"192.168.1.1\"] Coraza: Warning. Inbound Anomaly Score Exceeded (Total Score: 25) [file \"/ruleset/coreruleset/rules/REQUEST-949-BLOCKING-EVALUATION.conf\"] [line \"0\"] [id \"949110\"] [rev \"\"] [msg \"Inbound Anomaly Score Exceeded (Total Score: 25)\"] [data \"\"] [severity \"emergency\"] [ver \"OWASP_CRS/4.0.0-rc2\"] [maturity \"0\"] [accuracy \"0\"] [tag \"anomaly-evaluation\"] [hostname \"\"] [uri \"/?foo=/etc/passwd&bar=/bin/sh\"] [unique_id \"pzIBCQEecpuPBGDi\"]\n"
}

{
    "level": "error",
    "ts": 1711207475.5751467,
    "logger": "http.handlers.waf",
    "msg": "[client \"192.168.1.1\"] Coraza: Warning.  [file \"/ruleset/coreruleset/rules/RESPONSE-980-CORRELATION.conf\"] [line \"0\"] [id \"980170\"] [rev \"\"] [msg \"\"] [data \"\"] [severity \"emergency\"] [ver \"OWASP_CRS/4.0.0-rc2\"] [maturity \"0\"] [accuracy \"0\"] [tag \"reporting\"] [hostname \"\"] [uri \"/?foo=/etc/passwd&bar=/bin/sh\"] [unique_id \"pzIBCQEecpuPBGDi\"]\n"
}

4. Caddy version:

v2.7.6 h1:w0NymbG2m9PcvKWsrXO6EEkY9Ru4FJK8uQbYcev1p3A=

5. How I installed and ran Caddy and Coraza:

a. System environment:

I'm using a raspeberrypi 4B

Linux srvone4all 5.4.0-1100-raspi #112-Ubuntu SMP PREEMPT Fri Nov 24 15:35:17 UTC 2023 aarch64 aarch64 aarch64 GNU/Linux


NAME="Ubuntu"
VERSION="20.04.6 LTS (Focal Fossa)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 20.04.6 LTS"
VERSION_ID="20.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=focal
UBUNTU_CODENAME=focal

Docker version

Docker version 26.0.0, build 2ae903e

b. Command:

Caddy and Coraza is a service and it is build from a Dockerfile

docker compose up -d

c. Dockerfile:

FROM caddy:builder AS builder
RUN xcaddy build \
    --with github.com/corazawaf/coraza-caddy \
    --with github.com/caddy-dns/gandi

FROM caddy:alpine

COPY --from=builder /usr/bin/caddy /usr/bin/caddy
RUN set -eux; \
    apk add --no-cache libcap tzdata; \
    setcap cap_net_bind_service=ep /usr/bin/caddy; \
    addgroup -g 2023 -S www-caddy; \
    adduser -u 2023 -D -S -G www-caddy www-caddy; \
    chown -R www-caddy /data /var/log

USER www-caddy

WORKDIR /srv

CMD ["/usr/bin/caddy", "run", "--config", "/Caddyfile", "--adapter", "caddyfile"]

d. My complete Caddy config:

{
	order coraza_waf first
	persist_config off
	log {
		level INFO
		output file /var/log/caddy/caddy.log
	}
	servers {
		timeouts {
			idle 10s
			read_body 1m
			read_header 10s
		}
		max_header_size 4KB
	}
}

# Default server block that will respond with a "Not found" message for all requests to port 443
:443 {
	log
	respond "Not found" 404
}
# Default server block that will respond with a "Not found" message for all requests to port 80
:80 {
	log
	respond "Not found" 404
}

{$DOMAIN} {
	log
	coraza_waf {
		directives `
		Include /ruleset/coraza.conf
		Include /ruleset/vaultwarden/crs-setup.conf
		Include /ruleset/coreruleset/rules/*.conf
		`
	}

	request_body {
		max_size 100MB
	}

	# Handle vaultwarden sends with file upload.
	@not-api not path /api/sends/*
	request_body @not-api {
		max_size 100KB
	}

	encode gzip
	tls {
			dns gandi {$GANDI_API_KEY}
	}

	# By default, Vaultwarden actually handle a lot Web Security Header and caching.
	header {
		Strict-Transport-Security "max-age=15768000;"
		Referrer-Policy "no-referrer"
		X-Robots-Tag "none"
	}

	@insecureadmin {
		not remote_ip 192.168.1.0/24
		path /admin*
	}
	redir @insecureadmin /
	reverse_proxy vaultwarden:60278 {
		header_up X-Real-IP {remote_host}
	}
}

e. CRS version:

from crs-setup.conf: tx.crs_setup_version=400

[M4tteoP]

Hey, apologies, I just took a look at this now. I'm quite confident you are facing the point 3. written in the PR you mentioned:

Just like phases 3 and phases 4, also for phase 5 I had to explicitly set SecDefaultAction "phase:5,log,auditlog,pass" (Related to #494). Rule 980170 does not have explicit log, therefore Coraza does not log its message without setting the default action also for this phase.

So something like the following should do the trick 🤞

	coraza_waf {
		directives `
		Include /ruleset/coraza.conf
		Include /ruleset/vaultwarden/crs-setup.conf
		SecDefaultAction "phase:5,log,auditlog,pass"
		Include /ruleset/coreruleset/rules/*.conf
		`
	}

[github-actions]

This issue has been open 30 days waiting for feedback. Remove the stale label or comment, or this will be closed in 14 days.

[github-actions]

This issue was closed because it has been inactive for 14 days since being marked as stale.

[github-actions]

This issue has been open 30 days waiting for feedback. Remove the stale label or comment, or this will be closed in 14 days.

[Barnoux]

Hello, sorry for the late reply, There is no more the issue 👍

{
    "level": "error",
    "ts": 1726170503.9216244,
    "logger": "http.handlers.waf",
    "msg": "[client \"192.168.1.1\"] Coraza: Access denied (phase 5). Anomaly Scores: (Inbound Scores: blocking=3, detection=3, per_pl=0-0-3-0, threshold=1000) - (Outbound Scores: blocking=0, detection=0, per_pl=0-0-0-0, threshold=1000) - (SQLI=3, XSS=0, RFI=0, LFI=0, R [file \"/ruleset/coreruleset/rules/RESPONSE-980-CORRELATION.conf\"]
        [line \"13679\"]
        [id \"980170\"]
        [rev \"\"]
        [msg \"Anomaly Scores: (Inbound Scores: blocking=3, detection=3, per_pl=0-0-3-0, threshold=1000) - (Outbound Scores: blocking=0, detection=0, per_pl=0-0-0-0, threshold=1000) - (SQLI=3, XSS=0, RFI=0, LFI=0, R\"]
        [data \"\"]
        [severity \"emergency\"]
        [ver \"OWASP_CRS/4.3.0\"]
        [maturity \"0\"]
        [accuracy \"0\"]
        [tag \"reporting\"]
        [tag \"OWASP_CRS\"]
        [hostname \"\"]
        [uri \"/notifications/hub?access_token=eyJ0eXAiOiJKV1QiLCJhbGciOiJSUzI1NiJ9.eyJuYmYiOjE3MjYxNjk2OTksImV4cCI6MTcyNjE3Njg5OSwiaXNzIjoiaHR0cHM6Ly92YXVsdHdhcmRlbi5vbmU0YWxsLmljdXxsb2dpbiIsInN1YiI6IjYxZGRiOGQ4LWE1MDgtNGM5My1iZmUwLTAzZjE2MzU4OGNkMyIsInByZW1pdW0iOnRydWUsIm5hbWUiOiJCYXJub3V4IiwiZW1haWwiOiJiYmFybm91eEBnbWFpbC5jb20iLCJlbWFpbF92ZXJpZmllZCI6dHJ1ZSwic3N0YW1wIjoiYjM0NGMxODMtNjUyYS00MjZhLThhYjAtYTVhODgwMWZiZTY5IiwiZGV2aWNlIjoiNzVhOWMxNTctMjg1OS00YTE3LWExMzctNDBjNDlmODFhMGQ1Iiwic2NvcGUiOlsiYXBpIiwib2ZmbGluZV9hY2Nlc3MiXSwiYW1yIjpbIkFwcGxpY2F0aW9uIl19.a8QDqEPyvGvHPeiAlp4dNdfC2hMQHaP2tpeQ_vqCUCFYaL0_6tVhFj_T6UU7B_eyl7-IoLLtHKLVXi7UelSXJcq-RwN2Ad-PTBbKO9DcvJuLKMaN0u1NR3HxTeeW1u9llpgQyIDq9XxZ13mYVGjvOSiXGEryOMCXXIyu9p2H_Tj6u8S9yOhZf1d1eXOFq82cSGUBgKiMXZsItyoMzgRmjy9y9ULxODEZicO0_66K52uVjvuwtUFRI6PbId54KMtmdvAt-jC-VO1vLKNUjCwWdjWl4oXFML8HSFxFKvm1ZCktOj-l1d2ZFzWMDdKH80_GI_-Qsk7uIIHSK166l_rD_w\"]
        [unique_id \"clpuhxOGpwZLPcST\"]\n"
}