Okay, after I spent the afternoon searching for the answer, I saw it’s related to a previous question I’ve asked: Log reverse_proxy upstream - #4 by matt
added
{
debug
}
but still nothing:
2020/08/16 15:00:55.748 DEBUG http.reverse_proxy.transport.fastcgi roundtrip {"request": {"method": "GET", "uri": "/test.cgi", "proto": "HTTP/2.0", "remote_addr": "[fd12:ac4a:1e71:d241:3999:9360:3804:8e5e]:34612", "host": "pubserv.toets.co.za", "headers": {"User-Agent": ["curl/7.64.0"], "Accept": ["*/*"], "X-Forwarded-For": ["fd12:ac4a:1e71:d241:3999:9360:3804:8e5e"], "X-Forwarded-Proto": ["https"]}, "tls": {"resumed": false, "version": 772, "ciphersuite": 4867, "proto": "h2", "proto_mutual": true, "server_name": "pubserv.toets.co.za"}}, "dial": "/run/fcgiwrap.socket", "env": {"AUTH_TYPE":"","CONTENT_LENGTH":"","CONTENT_TYPE":"","DOCUMENT_ROOT":"/usr/local/bin","DOCUMENT_URI":"/test.cgi","GATEWAY_INTERFACE":"CGI/1.1","HTTPS":"on","HTTP_ACCEPT":"*/*","HTTP_HOST":"pubserv.toets.co.za","HTTP_USER_AGENT":"curl/7.64.0","HTTP_X_FORWARDED_FOR":"fd12:ac4a:1e71:d241:3999:9360:3804:8e5e","HTTP_X_FORWARDED_PROTO":"https","PATH_INFO":"","QUERY_STRING":"","REMOTE_ADDR":"fd12:ac4a:1e71:d241:3999:9360:3804:8e5e","REMOTE_HOST":"fd12:ac4a:1e71:d241:3999:9360:3804:8e5e","REMOTE_IDENT":"","REMOTE_PORT":"34612","REMOTE_USER":"","REQUEST_METHOD":"GET","REQUEST_SCHEME":"https","REQUEST_URI":"/test.cgi","SCRIPT_FILENAME":"/usr/local/bin/test.cgi","SCRIPT_NAME":"/test.cgi","SERVER_NAME":"pubserv.toets.co.za","SERVER_PORT":"","SERVER_PROTOCOL":"HTTP/2.0","SERVER_SOFTWARE":"Caddy/v2.1.1","SSL_CIPHER":"TLS_CHACHA20_POLY1305_SHA256","SSL_PROTOCOL":"TLSv1.3"}}
2020/08/16 15:00:55.753 DEBUG http.handlers.reverse_proxy upstream roundtrip {"upstream": "unix//run/fcgiwrap.socket", "request": {"method": "GET", "uri": "/test.cgi", "proto": "HTTP/2.0", "remote_addr": "[fd12:ac4a:1e71:d241:3999:9360:3804:8e5e]:34612", "host": "pubserv.toets.co.za", "headers": {"Accept": ["*/*"], "X-Forwarded-For": ["fd12:ac4a:1e71:d241:3999:9360:3804:8e5e"], "X-Forwarded-Proto": ["https"], "User-Agent": ["curl/7.64.0"]}, "tls": {"resumed": false, "version": 772, "ciphersuite": 4867, "proto": "h2", "proto_mutual": true, "server_name": "pubserv.toets.co.za"}}, "duration": 0.005227912, "headers": {"Status": ["403 Forbidden"], "Content-Type": ["text/plain"]}, "status": 403}
1.5975900557532492e+09 error http.log.access.log0 handled request {"request": {"method": "GET", "uri": "/test.cgi", "proto": "HTTP/2.0", "remote_addr": "[fd12:ac4a:1e71:d241:3999:9360:3804:8e5e]:34612", "host": "pubserv.toets.co.za", "headers": {"User-Agent": ["curl/7.64.0"], "Accept": ["*/*"]}, "tls": {"resumed": false, "version": 772, "ciphersuite": 4867, "proto": "h2", "proto_mutual": true, "server_name": "pubserv.toets.co.za"}}, "common_log": "fd12:ac4a:1e71:d241:3999:9360:3804:8e5e - - [16/Aug/2020:17:00:55 +0200] \"GET /test.cgi HTTP/2.0\" 403 15",
"duration": 0.005335867, "size": 15, "status": 403, "resp_headers": {"Server": ["Caddy"], "Status": ["403 Forbidden"], "Content-Type": ["text/plain"]}}
2020/08/16 15:00:55.753 ERROR http.log.access.log0 handled request {"request": {"method": "GET", "uri": "/test.cgi", "proto": "HTTP/2.0", "remote_addr": "[fd12:ac4a:1e71:d241:3999:9360:3804:8e5e]:34612", "host": "pubserv.toets.co.za", "headers": {"User-Agent": ["curl/7.64.0"], "Accept": ["*/*"]}, "tls": {"resumed": false, "version": 772, "ciphersuite": 4867, "proto": "h2", "proto_mutual": true, "server_name": "pubserv.toets.co.za"}}, "common_log": "fd12:ac4a:1e71:d241:3999:9360:3804:8e5e - - [16/Aug/2020:17:00:55 +0200] \"GET /test.cgi HTTP/2.0\" 403 15",
"duration": 0.005335867, "size": 15, "status": 403, "resp_headers": {"Server": ["Caddy"], "Status": ["403 Forbidden"], "Content-Type": ["text/plain"]}}
Then I added the "http.handlers.reverse_proxy" to the logging:
hvisage@jetaddzero ~ % curl -s -X PUT -H "Content-Type: application/json" -d '"http.handlers.reverse_proxy"' http://localhost:2019/config/logging/logs/log0/include/0 | jq .
hvisage@jetaddzero ~ % curl -s http://localhost:2019/config/
{"apps":{"http":{"servers":{"srv0":{"listen":[":443"],"logs":{"logger_names":{"intserv.toets.co.za":"log0","jetaddzero.toets.co.za":"log0","pubserv.toets.co.za":"log0"}},"routes":[{"handle":[{"handler":"subroute","routes":[{"handle":[{"handler":"vars","root":"/usr/share/caddy"}]},{"handle":[{"handler":"reverse_proxy","transport":{"protocol":"fastcgi","root":"/usr/local/bin","split_path":[".cgi"]},"upstreams":[{"dial":"unix//run/fcgiwrap.socket"}]}],"match":[{"path":["/test.cgi"]}]},{"handle":[{"handler":"file_server","hide":["Caddyfile"]}]}]}],"match":[{"host":["pubserv.toets.co.za","intserv.toets.co.za","jetaddzero.toets.co.za"]}],"terminal":true}],"tls_connection_policies":[{"certificate_selection":{"any_tag":["cert0"]},"match":{"sni":["pubserv.toets.co.za","intserv.toets.co.za","jetaddzero.toets.co.za"]}},{}]}}},"tls":{"certificates":{"load_files":[{"certificate":"/etc/letsencrypt/live/pubserv.toets.co.za/fullchain.pem","key":"/etc/letsencrypt/live/pubserv.toets.co.za/privkey.pem","tags":["cert0"]}]}}},"logging":{"logs":{"default":{"level":"DEBUG"},"log0":{"encoder":{"format":"console"},"include":["http.handlers.reverse_proxy.fastcgi","http.handlers.reverse_proxy.fastcgi","http.handlers.reverse_proxy","http.log.access.log0"],"level":"DEBUG","writer":{"output":"stdout"}}}}}
Seems I get some extra debugging, but still not the fcpiwrap's error message:
2020/08/16 15:25:20.122 DEBUG http.reverse_proxy.transport.fastcgi roundtrip {"request": {"method": "GET", "uri": "/test.cgi", "proto": "HTTP/2.0", "remote_addr": "[fd12:ac4a:1e71:d241:3999:9360:3804:8e5e]:34702", "host": "pubserv.toets.co.za", "headers": {"X-Forwarded-Proto": ["https"], "User-Agent": ["curl/7.64.0"], "Accept": ["*/*"], "X-Forwarded-For": ["fd12:ac4a:1e71:d241:3999:9360:3804:8e5e"]}, "tls": {"resumed": false, "version": 772, "ciphersuite": 4867, "proto": "h2", "proto_mutual": true, "server_name": "pubserv.toets.co.za"}}, "dial": "/run/fcgiwrap.socket", "env": {"AUTH_TYPE":"","CONTENT_LENGTH":"","CONTENT_TYPE":"","DOCUMENT_ROOT":"/usr/local/bin","DOCUMENT_URI":"/test.cgi","GATEWAY_INTERFACE":"CGI/1.1","HTTPS":"on","HTTP_ACCEPT":"*/*","HTTP_HOST":"pubserv.toets.co.za","HTTP_USER_AGENT":"curl/7.64.0","HTTP_X_FORWARDED_FOR":"fd12:ac4a:1e71:d241:3999:9360:3804:8e5e","HTTP_X_FORWARDED_PROTO":"https","PATH_INFO":"","QUERY_STRING":"","REMOTE_ADDR":"fd12:ac4a:1e71:d241:3999:9360:3804:8e5e","REMOTE_HOST":"fd12:ac4a:1e71:d241:3999:9360:3804:8e5e","REMOTE_IDENT":"","REMOTE_PORT":"34702","REMOTE_USER":"","REQUEST_METHOD":"GET","REQUEST_SCHEME":"https","REQUEST_URI":"/test.cgi","SCRIPT_FILENAME":"/usr/local/bin/test.cgi","SCRIPT_NAME":"/test.cgi","SERVER_NAME":"pubserv.toets.co.za","SERVER_PORT":"","SERVER_PROTOCOL":"HTTP/2.0","SERVER_SOFTWARE":"Caddy/v2.1.1","SSL_CIPHER":"TLS_CHACHA20_POLY1305_SHA256","SSL_PROTOCOL":"TLSv1.3"}}
2020/08/16 15:25:20.127 DEBUG http.handlers.reverse_proxy upstream roundtrip {"upstream": "unix//run/fcgiwrap.socket", "request": {"method": "GET", "uri": "/test.cgi", "proto": "HTTP/2.0", "remote_addr": "[fd12:ac4a:1e71:d241:3999:9360:3804:8e5e]:34702", "host": "pubserv.toets.co.za", "headers": {"User-Agent": ["curl/7.64.0"], "Accept": ["*/*"], "X-Forwarded-For":
["fd12:ac4a:1e71:d241:3999:9360:3804:8e5e"], "X-Forwarded-Proto": ["https"]}, "tls": {"resumed": false, "version": 772, "ciphersuite": 4867, "proto": "h2", "proto_mutual": true, "server_name": "pubserv.toets.co.za"}}, "duration": 0.004894642, "headers": {"Content-Type": ["text/plain"], "Status": ["403 Forbidden"]}, "status": 403}
1.5975915201271837e+09 debug http.handlers.reverse_proxy upstream roundtrip {"upstream": "unix//run/fcgiwrap.socket", "request": {"method": "GET", "uri": "/test.cgi", "proto": "HTTP/2.0", "remote_addr": "[fd12:ac4a:1e71:d241:3999:9360:3804:8e5e]:34702", "host": "pubserv.toets.co.za", "headers": {"User-Agent": ["curl/7.64.0"], "Accept": ["*/*"], "X-Forwarded-For":
["fd12:ac4a:1e71:d241:3999:9360:3804:8e5e"], "X-Forwarded-Proto": ["https"]}, "tls": {"resumed": false, "version": 772, "ciphersuite": 4867, "proto": "h2", "proto_mutual": true, "server_name": "pubserv.toets.co.za"}}, "duration": 0.004894642, "headers": {"Status": ["403 Forbidden"], "Content-Type": ["text/plain"]}, "status": 403}
2020/08/16 15:25:20.127 ERROR http.log.access.log0 handled request {"request": {"method": "GET", "uri": "/test.cgi", "proto": "HTTP/2.0", "remote_addr": "[fd12:ac4a:1e71:d241:3999:9360:3804:8e5e]:34702", "host": "pubserv.toets.co.za", "headers": {"User-Agent": ["curl/7.64.0"], "Accept": ["*/*"]}, "tls": {"resumed": false, "version": 772, "ciphersuite": 4867, "proto": "h2", "proto_mutual": true, "server_name": "pubserv.toets.co.za"}}, "common_log": "fd12:ac4a:1e71:d241:3999:9360:3804:8e5e - - [16/Aug/2020:17:25:20 +0200] \"GET /test.cgi HTTP/2.0\" 403 15",
"duration": 0.005031943, "size": 15, "status": 403, "resp_headers": {"Status": ["403 Forbidden"], "Content-Type": ["text/plain"], "Server": ["Caddy"]}}
1.5975915201272664e+09 error http.log.access.log0 handled request {"request": {"method": "GET", "uri": "/test.cgi", "proto": "HTTP/2.0", "remote_addr": "[fd12:ac4a:1e71:d241:3999:9360:3804:8e5e]:34702", "host": "pubserv.toets.co.za", "headers": {"User-Agent": ["curl/7.64.0"], "Accept": ["*/*"]}, "tls": {"resumed": false, "version": 772, "ciphersuite": 4867, "proto": "h2", "proto_mutual": true, "server_name": "pubserv.toets.co.za"}}, "common_log": "fd12:ac4a:1e71:d241:3999:9360:3804:8e5e - - [16/Aug/2020:17:25:20 +0200] \"GET /test.cgi HTTP/2.0\" 403 15",
"duration": 0.005031943, "size": 15, "status": 403, "resp_headers": {"Server": ["Caddy"], "Status": ["403 Forbidden"], "Content-Type": ["text/plain"]}}