About how to record the POST request content to the log file

Help
1

I want to record HTTP Post’s request body to the log, but I tried many methods to achieve it. Where is my configuration problem? I hope to help me thank me very much.

I use the Windows version Caddy 2.9.1 version
My Caddyfile file content

{
    debug
}
test.wanvb.com {
    log {
        output file access.log
        format json
    }
	handle {
		log_append area "dynamic"
		log_append postbody {http.request.body}
		log_append method {http.request.method}
		reverse_proxy http://127.0.0.1:5805
	}
    tls {
		dns dnspod 5511***,ad3b981490f4d85d******
        on_demand
    }
}

The real log record content is

{"level":"info","ts":1738420546.9797857,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"117.189.107.50","remote_port":"6849","client_ip":"117.189.107.50","proto":"HTTP/1.1","method":"POST","host":"test.wanvb.com","uri":"/UKEYA.php","headers":{"Accept":["*/*"],"Sec-Fetch-Site":["cross-site"],"Content-Length":["52"],"User-Agent":["Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/107.0.0.0 Safari/537.36 MicroMessenger/7.0.20.1781(0x6700143B) NetType/WIFI MiniProgramEnv/Windows WindowsWechat/WMPF XWEB/8391"],"Sec-Fetch-Mode":["cors"],"Sec-Fetch-Dest":["empty"],"Referer":["https://test.wanvb.com/UKEYA.php"],"Xweb_xhr":["1"],"Cache-Control":["no-cache"],"Content-Type":["application/x-www-form-urlencoded"],"Cookie":["REDACTED"],"Accept-Language":["zh-cn"]},"tls":{"resumed":false,"version":772,"cipher_suite":4865,"proto":"","server_name":"test.wanvb.com"}},"bytes_read":52,"user_id":"","duration":0.0350536,"size":6,"status":200,"resp_headers":{"Content-Type":["text/html; charset=utf-8"],"X-Powered-By":["PHP/8.2.0"],"Server":["Caddy","nginx"],"Alt-Svc":["h3=\":443\"; ma=2592000"],"Date":["Sat, 01 Feb 2025 14:35:46 GMT"]},"method":"POST","postbody":"","area":"dynamic"}

{"level":"info","ts":1738420563.9426904,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_ip":"117.189.107.50","remote_port":"6874","client_ip":"117.189.107.50","proto":"HTTP/1.1","method":"POST","host":"test.wanvb.com","uri":"/UKEYA.php","headers":{"Cookie":["REDACTED"],"Referer":["https://test.wanvb.com/UKEYA.php"],"Sec-Fetch-Site":["cross-site"],"Sec-Fetch-Mode":["cors"],"Accept":["*/*"],"Content-Length":["138"],"Cache-Control":["no-cache"],"User-Agent":["Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/107.0.0.0 Safari/537.36 MicroMessenger/7.0.20.1781(0x6700143B) NetType/WIFI MiniProgramEnv/Windows WindowsWechat/WMPF XWEB/8391"],"Content-Type":["application/json"],"Sec-Fetch-Dest":["empty"],"Accept-Language":["zh-cn"],"Xweb_xhr":["1"]},"tls":{"resumed":false,"version":772,"cipher_suite":4865,"proto":"","server_name":"test.wanvb.com"}},"bytes_read":138,"user_id":"","duration":0.0221012,"size":6,"status":200,"resp_headers":{"X-Powered-By":["PHP/8.2.0"],"Date":["Sat, 01 Feb 2025 14:36:03 GMT"],"Content-Type":["text/html; charset=utf-8"],"Server":["Caddy","nginx"],"Alt-Svc":["h3=\":443\"; ma=2592000"]},"method":"POST","postbody":"","area":"dynamic"}

Regardless of whether I turn on the debug mode, Postbody is empty, and I don’t know where the problem is.

I tried Content-Type: Application/X-WWW-FORM-Urlencoded Method POST Submit index=0&isActive=false&age=21&eyeColor=blue&test=123

Try the Content-Type: Application/JSON method post submit {“Index”: 0, “Isactive”: false, “Age”: 21, “Eyecolor”: “Blue”} log postbody records are also empty,

I hope the management master will help guide how I set it up to correctly record the content of the HTTP POST’s request body to the log? Thank you so much.
Because my back -end system often has an attacker to initiate POST malicious injection code for attack, I need to analyze the POST content they submitted, and then do targeted filtering and prevention. Power, this record is very useful. It can be recorded normally on nginx using $ Request_body variables, but currently I can’t successfully set the record on Caddy
[/quote]

2

I’m not able to reproduce it. This config:

{
	debug
}
localhost {
	log
	handle {
		log_append req_body {http.request.body}
		respond "OK"
	}
}

Prints this log line:

{
	"level": "info",
	"ts": 1738491714.210384,
	"logger": "http.log.access",
	"msg": "handled request",
	"request": {
		"remote_ip": "::1",
		"remote_port": "61490",
		"client_ip": "::1",
		"proto": "HTTP/2.0",
		"method": "POST",
		"host": "localhost",
		"uri": "/",
		"headers": {
			"Content-Length": [
				"62"
			],
			"Content-Type": [
				"application/x-www-form-urlencoded"
			],
			"User-Agent": [
				"curl/8.11.1"
			],
			"Accept": [
				"*/*"
			]
		},
		"tls": {
			"resumed": false,
			"version": 772,
			"cipher_suite": 4865,
			"proto": "h2",
			"server_name": "localhost"
		}
	},
	"bytes_read": 62,
	"user_id": "",
	"duration": 2.958173448,
	"size": 2,
	"status": 200,
	"resp_headers": {
		"Server": [
			"Caddy"
		],
		"Alt-Svc": [
			"h3=\":443\"; ma=2592000"
		],
		"Content-Type": [
			"text/plain; charset=utf-8"
		]
	},
	"req_body": "{\"Index\": 0, \"Isactive\": false, \"Age\": 21, \"Eyecolor\": \"Blue\"}"
}

With this request body:

~ $ curl -k https://localhost -d @body.txt
OK%
~ $ cat body.txt
{"Index": 0, "Isactive": false, "Age": 21, "Eyecolor": "Blue"}

Show me a proof with curl so I can reproduce it.

3

Hello brother, thank you very much for providing help. After testing your Caddyfile configuration, Req_body variable can record the Post Body normally. I find that the problem is not available to the reverse proxy of the reverse_proxy. Once you use the reverse_proxy, then the REQ_BODY variable will not be able to record the post request body. Is this a bug? Or do I need to configure to record the POST request body in the case of reverse?

{
	debug
}
localhost {
	log
	handle {
		log_append req_body {http.request.body}
		#respond "OK"
		reverse_proxy http://127.0.0.1:5805
	}
}

Req_body in the above configuration log is empty

4

Good catch! Yes, it’s a bug, and I can reproduce it.

{
	"level": "info",
	"ts": 1738495897.270564,
	"logger": "http.log.access",
	"msg": "handled request",
	"request": {
		"remote_ip": "::1",
		"remote_port": "50245",
		"client_ip": "::1",
		"proto": "HTTP/1.1",
		"method": "POST",
		"host": "localhost",
		"uri": "/",
		"headers": {
			"User-Agent": [
				"curl/8.11.1"
			],
			"Accept": [
				"*/*"
			],
			"Content-Length": [
				"62"
			],
			"Content-Type": [
				"application/x-www-form-urlencoded"
			]
		}
	},
	"bytes_read": 62,
	"user_id": "",
	"duration": 11.395598527,
	"size": 2,
	"status": 200,
	"resp_headers": {
		"Via": [
			"1.1 Caddy"
		],
		"Content-Length": [
			"2"
		],
		"Content-Type": [
			"text/plain; charset=utf-8"
		],
		"Server": [
			"Caddy"
		],
		"Date": [
			"Sun, 02 Feb 2025 11:31:25 GMT"
		]
	},
	"req_body": ""
}

Can you file a bug here, if you don’t mind?

5

I have a workaround. Use the vars handler to set the request body placeholder to another placeholder, then use the new placeholder in log_appened. Something like this works:

{
	debug
}
example.com {
	log
	vars request_body {http.request.body}
	log_append req_body {http.vars.request_body}
	reverse_proxy localhost:8080
}
http://localhost:8080 {
	respond "ok"
}

The log_append handler calls the next handler before recording the value of the appended key because it might depend on the response of the next handler; however, when used with reverse_proxy handler, the reverse_proxy consumes the request body before the log_append gets a chance to read it. Caddy doesn’t buffer the full request in memory to avoid memory-exhaustion attacks (malicious or unintended). Any change or fix I would do will incur full buffering of the request into memory, which is undesirable. I’m hesitant changing the current behavior, especially since a workaround is available.

6

This is actually quite interesting - I was wondering how Caddy handles situations like this.

For example, when processing POST data in F5 BIG-IP iRules (TCL language), I specify the amount of POST data I want to collect for further processing within the iRule.

Can I do something similar in Caddy? Specifically, can I control how much POST data gets collected for logging or making traffic flow decisions?

7

You can most likely build a handler that works that way. However, my experiments yesterday say the execution of the handler has to be in controlled manner because there’s no way to make it concurrency-safe. In an attempt to make the earlier config work as-is yesterday, I made a cylic buffer, which resets when reaches the end, to allow multiple consecutive consumers, but I realized the cursor will advance when another concurrent consumer reads from it.

1 Like
8

Thank you very much bro, I tested it really fine as you suggested, thank you very much