Fcgiwrap - errors & variables

1. Caddy version (caddy version):

v2.1.1 h1:X9k1+ehZPYYrSqBvf/ocUgdLSRIuiNiMo7CvyGUQKeA=

2. How I run Caddy:

a. System environment:

Virtual machine:
4.19.0-10-amd64 #1 SMP Debian 4.19.132-1 (2020-07-24) x86_64 GNU/Linux

b. Command:

caddy run --watch

d. My complete Caddyfile or JSON config:

pubserv.toets.co.za intserv.toets.co.za jetaddzero.toets.co.za
root * /usr/share/caddy
file_server
log {
 format console
 output stdout
}
tls /etc/letsencrypt/live/pubserv.toets.co.za/fullchain.pem /etc/letsencrypt/live/pubserv.toets.co.za/privkey.pem
reverse_proxy /test.cgi {
 to unix//run/fcgiwrap.socket
 transport fastcgi {
   root /usr/local/bin
   split .cgi
 }
}

3. The problem I’m having:

I’m trying to see the errors that fcgiwrap emits (using it’s -f parameter) back on the fastcgi Unix socket on the Caddy side
Combined log in Caddy2 + error log question refers, as that haven’t been answered it seemed ?

4. Error messages and/or full log output:

5. What I already tried:

hvisage@jetaddzero ~ % curl   https://pubserv.toets.co.za/test.cgi
403 Forbidden
2020/08/16 14:45:03.685 INFO    watcher watching config file for changes        {"config_file": "Caddyfile"}
2020/08/16 16:45:03 [INFO][cache:0xc0002474a0] Started certificate maintenance routine
1.5975891084600637e+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]:34606", "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:16:45:08 +0200] \"GET /test.cgi HTTP/2.0\" 403 15",
"duration": 0.008544152, "size": 15, "status": 403, "resp_headers": {"Server": ["Caddy"], "Status": ["403 Forbidden"], "Content-Type": ["text/plain"]}}

accept(0, {sa_family=AF_UNIX}, [112->2]) = 3
poll([{fd=3, events=POLLIN}], 1, 2000)  = 1 ([{fd=3, revents=POLLIN}])
read(3, "\1\1\0\1\0\10\0\0\0\1\0\0\0\0\0\0", 8192) = 16
read(3, "\1\4\0\1\2\357\1\0\v'REMOTE_HOSTfd12:ac4a:1e71:d241:3999:9360:3804:8e5e\t\23HTTP_HOSTpubserv.toets.co.za\17\vHTTP_USER_AGENTcurl/7.64.0\24'HTTP_X_FORWARDED_FORfd12:ac4a:1e71:d241:3999:9360:3804:8e5e\t\0AUTH_TYPE\v\0REMOTE_USER\v\5REMOTE_PORT34606\26\5HTTP_X_FORWARDED_PROTOhttps\17\27SCRIPT_FILENAME/usr/local/bin/test.cgi\t\0PATH_INFO\v\0SERVER_PORT\17\10SERVER_PROTOCOLHTTP/2.0\v\tSCRIPT_NAME/test.cgi\v\23SERVER_NAMEpubserv.toets.co.za\v\tREQUEST_URI/test.cgi\f\7SSL_PROTOCOLTLSv1.3\f\0REMOTE_IDENT\16\1CONTENT_LENGTH0\f\tDOCUMENT_URI/test.cgi\n\34SSL_CIPHERTLS_CHACHA20_POLY1305_SHA256\21\7GATEWAY_INTERFACECGI/1.1\f\0QUERY_STRING\r\16DOCUMENT_ROOT/usr/local/bin\5\2HTTPSon\v\3HTTP_ACCEPT*/*\v'REMOTE_ADDRfd12:ac4a:1e71:d241:3999:9360:3804:8e5e\17\fSERVER_SOFTWARECaddy/v2.1.1\16\5REQUEST_SCHEMEhttps\f\0CONTENT_TYPE\16\3REQUEST_METHODGET\0", 8192) = 760
read(3, "\1\4\0\1\0\0\0\0", 8192)       = 8
pipe([4, 5])                            = 0
pipe([6, 7])                            = 0
pipe([8, 9])                            = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f31d0ef1a90) = 4790
close(4)                                = 0
close(7)                                = 0
close(9)                                = 0
read(3, "\1\5\0\1\0\0\0\0", 8192)       = 8
close(5)                                = 0
select(9, [6 8], NULL, NULL, NULLstrace: Process 4790 attached
 <unfinished ...>
[pid  4790] set_robust_list(0x7f31d0ef1aa0, 24) = 0
[pid  4790] close(5)                    = 0
[pid  4790] close(6)                    = 0
[pid  4790] close(8)                    = 0
[pid  4790] dup2(4, 0)                  = 0
[pid  4790] dup2(7, 1)                  = 1
[pid  4790] dup2(9, 2)                  = 2
[pid  4790] close(4)                    = 0
[pid  4790] close(7)                    = 0
[pid  4790] close(9)                    = 0
[pid  4790] close(-1)                   = -1 EBADF (Bad file descriptor)
[pid  4790] rt_sigaction(SIGCHLD, {sa_handler=SIG_DFL, sa_mask=[CHLD], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f31d10fb840}, {sa_handler=SIG_IGN, sa_mask=[CHLD], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f31d10fb840}, 8) = 0
[pid  4790] rt_sigaction(SIGPIPE, {sa_handler=SIG_DFL, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f31d10fb840}, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f31d10fb840}, 8) = 0
[pid  4790] lstat("/usr/local/bin/test.cgi", 0x7ffdb5a43c90) = -1 ENOENT (No such file or directory)
[pid  4790] fstat(1, {st_dev=makedev(0, 0xc), st_ino=1390500, st_mode=S_IFIFO|0600, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=0, st_size=0, st_atime=1597589108 /* 2020-08-16T16:45:08.450491005+0200 */, st_atime_nsec=450491005, st_mtime=1597589108 /* 2020-08-16T16:45:08.450491005+0200 */, st_mtime_nsec=450491005, st_ctime=1597589108 /* 2020-08-16T16:45:08.450491005+0200 */, st_ctime_nsec=450491005}) = 0
[pid  4790] write(1, "Status: 403 Forbidden\r\nContent-Type: text/plain\r\n\r\n403 Forbidden\r\n", 66 <unfinished ...>
[pid  4537] <... select resumed> )      = 1 (in [6])
[pid  4790] <... write resumed> )       = 66
[pid  4537] read(6, "Status: 403 Forbidden\r\nContent-Type: text/plain\r\n\r\n403 Forbidden\r\n", 4096) = 66
[pid  4537] select(9, [6 8], NULL, NULL, NULL <unfinished ...>
[pid  4790] write(2, "Cannot get script name, are DOCUMENT_ROOT and SCRIPT_NAME (or SCRIPT_FILENAME) set and is the script executable?", 112 <unfinished ...>
[pid  4537] <... select resumed> )      = 1 (in [8])
[pid  4790] <... write resumed> )       = 112
[pid  4537] read(8, "Cannot get script name, are DOCUMENT_ROOT and SCRIPT_NAME (or SCRIPT_FILENAME) set and is the script executable?", 4096) = 112
[pid  4537] select(9, [6 8], NULL, NULL, NULL <unfinished ...>
[pid  4790] write(2, "\n", 1 <unfinished ...>
[pid  4537] <... select resumed> )      = 1 (in [8])
[pid  4790] <... write resumed> )       = 1
[pid  4537] read(8, "\n", 4096)         = 1
[pid  4537] select(9, [6 8], NULL, NULL, NULL <unfinished ...>
[pid  4790] exit_group(99)              = ?
[pid  4537] <... select resumed> )      = 1 (in [8])
[pid  4537] read(8, "", 4096)           = 0
[pid  4537] close(8)                    = 0
[pid  4537] select(9, [6], NULL, NULL, NULL) = 1 (in [6])
[pid  4537] read(6, "", 4096)           = 0
[pid  4537] close(6)                    = 0
[pid  4537] write(3, "\1\7\0\1\0q\7\0Cannot get script name, are DOCUMENT_ROOT and SCRIPT_NAME (or SCRIPT_FILENAME) set and is the script executable?\n\0\0\0\0\0\0\0\1\7\0\1\0\0\0\0", 136) = 136
[pid  4537] write(3, "\1\6\0\1\0B\6\0Status: 403 Forbidden\r\nContent-Type: text/plain\r\n\r\n403 Forbidden\r\n\0\0\0\0\0\0\1\6\0\1\0\0\0\0\1\3\0\1\0\10\0\0\0\0\0\0\0\0\0\0", 104) = 104
[pid  4537] shutdown(3, SHUT_WR)        = 0
[pid  4537] poll([{fd=3, events=POLLIN}], 1, 2000) = 1 ([{fd=3, revents=POLLIN|POLLERR|POLLHUP}])
[pid  4537] read(3, 0x7ffdb5a438b0, 1024) = -1 ECONNRESET (Connection reset by peer)
[pid  4537] close(3)                    = 0
[pid  4537] accept(0,  <unfinished ...>
[pid  4790] +++ exited with 99 +++
<... accept resumed> 0x7ffdb5a43c50, [112]) = ? ERESTARTSYS (To be restarted if SA_RESTART is set)
--- SIGWINCH {si_signo=SIGWINCH, si_code=SI_KERNEL} ---
accept(0,

6. Links to relevant resources:

As can be seen with this line, fcgiwrap writes the data back, but how do I get that into a error_log type file to track the errors coming from fcgiwrap ?

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"]}}

I think fcgiwrap isn’t bubbling up its errors to Caddy other than returning a 403 Forbidden error.

Could you try v2.2.0-rc.1 to see if it works any better for you? We’ve made a bunch of changes to the fastcgi transport that may be relevant for you. This PR in particular might be the relevant fix:

https://github.com/caddyserver/caddy/pull/3570

Hmmm… that is wrong, from the strace information, it IS, the handlers doesn’t report on it?

Testing with Caddy 2.2.0-rc1:

[pid 23156] write(3, "\1\7\0\1\0q\7\0Cannot get script name, are DOCUMENT_ROOT and SCRIPT_NAME (or SCRIPT_FILENAME) set and is the script executable?\n\0\0\0\0\0\0\0\1\7\0\1\0\0\0\0", 136)
= 136
[pid 23156] write(3, "\1\6\0\1\0B\6\0Status: 403 Forbidden\r\nContent-Type: text/plain\r\n\r\n403 Forbidden\r\n\0\0\0\0\0\0\1\6\0\1\0\0\0\0\1\3\0\1\0\10\0\0\0\0\0\0\0\0\0\0", 104) = 104

See, fcgiwrap did sent the reason for the error, but Caddy doesn’t report anything??

1.5975938997784736e+09  info    http.log.access.log0    handled request {"request": {"remote_addr": "[fd12:ac4a:1e71:d241:3999:9360:3804:8e5e]:34760", "proto": "HTTP/2.0", "method": "GET", "host": "pubserv.toets.co.za", "uri": "/cgi/test.cgi?mac=1.2.3.4", "headers": {"User-Agent": ["curl/7.64.0"], "Accept": ["*/*"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": $
867, "proto": "h2", "proto_mutual": true, "server_name": "pubserv.toets.co.za"}}, "common_log": "fd12:ac4a:1e71:d241:3999:9360:3804:8e5e - - [16/Aug/2020:18:04:59 +0200] \"GET /cgi/test.cg$
?mac=1.2.3.4 HTTP/2.0\" 200 177", "duration": 0.09157027, "size": 177, "status": 200, "resp_headers": {"Server": ["Caddy"], "Content-Type": ["text/html"]}}
2020/08/16 16:05:09.016 DEBUG   http.reverse_proxy.transport.fastcgi    roundtrip       {"request": {"remote_addr": "[fd12:ac4a:1e71:d241:3999:9360:3804:8e5e]:34762", "proto": "HTTP/2.0", $method": "GET", "host": "pubserv.toets.co.za", "uri": "/cgi/test1.cgi?mac=1.2.3.4", "headers": {"X-Forwarded-For": ["fd12:ac4a:1e71:d241:3999:9360:3804:8e5e"], "X-Forwarded-Proto": ["https$
], "User-Agent": ["curl/7.64.0"], "Accept": ["*/*"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": 4867, "proto": "h2", "proto_mutual": true, "server_name": "pubserv.toets.co.$
a"}}, "dial": "/run/fcgiwrap.socket", "env": {"AUTH_TYPE":"","CONTENT_LENGTH":"","CONTENT_TYPE":"","DOCUMENT_ROOT":"/usr/local/bin","DOCUMENT_URI":"/cgi/test1.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_P$
OTO":"https","PATH_INFO":"","QUERY_STRING":"mac=1.2.3.4","REMOTE_ADDR":"fd12:ac4a:1e71:d241:3999:9360:3804:8e5e","REMOTE_HOST":"fd12:ac4a:1e71:d241:3999:9360:3804:8e5e","REMOTE_IDENT":"","$
EMOTE_PORT":"34762","REMOTE_USER":"","REQUEST_METHOD":"GET","REQUEST_SCHEME":"https","REQUEST_URI":"/cgi/test1.cgi?mac=1.2.3.4","SCRIPT_FILENAME":"/usr/local/bin/cgi/test1.cgi","SCRIPT_NAM$
":"/cgi/test1.cgi","SERVER_NAME":"pubserv.toets.co.za","SERVER_PROTOCOL":"HTTP/2.0","SERVER_SOFTWARE":"Caddy/v2.2.0-rc.1","SSL_CIPHER":"TLS_CHACHA20_POLY1305_SHA256","SSL_PROTOCOL":"TLSv1.$
"}}
2020/08/16 16:05:09.021 DEBUG   http.handlers.reverse_proxy     upstream roundtrip      {"upstream": "unix//run/fcgiwrap.socket", "request": {"remote_addr": "[fd12:ac4a:1e71:d241:3999:9360$3804:8e5e]:34762", "proto": "HTTP/2.0", "method": "GET", "host": "pubserv.toets.co.za", "uri": "/cgi/test1.cgi?mac=1.2.3.4", "headers": {"X-Forwarded-For": ["fd12:ac4a:1e71:d241:3999:9360:$
804:8e5e"], "X-Forwarded-Proto": ["https"], "User-Agent": ["curl/7.64.0"], "Accept": ["*/*"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": 4867, "proto": "h2", "proto_mutual"$ true, "server_name": "pubserv.toets.co.za"}}, "duration": 0.004566342, "headers": {"Status": ["403 Forbidden"], "Content-Type": ["text/plain"]}, "status": 403}
1.5975939090210094e+09  debug   http.handlers.reverse_proxy     upstream roundtrip      {"upstream": "unix//run/fcgiwrap.socket", "request": {"remote_addr": "[fd12:ac4a:1e71:d241:3999:9360$3804:8e5e]:34762", "proto": "HTTP/2.0", "method": "GET", "host": "pubserv.toets.co.za", "uri": "/cgi/test1.cgi?mac=1.2.3.4", "headers": {"X-Forwarded-Proto": ["https"], "User-Agent": ["cur$
/7.64.0"], "Accept": ["*/*"], "X-Forwarded-For": ["fd12:ac4a:1e71:d241:3999:9360:3804:8e5e"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": 4867, "proto": "h2", "proto_mutual"$
 true, "server_name": "pubserv.toets.co.za"}}, "duration": 0.004566342, "headers": {"Status": ["403 Forbidden"], "Content-Type": ["text/plain"]}, "status": 403}
2020/08/16 16:05:09.021 ERROR   http.log.access.log0    handled request {"request": {"remote_addr": "[fd12:ac4a:1e71:d241:3999:9360:3804:8e5e]:34762", "proto": "HTTP/2.0", "method": "GET",
"host": "pubserv.toets.co.za", "uri": "/cgi/test1.cgi?mac=1.2.3.4", "headers": {"User-Agent": ["curl/7.64.0"], "Accept": ["*/*"]}, "tls": {"resumed": false, "version": 772, "cipher_suite":
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:18:05:09 +0200] \"GET /cgi/test1.$
gi?mac=1.2.3.4 HTTP/2.0\" 403 15", "duration": 0.004667577, "size": 15, "status": 403, "resp_headers": {"Server": ["Caddy"], "Content-Type": ["text/plain"], "Status": ["403 Forbidden"]}}
1.5975939090210729e+09  error   http.log.access.log0    handled request {"request": {"remote_addr": "[fd12:ac4a:1e71:d241:3999:9360:3804:8e5e]:34762", "proto": "HTTP/2.0", "method": "GET",
"host": "pubserv.toets.co.za", "uri": "/cgi/test1.cgi?mac=1.2.3.4", "headers": {"User-Agent": ["curl/7.64.0"], "Accept": ["*/*"]}, "tls": {"resumed": false, "version": 772, "cipher_suite":
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:18:05:09 +0200] \"GET /cgi/test1.$
gi?mac=1.2.3.4 HTTP/2.0\" 403 15", "duration": 0.004667577, "size": 15, "status": 403, "resp_headers": {"Server": ["Caddy"], "Content-Type": ["text/plain"], "Status": ["403 Forbidden"]}}

This topic was automatically closed after 30 days. New replies are no longer allowed.