From c59834141d77e188835c1ffb65e9455f860dfa3b Mon Sep 17 00:00:00 2001 From: MickLesk <47820557+MickLesk@users.noreply.github.com> Date: Wed, 11 Nov 2026 23:05:44 +0100 Subject: [PATCH 1/2] Say why a container stopped by itself during its setup 55 runs in a week ended in "Container stopped by itself during its setup" with only the host unit's start and stop in the log. Log what the host kernel said about the container and, read from its stopped rootfs, where its own shutdown began. Start the setup clock with the container, too: during the network wait it was unset, so a stop task from seconds earlier was not found and the stop counted as the container's own. --- .github/workflows/verify-split-files.yml | 5 ++ pve/backend.func | 25 +++++++ tests/ct-stop-facts.sh | 93 ++++++++++++++++++++++++ 3 files changed, 123 insertions(+) create mode 100644 tests/ct-stop-facts.sh diff --git a/.github/workflows/verify-split-files.yml b/.github/workflows/verify-split-files.yml index 85a3153..6319d5c 100644 --- a/.github/workflows/verify-split-files.yml +++ b/.github/workflows/verify-split-files.yml @@ -31,6 +31,7 @@ on: - "tests/docker-lxcfs.sh" - "tests/java-memory.sh" - "tests/sudo-env.sh" + - "tests/ct-stop-facts.sh" - "tests/deb822-local-keyring.sh" - "tests/gpu-pci-class.sh" - "tests/nvidia-version-pin.sh" @@ -92,6 +93,7 @@ on: - "tests/docker-lxcfs.sh" - "tests/java-memory.sh" - "tests/sudo-env.sh" + - "tests/ct-stop-facts.sh" - "tests/deb822-local-keyring.sh" - "tests/gpu-pci-class.sh" - "tests/nvidia-version-pin.sh" @@ -179,6 +181,9 @@ jobs: - name: sudo environment tests run: bash tests/sudo-env.sh + - name: Container stop facts tests + run: bash tests/ct-stop-facts.sh + - name: deb822 local keyring tests run: bash tests/deb822-local-keyring.sh diff --git a/pve/backend.func b/pve/backend.func index da4bd73..5e78caf 100644 --- a/pve/backend.func +++ b/pve/backend.func @@ -192,6 +192,27 @@ _pve_ct_stopped_by() { grep -oE 'UPID:[^"]+' | awk -F: '$6 ~ /^vz(stop|shutdown|reboot|destroy)$/ { print $6 " by " $8; exit }' } +# Why a container stopped by itself is in its own journal, which stops with it: +# what the host kernel logged about it, and where its shutdown began. +_pve_ct_stop_facts() { + local root="/var/lib/lxc/${CTID}/rootfs" log="" + journalctl -k --since "@${_CS_INSTALL_STARTED:-0}" -o cat --no-pager 2>/dev/null | + grep -E "lxc-${CTID}_<|/lxc/${CTID}/" | tail -n 5 | sed "s/^/${TAB}kernel: /" || true + pct mount "$CTID" >/dev/null 2>&1 || return 0 + if [[ -d "$root/var/log/journal" ]]; then + log="$(journalctl -D "$root/var/log/journal" -n 300 -o short-monotonic --no-hostname --no-pager -q 2>/dev/null)" || log="" + else + log="$(tail -n 300 "$root/var/log/syslog" 2>/dev/null || tail -n 300 "$root/var/log/messages" 2>/dev/null)" || log="" + fi + pct unmount "$CTID" >/dev/null 2>&1 || true + [[ -n "$log" ]] || return 0 + echo "${TAB}Container log where its shutdown began:" + awk '!s && /Received SIG|[Pp]owering (off|down)|Shutting down|Freezing|Caught <|emergency/ { s = NR } + { l[NR] = $0 } + END { f = s ? s - 3 : NR - 11; if (f < 1) f = 1; for (i = f; i <= NR && i < f + 12; i++) print l[i] }' <<<"$log" | + sed "s/^/${TAB} /" +} + # ------------------------------------------------------------------------------ # _pve_ct_gone_during_setup # @@ -214,6 +235,7 @@ _pve_ct_gone_during_setup() { fi msg_error "Container ${CTID} stopped by itself during its setup" journalctl -u "pve-container@${CTID}" -n 10 --no-pager -o cat 2>/dev/null | sed "s/^/${TAB}/" || true + _pve_ct_stop_facts export ERROR_CATEGORY_OVERRIDE="proxmox" _CS_SETUP_GONE_RC=199 } @@ -248,6 +270,7 @@ _pve_wait_for_detached_install() { echo "[INFO] The install did not fail: ${stopped_by} ended it" return 143 fi + _pve_ct_stop_facts return 199 fi pid="$(pct exec "$CTID" -- cat "${base}.pid" 2>/dev/null | tr -d '[:space:]')" @@ -1074,6 +1097,8 @@ EOF # ============================================================================ msg_info "Starting container" + # From here a stop counts as during the setup; unset, _pve_ct_stopped_by looked only from "now". + _CS_INSTALL_STARTED="$(date +%s)" # Checked, and with its own code. Unchecked, a failure here surfaced as pct's # generic 255 -- which the exit table reads as DPKG's fatal error, so 197 runs # across 70 apps in a fortnight were filed as a package manager problem when diff --git a/tests/ct-stop-facts.sh b/tests/ct-stop-facts.sh new file mode 100644 index 0000000..f5053fd --- /dev/null +++ b/tests/ct-stop-facts.sh @@ -0,0 +1,93 @@ +#!/usr/bin/env bash +# 55 runs in a week ended in "Container stopped by itself during its setup" +# with nothing but the host unit's start and stop in the log. +set -uo pipefail + +CORE_DIR="$(cd -- "$(dirname -- "${BASH_SOURCE[0]}")/.." && pwd)" +BACKEND="$CORE_DIR/pve/backend.func" +TEST_DIR="$(mktemp -d)" +trap 'rm -rf -- "$TEST_DIR"' EXIT +eval "$(awk '/^_pve_ct_stop_facts[(][)] [{]/,/^}/' "$BACKEND" | sed "s#/var/lib/lxc#$TEST_DIR/lxc#g")" +passed=0 failed=0 + +expect() { + if [[ "$2" == "$3" ]]; then + echo "PASS $1" + passed=$((passed + 1)) + else + echo "FAIL $1: expected <$2>, got <$3>" >&2 + failed=$((failed + 1)) + fi +} + +TAB=" " CTID=101 _CS_INSTALL_STARTED=1793658000 +ROOT="$TEST_DIR/lxc/101/rootfs" +MOUNT_OK=1 +pct() { + echo "$1" >>"$TEST_DIR/pct.calls" + [[ "$1" != mount ]] || ((MOUNT_OK)) +} +journalctl() { + case " $* " in + *" -k "*) cat "$TEST_DIR/kernel" ;; + *" -D $ROOT/var/log/journal "*) cat "$TEST_DIR/ctjournal" ;; + *) return 1 ;; + esac +} +reset() { + rm -rf "$TEST_DIR/lxc" "$TEST_DIR/pct.calls" + mkdir -p "$ROOT/var/log" + : >"$TEST_DIR/kernel" + : >"$TEST_DIR/ctjournal" +} + +reset +mkdir -p "$ROOT/var/log/journal" +for i in $(seq 1 20); do echo "[ 0.$i] systemd[1]: Started unit$i.service." >>"$TEST_DIR/ctjournal"; done +echo "[ 2.1] systemd[1]: Received SIGRTMIN+4 from PID 1 (systemd)." >>"$TEST_DIR/ctjournal" +for i in $(seq 1 20); do echo "[ 2.$((i + 1))] systemd[1]: Stopped unit$i.service." >>"$TEST_DIR/ctjournal"; done +printf '%s\n' \ + 'audit: type=1400 apparmor="DENIED" operation="mount" profile="lxc-101_" name="/run/"' \ + 'audit: type=1400 apparmor="DENIED" operation="mount" profile="lxc-1010_" name="/run/"' \ + 'oom-kill:constraint=CONSTRAINT_MEMCG,task_memcg=/lxc/101/ns/system.slice,task=node' \ + 'oom-kill:constraint=CONSTRAINT_MEMCG,task_memcg=/lxc/1010/ns/system.slice,task=java' >"$TEST_DIR/kernel" +out="$(_pve_ct_stop_facts)" +expect "kernel lines about this container only" 2 "$(grep -c '^ kernel: ' <<<"$out")" +expect "no kernel line about container 1010" 0 "$(grep -c '1010' <<<"$out" || true)" +expect "the log starts three entries before the shutdown signal" "Started unit18.service." \ + "$(grep -A1 'shutdown began' <<<"$out" | tail -n1 | awk '{print $(NF-1), $NF}')" +expect "the shutdown signal is shown" 1 "$(grep -c 'Received SIGRTMIN+4' <<<"$out")" +expect "twelve log lines at most" 12 "$(grep -c '^ \[' <<<"$out")" +expect "the rootfs is unmounted again" "mount unmount" "$(paste -sd' ' "$TEST_DIR/pct.calls")" + +reset +for i in $(seq 1 30); do echo "Nov 11 10:48:0$((i % 10)) ct kernel: line $i" >>"$ROOT/var/log/syslog"; done +out="$(_pve_ct_stop_facts)" +expect "without a journal, the tail of syslog" "line 30" "$(tail -n1 <<<"$out" | awk '{print $(NF-1), $NF}')" +expect "twelve syslog lines without a shutdown marker" 12 "$(grep -c 'kernel: line' <<<"$out")" + +reset +mkdir -p "$ROOT/var/log/journal" +echo "[ 0.1] systemd[1]: Started x.service." >"$TEST_DIR/ctjournal" +MOUNT_OK=0 +out="$(_pve_ct_stop_facts)" +expect "a rootfs that will not mount is left alone" "mount" "$(paste -sd' ' "$TEST_DIR/pct.calls")" +expect "and nothing is printed for it" "" "$out" +MOUNT_OK=1 + +reset +rc="$( + set -eEo pipefail + trap 'echo ERR' ERR + _pve_ct_stop_facts >/dev/null + echo "rc=$?" +)" +expect "an empty kernel log and no container log trip neither errexit nor the ERR trap" "rc=0" "$rc" + +expect "both stopped-by-itself paths collect the facts" 2 \ + "$(awk '/^(_pve_ct_gone_during_setup|_pve_wait_for_detached_install)[(][)] [{]/,/^}/' "$BACKEND" | grep -c '^ *_pve_ct_stop_facts$')" +expect "the setup clock starts with the container" 1 \ + "$(grep -A2 'msg_info "Starting container"' "$BACKEND" | grep -c '_CS_INSTALL_STARTED="$(date +%s)"')" + +printf '%s passed, %s failed\n' "$passed" "$failed" +((failed == 0)) From 5fe02629fd141f20c6843ca9b5a8e37897253760 Mon Sep 17 00:00:00 2001 From: MickLesk <47820557+MickLesk@users.noreply.github.com> Date: Thu, 12 Nov 2026 11:38:27 +0100 Subject: [PATCH 2/2] Move the test entry away from the other open branches --- .github/workflows/verify-split-files.yml | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/.github/workflows/verify-split-files.yml b/.github/workflows/verify-split-files.yml index 6319d5c..023e438 100644 --- a/.github/workflows/verify-split-files.yml +++ b/.github/workflows/verify-split-files.yml @@ -31,8 +31,8 @@ on: - "tests/docker-lxcfs.sh" - "tests/java-memory.sh" - "tests/sudo-env.sh" - - "tests/ct-stop-facts.sh" - "tests/deb822-local-keyring.sh" + - "tests/ct-stop-facts.sh" - "tests/gpu-pci-class.sh" - "tests/nvidia-version-pin.sh" - "tests/external-installer.sh" @@ -93,8 +93,8 @@ on: - "tests/docker-lxcfs.sh" - "tests/java-memory.sh" - "tests/sudo-env.sh" - - "tests/ct-stop-facts.sh" - "tests/deb822-local-keyring.sh" + - "tests/ct-stop-facts.sh" - "tests/gpu-pci-class.sh" - "tests/nvidia-version-pin.sh" - "tests/external-installer.sh" @@ -181,12 +181,12 @@ jobs: - name: sudo environment tests run: bash tests/sudo-env.sh - - name: Container stop facts tests - run: bash tests/ct-stop-facts.sh - - name: deb822 local keyring tests run: bash tests/deb822-local-keyring.sh + - name: Container stop facts tests + run: bash tests/ct-stop-facts.sh + - name: GPU detection by PCI class tests run: bash tests/gpu-pci-class.sh