From d4b6efeea19824ffb7895040592ca497b95eb111 Mon Sep 17 00:00:00 2001 From: twothatIT Date: Fri, 21 Aug 2026 22:40:12 +0200 Subject: [PATCH] feat(monitoring): add update-run log, fix scheduler skipping stale customer containers MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The automatic scheduler only recreated customer containers when it had just found a NEW image on Docker Hub. If an image was already pulled locally (e.g. from an earlier manual pull, or auto-apply was off at the time) but customer containers hadn't been recreated yet, the daily check reported "already up to date" and silently never touched those customers again — the recreate step needs to run independently of whether Hub had anything new, based on each customer's actual container-vs-local-image state. Also adds a persistent UpdateRunLog: every scheduled and manual pull/update run now records per-image pull results and per-customer recreate results, visible in Monitoring > Update Log, instead of only existing in container logs. --- app/database.py | 1 + app/models.py | 51 ++++++++++++++++++ app/routers/deployments.py | 11 +++- app/routers/monitoring.py | 53 +++++++++++++++++-- app/services/scheduler_service.py | 84 ++++++++++++++++++++--------- app/services/update_log_service.py | 84 +++++++++++++++++++++++++++++ static/index.html | 13 +++++ static/js/app.js | 85 +++++++++++++++++++++++++++++- static/lang/de.json | 21 +++++++- static/lang/en.json | 21 +++++++- 10 files changed, 391 insertions(+), 33 deletions(-) create mode 100644 app/services/update_log_service.py diff --git a/app/database.py b/app/database.py index a49003c..45ad713 100644 --- a/app/database.py +++ b/app/database.py @@ -45,6 +45,7 @@ def init_db() -> None: Deployment, DeploymentLog, SystemConfig, + UpdateRunLog, User, ) diff --git a/app/models.py b/app/models.py index 95857d4..97f689f 100644 --- a/app/models.py +++ b/app/models.py @@ -1,5 +1,6 @@ """SQLAlchemy ORM models for NetBird MSP Appliance.""" +import json from datetime import datetime from typing import Optional @@ -321,6 +322,56 @@ class DeploymentLog(Base): } +class UpdateRunLog(Base): + """Audit trail for NetBird Docker image update runs (pull + container recreate). + + Written for both scheduled (automatic) and manual (button-triggered) + runs, so the actual outcome — which image pulls failed, which customer + container recreates failed — is visible in the UI instead of only in + container logs. + """ + + __tablename__ = "update_run_logs" + + id: Mapped[int] = mapped_column(Integer, primary_key=True, autoincrement=True) + run_type: Mapped[str] = mapped_column(String(20), nullable=False) # "scheduled" | "manual" + trigger: Mapped[Optional[str]] = mapped_column(String(255), nullable=True) # username, or "scheduler" + started_at: Mapped[datetime] = mapped_column(DateTime, default=datetime.utcnow) + finished_at: Mapped[Optional[datetime]] = mapped_column(DateTime, nullable=True) + status: Mapped[str] = mapped_column( + String(20), default="running" + ) # running | no_update | success | partial | failed + any_update_available: Mapped[Optional[bool]] = mapped_column(Boolean, nullable=True) + pull_attempted: Mapped[bool] = mapped_column(Boolean, default=False) + pull_success: Mapped[Optional[bool]] = mapped_column(Boolean, nullable=True) + pull_details: Mapped[Optional[str]] = mapped_column(Text, nullable=True) # JSON: {image: {success, error}} + apply_attempted: Mapped[bool] = mapped_column(Boolean, default=False) + customers_updated: Mapped[Optional[int]] = mapped_column(Integer, nullable=True) + customers_total: Mapped[Optional[int]] = mapped_column(Integer, nullable=True) + customer_details: Mapped[Optional[str]] = mapped_column(Text, nullable=True) # JSON list + error: Mapped[Optional[str]] = mapped_column(Text, nullable=True) + + def to_dict(self) -> dict: + """Serialize to dict, parsing the embedded JSON blobs.""" + return { + "id": self.id, + "run_type": self.run_type, + "trigger": self.trigger, + "started_at": self.started_at.isoformat() if self.started_at else None, + "finished_at": self.finished_at.isoformat() if self.finished_at else None, + "status": self.status, + "any_update_available": self.any_update_available, + "pull_attempted": self.pull_attempted, + "pull_success": self.pull_success, + "pull_details": json.loads(self.pull_details) if self.pull_details else None, + "apply_attempted": self.apply_attempted, + "customers_updated": self.customers_updated, + "customers_total": self.customers_total, + "customer_details": json.loads(self.customer_details) if self.customer_details else None, + "error": self.error, + } + + class User(Base): """Admin user model.""" diff --git a/app/routers/deployments.py b/app/routers/deployments.py index 0d09225..6acc712 100644 --- a/app/routers/deployments.py +++ b/app/routers/deployments.py @@ -9,7 +9,7 @@ from sqlalchemy.orm import Session from app.database import SessionLocal, get_db from app.dependencies import get_current_user from app.models import Customer, Deployment, SystemConfig, User -from app.services import docker_service, image_service, netbird_client_update_service, netbird_service +from app.services import docker_service, image_service, netbird_client_update_service, netbird_service, update_log_service from app.utils.security import decrypt_value, encrypt_value from app.utils.validators import NetbirdApiTokenPayload, NetbirdClientAutoUpdatePayload @@ -246,9 +246,18 @@ async def update_customer_images( status_code=status.HTTP_503_SERVICE_UNAVAILABLE, detail="System not configured." ) + started_at = datetime.utcnow() instance_dir = f"{config.data_dir}/{customer.subdomain}" result = await image_service.update_customer_containers(instance_dir, deployment.container_prefix) + update_log_service.record_run( + db, run_type="manual", trigger=current_user.username, started_at=started_at, + apply_attempted=True, + customer_results=[{ + "customer_name": customer.name, "success": result["success"], "error": result.get("error"), + }], + ) + if not result["success"]: raise HTTPException( status_code=status.HTTP_500_INTERNAL_SERVER_ERROR, diff --git a/app/routers/monitoring.py b/app/routers/monitoring.py index e32c933..3277cc7 100644 --- a/app/routers/monitoring.py +++ b/app/routers/monitoring.py @@ -4,6 +4,7 @@ import asyncio import logging import platform import time +from datetime import datetime from typing import Any import psutil @@ -12,8 +13,8 @@ from sqlalchemy.orm import Session from app.database import SessionLocal, get_db from app.dependencies import get_current_user -from app.models import Customer, Deployment, SystemConfig, User -from app.services import docker_service, image_service, netbird_client_update_service +from app.models import Customer, Deployment, SystemConfig, UpdateRunLog, User +from app.services import docker_service, image_service, netbird_client_update_service, update_log_service from app.utils.security import decrypt_value from app.utils.validators import NetbirdClientAutoUpdatePayload @@ -194,14 +195,25 @@ async def pull_all_netbird_images( config.netbird_dashboard_image, ] + username = current_user.username + async def _pull_bg() -> None: + started_at = datetime.utcnow() bg_db = SessionLocal() try: cfg = bg_db.query(SystemConfig).filter(SystemConfig.id == 1).first() - if cfg: - await image_service.pull_all_images(cfg) - except Exception: + if not cfg: + return + pull_result = await image_service.pull_all_images(cfg) + update_log_service.record_run( + bg_db, run_type="manual", trigger=username, started_at=started_at, + any_update_available=True, pull_attempted=True, pull_results=pull_result["results"], + ) + except Exception as exc: logger.exception("Background image pull failed") + update_log_service.record_run( + bg_db, run_type="manual", trigger=username, started_at=started_at, error=str(exc), + ) finally: bg_db.close() @@ -285,6 +297,28 @@ async def apply_netbird_client_updates_to_all( } +@router.get("/update-logs") +async def get_update_logs( + limit: int = 30, + current_user: User = Depends(get_current_user), + db: Session = Depends(get_db), +) -> list[dict[str, Any]]: + """Return the most recent NetBird image update runs (scheduled and manual). + + Shows exactly what happened on each run: whether an image pull was + attempted and its per-image result, and whether customer containers + were recreated and which ones failed — so this doesn't have to be + reconstructed from container logs. + """ + logs = ( + db.query(UpdateRunLog) + .order_by(UpdateRunLog.started_at.desc()) + .limit(min(limit, 100)) + .all() + ) + return [log.to_dict() for log in logs] + + @router.post("/customers/update-all") async def update_all_customers( current_user: User = Depends(get_current_user), @@ -299,6 +333,7 @@ async def update_all_customers( if current_user.role != "admin": raise HTTPException(status_code=status.HTTP_403_FORBIDDEN, detail="Admin only.") + started_at = datetime.utcnow() config = db.query(SystemConfig).filter(SystemConfig.id == 1).first() if not config: raise HTTPException(status_code=status.HTTP_503_SERVICE_UNAVAILABLE, detail="System not configured.") @@ -317,6 +352,10 @@ async def update_all_customers( }) if not to_update: + update_log_service.record_run( + db, run_type="manual", trigger=current_user.username, + started_at=started_at, apply_attempted=True, customer_results=[], + ) return {"message": "All customers are already up to date.", "updated": 0, "results": []} # Update customers sequentially — one at a time. A failure for one @@ -343,6 +382,10 @@ async def update_all_customers( }) success_count = sum(1 for r in update_results if r["success"]) + update_log_service.record_run( + db, run_type="manual", trigger=current_user.username, + started_at=started_at, apply_attempted=True, customer_results=update_results, + ) return { "message": f"Updated {success_count} of {len(update_results)} customer(s).", "updated": success_count, diff --git a/app/services/scheduler_service.py b/app/services/scheduler_service.py index c1d03a5..2d83927 100644 --- a/app/services/scheduler_service.py +++ b/app/services/scheduler_service.py @@ -12,7 +12,7 @@ from datetime import datetime, timedelta from app.database import SessionLocal from app.models import Deployment, SystemConfig -from app.services import image_service, netbird_client_update_service +from app.services import image_service, netbird_client_update_service, update_log_service from app.utils.security import decrypt_value, encrypt_value logger = logging.getLogger(__name__) @@ -125,29 +125,49 @@ async def _tick() -> None: logger.info( "Running scheduled NetBird image update check (auto-apply=%s)...", apply_enabled ) - await _run_check_and_optionally_apply(config, apply_enabled) + await _run_check_and_optionally_apply(config, apply_enabled, started_at=now) finally: db.close() -async def _run_check_and_optionally_apply(config: SystemConfig, apply_enabled: bool) -> None: - hub_status = await image_service.check_all_images(config) - if not hub_status["any_update_available"]: - logger.info("Scheduled check: all NetBird images already up to date.") - return +async def _run_check_and_optionally_apply(config: SystemConfig, apply_enabled: bool, started_at: datetime) -> None: + """Check Docker Hub, pull if needed, then (if enabled) recreate any + customer container that isn't running the locally-pulled image yet. - logger.info("Scheduled check: new NetBird image(s) available — pulling.") - pull_result = await image_service.pull_all_images(config) - if not pull_result["all_success"]: - logger.error("Scheduled image pull had failures: %s", pull_result["results"]) - - if not apply_enabled: - logger.info("Auto-apply disabled — images pulled, customer containers left untouched.") - return - - db = SessionLocal() + The "recreate" step is intentionally NOT gated on a Hub update having + just been found: a customer can already be behind the *locally pulled* + image from an earlier check/pull that was never applied (e.g. auto-apply + was off at the time, or a previous run failed) — that backlog must keep + being cleared on every run, not just on runs that also found something + new on Hub, otherwise it silently never happens. + """ + log_db = SessionLocal() try: - deployments = db.query(Deployment).all() + hub_status = await image_service.check_all_images(config) + any_update = hub_status["any_update_available"] + + pull_attempted = False + pull_results = None + if any_update: + logger.info("Scheduled check: new NetBird image(s) available — pulling.") + pull_attempted = True + pull_result = await image_service.pull_all_images(config) + pull_results = pull_result["results"] + if not pull_result["all_success"]: + logger.error("Scheduled image pull had failures: %s", pull_results) + else: + logger.info("Scheduled check: all NetBird images already up to date on Docker Hub.") + + if not apply_enabled: + logger.info("Auto-apply disabled — customer containers left untouched.") + update_log_service.record_run( + log_db, run_type="scheduled", trigger="scheduler", + started_at=started_at, any_update_available=any_update, + pull_attempted=pull_attempted, pull_results=pull_results, + ) + return + + deployments = log_db.query(Deployment).all() to_update = [] for dep in deployments: cs = image_service.get_customer_container_image_status(dep.container_prefix, config) @@ -159,16 +179,32 @@ async def _run_check_and_optionally_apply(config: SystemConfig, apply_enabled: b "customer_name": customer.name, }) logger.info("Scheduled auto-apply: updating %d customer(s)...", len(to_update)) + customer_results = [] for entry in to_update: try: res = await image_service.update_customer_containers( entry["instance_dir"], entry["project_name"] ) - logger.info( - "Scheduled update for %s: %s", - entry["customer_name"], "OK" if res["success"] else res.get("error"), - ) - except Exception: + ok = res["success"] + err = res.get("error") + except Exception as exc: logger.exception("Scheduled update failed for %s", entry["customer_name"]) + ok = False + err = str(exc) + logger.info("Scheduled update for %s: %s", entry["customer_name"], "OK" if ok else err) + customer_results.append({"customer_name": entry["customer_name"], "success": ok, "error": err}) + + update_log_service.record_run( + log_db, run_type="scheduled", trigger="scheduler", + started_at=started_at, any_update_available=any_update, + pull_attempted=pull_attempted, pull_results=pull_results, + apply_attempted=True, customer_results=customer_results, + ) + except Exception as exc: + logger.exception("Scheduled update run failed") + update_log_service.record_run( + log_db, run_type="scheduled", trigger="scheduler", + started_at=started_at, error=str(exc), + ) finally: - db.close() + log_db.close() diff --git a/app/services/update_log_service.py b/app/services/update_log_service.py new file mode 100644 index 0000000..a56f81e --- /dev/null +++ b/app/services/update_log_service.py @@ -0,0 +1,84 @@ +"""Persists the outcome of every NetBird Docker image update run. + +Both the automatic scheduler and the manual "Check/Pull/Update" buttons in +the UI write here, so it's visible afterwards which run pulled which image +successfully, and which customer container recreate failed — instead of +that information only existing in container logs. +""" + +import json +import logging +from datetime import datetime +from typing import Any, Optional + +from sqlalchemy.orm import Session + +from app.models import UpdateRunLog + +logger = logging.getLogger(__name__) + + +def record_run( + db: Session, + *, + run_type: str, + trigger: Optional[str], + started_at: datetime, + any_update_available: Optional[bool] = None, + pull_attempted: bool = False, + pull_results: Optional[dict[str, Any]] = None, + apply_attempted: bool = False, + customer_results: Optional[list[dict[str, Any]]] = None, + error: Optional[str] = None, +) -> UpdateRunLog: + """Write one completed update-run entry. + + Args: + run_type: "scheduled" or "manual". + trigger: username for manual runs, "scheduler" for automatic ones. + pull_results: {image: {"success": bool, "error": str|None}} as returned + by image_service.pull_all_images()["results"]. + customer_results: list of {"customer_name", "success", "error"} as + returned by the update-all / update-customer flows. + """ + pull_success = None + if pull_results: + pull_success = all(r.get("success") for r in pull_results.values()) + + customers_total = len(customer_results) if customer_results is not None else None + customers_updated = ( + sum(1 for r in customer_results if r.get("success")) if customer_results is not None else None + ) + + if error: + status = "failed" + elif pull_attempted and pull_success is False: + status = "failed" + elif apply_attempted and customers_total and customers_updated != customers_total: + status = "partial" + elif not pull_attempted and not customers_total: + # Nothing to pull (Hub already matched local) and no customer + # container was behind the locally pulled image either. + status = "no_update" + else: + status = "success" + + log = UpdateRunLog( + run_type=run_type, + trigger=trigger, + started_at=started_at, + finished_at=datetime.utcnow(), + status=status, + any_update_available=any_update_available, + pull_attempted=pull_attempted, + pull_success=pull_success, + pull_details=json.dumps(pull_results) if pull_results is not None else None, + apply_attempted=apply_attempted, + customers_updated=customers_updated, + customers_total=customers_total, + customer_details=json.dumps(customer_results) if customer_results is not None else None, + error=error, + ) + db.add(log) + db.commit() + return log diff --git a/static/index.html b/static/index.html index 2031359..07c3351 100644 --- a/static/index.html +++ b/static/index.html @@ -1260,6 +1260,19 @@

Click "Check for Updates" to compare local images with Docker Hub.

+ + +
+
+ Update Log + +
+
+

Loading...

+
+
diff --git a/static/js/app.js b/static/js/app.js index 6bd0f43..e9f2938 100644 --- a/static/js/app.js +++ b/static/js/app.js @@ -1943,7 +1943,90 @@ function togglePasswordVisibility(inputId) { // Monitoring // --------------------------------------------------------------------------- async function loadMonitoring() { - await Promise.all([loadResources(), loadAllCustomerStatuses()]); + await Promise.all([loadResources(), loadAllCustomerStatuses(), loadUpdateLog()]); +} + +const _updateLogStatusBadge = { + success: 'bg-success', + no_update: 'bg-secondary', + partial: 'bg-warning text-dark', + failed: 'bg-danger', + running: 'bg-info', +}; + +async function loadUpdateLog() { + const body = document.getElementById('update-log-body'); + body.innerHTML = `${t('common.loading')}`; + try { + const logs = await api('GET', '/monitoring/update-logs?limit=30'); + if (logs.length === 0) { + body.innerHTML = `

${t('monitoring.noUpdateLogs')}

`; + return; + } + const rows = logs.map((l, i) => { + const badgeClass = _updateLogStatusBadge[l.status] || 'bg-secondary'; + const typeLabel = l.run_type === 'scheduled' ? t('monitoring.logTypeScheduled') : t('monitoring.logTypeManual'); + const pullSummary = l.pull_attempted + ? (l.pull_success ? t('monitoring.logPullOk') : t('monitoring.logPullFailed')) + : t('monitoring.logPullSkipped'); + const applySummary = l.apply_attempted + ? t('monitoring.logApplySummary', { updated: l.customers_updated ?? 0, total: l.customers_total ?? 0 }) + : t('monitoring.logApplySkipped'); + const detailId = `update-log-detail-${i}`; + const hasDetails = (l.pull_details && Object.keys(l.pull_details).length > 0) || + (l.customer_details && l.customer_details.length > 0) || l.error; + const detailsHtml = hasDetails ? ` +
+ ${l.error ? `
${esc(l.error)}
` : ''} + ${l.pull_details ? ` + + + ${Object.entries(l.pull_details).map(([img, r]) => ` + + + + `).join('')} +
${t('monitoring.thImage')}${t('monitoring.thStatus')}
${esc(img)}${r.success ? `OK` : `Error`}${esc(r.error || '')}
` : ''} + ${l.customer_details && l.customer_details.length > 0 ? ` + + + ${l.customer_details.map(r => ` + + + + `).join('')} +
${t('monitoring.thName')}${t('monitoring.thStatus')}
${esc(r.customer_name)}${r.success ? `OK` : `Error`}${esc(r.error || '')}
` : ''} +
` : ''; + return ` + ${formatDate(l.started_at)} + ${typeLabel} + ${t('monitoring.logStatus_' + l.status)} + ${pullSummary} + ${applySummary} + ${esc(l.trigger || '')} + ${hasDetails ? `` : ''} + ${detailsHtml ? `${detailsHtml}` : ''}`; + }).join(''); + body.innerHTML = ` +
+ + + + + + + + + + + + + ${rows} +
${t('monitoring.logTime')}${t('monitoring.logType')}${t('monitoring.thStatus')}${t('monitoring.logPull')}${t('monitoring.logApply')}${t('monitoring.logTrigger')}
+
`; + } catch (err) { + body.innerHTML = `
${esc(err.message)}
`; + } } async function loadResources() { diff --git a/static/lang/de.json b/static/lang/de.json index fedc11c..2881c80 100644 --- a/static/lang/de.json +++ b/static/lang/de.json @@ -454,6 +454,25 @@ "autoUpdateApplyHint": "Wenn aktiviert, werden nach einer gefundenen Aktualisierung automatisch alle Kunden-Container neu erstellt (kurzer Neustart der Dienste). Wenn deaktiviert, werden nur die Images geladen — die Aktualisierung der Kunden erfolgt weiterhin manuell.", "autoUpdateLastRun": "Letzte automatische Prüfung", "autoUpdateNever": "Noch nie ausgeführt", - "saveAutoUpdateSettings": "Automatisierung speichern" + "saveAutoUpdateSettings": "Automatisierung speichern", + "updateLogTitle": "Update-Verlauf", + "noUpdateLogs": "Noch keine Update-Läufe protokolliert.", + "logTypeScheduled": "Automatisch", + "logTypeManual": "Manuell", + "logTime": "Zeitpunkt", + "logType": "Typ", + "logPull": "Image-Download", + "logApply": "Kunden-Update", + "logTrigger": "Ausgelöst von", + "logPullOk": "Erfolgreich", + "logPullFailed": "Fehlgeschlagen", + "logPullSkipped": "Nicht nötig", + "logApplySummary": "{updated}/{total} Kunden", + "logApplySkipped": "Nicht ausgeführt", + "logStatus_success": "Erfolgreich", + "logStatus_no_update": "Kein Update nötig", + "logStatus_partial": "Teilweise", + "logStatus_failed": "Fehlgeschlagen", + "logStatus_running": "Läuft…" } } \ No newline at end of file diff --git a/static/lang/en.json b/static/lang/en.json index 8da1bbc..72eab7b 100644 --- a/static/lang/en.json +++ b/static/lang/en.json @@ -361,7 +361,26 @@ "autoUpdateApplyHint": "When enabled, all customer containers are automatically recreated after a new image is found (services briefly restart). When disabled, only the images are pulled — updating customers stays a manual step.", "autoUpdateLastRun": "Last automatic check", "autoUpdateNever": "Never run", - "saveAutoUpdateSettings": "Save Automation" + "saveAutoUpdateSettings": "Save Automation", + "updateLogTitle": "Update Log", + "noUpdateLogs": "No update runs logged yet.", + "logTypeScheduled": "Automatic", + "logTypeManual": "Manual", + "logTime": "Time", + "logType": "Type", + "logPull": "Image Pull", + "logApply": "Customer Update", + "logTrigger": "Triggered by", + "logPullOk": "Succeeded", + "logPullFailed": "Failed", + "logPullSkipped": "Not needed", + "logApplySummary": "{updated}/{total} customers", + "logApplySkipped": "Not run", + "logStatus_success": "Success", + "logStatus_no_update": "No update needed", + "logStatus_partial": "Partial", + "logStatus_failed": "Failed", + "logStatus_running": "Running…" }, "userModal": { "title": "New User",