Why is log output trying to create a directory that already exists?

1. The problem I’m having:

I am setting up a server for several virtual hosts, each of which is supposed to have its own access log.

Caddy fails to start, because it can’t create one of the parent directories of one of the log files. But it shouldn’t be trying to create that directory at all; it already exists!

2. Error messages and/or full log output:

Sep 23 22:42:09 tinka systemd[1]: Starting Caddy...
Sep 23 22:42:09 tinka caddy[749]: {"level":"info","ts":1758667329.4293368,"msg":"maxprocs: Leaving GOMAXPROCS=2: CPU quota undefined"}
Sep 23 22:42:09 tinka caddy[749]: {"level":"info","ts":1758667329.4297462,"msg":"GOMEMLIMIT is updated","package":"github.com/KimMachineGun/automemlimit/memlimit","GOMEMLIMIT":7493245747,"previous":9223372036854775807}
Sep 23 22:42:09 tinka caddy[749]: {"level":"info","ts":1758667329.4298112,"msg":"using config from file","file":"/etc/caddy/caddy_config"}
Sep 23 22:42:09 tinka caddy[749]: {"level":"info","ts":1758667329.432147,"msg":"adapted config to JSON","adapter":"caddyfile"}
Sep 23 22:42:09 tinka caddy[749]: {"level":"info","ts":1758667329.4343011,"msg":"maxprocs: No GOMAXPROCS change to reset"}
Sep 23 22:42:09 tinka caddy[749]: Error: loading initial config: loading new config: setting up custom log 'log2': opening log writer using &logging.FileWriter{Filename:"/home/web-research/logs/access.log", Mode:0x0, Roll:(*bool)(nil), RollSizeMB:0, RollCompress:(*bool)(nil), RollLocalTime:false, RollKeep:0, RollKeepDays:0}: mkdir /home/web-research: permission denied
Sep 23 22:42:09 tinka systemd[1]: caddy.service: Main process exited, code=exited, status=1/FAILURE
Sep 23 22:42:09 tinka systemd[1]: caddy.service: Failed with result 'exit-code'.
Sep 23 22:42:09 tinka systemd[1]: Failed to start Caddy.

Demonstrating that the directory it’s trying to create already exists:

# ls -ld / /home /home/web-research /home/web-research/logs
drwxr-xr-x 16 root         root   320 Sep 23 22:30 /
drwxr-xr-x  6 root         root  4096 Sep 23 22:29 /home
drwx--x--x  4 web-research users 4096 Sep 23 22:32 /home/web-research
drwxrwxr-x  2 web-research caddy 4096 Sep 23 22:41 /home/web-research/logs

Demonstrating that the caddy daemon account can write to that directory already:

# ls -l  /home/web-research/logs
total 0
# runuser -u caddy -- touch /home/web-research/logs/access.log
# ls -l /home/web-research/logs/
total 0
-rw-r--r-- 1 caddy caddy 0 Sep 23 22:54 access.log

3. Caddy version:

2.10.0

4. How I installed and ran Caddy:

Installed as NixOS 25.05 system service. Relevant excerpt of configuration.nix:

{
  services.caddy = {
    enable = true;
    email = "[REDACTED]";
    globalConfig = ''
      default_sni [REDACTED]
    '';
    extraConfig = ''
    '';
    virtualHosts = {
        # ...
    };
  };
}

Caddy is then started on boot as a systemd service.

a. System environment:

# uname -a
Linux tinka 6.12.48 #1-NixOS SMP PREEMPT_DYNAMIC Fri Sep 19 14:35:52 UTC 2025 x86_64 GNU/Linux
# nixos-version
25.05.20250923.d1d8831 (Warbler)
# systemctl --version
systemd 257 (257.9)
+PAM +AUDIT -SELINUX +APPARMOR +IMA +IPE +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBCRYPTSETUP_PLUGINS +LIBFDISK +PCRE2 +PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD +BPF_FRAMEWORK -BTF -XKBCOMMON +UTMP -SYSVINIT +LIBARCHIVE

Please let me know if anything else is relevant.

b. Command:

systemctl start caddy.service

c. Service/unit/compose file:

This is 100% NixOS stock. The substantial amount of gobbledygook in here is just how NixOS works.

# 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
StartLimitBurst=10
StartLimitIntervalSec=14400
X-Reload-Triggers=/nix/store/vhsm0pvjsdj3zzm725jkdra2zl9pdx44-X-Reload-Triggers-caddy

[Service]
Type=notify
User=caddy
Group=caddy
TimeoutStopSec=5s
LimitNOFILE=1048576
PrivateTmp=true
ProtectSystem=full
AmbientCapabilities=CAP_NET_ADMIN CAP_NET_BIND_SERVICE
LogsDirectory=caddy
StateDirectory=caddy
NoNewPrivileges=true
PrivateDevices=true
ProtectHome=true
ReadWritePaths=/var/lib/caddy
Restart=on-failure
RestartPreventExitStatus=1
RestartSec=5s
Environment="LOCALE_ARCHIVE=/nix/store/yczfclil9jjhcbdy1a6rqinihmfdzcz3-glibc-locales-2.40-66/lib/locale/locale-archive"
Environment="PATH=/nix/store/rry6qingvsrqmc7ll7jgaqpybcbdgf5v-coreutils-9.7/bin:/nix/store/392hs9nhm6wfw4imjllbvb1wil1n39qx-findutils-4.10.0/bin:/nix/store/l2wvwyg680h0v2la18hz3yiznxy2naqw-gnugrep-3.11/bin:/nix/store/4rpiqv9yr2pw5094v4wc33ijkqjpm9sa-gnused-4.9/bin:/nix/store/d84f8nm2na5cr53m4jk0qk2mj7lgr9fx-systemd-257.9/bin:/nix/store/rry6qingvsrqmc7ll7jgaqpybcbdgf5v-coreutils-9.7/sbin:/nix/store/392hs9nhm6wfw4imjllbvb1wil1n39qx-findutils-4.10.0/sbin:/nix/store/l2wvwyg680h0v2la18hz3yiznxy2naqw-gnugrep-3.11/sbin:/nix/store/4rpiqv9yr2pw5094v4wc33ijkqjpm9sa-gnused-4.9/sbin:/nix/store/d84f8nm2na5cr53m4jk0qk2mj7lgr9fx-systemd-257.9/sbin"
Environment="TZDIR=/nix/store/f7yb9lhi1z8dk4x8gy3c5xf3gvn3yi1s-tzdata-2025b/share/zoneinfo"
ExecReload=/nix/store/z26qnmzvrv93x3fprcnvc0s7ja131lsr-caddy-2.10.0/bin/caddy reload --config /etc/caddy/caddy_config --adapter caddyfile --force
ExecStart=/nix/store/z26qnmzvrv93x3fprcnvc0s7ja131lsr-caddy-2.10.0/bin/caddy run --config /etc/caddy/caddy_config --adapter caddyfile

[Install]
WantedBy=multi-user.target

d. My complete Caddy config:

I did cut this down substantially, but then I rechecked that the cut-down version produces the exact same error.

{
        default_sni tinka.owlfolio.org

        # test mode for test VM
        debug
        local_certs
        skip_install_trust
        email not.a.real.email@dont.use.invalid
}

research.owlfolio.org {
        log {
                output file /home/web-research/logs/access.log
        }
        root * /home/web-research/html
        file_server {
                precompressed
        }
        encode
}
# three other vhosts redacted

5. Links to relevant resources:

I was able to get some help from NixOS people; this turns out to be a conflict between my filesystem layout and NixOS’s default systemd service configuration for Caddy. Since this system is a dedicated web server with several people who need to be able to upload files for their site but no others, I put all the site roots and log directories in /home, as subdirectories of the user accounts for the people who manage them. That worked fine with the old system configuration (using neither Caddy nor NixOS). However, NixOS by default sets quite aggressive service isolation parameters for all systemd services: for Caddy it looks like this:

[Service]
PrivateTmp=true
PrivateDevices=true
ProtectSystem=full
ProtectHome=true
ReadWritePaths=/var/lib/caddy

Among other things, this makes /home appear to Caddy as an empty directory with mode 000 (d--------- in ls output), so it couldn’t access any of the things I told it to look for in there. That’s why it was trying to create directories that, from the perspective of an unconfined maintenance shell, appear to already exist.

When /home is being used as the website storage area, one wants systemd service isolation rules like this instead:

[Service]
ProtectHome=read-only
InaccessiblePaths=-/root -/run/user -/home/lost+found
ReadWritePaths=/var/lib/caddy
ReadWritePaths=[list all the log output directories here]
NoExecPaths=[list all the log output directories again here]

Which is expressed like this in Nix configuration language:

  systemd.services.caddy.serviceConfig = {
    ProtectHome = lib.mkForce "read-only";
    InaccessiblePaths = lib.mkAfter (lib.concatStringsSep " " [
      "-/root"
      "-/run/user"
      "-/home/lost+found"
    ]);
    ReadWritePaths = lib.mkAfter (lib.concatStringsSep " " [
        # log output directories here
    ]);
    NoExecPaths = lib.mkAfter (lib.concatStringsSep " " [
        # log output directories here again
    ]);
  };
2 Likes

Thank you for sharing your solution. This seems to be similar to this issue:

1 Like

Yes, very similar situation. I guess the general lesson is that systemd’s service isolation rules can cause the caddy daemon to have a different view of the filesystem than a root shell would.

The NixOS people taught me some tricks for troubleshooting this class of problem:

  1. systemctl edit --runtime caddy.service brings up an editor in which you can write temporary (until next reboot) overrides for the caddy service configuration. This is particularly handy in a declarative-configuration environment like NixOS because it lets you test things like changing ProtectHome=true to ProtectHome=read-only without rebuilding the entire system. (Don’t forget to write the [Service] header line or systemd will refuse to process your directives!)
  2. You can use the nsenter command to spawn a shell inside the “filesystem namespace” of the caddy daemon, which lets you see what the filesystem winds up looking like after the service isolation rules have been applied.
  3. nsenter only works if there’s a long-lived process running in the namespace you want to look at. If caddy is crashing on startup because the isolation rules are wrong, there won’t be any long-lived process to glom onto. But you can make there be a long-lived process by putting
    [Service]
    ExecStart=
    ExecStart=/path/to/sleep 86400
    
    in that temporary service configuration override file.
1 Like

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