Trying to get more log files

yves · March 31, 2021, 5:42pm

1. Caddy version (`caddy version`):

v2.3.0 h1:fnrqJLa3G5vfxcxmOH/+kJOcunPLhSBnjgIvjXV/QTA=

2. How I run Caddy:

a. System environment:

[yves@sd-163808 log]$ cat /etc/os-release 
NAME="CentOS Stream"
VERSION="8"
ID="centos"
ID_LIKE="rhel fedora"
VERSION_ID="8"
PLATFORM_ID="platform:el8"
PRETTY_NAME="CentOS Stream 8"
ANSI_COLOR="0;31"
CPE_NAME="cpe:/o:centos:centos:8"
HOME_URL="https://centos.org/"
BUG_REPORT_URL="https://bugzilla.redhat.com/"
REDHAT_SUPPORT_PRODUCT="Red Hat Enterprise Linux 8"
REDHAT_SUPPORT_PRODUCT_VERSION="CentOS Stream"
[yves@sd-163808 log]$

b. Command:

sudo systemctl restart caddy

c. Service/unit/compose file:

I am not using Docker.

[yves@sd-163808 log]$ cat /usr/lib/systemd/system/caddy.service
# caddy.service
#
# For using Caddy with a config file.
#
# Make sure the ExecStart and ExecReload commands are correct
# for your installation.
#
# See https://caddyserver.com/docs/install for instructions.
#
# WARNING: This service does not use the --resume flag, so if you
# use the API to make changes, they will be overwritten by the
# Caddyfile next time the service is restarted. If you intend to
# use Caddy's API to configure it, add the --resume flag to the
# `caddy run` command or use the caddy-api.service file instead.

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

[Service]
User=caddy
Group=caddy
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
ProtectSystem=full
AmbientCapabilities=CAP_NET_BIND_SERVICE

[Install]
WantedBy=multi-user.target
[yves@sd-163808 log]$

d. My complete Caddyfile or JSON config:

[yves@sd-163808 tmp]$ sudo cat /etc/caddy/Caddyfile
team-tabulos.com

#log {
#  output file /tmp/caddy.log
#  level DEBUG
#}

log

root * /tmp/tabulos
#root * /var/tabulos_backup
php_fastcgi unix//run/php-fpm/www.sock 
[yves@sd-163808 tmp]$

3. The problem I’m having:

I have a specific problem: when I point root to /var/tabulos_backup, then my site is working (php files get executed and I get their results). If I migrate root to /tmp/tabulos/ it no longer works: instead my brower gets “File not found.” reply. I guess the issue is easy: it is some privilege work to do somewhere… I guess…

So… in order to find out what’s happening, I’m trying to get more log files, in order to investigate this specific issue. To do so, I’ve added the log directive in my config file. Thus I expect to have more log when launching the journal -u caddy command. And it’s the case, but it’s not really helpful: I am just seeing the 404 error answered back.

So my question is the following: how can I get caddy to be more verbose with its log file so I can get more information on what’s happening with my files not being found out.

PS: I am not a web developer and I do not usually install VPS, web servers and the like. That’s what I am doing right now, and I’m doing it to learn. So the actual problem might be … me , not seeing obvious resolution to my problems.

4. Error messages and/or full log output:

Mar 31 19:36:08 sd-163808 systemd[1]: caddy.service: Succeeded.
Mar 31 19:36:08 sd-163808 systemd[1]: Stopped Caddy.
Mar 31 19:36:08 sd-163808 systemd[1]: Started Caddy.
Mar 31 19:36:08 sd-163808 caddy[103637]: caddy.HomeDir=/var/lib/caddy
Mar 31 19:36:08 sd-163808 caddy[103637]: caddy.AppDataDir=/var/lib/caddy/.local/share/caddy
Mar 31 19:36:08 sd-163808 caddy[103637]: caddy.AppConfigDir=/var/lib/caddy/.config/caddy
Mar 31 19:36:08 sd-163808 caddy[103637]: caddy.ConfigAutosavePath=/var/lib/caddy/.config/caddy/autosave.json
Mar 31 19:36:08 sd-163808 caddy[103637]: caddy.Version=v2.3.0
Mar 31 19:36:08 sd-163808 caddy[103637]: runtime.GOOS=linux
Mar 31 19:36:08 sd-163808 caddy[103637]: runtime.GOARCH=amd64
Mar 31 19:36:08 sd-163808 caddy[103637]: runtime.Compiler=gc
Mar 31 19:36:08 sd-163808 caddy[103637]: runtime.NumCPU=2
Mar 31 19:36:08 sd-163808 caddy[103637]: runtime.GOMAXPROCS=2
Mar 31 19:36:08 sd-163808 caddy[103637]: runtime.Version=go1.14.12
Mar 31 19:36:08 sd-163808 caddy[103637]: os.Getwd=/
Mar 31 19:36:08 sd-163808 caddy[103637]: LANG=en_US.UTF-8
Mar 31 19:36:08 sd-163808 caddy[103637]: PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin
Mar 31 19:36:08 sd-163808 caddy[103637]: HOME=/var/lib/caddy
Mar 31 19:36:08 sd-163808 caddy[103637]: LOGNAME=caddy
Mar 31 19:36:08 sd-163808 caddy[103637]: USER=caddy
Mar 31 19:36:08 sd-163808 caddy[103637]: INVOCATION_ID=1a4d985b16f24b0bbd3a6c2e1ad7357c
Mar 31 19:36:08 sd-163808 caddy[103637]: JOURNAL_STREAM=9:757470
Mar 31 19:36:08 sd-163808 caddy[103637]: {"level":"info","ts":1617212168.7591827,"msg":"using provided configuration","config_file":"/etc/caddy/Caddyfile","config_adapter":""}
Mar 31 19:36:08 sd-163808 caddy[103637]: {"level":"info","ts":1617212168.7677064,"logger":"admin","msg":"admin endpoint started","address":"tcp/localhost:2019","enforce_origin":false,"origins":["localhost:2019","[::1]:2019","127.0.0.1:2019"]}
Mar 31 19:36:08 sd-163808 caddy[103637]: {"level":"info","ts":1617212168.7683446,"logger":"tls.cache.maintenance","msg":"started background certificate maintenance","cache":"0xc000493730"}
Mar 31 19:36:08 sd-163808 caddy[103637]: {"level":"info","ts":1617212168.7685227,"logger":"http","msg":"server is listening only on the HTTPS port but has no TLS connection policies; adding one to enable TLS","server_name":"srv0","https_port":443}
Mar 31 19:36:08 sd-163808 caddy[103637]: {"level":"info","ts":1617212168.768588,"logger":"http","msg":"enabling automatic HTTP->HTTPS redirects","server_name":"srv0"}
Mar 31 19:36:08 sd-163808 caddy[103637]: {"level":"info","ts":1617212168.771519,"logger":"http","msg":"enabling automatic TLS certificate management","domains":["team-tabulos.com"]}
Mar 31 19:36:08 sd-163808 caddy[103637]: {"level":"info","ts":1617212168.7744782,"logger":"tls","msg":"cleaned up storage units"}
Mar 31 19:36:08 sd-163808 caddy[103637]: {"level":"info","ts":1617212168.841473,"msg":"autosaved config","file":"/var/lib/caddy/.config/caddy/autosave.json"}
Mar 31 19:36:08 sd-163808 caddy[103637]: {"level":"info","ts":1617212168.841576,"msg":"serving initial configuration"}
Mar 31 19:36:30 sd-163808 caddy[103637]: {"level":"error","ts":1617212190.3053584,"logger":"http.log.access","msg":"handled request","request":{"remote_addr":"88.163.254.7:4121","proto":"HTTP/2.0","method":"GET","host":"team-tabulos.com","uri":"/index.php","headers":{"Cookie":["PHPSESSID=p2du122j9dflhrui2n4dgaj3uu; _ga=GA1.2.247871532.1617000897"],"Accept":["text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"],"User-Agent":["Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_6) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/14.0.3 Safari/605.1.15"],"Accept-Language":["fr-fr"],"Accept-Encoding":["gzip, deflate, br"]},"tls":{"resumed":false,"version":772,"cipher_suite":4865,"proto":"h2","proto_mutual":true,"server_name":"team-tabulos.com"}},"common_log":"88.163.254.7 - - [31/Mar/2021:19:36:30 +0200] \"GET /index.php HTTP/2.0\" 404 16","duration":0.00212895,"size":16,"status":404,"resp_headers":{"Server":["Caddy"],"Status":["404 Not Found"],"X-Powered-By":["PHP/7.2.24"],"Content-Type":["text/html; charset=UTF-8"]}}
Mar 31 19:36:42 sd-163808 caddy[103637]: {"level":"error","ts":1617212202.4979668,"logger":"http.log.access","msg":"handled request","request":{"remote_addr":"107.180.88.41:48652","proto":"HTTP/1.1","method":"GET","host":"team-tabulos.com","uri":"/wp-login.php","headers":{"Referer":["http://team-tabulos.com/wp-login.php"],"Accept-Encoding":["gzip"],"Connection":["close"],"User-Agent":["Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:62.0) Gecko/20100101 Firefox/62.0"]},"tls":{"resumed":false,"version":771,"cipher_suite":49196,"proto":"","proto_mutual":true,"server_name":"team-tabulos.com"}},"common_log":"107.180.88.41 - - [31/Mar/2021:19:36:42 +0200] \"GET /wp-login.php HTTP/1.1\" 404 16","duration":0.001768437,"size":16,"status":404,"resp_headers":{"Server":["Caddy"],"Content-Type":["text/html; charset=UTF-8"],"Status":["404 Not Found"],"X-Powered-By":["PHP/7.2.24"]}}

5. What I already tried:

I’ve tried to fiddle with the php-fpm config file in order to improve log level as well, but no really helpful anyway.
How can I get better log level?

6. Links to relevant resources:

francislavoie · March 31, 2021, 6:04pm

You need to add file_server for static files to get served. As-is, your config will only handle PHP files and respond to requests for anything else with an empty 200 response.

/tmp doesn’t seem like a good place to serve your site from though. Why are you putting it in /tmp?

For debugging, you should enable the debug global option. At the top of your Caddyfile, add this:

{
	debug
}

The log directive only configures access logs, and there’s only INFO and ERROR level access logs emitted (at least for now) so setting the log level to DEBUG doesn’t do anything.

yves · March 31, 2021, 8:12pm

Good question. Actually I want to edit my files directly on the server from my desktop computer using sshfs, so I can use Visual Code to edit files remotely.

If I mount the sd-163808:/var/tabulos_backup directory, I cannot edit it since it belongs to the root user. So I chose to mount the sd-163808:/tmp/tabulos folder instead which belongs to the normal user (yves) on my server.

As a workaround I will enable to login as the root user and mount sd-163808:/var/tabulos_backup on my machine. But that does not explain why I am not able to point to /tmp/tabulos from the Caddyfile.

Not sure all this explanation is clear.

francislavoie · March 31, 2021, 8:25pm

When running as a systemd service, Caddy uses the caddy user:

Make sure that user can read those files.

yves · March 31, 2021, 8:35pm

Make sure that user can read those files.

That’s a good remark. But how would you do that?

If I try to login as this user, it’s not available (its shell is nologin):

[root@sd-163808 ~]# su - caddy
Last login: Wed Mar 31 22:32:27 CEST 2021 on pts/0
This account is currently not available.

Maybe changing (temporarily) its shell to a real shell?

Regards
Yves

francislavoie · March 31, 2021, 8:37pm

Either add the caddy user to the group that the files are group-owned by, or change the group of the files to be one that you could add caddy to.

yves · March 31, 2021, 8:52pm

First, I added a shell to the caddy user file and it’s been able to access the files in /tmp/tabulos.
Secondly, as you suggested, I added the caddy user to the yves group. But it doesn’t help, the issue is still here.

I still think it’s a privilege issue, but I think it’s somewhere else. Maybe related to the php-fpm server?

francislavoie · April 1, 2021, 1:49am

Yeah, php-fpm would also need access to those files to run them.

agrajag · April 1, 2021, 4:36am

Dont use /tmp here, create a path, set ownership, if you only have your /home/whatever, do it there before trying to attach processes to serving files out of /tmp

francislavoie · April 1, 2021, 5:34am

Somewhere like /opt or /srv might be appropriate.

yves · April 1, 2021, 11:50am

Just to end this thread: it has indeed to do with php-fpm, i.e. not caddy. That’s what I see in /var/log/php-fpm/error.log file when requesting a file and getting a 404 error as a reply:

[01-Apr-2021 13:00:23.522443] WARNING: pid 120232, fpm_stdio_child_said(), line 190: [pool www] child 120235 said into stderr: "DEBUG: mai
n(), line 1947: Primary script unknown"

I though at some point it was related to selinux, but it’s not since selinux is disabled on my device:

[root@sd-163808 opt]# sestatus
SELinux status:                 disabled

If I move my git repo into /opt as suggested by @francislavoie then my browser get the correct result.

So in conclusion I see that there’s some privilege issues with php-fpm, but fail to see exactly why. Thank you everyone for the time spent on this issue.

system · April 30, 2021, 5:43pm

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