diff --git a/.github/workflows/install-test-comment.yml b/.github/workflows/install-test-comment.yml new file mode 100644 index 0000000..3820c3c --- /dev/null +++ b/.github/workflows/install-test-comment.yml @@ -0,0 +1,118 @@ +name: Install test comment + +# Posts the install test's numbers on the pull request as one comment, kept +# up to date on every run, next to quattro's latest numbers. GitHub runs +# workflow_run workflows from the default branch, with write access even for +# pull requests from forks, so this job never checks out or runs pull request +# code: it only reads the finished run's artifact, as data. + +on: + workflow_run: + workflows: ["Install test"] + types: [completed] + +permissions: + actions: read + pull-requests: write + +jobs: + comment: + if: github.event.workflow_run.event == 'pull_request' + runs-on: ubuntu-latest + env: + GH_TOKEN: ${{ github.token }} + REPO: ${{ github.repository }} + RUN_ID: ${{ github.event.workflow_run.id }} + RUN_URL: ${{ github.event.workflow_run.html_url }} + HEAD_SHA: ${{ github.event.workflow_run.head_sha }} + CONCLUSION: ${{ github.event.workflow_run.conclusion }} + steps: + # A rerun keeps earlier attempts' artifacts under the same run, so take + # exactly the attempt that finished (and the baseline's latest attempt). + - name: Fetch this run's numbers and quattro's latest + env: + ATTEMPT: ${{ github.event.workflow_run.run_attempt }} + run: | + gh run download "$RUN_ID" -R "$REPO" -n "install-test-$RUN_ID-$ATTEMPT" -D pr || true + base=$(gh run list -R "$REPO" --workflow install-test.yml --branch quattro --event push \ + --status success -L 1 --json databaseId -q '.[0].databaseId') + if [ -n "$base" ]; then + base_attempt=$(gh api "repos/$REPO/actions/runs/$base" -q .run_attempt) + gh run download "$base" -R "$REPO" -n "install-test-$base-$base_attempt" -D base || true + fi + + - name: Comment on the pull request + run: | + set -euo pipefail + marker='' + + # The number comes from the pull request's own run, so trust it only + # when that pull request's head is the commit this run tested. + pr=$({ find pr -name pr-number -exec cat {} + 2>/dev/null || true; } | head -1 | tr -dc 0-9) + [ -n "$pr" ] || { echo "No pull request number in the artifact"; exit 0; } + [ "$(gh api "repos/$REPO/pulls/$pr" -q .head.sha)" = "$HEAD_SHA" ] || + { echo "PR #$pr has moved past $HEAD_SHA; not commenting"; exit 0; } + + # Every lookup prints nothing rather than failing, so a missing baseline (none + # yet, or expired) shows as "–" instead of ending the script under set -e. + timing() { { find "$1" -name omarchy-install-timing.json 2>/dev/null || true; } | head -1; } + install_s() { [ -n "$1" ] || return 0; jq -r '.finished_at - .started_at' "$1" 2>/dev/null || true; } + # "Startup finished in … = 1min 2.3s" or "= 12.104s" -> seconds + boot_s() { + local f + f=$({ find "$1" -path "$2" 2>/dev/null || true; } | head -1) + [ -n "$f" ] || return 0 + head -1 "$f" | sed -n 's/.*= *//p' | + awk '{t=0; for (i=1;i<=NF;i++) { if ($i ~ /min$/) t+=60*$i; else if ($i ~ /ms$/) t+=$i/1000; else t+=$i } printf "%.3f", t}' + } + cell() { [ -n "$1" ] && awk -v x="$1" 'BEGIN{printf "%.1f s", x}' || echo "–"; } + change() { + [ -n "$1" ] && [ -n "$2" ] || { echo "–"; return; } + awk -v a="$1" -v b="$2" 'BEGIN{d=a-b; printf "%s%.1f s", (d>=0?"+":"−"), (d<0?-d:d)}' + } + + pt=$(timing pr); bt=$(timing base) + rows=( + "Install|$(install_s "$pt")|$(install_s "$bt")" + "First boot|$(boot_s pr '*/first-boot-systemd-analyze.txt')|$(boot_s base '*/first-boot-systemd-analyze.txt')" + "Everyday boot|$(boot_s pr '*-boot/systemd-analyze.txt')|$(boot_s base '*-boot/systemd-analyze.txt')" + ) + + status="passed"; [ "$CONCLUSION" = success ] || status="**${CONCLUSION}**" + { + echo "$marker" + echo "### Install test $status" + echo + echo "| | This PR | quattro | Change |" + echo "| --- | ---: | ---: | ---: |" + for row in "${rows[@]}"; do + IFS='|' read -r name this base_v <<<"$row" + echo "| $name | $(cell "$this") | $(cell "$base_v") | $(change "$this" "$base_v") |" + done + if [ -n "$pt" ]; then + echo + echo "
Install phases" + echo + echo "| Phase | This PR | quattro |" + echo "| --- | ---: | ---: |" + # Phase names come from the pull request's installer: keep them to plain text. + jq -r --slurpfile b <( [ -n "$bt" ] && cat "$bt" || echo '{"phases":[]}' ) ' + ($b[0].phases | map({key: .name, value: .elapsed}) | from_entries) as $base + | .phases[] + | "| \(.name | gsub("[^A-Za-z0-9 +&/().-]"; "") | .[0:60]) | \(.elapsed * 10 | round / 10) s | \(($base[.name] // null) | if . == null then "–" else "\(. * 10 | round / 10) s" end) |" + ' "$pt" + echo + echo "
" + fi + echo + echo "[Run]($RUN_URL) · ${HEAD_SHA:0:8}" + } > comment.md + + existing=$(gh api "repos/$REPO/issues/$pr/comments" --paginate \ + -q ".[] | select(.user.login == \"github-actions[bot]\" and (.body | startswith(\"$marker\"))) | .id" | head -1) + if [ -n "$existing" ]; then + gh api -X PATCH "repos/$REPO/issues/comments/$existing" -F body=@comment.md >/dev/null + else + gh api "repos/$REPO/issues/$pr/comments" -F body=@comment.md >/dev/null + fi + cat comment.md diff --git a/.github/workflows/install-test.yml b/.github/workflows/install-test.yml new file mode 100644 index 0000000..ccec9b0 --- /dev/null +++ b/.github/workflows/install-test.yml @@ -0,0 +1,117 @@ +name: Install test + +# Builds the ISO a pull request produces, installs it unattended in a KVM +# guest, boots the installed system again, and reports how long the install +# and both boots took. Every later change to the installer is measured +# against these numbers in its own PR. + +on: + pull_request: + # Each merge records quattro's numbers, which PR comments compare against. + push: + branches: [quattro] + workflow_dispatch: + +permissions: + contents: read + +concurrency: + group: install-test-${{ github.event.pull_request.number || github.ref }} + cancel-in-progress: true + +jobs: + install: + runs-on: ubuntu-24.04 + timeout-minutes: 75 + steps: + - uses: actions/checkout@08c6903cd8c0fde910a37f88322edcfb5dd907a8 # v5 + + # The hosted runner has far more disk than the build needs (145 GB, + # ~86 GB free); fail early and loudly if that ever changes. + - name: Check disk space + run: | + df -h / + avail_gb=$(df -BG --output=avail / | tail -1 | tr -dc 0-9) + [ "$avail_gb" -ge 40 ] || { echo "::error::only ${avail_gb} GB free, the ISO build and install test need ~40 GB"; exit 1; } + + - uses: docker/setup-buildx-action@37fe631027851001ddb9b187196cc803df7f5f0e # v4 + + - name: Build the ISO + run: NO_BOOT_OFFER=1 ./bin/omarchy-iso-make + + # The harness runs in an Arch container: Arch's current QEMU and OVMF + # (QEMU 11) instead of Ubuntu 24.04's QEMU 8.2, at the paths the + # harness expects, the same as on an Omarchy workstation. + - name: Install unattended, then boot the installed system + run: | + sudo chmod 0666 /dev/kvm + docker run --rm --device /dev/kvm -v "$PWD:/w" -w /w \ + -e OMARCHY_INTEGRATION_DISK_CACHE=none \ + archlinux:latest bash -euo pipefail -c ' + pacman -Syu --noconfirm --needed qemu-system-x86 qemu-hw-display-virtio-gpu qemu-hw-display-virtio-vga qemu-img edk2-ovmf socat \ + imagemagick tesseract tesseract-data-eng mtools dosfstools jq openssh openssl python curl >/dev/null + # test/integration installs its tools through Omarchy'"'"'s helper; they are installed above. + printf "#!/bin/sh\nexit 0\n" >/usr/local/bin/omarchy-pkg-add + chmod 0755 /usr/local/bin/omarchy-pkg-add + qemu-system-x86_64 --version | head -1 + ./test/integration release/*.iso boot --no-preview --memory 8192 --timeout 1800 + ' + + # The harness ran as root in its container: test-runs and what QEMU + # wrote there (the serial logs) belong to root until this step. + - name: Hand the results to the runner's user + if: always() + run: | + mkdir -p test-runs + sudo chown -R "$(id -u):$(id -g)" test-runs + + - name: Report times + if: always() + run: | + base=$(ls -d test-runs/*-integration 2>/dev/null | head -1) + [ -n "$base" ] || { echo "No test run to report" >> "$GITHUB_STEP_SUMMARY"; exit 0; } + { + echo "## Install test" + echo + if [ -f "$base/omarchy-install-timing.json" ]; then + jq -r '"**Install:** \((.finished_at - .started_at) * 10 | round / 10) s across \(.phases | length) phases"' "$base/omarchy-install-timing.json" + echo + echo "| Phase | Seconds |" + echo "| --- | ---: |" + jq -r '.phases[] | "| \(.name) | \(.elapsed * 10 | round / 10) |"' "$base/omarchy-install-timing.json" + echo + fi + if [ -f "$base/first-boot-systemd-analyze.txt" ]; then + echo "**First boot:** $(head -1 "$base/first-boot-systemd-analyze.txt")" + echo + fi + boot_dir=$(ls -d "$base"/runs/*-boot 2>/dev/null | tail -1) + if [ -n "$boot_dir" ] && [ -f "$boot_dir/systemd-analyze.txt" ]; then + echo "**Everyday boot:** $(head -1 "$boot_dir/systemd-analyze.txt")" + echo + echo "System state: $(jq -r .system_state "$boot_dir/boot-timing.json" 2>/dev/null)" + fi + } >> "$GITHUB_STEP_SUMMARY" + + # The comment workflow runs from quattro and reads only this artifact; + # it needs the PR number, which a workflow_run event omits for forks. + - name: Record the pull request + if: always() && github.event_name == 'pull_request' + run: echo "${{ github.event.pull_request.number }}" > test-runs/pr-number + + - name: Upload test artifacts + if: always() + uses: actions/upload-artifact@b7c566a772e6b6bfb58ed0dc250532a479d7789f # v6 + with: + name: install-test-${{ github.run_id }}-${{ github.run_attempt }} + path: | + test-runs/pr-number + test-runs/*/omarchy-install-timing.json + test-runs/*/omarchy-install.log + test-runs/*/first-boot-systemd-analyze.txt + test-runs/*/runs/**/*.png + test-runs/*/runs/**/*.txt + test-runs/*/runs/**/*.json + test-runs/*/runs/**/*.log + if-no-files-found: ignore + retention-days: 14 diff --git a/test/integration.d/base-test.sh b/test/integration.d/base-test.sh index df2d6ba..b9d4ab3 100644 --- a/test/integration.d/base-test.sh +++ b/test/integration.d/base-test.sh @@ -14,6 +14,9 @@ ISO="$OMARCHY_INTEGRATION_ISO" SSH_PORT="${OMARCHY_INTEGRATION_SSH_PORT:-2322}" MEMORY="${OMARCHY_INTEGRATION_MEMORY:-8192}" INSTALL_TIMEOUT="${OMARCHY_INTEGRATION_INSTALL_TIMEOUT:-2400}" +# cache=none keeps the host page cache out of the guest's disk writes, so +# install times measure the installer rather than the host (CI sets it). +DISK_CACHE="${OMARCHY_INTEGRATION_DISK_CACHE:-}" NO_PREVIEW="${OMARCHY_INTEGRATION_NO_PREVIEW:-false}" BOOT_TIMEOUT=600 @@ -166,7 +169,7 @@ start_vm() { -m "$MEMORY" \ -drive if=pflash,format=raw,readonly=on,file="$OVMF_CODE" \ -drive if=pflash,format=raw,file="$ACTIVE_OVMF" \ - -drive file="$disk",format=qcow2,if=none,id=drive0 \ + -drive file="$disk",format=qcow2,if=none,id=drive0${DISK_CACHE:+,cache=$DISK_CACHE} \ -device virtio-blk-pci,drive=drive0,bootindex=1 \ -device virtio-vga \ -display none \ @@ -282,8 +285,12 @@ ssh_sudo() { ssh_guest "echo $GUEST_PASSWORD | sudo -S -p '' bash -c $(printf %q "$1")" } +# The deadline is wall-clock: under QEMU user networking every attempt can +# spend its whole ConnectTimeout waiting for a banner, so counting only the +# sleeps let a "300 s" wait run for ten minutes or more, silently. wait_for_ssh() { - local timeout="$1" failure_name="${2:-failure-ssh-timeout}" waited=0 + local timeout="$1" failure_name="${2:-failure-ssh-timeout}" + local started=$SECONDS next_note=30 progress_name while ! ssh_guest true 2>/dev/null; do if ! vm_running; then @@ -291,14 +298,20 @@ wait_for_ssh() { return 1 fi - if ((waited >= timeout)); then + if ((SECONDS - started >= timeout)); then capture_console "$failure_name" echo "Timed out after ${timeout}s waiting for SSH" >&2 return 1 fi - sleep 5 - ((waited += 5)) + if ((SECONDS - started >= next_note)); then + printf -v progress_name 'waiting-ssh-%04ds' "$((SECONDS - started))" + capture_console "$progress_name" + echo " ... waiting for SSH ($((SECONDS - started))s)" + ((next_note += 30)) + fi + + sleep 2 done } @@ -556,16 +569,28 @@ install_phase() { return 1 fi + # A line every 30 s so a slow runner never looks hung; a screenshot of + # the installer's dashboard every 2 min, which is enough to see progress. if ((waited % 120 == 0)); then printf -v progress_name 'success-install-progress-%04ds' "$waited" capture_console "$progress_name" - echo " ... installing (${waited}s)" fi + ((waited % 30 == 0)) && echo " ... installing (${waited}s)" sleep 10 ((waited += 10)) done + # Keep the installer's own clock, its log and the first boot's numbers next + # to the base image while the system is reachable, so CI can report them + # without attaching the disk. + ssh_sudo "cat /var/log/omarchy-install-timing.json" >"$BASE_DIR/omarchy-install-timing.json" 2>/dev/null || true + ssh_sudo "cat /var/log/omarchy-install.log" >"$BASE_DIR/omarchy-install.log" 2>/dev/null || true + # SSH can answer before startup finishes, and systemd-analyze refuses until + # it has; wait (bounded) so the first-boot numbers are final. + ssh_guest "timeout 120 systemctl is-system-running --wait >/dev/null; systemd-analyze" \ + >"$BASE_DIR/first-boot-systemd-analyze.txt" 2>/dev/null || true + log "Installed system is up. Saving base image." stop_vm mv "$BASE_DISK.building" "$BASE_DISK" diff --git a/test/integration.d/boot-test.sh b/test/integration.d/boot-test.sh new file mode 100755 index 0000000..7bae941 --- /dev/null +++ b/test/integration.d/boot-test.sh @@ -0,0 +1,44 @@ +#!/bin/bash +# +# Everyday boot: boots the installed system a second time and records how +# long it takes to answer SSH and what systemd-analyze reports, then asserts +# that systemd finished starting with no failed units. CI reports these next +# to the install time, so a change that slows booting shows up in its PR. + +source "$(cd -- "$(dirname -- "${BASH_SOURCE[0]}")" && pwd)/base-test.sh" + +base_image_ready || { echo "No base image; run this through ./test/integration" >&2; exit 1; } + +log "Booting the installed system" +boot_started=$(date +%s%N) +start_vm_from_base +if ! wait_for_ssh 300 failure-boot-ssh-timeout; then + # The console screenshot is saved; the serial log shows what the firmware, + # loader and kernel printed, which a screenshot of a hung boot often lacks. + echo "--- last lines of the serial console ---" >&2 + tail -n 40 "$RUN_DIR/serial.log" >&2 2>/dev/null || true + exit 1 +fi +boot_ms=$((($(date +%s%N) - boot_started) / 1000000)) +# Coarse: wait_for_ssh polls every 2 s. systemd-analyze below has the exact +# firmware, loader, kernel and userspace split. +log "SSH answered within ${boot_ms} ms of power-on" + +# --wait returns once startup has finished, so systemd-analyze has final +# numbers and a unit that fails late in boot is still counted. It exits +# non-zero for "degraded"; keep the answer so the diagnostics below are still +# collected and the assertion reports it. +state=$(ssh_guest "timeout 120 systemctl is-system-running --wait" 2>/dev/null | tr -d '\r' || true) +ssh_guest "systemd-analyze" >"$RUN_DIR/systemd-analyze.txt" 2>/dev/null || true +ssh_guest "systemd-analyze blame --no-pager | head -n 20" >"$RUN_DIR/systemd-analyze-blame.txt" 2>/dev/null || true +# A query that fails must not read as "no failed units". +ssh_guest "systemctl --failed --no-legend --plain" >"$RUN_DIR/failed-units.txt" 2>/dev/null || + echo "could not query failed units over SSH" >"$RUN_DIR/failed-units.txt" +printf '{"boot_to_ssh_ms": %d, "system_state": "%s"}\n' "$boot_ms" "$state" >"$RUN_DIR/boot-timing.json" + +check "systemd reports the system running (got: ${state:-nothing})" test "$state" = running +check "no failed units" test ! -s "$RUN_DIR/failed-units.txt" +capture_console "success-boot" + +stop_vm +finish