Strange file permission error

Help
1

tl;dr: Caddy runs fine, but returns a 403 on an existing file. Caddy runs as user caddy, group caddy, file is owned by caddy:caddy as well. Path is readable and writable for caddy (access.log in same path works). Requesting the access.log works as well!

1. The problem I’m having:

I set up caddy to server a static file, just for testing the setup, but I’m getting a 403 back, when requesting the index.html file. I checked all the permission issues in here already and non seems to be related. The file path is /srv/www/vrwyw/index.html.
I configured Caddy to write an access.log to /srv/www/vrwyw/access.log and it works fine. Even curl https://domain.tld/access.log works as expected, while curl https://domain.tld returns a 404 and curl https://domain.tld/index.html returns a 403.
Trying to rescue my sanity, I even deleted index.html and cp access.log index.html but it still fails! My assumption is, that caddy somehow forbids serving HTML files. Does that even make sense? I also tried to create files with different names: cp index.html bccess.log and cp access.log cccess.log. They all behave like index.html.

2. Error messages and/or full log output:

Disclaimer: I replaced the real domain with “domain.tld”, because it might be counted as company secret for now. All subdomains and file paths are unchanged.

#> curl https://test.domain.tld/index.html
HTTP/2 403
alt-svc: h3=":443"; ma=2592000
permissions-policy: interest-cohort=()
referrer-policy: no-referrer-when-downgrade
server: Caddy
x-content-type-options: nosniff
x-frame-options: DENY
x-xss-protection: 1; mode=block
date: Thu, 21 Nov 2024 10:50:18 GMT

#> curl https://test.domain.tld
HTTP/2 404
alt-svc: h3=":443"; ma=2592000
permissions-policy: interest-cohort=()
referrer-policy: no-referrer-when-downgrade
server: Caddy
x-content-type-options: nosniff
x-frame-options: DENY
x-xss-protection: 1; mode=block
date: Thu, 21 Nov 2024 10:57:06 GMT

#> curl https://test.domain.tld/access.log
HTTP/2 200
accept-ranges: bytes
alt-svc: h3=":443"; ma=2592000
content-type: text/x-log; charset=utf-8
etag: "snarr654x"
last-modified: Thu, 21 Nov 2024 10:57:06 GMT
permissions-policy: interest-cohort=()
referrer-policy: no-referrer-when-downgrade
server: Caddy
x-content-type-options: nosniff
x-frame-options: DENY
x-xss-protection: 1; mode=block
content-length: 6657
date: Thu, 21 Nov 2024 10:57:49 GMT

Corresponding log, retrieved with journalctl -u caddy --no-pager (empty lines added for clarity):

Nov 21 10:50:15 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186215.2315962,"logger":"events","msg":"event","name":"tls_get_certificate","id":"8888db05-93ba-4c31-8c5f-f4eb165e4d43","origin":"tls","data":{"client_hello":{"CipherSuites":[4866,4867,4865,4868,49196,49200,52393,52392,49325,49195,49199,49324,49187,49191,49162,49172,49161,49171,157,49309,156,49308,61,60,53,47,159,52394,49311,158,49310,107,103,57,51,255],"ServerName":"test.domain.tld","SupportedCurves":[29,23,30,25,24,256,257,258,259,260],"SupportedPoints":"AAEC","SignatureSchemes":[1027,1283,1539,2055,2056,2057,2058,2059,2052,2053,2054,1025,1281,1537,771,769],"SupportedProtos":["h2","http/1.1"],"SupportedVersions":[772,771],"RemoteAddr":{"IP":"2.215.191.80","Port":62560,"Zone":""},"LocalAddr":{"IP":"51.158.175.161","Port":443,"Zone":""}}}}
Nov 21 10:50:15 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186215.2427142,"logger":"tls.handshake","msg":"choosing certificate","identifier":"test.domain.tld","num_choices":1}
Nov 21 10:50:15 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186215.2441688,"logger":"tls.handshake","msg":"default certificate selection results","identifier":"test.domain.tld","subjects":["test.domain.tld"],"managed":true,"issuer_key":"acme-v02.api.letsencrypt.org-directory","hash":"6c98033f7a175b8f53023703d923f9fd8f5a105cabfb5240a91b205b375c9c19"}
Nov 21 10:50:15 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186215.24433,"logger":"tls.handshake","msg":"matched certificate in cache","remote_ip":"2.215.191.80","remote_port":"62560","subjects":["test.domain.tld"],"managed":true,"expiration":1739887666,"hash":"6c98033f7a175b8f53023703d923f9fd8f5a105cabfb5240a91b205b375c9c19"}
Nov 21 10:50:15 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186215.4678802,"logger":"http.handlers.file_server","msg":"sanitized path join","site_root":"/srv/www/vrwyw","request_path":"/index.html","result":"/srv/www/vrwyw/index.html"}
Nov 21 10:50:15 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186215.472384,"logger":"http.log.error.log0","msg":"stat /srv/www/vrwyw/index.html: permission denied","request":{"remote_ip":"2.215.191.80","remote_port":"62560","client_ip":"2.215.191.80","proto":"HTTP/2.0","method":"GET","host":"test.domain.tld","uri":"/index.html","headers":{"User-Agent":["curl/8.9.1"],"Accept":["*/*"]},"tls":{"resumed":false,"version":772,"cipher_suite":4865,"proto":"h2","server_name":"test.domain.tld"}},"duration":0.00495795,"status":403,"err_id":"hxq5d8a6y","err_trace":"fileserver.(*FileServer).ServeHTTP (staticfiles.go:282)"}
Nov 21 10:50:18 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186218.2765286,"logger":"events","msg":"event","name":"tls_get_certificate","id":"c89b226e-9ec5-40ae-bc10-6ee267cff891","origin":"tls","data":{"client_hello":{"CipherSuites":[4866,4867,4865,4868,49196,49200,52393,52392,49325,49195,49199,49324,49187,49191,49162,49172,49161,49171,157,49309,156,49308,61,60,53,47,159,52394,49311,158,49310,107,103,57,51,255],"ServerName":"test.domain.tld","SupportedCurves":[29,23,30,25,24,256,257,258,259,260],"SupportedPoints":"AAEC","SignatureSchemes":[1027,1283,1539,2055,2056,2057,2058,2059,2052,2053,2054,1025,1281,1537,771,769],"SupportedProtos":["h2","http/1.1"],"SupportedVersions":[772,771],"RemoteAddr":{"IP":"2.215.191.80","Port":37626,"Zone":""},"LocalAddr":{"IP":"51.158.175.161","Port":443,"Zone":""}}}}
Nov 21 10:50:18 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186218.278414,"logger":"tls.handshake","msg":"choosing certificate","identifier":"test.domain.tld","num_choices":1}
Nov 21 10:50:18 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186218.2788136,"logger":"tls.handshake","msg":"default certificate selection results","identifier":"test.domain.tld","subjects":["test.domain.tld"],"managed":true,"issuer_key":"acme-v02.api.letsencrypt.org-directory","hash":"6c98033f7a175b8f53023703d923f9fd8f5a105cabfb5240a91b205b375c9c19"}
Nov 21 10:50:18 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186218.2790442,"logger":"tls.handshake","msg":"matched certificate in cache","remote_ip":"2.215.191.80","remote_port":"37626","subjects":["test.domain.tld"],"managed":true,"expiration":1739887666,"hash":"6c98033f7a175b8f53023703d923f9fd8f5a105cabfb5240a91b205b375c9c19"}
Nov 21 10:50:18 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186218.6354177,"logger":"http.handlers.file_server","msg":"sanitized path join","site_root":"/srv/www/vrwyw","request_path":"/index.html","result":"/srv/www/vrwyw/index.html"}
Nov 21 10:50:18 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186218.6393092,"logger":"http.log.error.log0","msg":"stat /srv/www/vrwyw/index.html: permission denied","request":{"remote_ip":"2.215.191.80","remote_port":"37626","client_ip":"2.215.191.80","proto":"HTTP/2.0","method":"HEAD","host":"test.domain.tld","uri":"/index.html","headers":{"User-Agent":["curl/8.9.1"],"Accept":["*/*"]},"tls":{"resumed":false,"version":772,"cipher_suite":4865,"proto":"h2","server_name":"test.domain.tld"}},"duration":0.002732825,"status":403,"err_id":"ztg7y85a7","err_trace":"fileserver.(*FileServer).ServeHTTP (staticfiles.go:282)"}

Nov 21 10:57:04 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186624.7450497,"logger":"tls.handshake","msg":"default certificate selection results","identifier":"test.domain.tld","subjects":["test.domain.tld"],"managed":true,"issuer_key":"acme-v02.api.letsencrypt.org-directory","hash":"6c98033f7a175b8f53023703d923f9fd8f5a105cabfb5240a91b205b375c9c19"}
Nov 21 10:57:04 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186624.745224,"logger":"tls.handshake","msg":"matched certificate in cache","remote_ip":"2.215.191.80","remote_port":"52110","subjects":["test.domain.tld"],"managed":true,"expiration":1739887666,"hash":"6c98033f7a175b8f53023703d923f9fd8f5a105cabfb5240a91b205b375c9c19"}
Nov 21 10:57:05 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186625.1403737,"logger":"http.handlers.file_server","msg":"sanitized path join","site_root":"/srv/www/vrwyw","request_path":"/","result":"/srv/www/vrwyw"}
Nov 21 10:57:05 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186625.1423483,"logger":"http.handlers.file_server","msg":"no index file in directory","path":"/srv/www/vrwyw","index_filenames":["index.html","index.txt"]}
Nov 21 10:57:05 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186625.1429286,"logger":"http.log.error.log0","msg":"{id=4s487ga1r} fileserver.(*FileServer).notFound (staticfiles.go:629): HTTP 404","request":{"remote_ip":"2.215.191.80","remote_port":"52110","client_ip":"2.215.191.80","proto":"HTTP/2.0","method":"HEAD","host":"test.domain.tld","uri":"/","headers":{"User-Agent":["curl/8.9.1"],"Accept":["*/*"]},"tls":{"resumed":false,"version":772,"cipher_suite":4865,"proto":"h2","server_name":"test.domain.tld"}},"duration":0.003613454,"status":404,"err_id":"4s487ga1r","err_trace":"fileserver.(*FileServer).notFound (staticfiles.go:629)"}
Nov 21 10:57:06 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186626.4166286,"logger":"events","msg":"event","name":"tls_get_certificate","id":"f27c10aa-889c-449e-b415-9899fe31ed11","origin":"tls","data":{"client_hello":{"CipherSuites":[4866,4867,4865,4868,49196,49200,52393,52392,49325,49195,49199,49324,49187,49191,49162,49172,49161,49171,157,49309,156,49308,61,60,53,47,159,52394,49311,158,49310,107,103,57,51,255],"ServerName":"test.domain.tld","SupportedCurves":[29,23,30,25,24,256,257,258,259,260],"SupportedPoints":"AAEC","SignatureSchemes":[1027,1283,1539,2055,2056,2057,2058,2059,2052,2053,2054,1025,1281,1537,771,769],"SupportedProtos":["h2","http/1.1"],"SupportedVersions":[772,771],"RemoteAddr":{"IP":"2.215.191.80","Port":33400,"Zone":""},"LocalAddr":{"IP":"51.158.175.161","Port":443,"Zone":""}}}}
Nov 21 10:57:06 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186626.4180145,"logger":"tls.handshake","msg":"choosing certificate","identifier":"test.domain.tld","num_choices":1}
Nov 21 10:57:06 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186626.4181175,"logger":"tls.handshake","msg":"default certificate selection results","identifier":"test.domain.tld","subjects":["test.domain.tld"],"managed":true,"issuer_key":"acme-v02.api.letsencrypt.org-directory","hash":"6c98033f7a175b8f53023703d923f9fd8f5a105cabfb5240a91b205b375c9c19"}
Nov 21 10:57:06 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186626.4181376,"logger":"tls.handshake","msg":"matched certificate in cache","remote_ip":"2.215.191.80","remote_port":"33400","subjects":["test.domain.tld"],"managed":true,"expiration":1739887666,"hash":"6c98033f7a175b8f53023703d923f9fd8f5a105cabfb5240a91b205b375c9c19"}
Nov 21 10:57:06 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186626.4511354,"logger":"http.handlers.file_server","msg":"sanitized path join","site_root":"/srv/www/vrwyw","request_path":"/","result":"/srv/www/vrwyw"}
Nov 21 10:57:06 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186626.452281,"logger":"http.handlers.file_server","msg":"no index file in directory","path":"/srv/www/vrwyw","index_filenames":["index.html","index.txt"]}
Nov 21 10:57:06 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186626.4526765,"logger":"http.log.error.log0","msg":"{id=1ih97g7vz} fileserver.(*FileServer).notFound (staticfiles.go:629): HTTP 404","request":{"remote_ip":"2.215.191.80","remote_port":"33400","client_ip":"2.215.191.80","proto":"HTTP/2.0","method":"HEAD","host":"test.domain.tld","uri":"/","headers":{"User-Agent":["curl/8.9.1"],"Accept":["*/*"]},"tls":{"resumed":false,"version":772,"cipher_suite":4865,"proto":"h2","server_name":"test.domain.tld"}},"duration":0.001601559,"status":404,"err_id":"1ih97g7vz","err_trace":"fileserver.(*FileServer).notFound (staticfiles.go:629)"}

Nov 21 10:57:49 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186669.8387926,"logger":"events","msg":"event","name":"tls_get_certificate","id":"24e9b564-b363-4c34-8e47-a41b9d9dc77b","origin":"tls","data":{"client_hello":{"CipherSuites":[4866,4867,4865,4868,49196,49200,52393,52392,49325,49195,49199,49324,49187,49191,49162,49172,49161,49171,157,49309,156,49308,61,60,53,47,159,52394,49311,158,49310,107,103,57,51,255],"ServerName":"test.domain.tld","SupportedCurves":[29,23,30,25,24,256,257,258,259,260],"SupportedPoints":"AAEC","SignatureSchemes":[1027,1283,1539,2055,2056,2057,2058,2059,2052,2053,2054,1025,1281,1537,771,769],"SupportedProtos":["h2","http/1.1"],"SupportedVersions":[772,771],"RemoteAddr":{"IP":"2.215.191.80","Port":61074,"Zone":""},"LocalAddr":{"IP":"51.158.175.161","Port":443,"Zone":""}}}}
Nov 21 10:57:49 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186669.840775,"logger":"tls.handshake","msg":"choosing certificate","identifier":"test.domain.tld","num_choices":1}
Nov 21 10:57:49 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186669.8415363,"logger":"tls.handshake","msg":"default certificate selection results","identifier":"test.domain.tld","subjects":["test.domain.tld"],"managed":true,"issuer_key":"acme-v02.api.letsencrypt.org-directory","hash":"6c98033f7a175b8f53023703d923f9fd8f5a105cabfb5240a91b205b375c9c19"}
Nov 21 10:57:49 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186669.8416667,"logger":"tls.handshake","msg":"matched certificate in cache","remote_ip":"2.215.191.80","remote_port":"61074","subjects":["test.domain.tld"],"managed":true,"expiration":1739887666,"hash":"6c98033f7a175b8f53023703d923f9fd8f5a105cabfb5240a91b205b375c9c19"}
Nov 21 10:57:49 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186669.8830025,"logger":"http.handlers.file_server","msg":"sanitized path join","site_root":"/srv/www/vrwyw","request_path":"/access.log","result":"/srv/www/vrwyw/access.log"}
Nov 21 10:57:49 scw-nice-cori caddy[483257]: {"level":"debug","ts":1732186669.88359,"logger":"http.handlers.file_server","msg":"opening file","filename":"/srv/www/vrwyw/access.log"}

3. Caddy version:

#> caddy version
v2.7.6

4. How I installed and ran Caddy:

Installed via Fedora package manager: dnf install caddy

a. System environment:

#> cat /etc/system-release
Fedora release 40 (Forty)

#> uname -a
Linux scw-nice-cori 6.11.3-200.fc40.x86_64 #1 SMP PREEMPT_DYNAMIC Thu Oct 10 22:31:19 UTC 2024 x86_64 GNU/Linux

b. Command:

Caddy runs as a service. Service files are the default ones from the fedora package.

systemctl start caddy

c. Service/unit/compose file:

#> cat /etc/systemd/system/multi-user.target.wants/caddy.service
[Unit]
Description=Caddy web server
Documentation=https://caddyserver.com/docs/
After=network.target

[Service]
Type=notify
User=caddy
Group=caddy
ExecStartPre=/usr/bin/caddy validate --config /etc/caddy/Caddyfile
ExecStart=/usr/bin/caddy run --environ --config /etc/caddy/Caddyfile
ExecReload=/usr/bin/caddy reload --config /etc/caddy/Caddyfile
TimeoutStopSec=5s
LimitNOFILE=1048576
LimitNPROC=512
PrivateTmp=true
ProtectHome=true
ProtectSystem=full
AmbientCapabilities=CAP_NET_ADMIN CAP_NET_BIND_SERVICE

[Install]
WantedBy=multi-user.target

d. My complete Caddy config:

#> cat /etc/caddy/Caddyfile
{
        http_port 80
        https_port 443
        default_sni domain.tld
        email hostmaster@domain.tld
        debug
}

localhost {
        respond "Caddy server is online."
}

domain.tld {
        encode zstd gzip
        header {
                Content-Type "text/html; charset=utf-8"
                Permissions-Policy interest-cohort=()
                X-Content-Type-Options nosniff # no media type sniffing
                X-Frame-Options DENY # clickjacking protection
                Referrer-Policy no-referrer-when-downgrade # no referrer data without HTTPS
                X-XSS-Protection "1; mode=block"
        }
        respond <<HTML
                <html>
                  <head><title>domain.tld</title></head>
                  <style>html,body{margin:20vh 0;padding:0;display:flex;justify-content:center;align-items:center;background:#121212;color:#a7b2be;}</style>
                  <body><h1>domain.tld comes soon.</h1></body>
                </html>
                HTML 200
}

test.domain.tld {
        encode zstd gzip
        header {
                Permissions-Policy interest-cohort=()
                X-Content-Type-Options nosniff # no media type sniffing
                X-Frame-Options DENY # clickjacking protection
                Referrer-Policy no-referrer-when-downgrade # no referrer data without HTTPS
                X-XSS-Protection "1; mode=block"
        }
    log {
        output file /srv/www/vrwyw/access.log
        level  debug
    }
        # try_files {path} index.html
        root * /srv/www/vrwyw
        file_server
}

import Caddyfile.d/*.caddyfile

(there are no files in Caddyfile.d/)

5. Links to relevant resources:

I’m using scaleway’s fedora workstation image:

2

Since you’re on Fedora, I assume it’ll be somekind of weird SELinux issue. Try disabling it temporarily and see if it helps. If it does, then you can go through these steps to figure out why.

Could be a situation here the fact the Caddy process itself created the access.log file means it’s allowed to read from it, but other files not being created by Caddy would not get permitted. Or something weird like that. I really don’t understand SELinux, I’ve never used a server with it on.

3

Thank you for pointing me to SELinux. I’d never have looked in that direction. It is indeed SELinux and even after I set it to permissive, it still doesn’t work. Stupid side projects… anyway,

All the issues are listed in /var/log/audit/audit.log. I found the following there:

#> cat /var/log/audit/audit.log | grep caddy
type=AVC msg=audit(1732297886.603:987186): avc:  denied  { getattr } for  pid=483257 comm="caddy" path="/srv/www/vrwyw/index.html" dev="sda4" ino=71952 scontext=system_u:system_r:httpd_t:s0 tcontext=unconfined_u:object_r:var_t:s0 tclass=file permissive=1

And despite the “permissive=1”, it is somehow blocking Caddy and I wondered why. I found one very useful command:

#> audit2why < /var/log/audit/audit.log
type=AVC msg=audit(1732297886.603:987186): avc:  denied  { getattr } for  pid=483257 comm="caddy" path="/srv/www/vrwyw/index.html" dev="sda4" ino=71952 scontext=system_u:system_r:httpd_t:s0 tcontext=unconfined_u:object_r:var_t:s0 tclass=file permissive=1

        Was caused by:
                Missing type enforcement (TE) allow rule.

                You can use audit2allow to generate a loadable module to allow this access.

This hints at “audit2allow” which sounds like SELinux people know that it is really complicated, so they wrote a tool for it:

#> echo 'type=AVC msg=audit(1732297886.603:987186): avc:  denied  { getattr } for  pid=483257 comm="caddy" path="/srv/www/vrwyw/index.html" dev="sda4" ino=71952 scontext=system_u:system_r:httpd_t:s0 tcontext=unconfined_u:object_r:var_t:s0 tclass=file permissive=1"' | audit2allow


#============= httpd_t ==============
allow httpd_t var_t:file getattr;

…what? Okay, looking further, I learned, that the more direct way to get the same result is:

#> audit2allow -w -a # produce "audit2why" output for all audit entries
# ~snip for clarity~
audit2allow -a # produce the "audit2allow" output for all audit entries


#============= httpd_t ==============
allow httpd_t var_t:file getattr;

Not sure why it always produces some empty lines, first :thinking:

Anyway, now you can create a permission file with …the same command?!

#> audit2allow -M caddy
******************** IMPORTANT ***********************
To make this policy package active, execute:

semodule -i caddy.pp

This creates two files, caddy.pp and caddy.te.

And as the output suggest, we do not use audit2allow this time, but semodule to apply the rule. This takes pretty long, like 10-15 seconds, on the virtual machine I’m one. Running audit2allow -a again produces a different output now, very vividly telling you that things are already allowed in the current policy.

And now… does it work? No! What? All this for nothing? What is our new friend audit2why saying?

type=AVC msg=audit(1732298557.094:488): avc:  denied  { getattr } for  pid=1446 comm="caddy" path="/srv/www/vrwyw/index.html" dev="sda4" ino=71952 scontext=system_u:system_r:httpd_t:s0 tcontext=unconfined_u:object_r:var_t:s0 tclass=file permissive=1
        Was caused by:
                Unknown - would be allowed by active policy
                Possible mismatch between this policy and the one under which the audit message was generated.

                Possible mismatch between current in-memory boolean settings vs. permanent ones.

“Unknown - would be allowed by active policy” …nice, so not even SELinux itself knows why it doesn’t work. Even after a reboot.

Although all this didn’t help me and I disabled SELinux in the end by setting SELINUX=disabled in /etc/selinux/config and rebooting, it may be helpful for others. I probably somehow screwed up my SELinux in the process, but I don’t care. It is just a test server.

4

:joy:

Yeah that’s wild. I don’t understand why it needs to be this arcane.

FYI @carlwgeorge

5

Some links I used and forgot to append to the post: