Deploy as the application's user, and take back what root already took

The 500 on the VPN config download was never in the VPN code. storage/logs/
laravel.log was owned by root, mode 644, since 27.07 04:16 — the moment a
failed `artisan optimize` wrote its error there during a deployment. From then
on the application could not append to its own log: Monolog threw on every
attempt, and a throw while logging is a 500 on any page that logs, with nothing
written down to say why. The error page said "Er wurde protokolliert". It was
not.

It surfaced on the config download because that is one of the few pages writing
a log line on its way through — on success and on a wrong password alike. Pages
that log nothing were unaffected, which is exactly why it looked like a VPN
fault for days.

`docker compose exec` is root unless told otherwise, and every deployment
script relied on that default — including the agent's allowlist sync, which
runs every minute. docker/entrypoint.sh had it right all along and drops to
www-data for precisely these commands. Now so does everything else, help text
included: telling an operator to run artisan as root is how the file ends up
owned by root in the first place.

update.sh also repairs what an earlier run left behind, before its first
unprivileged step rather than after — a root-owned log file is not
self-healing, the page that trips over it is nowhere near the deployment that
caused it, and with in_app unprivileged a root-owned vendor/ would break the
next composer step outright.

tests/Feature/DeploymentRunsAsTheAppUserTest.php holds the line. It was checked
against the previous commit and finds all nine places that were wrong.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>

VERSION

@@ -1 +1 @@
-1.1.0
+1.1.1

deploy/install-agent.sh

@@ -50,15 +50,12 @@ cat > /etc/systemd/system/clupilot-update-agent.timer <<'EOF'
 Description=Check for CluPilot updates and run requested ones
 
 [Timer]
-# Every minute: a `git fetch` against one remote is not a nuisance at this
+# Every minute: a `git fetch` against one remote is not a nuisance at this rate,
-# rate, and the panel now shows a live countdown to the next tick — a wait
+# and this is now only the FALLBACK — the path unit below wakes the agent the
-# that reads as "obviously nothing is happening" at five minutes reads as
+# moment somebody asks for something. What the timer still decides is how fresh
-# "obviously working" at one.
+# the "is there a new version" reading is on a console nobody is looking at.
 OnBootSec=3min
 OnUnitActiveSec=1min
-# Tightened along with the interval above: at five minutes a 30s fuzz was a
-# rounding error; at one minute it is half the interval, and the panel's
-# countdown would sit at 0:00 for as long as systemd felt like waiting.
 AccuracySec=5s
 
 [Install]
@@ -120,7 +117,11 @@ if command -v caddy >/dev/null 2>&1 && [[ -f "$CADDYFILE" ]]; then
     else
         # Compose discovers its own file from the working directory — naming it
         # here guessed wrong once.
-        if ( cd "$ROOT" && runuser -u "$APP_USER" -- docker compose exec -T app \
+        # -u www-data, like every other artisan call: exec defaults to root, and
+        # a command that logs would leave storage/logs owned by root — after
+        # which the application cannot append to its own log at all, and every
+        # page that logs answers 500. That is not hypothetical; it happened.
+        if ( cd "$ROOT" && runuser -u "$APP_USER" -- docker compose exec -T -u www-data app \
                 php artisan clupilot:console-access caddy ) > "$ALLOWFILE.new" 2>/dev/null \
             && grep -q '@allowed remote_ip .' "$ALLOWFILE.new"; then
             mv -f "$ALLOWFILE.new" "$ALLOWFILE"
@@ -210,7 +211,7 @@ if [[ -z "$VPN_HOST" ]]; then
             profiles=\"\$(printf '%s' \"\$profiles\" | tr ',' '\n' | grep -vx 'vpn' | grep -v '^\$' | paste -sd, - || true)\"
             sed -i '/^COMPOSE_PROFILES=/d' .env
             [ -n \"\$profiles\" ] && printf 'COMPOSE_PROFILES=%s\n' \"\$profiles\" >> .env
-            docker compose exec -T app php artisan config:clear >/dev/null 2>&1 || true
+            docker compose exec -T -u www-data app php artisan config:clear >/dev/null 2>&1 || true
             echo '  Tunnel gateway disabled — VPN_INTERNAL_HOST is empty.'
         fi
     " || true
@@ -283,8 +284,8 @@ if [[ -n "$VPN_HOST" ]]; then
         # resolver — the gateway running but nothing pointed at it.
         runuser -u "$APP_USER" -- sh -c "
             cd '$ROOT'
-            docker compose exec -T app php artisan config:clear >/dev/null 2>&1
+            docker compose exec -T -u www-data app php artisan config:clear >/dev/null 2>&1
-            docker compose exec -T app php artisan config:cache >/dev/null 2>&1
+            docker compose exec -T -u www-data app php artisan config:cache >/dev/null 2>&1
         " || true
 
         # Only when it is true. Announcing success while the gateway failed to
@@ -308,7 +309,7 @@ if [[ -n "$VPN_HOST" ]]; then
             profiles=\"\$(printf '%s' \"\$profiles\" | tr ',' '\n' | grep -vx 'vpn' | grep -v '^\$' | paste -sd, - || true)\"
             sed -i '/^COMPOSE_PROFILES=/d' .env
             [ -n \"\$profiles\" ] && printf 'COMPOSE_PROFILES=%s\n' \"\$profiles\" >> .env
-            docker compose exec -T app php artisan config:clear >/dev/null 2>&1 || true
+            docker compose exec -T -u www-data app php artisan config:clear >/dev/null 2>&1 || true
         " || true
 
         echo "  ! No certificate for $VPN_HOST in $CADDY_DATA yet."

deploy/install.sh

@@ -456,8 +456,8 @@ Still to do, in this order:
        customer.subscription.updated       customer.subscription.deleted
   3. Mirror the plan catalogue into Stripe — nothing can be sold until it knows
      what it is billing for. Look first; a Stripe Price cannot be deleted:
-       docker compose exec app php artisan stripe:sync-catalogue --dry-run
+       docker compose exec -u www-data app php artisan stripe:sync-catalogue --dry-run
-       docker compose exec app php artisan stripe:sync-catalogue
+       docker compose exec -u www-data app php artisan stripe:sync-catalogue
   4. Sign in and switch the website to hidden under Settings until you are
      ready to be found (Settings → Website visibility).
 

deploy/update-agent.sh

@@ -77,7 +77,11 @@ sync_console_allowlist() {
     [[ -w "$(dirname "$ALLOWFILE")" || -w "$ALLOWFILE" ]] || return 0
 
     local generated
-    generated="$(docker compose exec -T app php artisan clupilot:console-access caddy 2>/dev/null)" || return 0
+    # -u www-data: exec defaults to root, and this one runs every minute. An
+    # artisan command that logs anything as root leaves storage/logs owned by
+    # root, after which the application cannot append to its own log — and every
+    # page that logs answers 500 with nothing written to say why.
+    generated="$(docker compose exec -T -u www-data app php artisan clupilot:console-access caddy 2>/dev/null)" || return 0
     # Never write an empty matcher: in Caddy that matches nothing, and the
     # console would be unreachable from everywhere including the shell.
     grep -q '@allowed remote_ip .' <<<"$generated" || return 0

deploy/update.sh

@@ -52,7 +52,41 @@ phase() {
     log "$*"
 }
 
-in_app() { docker compose exec -T app "$@"; }
+# As the application's own user, not as root.
+#
+# `docker compose exec` runs as root unless told otherwise, and this did — so
+# when `artisan optimize` failed during a deployment it wrote its error into
+# storage/logs/laravel.log AS ROOT. From that moment the application could not
+# append to its own log: Monolog threw on every attempt, and a throw while
+# logging is a 500 on every page that logs, with nothing in the log to say why.
+# It surfaced as a 500 on the VPN config download — one of the few pages that
+# writes a log line on the way through — and looked for days like a fault in
+# the VPN code.
+#
+# docker/entrypoint.sh already drops to www-data for exactly these commands.
+# The deployment simply never did.
+in_app() { docker compose exec -T -u www-data app "$@"; }
+
+# Hand back anything an earlier run left owned by root.
+#
+# Not tidiness. That damage is silent and permanent — nothing repairs a
+# root-owned log file on its own, and the symptom surfaces on whichever page
+# happens to log first, which is nowhere near the deployment that caused it. A
+# server already carrying it heals on its next deployment instead of needing
+# somebody to work out what happened.
+#
+# And it is now load-bearing: with in_app unprivileged, a vendor/ or
+# node_modules/ left owned by root would make the very next composer or npm
+# step fail outright.
+normalise_ownership() {
+    docker compose exec -T -u root app sh -c '
+        chown -R www-data:www-data storage bootstrap/cache 2>/dev/null || true
+        for d in vendor node_modules public/build; do
+            [ -d "$d" ] || continue
+            [ "$(stat -c %U "$d" 2>/dev/null)" = "www-data" ] || chown -R www-data:www-data "$d" 2>/dev/null || true
+        done
+    ' >/dev/null 2>&1 || true
+}
 
 down=0
 finish() {
@@ -60,7 +94,7 @@ finish() {
     if [[ $code -ne 0 && $down -eq 1 ]]; then
         warn "Update failed. The site is STILL in maintenance mode on purpose."
         warn "Fix the problem and re-run this script, or force it back up with:"
-        warn "  docker compose exec app php artisan up"
+        warn "  docker compose exec -u www-data app php artisan up"
     fi
     exit $code
 }
@@ -306,6 +340,10 @@ else
     warn "Code is current but the last update did not finish — repeating the steps."
 fi
 
+# Before the first unprivileged command, not after: if an earlier run left the
+# log or the vendor directory owned by root, everything below fails on it.
+normalise_ownership
+
 phase maintenance_on "Enabling maintenance mode"
 in_app php artisan down --retry=60 >/dev/null || warn "Could not enable maintenance mode (continuing)"
 down=1

tests/Feature/DeploymentRunsAsTheAppUserTest.php

@@ -0,0 +1,70 @@
+<?php
+
+use Illuminate\Support\Facades\File;
+
+/**
+ * Nothing runs inside the app container without saying who it is running as.
+ *
+ * `docker compose exec` is root unless told otherwise, and the deployment
+ * scripts relied on that default. When `artisan optimize` failed during a
+ * deployment it wrote its error into storage/logs/laravel.log AS ROOT — and
+ * from that moment the application could not append to its own log. Monolog
+ * threw on every attempt, and a throw while logging is a 500 on every page that
+ * logs, with nothing written down to say why.
+ *
+ * It surfaced days later as a 500 on the VPN config download, that being one of
+ * the few pages writing a log line on its way through, and was chased through
+ * the VPN code, the encryption key and the session before anyone looked at the
+ * owner of a file.
+ *
+ * docker/entrypoint.sh had it right all along: it drops to www-data for exactly
+ * these commands. The rule is only that the user is named — `-u root` is a fine
+ * answer where root is what is wanted (the ownership repair in update.sh), as
+ * long as somebody chose it.
+ */
+it('never runs a command in the app container as whoever docker felt like', function () {
+    $offenders = [];
+
+    foreach (File::glob(base_path('deploy/*.sh')) as $path) {
+        foreach (preg_split('/\R/', File::get($path)) ?: [] as $i => $line) {
+            if (! str_contains($line, 'docker compose exec')) {
+                continue;
+            }
+
+            // Only the app container. The gateway and the queues are other
+            // images with other users, and none of them own this checkout.
+            if (! preg_match('/docker compose exec\b[^|]*?\bapp\b/', $line)) {
+                continue;
+            }
+
+            if (preg_match('/\s-u\s+\S+/', $line)) {
+                continue;
+            }
+
+            // Help text counts. Telling an operator to run it as root is how
+            // the file ends up owned by root in the first place.
+            $offenders[] = basename($path).':'.($i + 1).' — '.trim($line);
+        }
+    }
+
+    expect($offenders)->toBe([]);
+});
+
+it('repairs ownership before it needs it, not after', function () {
+    // A server already carrying the damage has to heal on its next deployment.
+    // Nothing else ever will: a root-owned log file stays root-owned, and the
+    // page that trips over it is nowhere near the deployment that caused it.
+    $update = File::get(base_path('deploy/update.sh'));
+
+    expect($update)->toContain('normalise_ownership')
+        ->and($update)->toContain('chown -R www-data:www-data storage bootstrap/cache');
+
+    // Before the first unprivileged step, or it cannot help: composer and npm
+    // would already have failed on a root-owned vendor directory.
+    $repair = strpos($update, "\nnormalise_ownership\n");
+    $maintenance = strpos($update, 'php artisan down --retry=60');
+
+    expect($repair)->not->toBeFalse()
+        ->and($maintenance)->not->toBeFalse()
+        ->and($repair)->toBeLessThan($maintenance);
+});