v0.2.1 add Logging

This commit is contained in:
Björn Nehlsen
2026-08-16 00:38:25 +02:00
parent 8ad924b6ba
commit 212e63c4e4
7 changed files with 763 additions and 9 deletions
+410 -8
View File
@@ -5,12 +5,13 @@ import shutil
import tarfile
import tempfile
import threading
import traceback
from datetime import datetime
from functools import wraps
from pathlib import Path
import zipfile
from flask import Flask, flash, jsonify, redirect, render_template, request, session, url_for
from flask import Flask, flash, g, got_request_exception, jsonify, redirect, render_template, request, session, url_for
import smbclient
try:
@@ -20,6 +21,7 @@ except Exception: # noqa: BLE001
from app.config_model import AppConfig, BackupExecutionJob, BackupJob
from app.config_store import ConfigStore
from app.log_store import LogStore
from app.remote_targets import (
TargetConnection,
browse_ftp_directories,
@@ -48,12 +50,52 @@ BACKUP_MODES = ["full", "sync", "clone"]
class FlaskServer:
def __init__(self, config: AppConfig, store: ConfigStore) -> None:
def __init__(self, config: AppConfig, store: ConfigStore, log_store: LogStore) -> None:
self.config = config
self.store = store
self.log_store = log_store
self._run_lock = threading.Lock()
self._active_runs: dict[int, dict] = {}
def _log(
self,
*,
level: str,
category: str,
event: str,
message: str,
username: str | None = None,
backup_id: int | None = None,
details: dict | None = None,
status_code: int | None = None,
) -> None:
try:
request_path = request.path if request else None
request_method = request.method if request else None
except RuntimeError:
request_path = None
request_method = None
resolved_user = username
if not resolved_user:
try:
resolved_user = session.get("adminuser")
except RuntimeError:
resolved_user = None
self.log_store.write(
level=level,
category=category,
event=event,
message=message,
username=resolved_user,
backup_id=backup_id,
request_path=request_path,
request_method=request_method,
status_code=status_code,
details=details,
)
def _get_run_status(self, backup_id: int) -> dict:
with self._run_lock:
state = self._active_runs.get(backup_id)
@@ -90,10 +132,24 @@ class FlaskServer:
with self._run_lock:
existing = self._active_runs.get(backup_id)
if existing and bool(existing.get("is_running", False)):
self._log(
level="WARNING",
category="backup",
event="run_start_rejected",
backup_id=backup_id,
message="Backup-Lauf konnte nicht gestartet werden, da bereits ein Lauf aktiv ist.",
)
return False, "Backup-Lauf ist bereits aktiv."
job = self.store.get_backup_execution_job(backup_id)
if job is None:
self._log(
level="ERROR",
category="backup",
event="run_start_failed",
backup_id=backup_id,
message="Backup-Lauf konnte nicht gestartet werden, da das Backup nicht gefunden wurde.",
)
return False, "Backup nicht gefunden."
stop_event = threading.Event()
@@ -114,16 +170,37 @@ class FlaskServer:
thread=thread,
)
thread.start()
self._log(
level="INFO",
category="backup",
event="run_started",
backup_id=backup_id,
message=f"Manueller Backup-Lauf wurde gestartet: {job.name}",
)
return True, f"Manueller Lauf für '{job.name}' wurde gestartet."
def _stop_backup_run(self, backup_id: int) -> tuple[bool, str]:
with self._run_lock:
state = self._active_runs.get(backup_id)
if not state or not bool(state.get("is_running", False)):
self._log(
level="WARNING",
category="backup",
event="run_stop_rejected",
backup_id=backup_id,
message="Backup-Abbruch angefordert, aber kein Lauf war aktiv.",
)
return False, "Kein aktiver Lauf zum Abbrechen."
stop_event = state.get("stop_event")
if stop_event is None or not hasattr(stop_event, "set"):
self._log(
level="ERROR",
category="backup",
event="run_stop_failed",
backup_id=backup_id,
message="Backup-Abbruch konnte nicht angefordert werden (fehlendes stop_event).",
)
return False, "Abbruch konnte nicht angefordert werden."
stop_event.set()
@@ -131,6 +208,13 @@ class FlaskServer:
state["status_message"] = "Abbruch wurde angefordert..."
self._active_runs[backup_id] = state
self._log(
level="INFO",
category="backup",
event="run_stop_requested",
backup_id=backup_id,
message="Abbruch eines laufenden Backups wurde angefordert.",
)
return True, "Abbruch wurde angefordert."
@staticmethod
@@ -1142,6 +1226,13 @@ class FlaskServer:
)
ok, msg = test_connection(source)
if not ok:
self._log(
level="ERROR",
category="backup",
event="source_check_failed",
backup_id=backup_id,
message=f"Quelle nicht erreichbar: {msg}",
)
self._set_run_state(
backup_id,
is_running=False,
@@ -1169,6 +1260,13 @@ class FlaskServer:
)
ok, msg = test_connection(destination)
if not ok:
self._log(
level="ERROR",
category="backup",
event="destination_check_failed",
backup_id=backup_id,
message=f"Ziel nicht erreichbar: {msg}",
)
self._set_run_state(
backup_id,
is_running=False,
@@ -1189,6 +1287,13 @@ class FlaskServer:
copied_files, copied_bytes = self._transfer_backup_payload(job, stop_event)
if stop_event.is_set():
self._log(
level="INFO",
category="backup",
event="run_stopped",
backup_id=backup_id,
message="Backup-Lauf wurde manuell gestoppt.",
)
self._set_run_state(
backup_id,
is_running=False,
@@ -1200,6 +1305,16 @@ class FlaskServer:
self.store.mark_backup_run(backup_id, copied_bytes)
self._apply_rotation(job)
self._log(
level="INFO",
category="backup",
event="run_finished",
backup_id=backup_id,
message=(
f"Backup erfolgreich abgeschlossen: {copied_files} Dateien, {copied_bytes} Bytes."
),
details={"copied_files": copied_files, "copied_bytes": copied_bytes},
)
self._set_run_state(
backup_id,
is_running=False,
@@ -1218,6 +1333,14 @@ class FlaskServer:
progress_text="Fehler",
status_message=f"Lauf fehlgeschlagen: {exc}",
)
self._log(
level="ERROR",
category="backup",
event="run_failed",
backup_id=backup_id,
message=f"Lauf fehlgeschlagen: {exc}",
details={"traceback": traceback.format_exc()},
)
@staticmethod
def _parse_port(value: str) -> int | None:
@@ -1345,6 +1468,40 @@ class FlaskServer:
SESSION_COOKIE_SAMESITE="Lax",
)
@app.before_request
def _capture_request_start() -> None:
g._request_started_at = datetime.now()
@app.after_request
def _log_problematic_requests(response):
status = int(response.status_code)
if status >= 400:
elapsed_ms = None
started = getattr(g, "_request_started_at", None)
if isinstance(started, datetime):
elapsed_ms = int((datetime.now() - started).total_seconds() * 1000)
self._log(
level="WARNING" if status < 500 else "ERROR",
category="http",
event="request_completed",
message=f"HTTP {status} für {request.method} {request.path}",
details={"elapsed_ms": elapsed_ms},
status_code=status,
)
return response
def _handle_exception(sender, exception, **extra):
self._log(
level="ERROR",
category="http",
event="unhandled_exception",
message=f"Unhandled Exception: {exception}",
details={"traceback": traceback.format_exc()},
status_code=500,
)
got_request_exception.connect(_handle_exception, app)
@app.template_filter("fmt_bytes")
def fmt_bytes(value):
if value is None:
@@ -1407,7 +1564,21 @@ class FlaskServer:
session["is_authenticated"] = True
session["is_admin"] = user.is_admin
session["adminuser"] = user.username
self._log(
level="INFO",
category="auth",
event="login_success",
message="Benutzer hat sich erfolgreich angemeldet.",
username=user.username,
)
return redirect(url_for("dashboard"))
self._log(
level="WARNING",
category="auth",
event="login_failed",
message="Anmeldung fehlgeschlagen.",
username=username.strip() or None,
)
error_message = "Anmeldung fehlgeschlagen."
return render_template("login.html", error_message=error_message)
@@ -1422,6 +1593,75 @@ class FlaskServer:
active_menu="dashboard",
)
@app.get("/logs")
@login_required
@admin_required
def logs_view():
level = request.args.get("level", "").strip().upper()
category = request.args.get("category", "").strip()
search = request.args.get("q", "").strip()
try:
limit = int(request.args.get("limit", "200") or "200")
except ValueError:
limit = 200
entries = self.log_store.query_logs(
level=level or None,
category=category or None,
search=search or None,
limit=limit,
)
level_stats = self.log_store.count_by_level_last_hours(24)
categories = self.log_store.list_categories()
return render_template(
"logs.html",
adminuser=session.get("adminuser", "admin"),
logs=entries,
level_stats=level_stats,
categories=categories,
filters={
"level": level,
"category": category,
"q": search,
"limit": str(limit),
},
active_menu="logs",
detail_compactor=self.log_store.compact_details,
)
@app.get("/api/logs")
@login_required
@admin_required
def logs_api():
level = request.args.get("level", "").strip().upper()
category = request.args.get("category", "").strip()
search = request.args.get("q", "").strip()
try:
limit = int(request.args.get("limit", "200") or "200")
except ValueError:
limit = 200
entries = self.log_store.query_logs(
level=level or None,
category=category or None,
search=search or None,
limit=limit,
)
return jsonify({"ok": True, "entries": entries, "count": len(entries)})
@app.post("/logs/clear")
@login_required
@admin_required
def logs_clear():
removed = self.log_store.clear()
self._log(
level="WARNING",
category="audit",
event="logs_cleared",
message=f"Logdaten wurden bereinigt. Geloeschte Eintraege: {removed}",
)
flash(f"Logdaten wurden bereinigt ({removed} Einträge).", "success")
return redirect(url_for("logs_view"))
@app.post("/backups/<int:backup_id>/run")
@login_required
@admin_required
@@ -1480,6 +1720,13 @@ class FlaskServer:
def backup_edit(backup_id: int):
backup = self.store.get_full_backup_for_edit(backup_id)
if backup is None:
self._log(
level="WARNING",
category="backup",
event="edit_not_found",
backup_id=backup_id,
message="Backup konnte nicht bearbeitet werden, da es nicht gefunden wurde.",
)
flash("Backup nicht gefunden.", "error")
return redirect(url_for("dashboard"))
@@ -1580,9 +1827,24 @@ class FlaskServer:
)
if not updated:
self._log(
level="ERROR",
category="backup",
event="edit_failed",
backup_id=backup_id,
message="Backup-Update konnte nicht gespeichert werden.",
)
flash("Backup konnte nicht gespeichert werden.", "error")
return redirect(url_for("backup_edit", backup_id=backup_id))
self._log(
level="INFO",
category="backup",
event="edit_saved",
backup_id=backup_id,
message=f"Backup wurde aktualisiert: {name}",
details={"backup_mode": backup_mode, "compression_method": compression_method},
)
flash("Backup wurde aktualisiert.", "success")
return redirect(url_for("dashboard"))
@@ -1603,8 +1865,22 @@ class FlaskServer:
def backup_delete(backup_id: int):
deleted = self.store.delete_backup(backup_id)
if not deleted:
self._log(
level="WARNING",
category="backup",
event="delete_not_found",
backup_id=backup_id,
message="Backup-Loeschung angefordert, aber Backup nicht gefunden.",
)
flash("Backup nicht gefunden.", "error")
else:
self._log(
level="WARNING",
category="backup",
event="deleted",
backup_id=backup_id,
message="Backup wurde geloescht.",
)
flash("Backup wurde gelöscht.", "success")
return redirect(url_for("dashboard"))
@@ -1694,18 +1970,61 @@ class FlaskServer:
parts = expr.split()
description = "Benutzerdefinierter Zeitplan"
def _format_weekday_text(value: str) -> str | None:
de_dow = ["Sonntag", "Montag", "Dienstag", "Mittwoch", "Donnerstag", "Freitag", "Samstag"]
short = ["So", "Mo", "Di", "Mi", "Do", "Fr", "Sa"]
token = value.strip()
if not token or token == "*":
return "jeden Tag"
if "/" in token:
return None
if "-" in token and "," not in token:
try:
start_raw, end_raw = token.split("-", 1)
start = int(start_raw) % 7
end = int(end_raw) % 7
except ValueError:
return None
if start == end:
return de_dow[start]
return f"{short[start]}-{short[end]}"
if "," in token:
labels: list[str] = []
for part in token.split(","):
part = part.strip()
if not part:
return None
try:
idx = int(part) % 7
except ValueError:
return None
labels.append(short[idx])
return ", ".join(labels)
try:
idx = int(token) % 7
except ValueError:
return None
return de_dow[idx]
if len(parts) == 5:
minute, hour, dom, month, dow = parts
DE_DOW = ["Sonntag", "Montag", "Dienstag", "Mittwoch", "Donnerstag", "Freitag", "Samstag"]
t = f"{int(hour):02d}:{int(minute):02d} Uhr" if hour.isdigit() and minute.isdigit() else ""
dow_text = _format_weekday_text(dow)
if all(p in ("*", "*/1") for p in parts):
description = "Jede Minute"
elif hour == "*" and dom == "*" and month == "*" and dow == "*" and minute.isdigit():
description = f"Jede Stunde um :{int(minute):02d} Uhr"
elif dom == "*" and month == "*" and dow == "*" and t:
description = f"Täglich um {t}"
elif dom == "*" and month == "*" and dow.isdigit() and t:
description = f"Wöchentlich am {DE_DOW[int(dow) % 7]} um {t}"
elif dom == "*" and month == "*" and dow_text and t and dow != "*":
if "-" in dow_text or "," in dow_text:
description = f"Wochentags {dow_text} um {t}"
else:
description = f"Wöchentlich am {dow_text} um {t}"
elif month == "*" and dow == "*" and dom.isdigit() and t:
description = f"Monatlich am {dom}. um {t}"
@@ -1966,9 +2285,26 @@ class FlaskServer:
created = self.store.create_backup(backup)
if not created:
self._log(
level="ERROR",
category="backup",
event="create_failed",
message=f"Backup konnte nicht erstellt werden, Name existiert bereits: {name}",
)
flash("Backup-Name existiert bereits.", "error")
return redirect(url_for("backup_new"))
self._log(
level="INFO",
category="backup",
event="created",
message=f"Backup wurde erstellt: {name}",
details={
"source_protocol": source_target.protocol,
"destination_protocol": destination_target.protocol,
"backup_mode": backup_mode,
},
)
flash("Backup wurde gespeichert.", "success")
return redirect(url_for("dashboard"))
@@ -2000,6 +2336,13 @@ class FlaskServer:
self.config = AppConfig(ip=ip, port=port, debug=debug)
self.store.save_config(self.config)
self._log(
level="INFO",
category="config",
event="server_settings_saved",
message="Server-Einstellungen wurden aktualisiert.",
details={"ip": ip, "port": port, "debug": debug},
)
flash("Server-Settings gespeichert. Neustart des Services erforderlich.", "success")
return redirect(url_for("server_settings"))
@@ -2047,6 +2390,13 @@ class FlaskServer:
flash("Benutzername existiert bereits.", "error")
return redirect(url_for("account_settings"))
self._log(
level="INFO",
category="auth",
event="account_updated",
message="Account-Zugangsdaten wurden aktualisiert.",
username=new_username,
)
session["adminuser"] = new_username
flash("Deine Zugangsdaten wurden aktualisiert.", "success")
return redirect(url_for("account_settings"))
@@ -2086,6 +2436,13 @@ class FlaskServer:
flash("Benutzername existiert bereits.", "error")
return redirect(url_for("users"))
self._log(
level="INFO",
category="auth",
event="user_created",
message=f"Neuer Benutzer wurde erstellt: {username}",
details={"is_admin": is_admin},
)
flash("Neuer Benutzer wurde angelegt.", "success")
return redirect(url_for("users"))
@@ -2098,6 +2455,12 @@ class FlaskServer:
@app.post("/logout")
def logout():
self._log(
level="INFO",
category="auth",
event="logout",
message="Benutzer wurde abgemeldet.",
)
session.clear()
return redirect(url_for("login"))
@@ -2121,7 +2484,13 @@ class FlaskServer:
fire_time = datetime.now()
try:
backups = self.store.list_backups()
except Exception:
except Exception as exc:
self._log(
level="ERROR",
category="scheduler",
event="list_backups_failed",
message=f"Scheduler konnte Backup-Liste nicht laden: {exc}",
)
continue
for b in backups:
@@ -2138,8 +2507,28 @@ class FlaskServer:
if fired.get(b.backup_id) == sched_key:
continue
fired[b.backup_id] = sched_key
self._start_backup_run(b.backup_id)
except Exception:
ok, start_message = self._start_backup_run(b.backup_id)
self._log(
level="INFO" if ok else "WARNING",
category="scheduler",
event="scheduled_run_triggered" if ok else "scheduled_run_not_started",
backup_id=b.backup_id,
message=(
f"Geplanter Lauf ausgeloest fuer Backup: {b.name}"
if ok
else f"Geplanter Lauf konnte nicht gestartet werden: {b.name} ({start_message})"
),
details={"scheduled_slot": sched_key, "cron": b.schedule_cron, "start_message": start_message},
)
except Exception as exc:
self._log(
level="ERROR",
category="scheduler",
event="cron_evaluation_failed",
backup_id=b.backup_id,
message=f"CRON-Auswertung fehlgeschlagen fuer Backup '{b.name}': {exc}",
details={"cron": b.schedule_cron},
)
continue
def run(self) -> None:
@@ -2151,4 +2540,17 @@ class FlaskServer:
threading.Thread(
target=self._run_scheduler, daemon=True, name="backup-scheduler"
).start()
self._log(
level="INFO",
category="scheduler",
event="started",
message="Backup-Scheduler wurde gestartet.",
)
self._log(
level="INFO",
category="app",
event="startup",
message=f"Webserver startet auf {self.config.ip}:{self.config.port} (debug={self.config.debug}).",
details={"ip": self.config.ip, "port": self.config.port, "debug": self.config.debug},
)
app.run(host=self.config.ip, port=self.config.port, debug=self.config.debug)