From 150666d7c35fcc1c70dfaed40cda50277376a984 Mon Sep 17 00:00:00 2001 From: naturallaw77 Date: Thu, 2 Apr 2026 13:15:19 -0500 Subject: [PATCH] updated logging --- app/sovran_systemsos_web/server.py | 84 ++++++----------- app/sovran_systemsos_web/static/app.js | 124 ++++++++++--------------- modules/core/sovran-hub.nix | 63 +++++++++++-- 3 files changed, 134 insertions(+), 137 deletions(-) diff --git a/app/sovran_systemsos_web/server.py b/app/sovran_systemsos_web/server.py index c5f301c..c0d3bbc 100644 --- a/app/sovran_systemsos_web/server.py +++ b/app/sovran_systemsos_web/server.py @@ -8,10 +8,9 @@ import os import socket import subprocess import urllib.request -from typing import AsyncIterator -from fastapi import FastAPI, HTTPException, Response -from fastapi.responses import HTMLResponse, StreamingResponse +from fastapi import FastAPI, HTTPException +from fastapi.responses import HTMLResponse from fastapi.staticfiles import StaticFiles from fastapi.templating import Jinja2Templates from fastapi.requests import Request @@ -26,10 +25,9 @@ FLAKE_INPUT_NAME = "Sovran_Systems" GITEA_API_BASE = "https://git.sovransystems.com/api/v1/repos/Sovran_Systems/Sovran_SystemsOS/commits" UPDATE_UNIT = "sovran-hub-update.service" +UPDATE_LOG = "/var/log/sovran-hub-update.log" -REBOOT_COMMAND = [ - "reboot", -] +REBOOT_COMMAND = ["reboot"] CATEGORY_ORDER = [ ("infrastructure", "Infrastructure"), @@ -58,7 +56,6 @@ app.mount( name="static", ) -# Also serve icons from the app/icons directory (set via env or adjacent folder) _ICONS_DIR = os.environ.get( "SOVRAN_HUB_ICONS", os.path.join(os.path.dirname(_BASE_DIR), "icons"), @@ -141,7 +138,6 @@ def _get_internal_ip() -> str: def _get_external_ip() -> str: - # Max length 46 covers the longest valid IPv6 address (45 chars) plus a newline MAX_IP_LENGTH = 46 for url in [ "https://api.ipify.org", @@ -184,44 +180,21 @@ def _update_result() -> str: return "unknown" -def _get_update_invocation_id() -> str: - """Get the current InvocationID of the update unit.""" - r = subprocess.run( - ["systemctl", "show", "-p", "InvocationID", "--value", UPDATE_UNIT], - capture_output=True, text=True, - ) - return r.stdout.strip() - - -def _read_journal_logs(since_cursor: str = "") -> tuple[list[str], str]: - """ - Read journal logs for the update unit. - Returns (lines, last_cursor). - Uses cursors so we never miss lines even if the server restarts. - """ - cmd = [ - "journalctl", "-u", UPDATE_UNIT, - "--no-pager", "-o", "cat", - "--show-cursor", - ] - if since_cursor: - cmd += ["--after-cursor", since_cursor] - else: - # Only get logs from the most recent invocation - cmd += ["-n", "10000"] - - r = subprocess.run(cmd, capture_output=True, text=True, timeout=10) - output = r.stdout - - lines = [] - cursor = since_cursor - for raw_line in output.split("\n"): - if raw_line.startswith("-- cursor: "): - cursor = raw_line[len("-- cursor: "):] - elif raw_line: - lines.append(raw_line) - - return lines, cursor +def _read_log(offset: int = 0) -> tuple[str, int]: + """Read the update log file from the given byte offset. + Returns (new_text, new_offset).""" + try: + with open(UPDATE_LOG, "rb") as f: + f.seek(0, 2) # seek to end + size = f.tell() + if offset > size: + # Log was truncated (new run), start over + offset = 0 + f.seek(offset) + chunk = f.read() + return chunk.decode(errors="replace"), offset + len(chunk) + except FileNotFoundError: + return "", 0 # ── Routes ─────────────────────────────────────────────────────── @@ -275,7 +248,6 @@ async def api_services(): def _get_allowed_units() -> set[str]: - """Return the set of unit names from the current config (whitelist).""" cfg = load_config() return {s.get("unit", "") for s in cfg.get("services", []) if s.get("unit")} @@ -356,19 +328,19 @@ async def api_updates_run(): """Kick off the detached update systemd unit.""" loop = asyncio.get_event_loop() - # Check if already running running = await loop.run_in_executor(None, _update_is_active) if running: return {"ok": True, "status": "already_running"} - # Reset the failed state (if any) and start the unit + # Reset failed state if any await asyncio.create_subprocess_exec( "systemctl", "reset-failed", UPDATE_UNIT, stdout=asyncio.subprocess.DEVNULL, stderr=asyncio.subprocess.DEVNULL, ) + proc = await asyncio.create_subprocess_exec( - "systemctl", "start", UPDATE_UNIT, + "systemctl", "start", "--no-block", UPDATE_UNIT, stdout=asyncio.subprocess.DEVNULL, stderr=asyncio.subprocess.DEVNULL, ) @@ -378,19 +350,17 @@ async def api_updates_run(): @app.get("/api/updates/status") -async def api_updates_status(cursor: str = ""): - """Poll endpoint: returns running state, result, and new journal lines.""" +async def api_updates_status(offset: int = 0): + """Poll endpoint: returns running state, result, and new log content.""" loop = asyncio.get_event_loop() running = await loop.run_in_executor(None, _update_is_active) result = await loop.run_in_executor(None, _update_result) - lines, new_cursor = await loop.run_in_executor( - None, _read_journal_logs, cursor, - ) + new_log, new_offset = await loop.run_in_executor(None, _read_log, offset) return { "running": running, "result": result, - "lines": lines, - "cursor": new_cursor, + "log": new_log, + "offset": new_offset, } \ No newline at end of file diff --git a/app/sovran_systemsos_web/static/app.js b/app/sovran_systemsos_web/static/app.js index afb2842..e62d49d 100644 --- a/app/sovran_systemsos_web/static/app.js +++ b/app/sovran_systemsos_web/static/app.js @@ -4,7 +4,7 @@ const POLL_INTERVAL_SERVICES = 5000; // 5 s const POLL_INTERVAL_UPDATES = 1800000; // 30 min const ACTION_REFRESH_DELAY = 1500; // 1.5 s after start/stop/restart -const UPDATE_POLL_INTERVAL = 2000; // 2 s while update is running +const UPDATE_POLL_INTERVAL = 1500; // 1.5 s while update is running const CATEGORY_ORDER = [ "infrastructure", @@ -21,29 +21,28 @@ const STATUS_LOADING_STATES = new Set([ // ── State ───────────────────────────────────────────────────────── -let _servicesCache = []; -let _categoryLabels = {}; -let _updateSource = null; -let _updateLog = ""; +let _servicesCache = []; +let _categoryLabels = {}; +let _updateLog = ""; let _updatePollTimer = null; -let _updateCursor = ""; -let _serverDownSince = 0; +let _updateLogOffset = 0; +let _serverWasDown = false; -// ── DOM refs ────────────────────────────────────────────────────── +// ── DOM refs ────────────────────────────────────────────���───────── -const $tilesArea = document.getElementById("tiles-area"); -const $updateBtn = document.getElementById("btn-update"); -const $updateBadge = document.getElementById("update-badge"); -const $refreshBtn = document.getElementById("btn-refresh"); -const $internalIp = document.getElementById("ip-internal"); -const $externalIp = document.getElementById("ip-external"); +const $tilesArea = document.getElementById("tiles-area"); +const $updateBtn = document.getElementById("btn-update"); +const $updateBadge = document.getElementById("update-badge"); +const $refreshBtn = document.getElementById("btn-refresh"); +const $internalIp = document.getElementById("ip-internal"); +const $externalIp = document.getElementById("ip-external"); -const $modal = document.getElementById("update-modal"); -const $modalSpinner = document.getElementById("modal-spinner"); -const $modalStatus = document.getElementById("modal-status"); -const $modalLog = document.getElementById("modal-log"); -const $btnReboot = document.getElementById("btn-reboot"); -const $btnSave = document.getElementById("btn-save-report"); +const $modal = document.getElementById("update-modal"); +const $modalSpinner = document.getElementById("modal-spinner"); +const $modalStatus = document.getElementById("modal-status"); +const $modalLog = document.getElementById("modal-log"); +const $btnReboot = document.getElementById("btn-reboot"); +const $btnSave = document.getElementById("btn-save-report"); const $btnCloseModal = document.getElementById("btn-close-modal"); // ── Helpers ─────────────────────────────────────────────────────── @@ -77,7 +76,6 @@ async function apiFetch(path, options = {}) { function buildTiles(services, categoryLabels) { _servicesCache = services; - // Group by category const grouped = {}; for (const svc of services) { const cat = svc.category || "other"; @@ -155,7 +153,6 @@ function buildTile(svc) { `; - // Toggle handler const chk = tile.querySelector(".tile-toggle"); if (!dis) { chk.addEventListener("change", async (e) => { @@ -168,7 +165,6 @@ function buildTile(svc) { }); } - // Restart handler const restartBtn = tile.querySelector(".tile-restart-btn"); if (!dis) { restartBtn.addEventListener("click", async () => { @@ -265,14 +261,14 @@ async function checkUpdates() { function openUpdateModal() { if (!$modal) return; _updateLog = ""; - _updateCursor = ""; - _serverDownSince = 0; - if ($modalLog) $modalLog.textContent = ""; - if ($modalStatus) $modalStatus.textContent = "Updating…"; - if ($modalSpinner) $modalSpinner.classList.add("spinning"); - if ($btnReboot) { $btnReboot.style.display = "none"; } - if ($btnSave) { $btnSave.style.display = "none"; } - if ($btnCloseModal) { $btnCloseModal.disabled = true; } + _updateLogOffset = 0; + _serverWasDown = false; + if ($modalLog) $modalLog.textContent = ""; + if ($modalStatus) $modalStatus.textContent = "Starting update…"; + if ($modalSpinner) $modalSpinner.classList.add("spinning"); + if ($btnReboot) { $btnReboot.style.display = "none"; } + if ($btnSave) { $btnSave.style.display = "none"; } + if ($btnCloseModal) { $btnCloseModal.disabled = true; } $modal.classList.add("open"); startUpdate(); @@ -286,18 +282,14 @@ function closeUpdateModal() { function appendLog(text) { if (!text) return; - _updateLog += text + "\n"; + _updateLog += text; if ($modalLog) { - $modalLog.textContent += text + "\n"; + $modalLog.textContent += text; $modalLog.scrollTop = $modalLog.scrollHeight; } } function startUpdate() { - appendLog("$ cd /etc/nixos && nix flake update && nixos-rebuild switch && flatpak update -y"); - appendLog(""); - - // Trigger the systemd unit via POST fetch("/api/updates/run", { method: "POST" }) .then(response => { if (!response.ok) { @@ -307,19 +299,18 @@ function startUpdate() { }) .then(data => { if (data.status === "already_running") { - appendLog("[Update already in progress, attaching…]"); + appendLog("[Update already in progress, attaching…]\n\n"); } - // Start polling for journal output + if ($modalStatus) $modalStatus.textContent = "Updating…"; startUpdatePoll(); }) .catch(err => { - appendLog(`[Error: failed to start update — ${err}]`); + appendLog(`[Error: failed to start update — ${err}]\n`); onUpdateDone(false); }); } function startUpdatePoll() { - // Poll immediately, then on interval pollUpdateStatus(); _updatePollTimer = setInterval(pollUpdateStatus, UPDATE_POLL_INTERVAL); } @@ -333,31 +324,22 @@ function stopUpdatePoll() { async function pollUpdateStatus() { try { - const data = await apiFetch( - `/api/updates/status?cursor=${encodeURIComponent(_updateCursor)}` - ); + const data = await apiFetch(`/api/updates/status?offset=${_updateLogOffset}`); - // Server is back — reset the down counter - if (_serverDownSince > 0) { - appendLog("[Server reconnected, resuming…]"); - _serverDownSince = 0; - } - - // Append new journal lines - if (data.lines && data.lines.length > 0) { - for (const line of data.lines) { - appendLog(line); - } - } - if (data.cursor) { - _updateCursor = data.cursor; - } - - // Update status text while running - if (data.running) { + // Server came back after being down + if (_serverWasDown) { + _serverWasDown = false; if ($modalStatus) $modalStatus.textContent = "Updating…"; - } else { - // Finished + } + + // Append any new log content + if (data.log) { + appendLog(data.log); + } + _updateLogOffset = data.offset; + + // Check if finished + if (!data.running) { stopUpdatePoll(); if (data.result === "success") { onUpdateDone(true); @@ -366,13 +348,12 @@ async function pollUpdateStatus() { } } } catch (err) { - // Server is likely restarting during nixos-rebuild switch - if (_serverDownSince === 0) { - _serverDownSince = Date.now(); - appendLog("[Server restarting — waiting for it to come back…]"); + // Server is likely restarting during nixos-rebuild switch — keep polling + if (!_serverWasDown) { + _serverWasDown = true; + appendLog("\n[Server restarting — waiting for it to come back…]\n\n"); if ($modalStatus) $modalStatus.textContent = "Server restarting…"; } - console.warn("Update poll failed (server may be restarting):", err); } } @@ -415,7 +396,6 @@ if ($btnCloseModal) $btnCloseModal.addEventListener("click", closeUpdateModal); if ($btnReboot) $btnReboot.addEventListener("click", doReboot); if ($btnSave) $btnSave.addEventListener("click", saveErrorReport); -// Close modal on overlay click if ($modal) { $modal.addEventListener("click", (e) => { if (e.target === $modal) closeUpdateModal(); @@ -425,7 +405,6 @@ if ($modal) { // ── Init ────────────────────────────────────────────────────────── async function init() { - // Load config to get category labels try { const cfg = await apiFetch("/api/config"); if (cfg.category_order) { @@ -433,17 +412,14 @@ async function init() { _categoryLabels[key] = label; } } - // Update role badge const badge = document.getElementById("role-badge"); if (badge && cfg.role_label) badge.textContent = cfg.role_label; } catch (_) {} - // Initial data loads await refreshServices(); loadNetwork(); checkUpdates(); - // Polling setInterval(refreshServices, POLL_INTERVAL_SERVICES); setInterval(checkUpdates, POLL_INTERVAL_UPDATES); } diff --git a/modules/core/sovran-hub.nix b/modules/core/sovran-hub.nix index 96cb817..04bc0ad 100644 --- a/modules/core/sovran-hub.nix +++ b/modules/core/sovran-hub.nix @@ -52,6 +52,61 @@ let services = monitoredServices; }); + # ── Update wrapper script ────────────────────────────────────── + update-script = pkgs.writeShellScript "sovran-hub-update.sh" '' + set -uo pipefail + export PATH="${lib.makeBinPath [ pkgs.nix pkgs.nixos-rebuild pkgs.git pkgs.flatpak pkgs.coreutils ]}:$PATH" + + LOG="/var/log/sovran-hub-update.log" + + # Truncate the log and redirect ALL output (stdout + stderr) into it + : > "$LOG" + exec > >(tee -a "$LOG") 2>&1 + + echo "══════════════════════════════════════════════════" + echo " Sovran_SystemsOS Update — $(date)" + echo "══════════════════════════════════════════════════" + echo "" + + RC=0 + + echo "── Step 1/3: nix flake update ────────────────────" + if ! nix flake update --flake /etc/nixos --print-build-logs 2>&1; then + echo "[ERROR] nix flake update failed" + RC=1 + fi + echo "" + + if [ "$RC" -eq 0 ]; then + echo "── Step 2/3: nixos-rebuild switch ──────────────────" + if ! nixos-rebuild switch --flake /etc/nixos --print-build-logs 2>&1; then + echo "[ERROR] nixos-rebuild switch failed" + RC=1 + fi + echo "" + fi + + if [ "$RC" -eq 0 ]; then + echo "── Step 3/3: flatpak update ────────────────────────" + if ! flatpak update -y 2>&1; then + echo "[WARNING] flatpak update failed (non-fatal)" + fi + echo "" + fi + + if [ "$RC" -eq 0 ]; then + echo "══════════════════════════════════════════════════" + echo " ✓ Update completed successfully" + echo "══════════════════════════════════════════════════" + else + echo "══════════════════════════════════════════════════" + echo " ✗ Update failed — see errors above" + echo "══════════════════════════════════════════════════" + fi + + exit "$RC" + ''; + sovran-hub-web = pkgs.python3Packages.buildPythonApplication { pname = "sovran-systemsos-hub-web"; version = "1.0.0"; @@ -133,13 +188,9 @@ in systemd.services.sovran-hub-update = { description = "Sovran_SystemsOS System Update"; serviceConfig = { - Type = "oneshot"; - ExecStart = "${pkgs.bash}/bin/bash -c 'cd /etc/nixos && nix flake update 2>&1 && nixos-rebuild switch 2>&1 && flatpak update -y 2>&1'"; - StandardOutput = "journal"; - StandardError = "journal"; - SyslogIdentifier = "sovran-hub-update"; + Type = "oneshot"; + ExecStart = "${update-script}"; }; - path = [ pkgs.nix pkgs.nixos-rebuild pkgs.git pkgs.flatpak ]; }; # ── Open firewall port ─────────────────────────────────────