Php_fastcgi: "Primary script unknown" @ '/index.php' and "403 Permission denied" @ '/'

Kevo · January 5, 2022, 12:11pm

Hi everyone,

I am part of a team that provides hosting for one forum software. I’m currently taking a look at Caddy (as a replacement for Nginx). I’m trying it for the first time, but I must say, I am impressed. I was able to reverse proxy to our Python Gunicorn backend with no issues and a few lines of configuration. However, the forum software that we are using is written in PHP - thus, we need to use PHP-FPM with Caddy to serve requests. And that’s where I got stuck.

1. Caddy version (`caddy version`):

v2.4.6 h1:HGkGICFGvyrodcqOOclHKfvJC0qTU7vny/7FhYp9hNw=

Using PHP 8.0.14

2. How I run Caddy:

a. System environment:

Ubuntu 20.04.3 LTS focal

b. Command:

I tried to run it as root with the following commands instead as well. This helped with file_server (see later below, 5.9.*):

cd /etc/caddy
caddy run

c. Service/unit/compose file:

`/etc/systemd/system/caddy.service:`

[Unit]
Description=Caddy web server
Documentation=https://caddyserver.com/docs/
After=network.target network-online.target
Requires=network-online.target

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

[Install]
WantedBy=multi-user.target

d. My complete Caddyfile or JSON config:

skeleton.kevo.link {
        root * /data/host/skeleton/app/public
        php_fastcgi unix//run/php/php-fpm.skeleton.sock

        header /assets {
                +Cache-Control "public, must-revalidate, proxy-revalidate"
                +Cache-Control "max-age=25000"
                Pragma "public"
        }

        file_server
}

My PHP-FPM pool config, if that helps:

[skeleton]

prefix = /data/host/skeleton/app/public

user = www-data
group = www-data


listen = /run/php/php-fpm.skeleton.sock

listen.owner = www-data
listen.group = www-data
listen.mode = 0660


pm = ondemand
pm.max_children = 3
pm.process_idle_timeout = 60s
pm.max_requests = 300


chroot = /data/host/skeleton/
catch_workers_output = yes
php_admin_value[session.save_path] = /sessions

Note that I am running PHP-FPM in chroot - however, removing that line doesn’t help.

3. The problem I’m having:

When visiting the site root, Caddy responds with 403 (https://skeleton.kevo.link) - this status code is weirdly not logged anywhere in Caddy (checked with tail -n 500 /var/log/www/caddy.log | grep 403).

Visiting https://skeleton.kevo.link/index.php results in 404 and “File not found.” text.

4. Error messages and/or full log output:

I am running both Caddy and PHP-FPM in debug mode. PHP-FPM outputs this error:

WARNING: pid 1021482, (null)(), line 0: [pool skeleton] child 1021549 said into stderr: "DEBUG: main(), line 1872: Primary script unknown"

As for Caddy, this relevant information was logged:

{"level":"debug","ts":1641316561.8956215,"logger":"http.reverse_proxy.transport.fastcgi","msg":"roundtrip","request":{"remote_addr":" ... ","proto":"HTTP/2.0","method":"GET","host":"skeleton.kevo.link","uri":"/index.php","headers":{ ... },"tls":{"resumed":true,"version":772,"cipher_suite":4865,"proto":"h2","proto_mutual":true,"server_name":"skeleton.kevo.link"}},"dial":"/run/php/php-fpm.skeleton.sock","env":{ ... "REQUEST_URI":"/index.php",

"SCRIPT_FILENAME":"/index.php","SCRIPT_NAME":"/index.php", <--- culprits(?)

"SERVER_NAME":"skeleton.kevo.link","SERVER_PROTOCOL":"HTTP/2.0","SERVER_SOFTWARE":"Caddy/v2.4.6","SSL_CIPHER":"TLS_AES_128_GCM_SHA256","SSL_PROTOCOL":"TLSv1.3"}}


{"level":"debug","ts":1641316561.9118648,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"unix//run/php/php-fpm.skeleton.sock","duration":0.016688851,"request":{"remote_addr":"...","proto":"HTTP/2.0","method":"GET","host":"skeleton.kevo.link","uri":"/index.php","headers":{ ... },"tls":{"resumed":true,"version":772,"cipher_suite":4865,"proto":"h2","proto_mutual":true,"server_name":"skeleton.kevo.link"}},"headers":{"Content-Type":["text/html; charset=UTF-8"],"Status":["404 Not Found"]},"status":404}

5. What I already tried:

sudo -u www-data caddy run - run Caddy outside of systemd. Didn’t help. Visiting the root path (https://skeleton.kevo.link/) responds again with 403, and https://skeleton.kevo.link/index.php just produces “File not found.”
Remove root * /data/host/skeleton/app/public line from my Caddyfile. Now the domain root responds with 404. “File not found.” message still happens when visiting /index.php.
Add index index.php, split .php and root /data/host/skeleton/app/public inside my php_fastcgi route configuration. This had no effect, because the standard php_fastcgi directive already has these values set as default.
Set permissions again, just for sure:
1. chmod -R 775 /data/host/skeleton
  - Note: /data/host is owned by www-data too.
2. chown -R www-data:www-data /data/host/skeleton
3. I also ensured that /run/php/php-fpm.skeleton.sock has user and group www-data:
  srw-rw---- 1 www-data www-data 0 Jan 5 11:33 /run/php/php-fpm.skeleton.sock
Move old index.php away and create a new one that just outputs phpinfo(). Same behavior.
Create a dummy .txt file with www-data owner & group to see if Caddy can serve that file properly, and that outputs another 403 that wasn’t logged (Caddy just outputs a debug info that the root path was sanitized, nothing else that’s relevant to that request: {"level":"debug","ts":1641382775.3904107,"logger":"http.handlers.file_server","msg":"sanitized path join","site_root":"/data/host/skeleton/app/public","request_path":"/dummy.txt","result":"/data/host/skeleton/app/public/dummy.txt"})
Remove file_server directive from my Caddyfile. That made all sites except for index.php (which had the same behavior) blank (makes sense). However, requests to the blank sites were not logged in both Caddy and PHP-FPM (or at least I couldn’t find anything that’s relevant to that requests in my logs).
Changed Caddyfile to listen to kevo.link instead of subdomain (skeleton.kevo.link), which resulted in the same behavior.
(see 2.b) Ran Caddy as root user outside systemd. This made file_server serve non-PHP files properly, however the issue with index.php wasn’t fixed (still “File not found.”). This leaves me to believe that Caddy’s file_server has indeed problems with permissions, but it makes no sense to me since all relevant directories are owned by the user that systemd Caddy runs as,
so www-data(?).
Lastly, I set /data/host/skeleton recursively to permission 777 and restarted both Caddy and PHP-FPM (systemd). This changed nothing, and / still responds with 403 & /index.php says “File not found.”

I’ve spend so much time trying to figure out what’s wrong now, and I am desperate. I don’t know why a 403 is sent and why PHP-FPM isn’t working.

I guess that it might be an issue with PHP-FPM and permissions, however the same setup works with Nginx (I checked that the permissions and PHP-FPM configurations are the same as they’re at the production server that’s using Nginx, but I admit that I might’ve missed something).

My goal is to visit the site root and forward traffic to PHP-FPM (without having to type /index.php in uri). Could you please guide me what I did wrong?

6. Links to relevant resources:

Caddy with PHP-FPM - File not found - Help - Caddy Community
403 Forbidden for static files - Help - Caddy Community
Cannot get PHP working · Issue #4181 · caddyserver/caddy (github.com)
…and more (but I could only attach 4 links to my message, apologies)

francislavoie · January 5, 2022, 2:10pm

That’s weird, it reads like Caddy doesn’t have a root defined if it didn’t prefix these with the root.

Are you sure that above log isn’t from when you tried this? Because you most definitely need root for things to work correctly.

I see this is different than the values we ship for our apt package, where we set the user/group to caddy and caddy. The package also adds the caddy user to the www-data group if it exists, so it shouldn’t be necessary to run as www-data.

Caddy doesn’t enable access logging by default, you need to turn that on with the log directive if you want it:

This tells me that Caddy isn’t able to see the files in your webroot. If you turn on the debug global option (which you seem to have done since you posted some debug logs), it should show a more detailed message from the file_server directive regarding permissions for requests to non-PHP files.

What does it look like when you make a request to your server with curl -v? What do the headers look like?

Kevo · January 5, 2022, 5:11pm

Thank you very much for the quick response, Francis!

Ah, you’re correct. I have tried so many times that I somehow copied the wrong log. With root directive, Caddy outputs:

[...] "SCRIPT_FILENAME":"/data/host/skeleton/app/public/index.php","SCRIPT_NAME":"/index.php" [...]

But this still responds with “File not found.”. I have attached more detailed logs later in this post.

Yes, in production we use www-data (because of Nginx). I changed it, so that we can migrate to new setup more easily, should we decide to use Caddy. If everything fails, I might as well just reinstall everything and try again, without changing the caddy user.

I actually already had this enabled in my parent Caddyfile. I thought that it wasn’t necessary, since nothing related to PHP-FPM is here, but I know that every bit of config helps, so forgive me for that:

{
        email my@email.com
        debug
        log {
                output file /var/log/www/caddy.log {
                        roll_size 100mb
                        roll_keep 5
                        roll_keep_for 30d
                }
        }
}

kevo.link {
        encode zstd gzip
        root * /data/company/company/webapp/static/

        handle * {
                reverse_proxy unix//run/gunicorn/webapp.sock
        }

        handle /docs* {
                root * /data/docs/site
                file_server
        }

        handle_path /static* {
                file_server {
                        root /data/company/company/webapp/static/
                        hide .*
                }
        }

        handle_path /api* {
                reverse_proxy unix//run/gunicorn/api.sock
        }
}

# Import other configs:
import conf.d/*.conf

curl -v https://skeleton.kevo.link:

*   Trying 78.47.98.198:443...
* TCP_NODELAY set
* Connected to skeleton.kevo.link (78.47.98.198) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*   CAfile: /etc/ssl/certs/ca-certificates.crt
  CApath: /etc/ssl/certs
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
* TLSv1.3 (IN), TLS handshake, Server hello (2):
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
* TLSv1.3 (IN), TLS handshake, Certificate (11):
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
* TLSv1.3 (IN), TLS handshake, Finished (20):
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.3 (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / TLS_AES_128_GCM_SHA256
* ALPN, server accepted to use h2
* Server certificate:
*  subject: CN=skeleton.kevo.link
*  start date: Jan  3 14:58:28 2022 GMT
*  expire date: Apr  3 14:58:27 2022 GMT
*  subjectAltName: host "skeleton.kevo.link" matched cert's "skeleton.kevo.link"
*  issuer: C=US; O=Let's Encrypt; CN=R3
*  SSL certificate verify ok.
* Using HTTP2, server supports multi-use
* Connection state changed (HTTP/2 confirmed)
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
* Using Stream ID: 1 (easy handle 0x556b05cf3880)
> GET / HTTP/2
> Host: skeleton.kevo.link
> user-agent: curl/7.68.0
> accept: */*
>
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* Connection state changed (MAX_CONCURRENT_STREAMS == 250)!
< HTTP/2 403
< server: Caddy
< content-length: 0
< date: Wed, 05 Jan 2022 16:51:27 GMT
<
* Connection #0 to host skeleton.kevo.link left intact

Caddy log after more requests to https://skeleton.kevo.link:

{"level":"debug","ts":1641401801.2205071,"logger":"http.handlers.file_server","msg":"sanitized path join","site_root":"/data/host/skeleton/app/public","request_path":"/","result":"/data/host/skeleton/app/public"}
{"level":"debug","ts":1641401802.5444238,"logger":"http.handlers.file_server","msg":"sanitized path join","site_root":"/data/host/skeleton/app/public","request_path":"/","result":"/data/host/skeleton/app/public"}
{"level":"debug","ts":1641401804.2578583,"logger":"http.handlers.file_server","msg":"sanitized path join","site_root":"/data/host/skeleton/app/public","request_path":"/","result":"/data/host/skeleton/app/public"}
{"level":"debug","ts":1641401804.3937633,"logger":"http.handlers.file_server","msg":"sanitized path join","site_root":"/data/host/skeleton/app/public","request_path":"/","result":"/data/host/skeleton/app/public"}
{"level":"debug","ts":1641401804.5250063,"logger":"http.handlers.file_server","msg":"sanitized path join","site_root":"/data/host/skeleton/app/public","request_path":"/","result":"/data/host/skeleton/app/public"}
{"level":"debug","ts":1641401804.657728,"logger":"http.handlers.file_server","msg":"sanitized path join","site_root":"/data/host/skeleton/app/public","request_path":"/","result":"/data/host/skeleton/app/public"}
{"level":"debug","ts":1641401804.7857268,"logger":"http.handlers.file_server","msg":"sanitized path join","site_root":"/data/host/skeleton/app/public","request_path":"/","result":"/data/host/skeleton/app/public"}

I tried to request the dummy file too, still 403:

{"level":"debug","ts":1641402028.4465332,"logger":"http.handlers.file_server","msg":"sanitized path join","site_root":"/data/host/skeleton/app/public","request_path":"/dummy.txt","result":"/data/host/skeleton/app/public/dummy.txt"}

…but nothing related to permission issue or 403? I checked with grep again and even looked manually, nothing.

Just to make sure that dummy.txt has correct permissions:
ls -la /data/host/skeleton/app/public/dummy.txt:

-rwxrwxr-x 1 www-data www-data 14 Jan  5 11:36 /data/host/skeleton/app/public/dummy.txt

Request to index.php

curl -v https://skeleton.kevo.link/index.php:


*   Trying 78.47.98.198:443...
* TCP_NODELAY set
* Connected to skeleton.kevo.link (78.47.98.198) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*   CAfile: /etc/ssl/certs/ca-certificates.crt
  CApath: /etc/ssl/certs
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
* TLSv1.3 (IN), TLS handshake, Server hello (2):
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
* TLSv1.3 (IN), TLS handshake, Certificate (11):
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
* TLSv1.3 (IN), TLS handshake, Finished (20):
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.3 (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / TLS_AES_128_GCM_SHA256
* ALPN, server accepted to use h2
* Server certificate:
*  subject: CN=skeleton.kevo.link
*  start date: Jan  3 14:58:28 2022 GMT
*  expire date: Apr  3 14:58:27 2022 GMT
*  subjectAltName: host "skeleton.kevo.link" matched cert's "skeleton.kevo.link"
*  issuer: C=US; O=Let's Encrypt; CN=R3
*  SSL certificate verify ok.
* Using HTTP2, server supports multi-use
* Connection state changed (HTTP/2 confirmed)
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
* Using Stream ID: 1 (easy handle 0x55aaf3f21880)
> GET /index.php HTTP/2
> Host: skeleton.kevo.link
> user-agent: curl/7.68.0
> accept: */*
>
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* Connection state changed (MAX_CONCURRENT_STREAMS == 250)!
< HTTP/2 404
< content-type: text/html; charset=UTF-8
< server: Caddy
< status: 404 Not Found
< content-length: 16
< date: Wed, 05 Jan 2022 16:52:15 GMT
<
File not found.
* Connection #0 to host skeleton.kevo.link left intact

Full Caddy debug log after this request (https://skeleton.kevo.link/index.php):

{"level":"debug","ts":1641401568.0529177,"logger":"http.reverse_proxy.transport.fastcgi","msg":"roundtrip","request":{"remote_addr":"78.47.98.198:36496","proto":"HTTP/2.0","method":"GET","host":"skeleton.kevo.link","uri":"/index.php","headers":{"User-Agent":["curl/7.68.0"],"Accept":["*/*"],"X-Forwarded-For":["78.47.98.198"],"X-Forwarded-Proto":["https"]},"tls":{"resumed":false,"version":772,"cipher_suite":4865,"proto":"h2","proto_mutual":true,"server_name":"skeleton.kevo.link"}},"dial":"/run/php/php-fpm.skeleton.sock","env":{"AUTH_TYPE":"","CONTENT_LENGTH":"","CONTENT_TYPE":"","DOCUMENT_ROOT":"/data/host/skeleton/app/public","DOCUMENT_URI":"/index.php","GATEWAY_INTERFACE":"CGI/1.1","HTTPS":"on","HTTP_ACCEPT":"*/*","HTTP_HOST":"skeleton.kevo.link","HTTP_USER_AGENT":"curl/7.68.0","HTTP_X_FORWARDED_FOR":"78.47.98.198","HTTP_X_FORWARDED_PROTO":"https","PATH_INFO":"","QUERY_STRING":"","REMOTE_ADDR":"78.47.98.198","REMOTE_HOST":"78.47.98.198","REMOTE_IDENT":"","REMOTE_PORT":"36496","REMOTE_USER":"","REQUEST_METHOD":"GET","REQUEST_SCHEME":"https","REQUEST_URI":"/index.php","SCRIPT_FILENAME":"/data/host/skeleton/app/public/index.php","SCRIPT_NAME":"/index.php","SERVER_NAME":"skeleton.kevo.link","SERVER_PROTOCOL":"HTTP/2.0","SERVER_SOFTWARE":"Caddy/v2.4.6","SSL_CIPHER":"TLS_AES_128_GCM_SHA256","SSL_PROTOCOL":"TLSv1.3"}}
{"level":"debug","ts":1641401568.0539944,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"unix//run/php/php-fpm.skeleton.sock","duration":0.001155486,"request":{"remote_addr":"78.47.98.198:36496","proto":"HTTP/2.0","method":"GET","host":"skeleton.kevo.link","uri":"/index.php","headers":{"X-Forwarded-Proto":["https"],"User-Agent":["curl/7.68.0"],"Accept":["*/*"],"X-Forwarded-For":["78.47.98.198"]},"tls":{"resumed":false,"version":772,"cipher_suite":4865,"proto":"h2","proto_mutual":true,"server_name":"skeleton.kevo.link"}},"headers":{"Status":["404 Not Found"],"Content-Type":["text/html; charset=UTF-8"]},"status":404}

And PHP-FPM:

[05-Jan-2022 16:55:09.721249] DEBUG: pid 1052217, fpm_children_make(), line 407: blocking signals before child birth
[05-Jan-2022 16:55:09.723740] DEBUG: pid 1052217, fpm_children_make(), line 431: unblocking signals, child born
[05-Jan-2022 16:55:09.723927] DEBUG: pid 1052217, fpm_children_make(), line 437: [pool skeleton] child 1053209 started
[05-Jan-2022 16:55:09.723946] DEBUG: pid 1052217, fpm_pctl_on_socket_accept(), line 538: [pool skeleton] got accept without idle child available .... I forked
[05-Jan-2022 16:55:09.723959] DEBUG: pid 1052217, fpm_event_loop(), line 435: event module triggered 1 events
[05-Jan-2022 16:55:09.726861] WARNING: pid 1052217, (null)(), line 0: [pool skeleton] child 1053209 said into stderr: "DEBUG: main(), line 1872: Primary script unknown"

francislavoie · January 5, 2022, 5:42pm

Kevo:

{
        email my@email.com
        debug
        log {
                output file /var/log/www/caddy.log {
                        roll_size 100mb
                        roll_keep 5
                        roll_keep_for 30d
                }
        }
}

Here, you actually used the log global option, which is not the same as the log directive. Access logs are only enabled if you use the log directive which goes inside of each site.

Okay so it definitely does hit Caddy (just a good sanity check)

At this point my thought is that it might be systemd’s protections preventing access to the files (i.e. ProtectSystem=full) which is commonly a thorn for some who try to put their project in /home which ends up protected.

But you said you tried running it standalone without the service, so I’m inclined to think that’s unlikely to be it.

Do you have a symlink situation going on? By default, Caddy doesn’t resolve the root to the real location if it’s a symlink, and php-fpm expects to see the real file location I think. There’s a flag for that in php_fastcgi to turn on to resolve the symlink, if that’s the case.

Something to try, add this to that site:

handle_errors {
	respond "{http.error.status_code}<br />{http.error.status_text}<br />{http.error.message}<br />{http.error.trace}"
}

This might show in the response where or what the actual problem is.

Kevo · January 5, 2022, 6:45pm

Oh, that makes sense. Thanks for your explanation! I thought that enabling the log globally will log access for every site I include…

After adding log directive to the child Caddyfile with php_fastcgi:

{"level":"error","ts":1641406931.2258363,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_addr":"78.47.98.198:36504","proto":"HTTP/2.0","method":"GET","host":"skeleton.kevo.link","uri":"/","headers":{"Accept":["*/*"],"User-Agent":["curl/7.68.0"]},"tls":{"resumed":false,"version":772,"cipher_suite":4865,"proto":"h2","proto_mutual":true,"server_name":"skeleton.kevo.link"}},"common_log":"78.47.98.198 - - [05/Jan/2022:18:22:11 +0000] \"GET / HTTP/2.0\" 403 136","user_id":"","duration":0.00021175,"size":136,"status":403,"resp_headers":{"Server":["Caddy"],"Content-Type":[]}}
{"level":"debug","ts":1641406937.5040588,"logger":"tls.handshake","msg":"choosing certificate","identifier":"skeleton.kevo.link","num_choices":1}
{"level":"debug","ts":1641406937.5041623,"logger":"tls.handshake","msg":"default certificate selection results","identifier":"skeleton.kevo.link","subjects":["skeleton.kevo.link"],"managed":true,"issuer_key":"acme-v02.api.letsencrypt.org-directory","hash":" ... "}
{"level":"debug","ts":1641406937.5041864,"logger":"tls.handshake","msg":"matched certificate in cache","subjects":["skeleton.kevo.link"],"managed":true,"expiration":1648997907,"hash":" ... "}
{"level":"debug","ts":1641406937.5084922,"logger":"http.reverse_proxy.transport.fastcgi","msg":"roundtrip","request":{"remote_addr":"78.47.98.198:36506","proto":"HTTP/2.0","method":"GET","host":"skeleton.kevo.link","uri":"/index.php","headers":{"User-Agent":["curl/7.68.0"],"Accept":["*/*"],"X-Forwarded-For":["78.47.98.198"],"X-Forwarded-Proto":["https"]},"tls":{"resumed":false,"version":772,"cipher_suite":4865,"proto":"h2","proto_mutual":true,"server_name":"skeleton.kevo.link"}},"dial":"/run/php/php-fpm.skeleton.sock","env":{"AUTH_TYPE":"","CONTENT_LENGTH":"","CONTENT_TYPE":"","DOCUMENT_ROOT":"/data/host/skeleton/app/public","DOCUMENT_URI":"/index.php","GATEWAY_INTERFACE":"CGI/1.1","HTTPS":"on","HTTP_ACCEPT":"*/*","HTTP_HOST":"skeleton.kevo.link","HTTP_USER_AGENT":"curl/7.68.0","HTTP_X_FORWARDED_FOR":"78.47.98.198","HTTP_X_FORWARDED_PROTO":"https","PATH_INFO":"","QUERY_STRING":"","REMOTE_ADDR":"78.47.98.198","REMOTE_HOST":"78.47.98.198","REMOTE_IDENT":"","REMOTE_PORT":"36506","REMOTE_USER":"","REQUEST_METHOD":"GET","REQUEST_SCHEME":"https","REQUEST_URI":"/index.php","SCRIPT_FILENAME":"/data/host/skeleton/app/public/index.php","SCRIPT_NAME":"/index.php","SERVER_NAME":"skeleton.kevo.link","SERVER_PROTOCOL":"HTTP/2.0","SERVER_SOFTWARE":"Caddy/v2.4.6","SSL_CIPHER":"TLS_AES_128_GCM_SHA256","SSL_PROTOCOL":"TLSv1.3"}}
{"level":"debug","ts":1641406937.510207,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"unix//run/php/php-fpm.skeleton.sock","duration":0.001846645,"request":{"remote_addr":"78.47.98.198:36506","proto":"HTTP/2.0","method":"GET","host":"skeleton.kevo.link","uri":"/index.php","headers":{"User-Agent":["curl/7.68.0"],"Accept":["*/*"],"X-Forwarded-For":["78.47.98.198"],"X-Forwarded-Proto":["https"]},"tls":{"resumed":false,"version":772,"cipher_suite":4865,"proto":"h2","proto_mutual":true,"server_name":"skeleton.kevo.link"}},"headers":{"Status":["404 Not Found"],"Content-Type":["text/html; charset=UTF-8"]},"status":404}
{"level":"error","ts":1641406937.510502,"logger":"http.log.access.log0","msg":"handled request","request":{"remote_addr":"78.47.98.198:36506","proto":"HTTP/2.0","method":"GET","host":"skeleton.kevo.link","uri":"/index.php","headers":{"User-Agent":["curl/7.68.0"],"Accept":["*/*"]},"tls":{"resumed":false,"version":772,"cipher_suite":4865,"proto":"h2","proto_mutual":true,"server_name":"skeleton.kevo.link"}},"common_log":"78.47.98.198 - - [05/Jan/2022:18:22:17 +0000] \"GET /index.php HTTP/2.0\" 404 16","user_id":"","duration":0.002461859,"size":16,"status":404,"resp_headers":{"Server":["Caddy"],"Status":["404 Not Found"],"Content-Type":["text/html; charset=UTF-8"]}}

Yes, and that actually fixed 403:

I tried to remove the "ProtectSystem=full" line from my caddy.service, reloaded systemd daemon, but that didn’t fix 403 when running in systemd. The result is the same.

Used:

handle_errors {
    respond "{http.error}"
}

curl -v https://skeleton.kevo.link:

*   Trying 78.47.98.198:443...
* TCP_NODELAY set
* Connected to skeleton.kevo.link (78.47.98.198) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*   CAfile: /etc/ssl/certs/ca-certificates.crt
  CApath: /etc/ssl/certs
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
* TLSv1.3 (IN), TLS handshake, Server hello (2):
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
* TLSv1.3 (IN), TLS handshake, Certificate (11):
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
* TLSv1.3 (IN), TLS handshake, Finished (20):
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.3 (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / TLS_AES_128_GCM_SHA256
* ALPN, server accepted to use h2
* Server certificate:
*  subject: CN=skeleton.kevo.link
*  start date: Jan  3 14:58:28 2022 GMT
*  expire date: Apr  3 14:58:27 2022 GMT
*  subjectAltName: host "skeleton.kevo.link" matched cert's "skeleton.kevo.link"
*  issuer: C=US; O=Let's Encrypt; CN=R3
*  SSL certificate verify ok.
* Using HTTP2, server supports multi-use
* Connection state changed (HTTP/2 confirmed)
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
* Using Stream ID: 1 (easy handle 0x55dd5f179880)
> GET / HTTP/2
> Host: skeleton.kevo.link
> user-agent: curl/7.68.0
> accept: */*
>
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* Connection state changed (MAX_CONCURRENT_STREAMS == 250)!
< HTTP/2 403
< server: Caddy
< content-length: 136
< date: Wed, 05 Jan 2022 18:15:43 GMT
<
* Connection #0 to host skeleton.kevo.link left intact
{id=vkiggbr49} fileserver.(*FileServer).ServeHTTP (staticfiles.go:193): HTTP 403: stat /data/host/skeleton/app/public: permission denied

When I set systemd like this:

User=root
Group=root

…then it works, and static files are served alright without 403. The site root also correctly forwards to index.php, but PHP-FPM still doesn’t work and says that “File not found.”.

The problem with file_server happens when running it in systemd as www-data. This means that this user might not have permissions to access the files, although ls -la outputs that it does. I’ll have a closer look at all the permissions again later, to make sure that I haven’t missed anything.

I think that systemd has another option that restricts Caddy from accessing /data/host/skeleton/..., but I am not very familiar with all the systemd settings.

I am not as concerned about that as I am about PHP-FPM right now. I can always run caddy run as root and after that, file_server works. Instead, I’d like to focus on making PHP-FPM work for now, and then I can fix systemd (since running any server as root is not usually the best idea).

I am trying to run PHP-FPM pool in chroot (/data/host/skeleton) and I symlinked system libraries required for PHP (/data/host/skeleton/dev/..., /data/host/skeleton/usr/..., etc…). No symlinks under /data/host/skeleton/app. Also, Caddy never interacts with these. And running PHP-FPM without chroot doesn’t make any difference.

One last thing that I could try is setup the forum software in completely different location (e. g. in /var/www) to see if that changes anything. I’ll try to do that tomorrow. Other than this, I am out of options.

jok · January 5, 2022, 8:08pm

What about the directories above /data/host/skeleton/app/public/ ?
Does www-data have access rights to /data , /data/host, /data/host/skeleton etc?

Kevo · January 6, 2022, 9:21am

No it didn’t have access, but chmod -R www-data:www-data /data didn’t help anyways. I also re-installed Caddy (apt purge caddy, then apt-get install caddy), so now it uses the default systemd config, which didn’t help.

Then, I just created a new directory at /var/test, installed the software via Composer and basically restarted the whole process. I copied the same config for PHP-FPM and the same Caddyfile config, just changed directories to use the new /var/test one.

I also assigned permissions for www-data:

chmod 775 -R /var/test
chown www-data:www-data /var/test

And now the test setup works as intended!

My guess is that systemd somehow restricts PHP-FPM and Caddy from accessing the /data directory. My current server is a test one, so I can just wipe it clean as well and restart it all again.

But at least we know that the issue is on my side, not in Caddy nor PHP-FPM (and that’s good to know, basically that’s why I created this thread anyways). I think that I’ll be handling this matter by myself now

Thank you everyone for your help - I really appreciate it

francislavoie · January 6, 2022, 3:33pm

Check the executable permission on all the directories above the the index.php file. @jok made a good point, every directory that is a parent of the files you want to access need to have the executable flag set, in addition to having the permission for the type of access you need (in this case, read access).

The precise rule is: you can traverse a directory if and only if you have execute permission on it. So for example to access dir/subdir/file, you need execute permission on dir and dir/subdir, plus the permissions on file for the type of access you want.

There’s also the “sticky” bit which might come into play, but less likely.

Kevo · January 6, 2022, 6:27pm

I debugged it with sudo -u www-data ls /data/host/... to see which directories are actually accessible by www-data, and after a lot of debugging and permission adjustments, I was able to finally get it to work. Thanks again for the help!