From 95c821deb289e5a6758e7d8d42510468bc311077 Mon Sep 17 00:00:00 2001 From: kisfenyo Date: Thu, 26 Feb 2026 18:14:43 +0100 Subject: [PATCH] feat: comprehensive debug logging across all controller modules Add detailed [DEBUG] logging to every controller module when logging.level is set to "debug". Each module with stateful debug uses SetDebug(bool) wired from main.go. Covers stacks, backup, cloudflare, integrations, system, monitor, settings, scheduler, web handlers, storage, metrics, API, selfupdate, and assets. Also includes the app export/import (.fab bundles) feature from v0.32.0 and its debug page integration. Co-Authored-By: Claude Opus 4.6 --- CHANGELOG.md | 50 + controller/README.md | 96 +- controller/cmd/controller/main.go | 173 +++ controller/internal/api/geo.go | 1 + controller/internal/api/router.go | 23 + controller/internal/appexport/crypto.go | 228 ++++ controller/internal/appexport/estimate.go | 177 +++ controller/internal/appexport/export.go | 793 ++++++++++++ controller/internal/appexport/manifest.go | 42 + controller/internal/appexport/provider.go | 52 + controller/internal/appexport/restore.go | 1119 +++++++++++++++++ controller/internal/assets/syncer.go | 41 +- controller/internal/backup/appdata.go | 6 +- controller/internal/backup/backup.go | 4 +- controller/internal/backup/restic.go | 95 +- .../internal/backup/restore_app_linux.go | 41 + .../internal/backup/restore_drives_linux.go | 37 +- controller/internal/backup/restore_scan.go | 16 + controller/internal/cloudflare/geosync.go | 82 +- controller/internal/cloudflare/waf.go | 33 + controller/internal/cloudflare/zone.go | 10 + controller/internal/integrations/lifecycle.go | 31 + controller/internal/integrations/manager.go | 66 + .../integrations/onlyoffice_filebrowser.go | 11 +- controller/internal/metrics/logscanner.go | 11 + controller/internal/monitor/pinger.go | 28 + controller/internal/scheduler/scheduler.go | 39 + controller/internal/selfupdate/updater.go | 48 +- controller/internal/settings/settings.go | 52 +- controller/internal/stacks/delete.go | 91 ++ controller/internal/stacks/deploy.go | 48 +- controller/internal/stacks/healthprobe.go | 14 + controller/internal/stacks/manager.go | 69 + controller/internal/storage/attach_linux.go | 2 +- controller/internal/storage/format_linux.go | 2 +- controller/internal/storage/migrate.go | 2 +- controller/internal/storage/migrate_drive.go | 22 + controller/internal/storage/scan_linux.go | 10 +- controller/internal/system/cpu_linux.go | 8 + controller/internal/system/info.go | 14 + controller/internal/system/info_linux.go | 29 + controller/internal/system/mounts_linux.go | 29 +- controller/internal/web/auth.go | 39 + controller/internal/web/handler_debug.go | 96 ++ controller/internal/web/handler_export.go | 356 ++++++ controller/internal/web/handler_restore.go | 35 + controller/internal/web/handlers.go | 53 + controller/internal/web/server.go | 39 + controller/internal/web/storage_handlers.go | 69 + .../internal/web/templates/app_export.html | 223 ++++ .../internal/web/templates/app_import.html | 287 +++++ .../internal/web/templates/app_info.html | 1 + controller/internal/web/templates/debug.html | 153 +++ controller/internal/web/templates/stacks.html | 1 + 54 files changed, 5015 insertions(+), 82 deletions(-) create mode 100644 controller/internal/appexport/crypto.go create mode 100644 controller/internal/appexport/estimate.go create mode 100644 controller/internal/appexport/export.go create mode 100644 controller/internal/appexport/manifest.go create mode 100644 controller/internal/appexport/provider.go create mode 100644 controller/internal/appexport/restore.go create mode 100644 controller/internal/web/handler_export.go create mode 100644 controller/internal/web/templates/app_export.html create mode 100644 controller/internal/web/templates/app_import.html diff --git a/CHANGELOG.md b/CHANGELOG.md index 80dc5ef..22f7b91 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,55 @@ ## Changelog +### v0.32.1 — Comprehensive debug logging across all modules (2026-02-26) + +#### Added +- **stacks/delete.go**: Debug logging for DeleteStack/RemoveStack with stack state, HDD mounts, compose output, path removal; GetStackHDDData/GetStackBackupData path scanning +- **stacks/manager.go**: Debug logging for ScanStacks per-stack discovery, refreshStatusLocked container resolution, Start/Stop/Restart pre-operation state, MigrateEncryption progress, getCatalogTemplateSlugs count +- **stacks/deploy.go**: Debug logging for UpdateStackConfig/UpdateOptionalConfig changed keys, InjectMissingFields per-stack checks, SaveAppConfig encryption counts, LoadAppConfig results +- **stacks/healthprobe.go**: Debug logging for per-target interval calculations and target collection summary +- **backup/restic.go**: `debug` field + `SetDebug()` method; debug logs for Snapshot/Prune/Check/ListSnapshots/LatestSnapshot/Stats/RestoreAppData with timing, sizes, and command details +- **backup/restore_scan.go**: Debug logging for ScanDrivesForBackups drive/app scanning with per-drive availability and backup component summary +- **backup/restore_app_linux.go**: Debug logging for RestoreAppFromBackup step timing, restoreUserData per-dir rsync, restoreDBDumps per-file copying +- **backup/restore_drives_linux.go**: Debug logging for MountDrivesFromLayout device discovery, mount strategy selection, fstab checks +- **cloudflare/geosync.go**: `debug` field + `SetDebug()` method; debug logs for Sync zone/ruleset resolution, existing/desired rule diffing, rule create/update/delete operations +- **cloudflare/waf.go**: Debug logging for GetCustomRulesetID/GetRules/GetFelhomRules counts, CreateRule/UpdateRule expression snippets +- **cloudflare/zone.go**: Debug logging for GetZoneID progressive domain lookup attempts +- **integrations/manager.go**: `debug` field + `SetDebug()` method; debug logs for Toggle validation/timing, ListForProvider counts, buildApplyContext details, ReapplyConfigForTarget per-integration progress +- **integrations/lifecycle.go**: Debug logging for OnStackStop/OnStackStart/OnStackRemove with integration counts, state checks, revoke/re-apply operations +- **integrations/onlyoffice_filebrowser.go**: Debug logging for Apply/Revoke config path, JWT secret presence, office URL +- **system/**: Package-level `DebugLogger` variable; debug logs for GetInfo timing/summary, readMemInfo/readDiskUsage/readLoadAvg/readTemperature raw values, CPU collector samples, GetDiskUsage/GetFSInfo/CheckBackupDestination/ProbeStoragePath/IsUSBDevice details +- **monitor/pinger.go**: `debug` field + `SetDebug()` method; debug logs for Ping/Fail/Start with UUIDs, send URL/attempts/response status +- **settings/settings.go**: `debug` field (json:"-") + `SetDebug()` method; debug logs for Load counts, save data size, AddStoragePath/RemoveStoragePath, SetDisconnected/SetDecommissioned, AddPendingEvent/DrainPendingEvents, SetGeoRestriction, SetIntegrationState, AutoDiscoverStoragePaths +- **scheduler**: `debug` field + `SetDebug()` method; debug logs for job registration, execution timing, daily job wait calculations +- **storage/**: Consistent `[DEBUG] [storage]` prefix; scan timing; drive migration debug logging +- **metrics/logscanner**: Debug logging for per-container scan timing, error/warning counts +- **api/router**: `debug` field + `SetDebug()` method; logs incoming API requests and handler entry points +- **selfupdate**: Expanded debug coverage with `dbg()` helper for TriggerUpdate preconditions, performUpdate step transitions, docker pull timing +- **assets/syncer**: Expanded debug coverage with `dbg()` helper for per-file hash comparison, download timing, manifest fetch details +- **web/auth.go**: Debug logging for RequireAuth middleware decisions, login attempts (IP, success/fail), session creation/cleanup +- **web/handlers.go**: Debug logging for deploy/restore/settings/storage handler entry points with key parameters +- **web/handler_restore.go**: Debug logging for restore page, status polls, restore-all execution per-app timing +- **web/storage_handlers.go**: Debug logging for all storage API operations (scan, init, migrate, disconnect, reconnect, attach, cleanup) +- **web/server.go**: Debug logging for NewServer initialization, template loading, ServeHTTP request routing +- **main.go**: Wire `SetDebug()` for settings, pinger, geoSync, integrationMgr, scheduler, apiRouter + +### v0.32.0 — App export/import (.fab bundles) (2026-02-26) + +#### Added +- **App export**: Per-app export to `.fab` bundles containing config, database dump, and all user data (HDD bind mounts or Docker named volumes) +- **App import**: Restore apps from `.fab` bundles — works for both existing and new apps (standalone import page) +- **Password protection**: Optional AES-256-CTR + HMAC-SHA256 encryption with scrypt key derivation for exported bundles +- **Pre-export estimation**: Size estimation with free space check before starting export +- **Export UI**: New export page accessible from app info header with drive picker, password field, stop-app checkbox, and real-time progress tracking +- **Import UI**: Standalone import page (`/import`) scans all registered storage drives for `.fab` files, shows manifest details, and handles encrypted bundles with password prompt +- **FileBrowser link**: After export, link to open the exports directory in FileBrowser +- **Bundle format**: `{appname}_{timestamp}.fab` — tar.gz internally with `manifest.json`, `config/`, `database/`, `data/` directories +- **New package**: `internal/appexport/` — export/import engine with provider adapter pattern (same as backup.StackDataProvider) +- **API endpoints**: `/api/export/estimate`, `/api/export/start`, `/api/export/status`, `/api/export/bundles`, `/api/export/manifest`, `/api/export/import`, `/api/export/import/status` + +#### Changed +- **backup/appdata.go**: Exported `ParseComposeNamedVolumes` (was lowercase) for reuse by appexport package + ### v0.31.7 — Infra backup retention + version picker (2026-02-26) #### Changed diff --git a/controller/README.md b/controller/README.md index 7ab5976..f59644d 100644 --- a/controller/README.md +++ b/controller/README.md @@ -13,19 +13,20 @@ A single, lightweight Go container that replaces Portainer + scattered systemd s - [Architecture](#architecture) - [Features](#features) - [App Management](#1-app-management) - - [Backup System](#2-backup-system) - - [Storage Management](#3-storage-management) - - [Monitoring & Health](#4-monitoring--health) - - [Notifications](#5-notifications) - - [Update Management](#6-update-management) - - [Authentication & Settings](#7-authentication--settings) - - [Central Hub](#8-central-hub-reporting) - - [Setup Wizard](#9-first-run-setup-wizard) - - [Disaster Recovery](#10-disaster-recovery) - - [Asset Sync](#11-asset-sync) - - [Debug Mode](#12-debug-mode) - - [Geo-Restriction](#13-geo-restriction) - - [App-to-App Integrations](#14-app-to-app-integrations) + - [App Export/Import](#2-app-exportimport-fab-bundles) + - [Backup System](#3-backup-system) + - [Storage Management](#4-storage-management) + - [Monitoring & Health](#5-monitoring--health) + - [Notifications](#6-notifications) + - [Update Management](#7-update-management) + - [Authentication & Settings](#8-authentication--settings) + - [Central Hub](#9-central-hub-reporting) + - [Setup Wizard](#10-first-run-setup-wizard) + - [Disaster Recovery](#11-disaster-recovery) + - [Asset Sync](#12-asset-sync) + - [Debug Mode](#13-debug-mode) + - [Geo-Restriction](#14-geo-restriction) + - [App-to-App Integrations](#15-app-to-app-integrations) - [Repository Layout](#repository-layout) - [Configuration](#configuration) - [REST API](#rest-api) @@ -106,6 +107,7 @@ A single, lightweight Go container that replaces Portainer + scattered systemd s | **Assets** | `internal/assets/` | Hub-managed asset syncer: downloads logos/screenshots with SHA-256 change detection | | **SelfTest** | `internal/selftest/` | Startup self-test: 9 diagnostic checks (Docker, dirs, storage, hub, restic, metrics) | | **Util** | `internal/util/` | Shared utilities: `TruncateStr` for debug log output truncation | +| **AppExport** | `internal/appexport/` | Per-app export/import via `.fab` bundles (config + DB + user data), optional AES-256 encryption | | **API** | `internal/api/` | REST JSON endpoints, diagnostic dump (`/api/debug/dump`) | | **Web** | `internal/web/` | Hungarian dashboard, auth, page handlers, template functions, alerts | @@ -234,7 +236,27 @@ Multiple checks per app are supported (all must pass). The probe scheduler runs --- -### 2. Backup System +### 2. App Export/Import (.fab bundles) + +Per-app export creates a self-contained `.fab` file (tar.gz, optionally encrypted) that can be stored externally or used to restore the app on the same server. Distinct from the automatic backup system — user-initiated, per-app, produces a single portable file. + +**Bundle contents:** `manifest.json` + `config/` (compose, .felhom.yml, app.yaml with plaintext secrets) + `database/` (gzipped SQL dump) + `data/` (HDD bind mount tars or Docker named volume tars). + +**Encryption:** Optional AES-256-CTR + HMAC-SHA256 with scrypt key derivation (N=32768). Format: `"FABE"` magic header + salt + IV + encrypted tar.gz + HMAC tag. Streaming for multi-GB files. + +**Export flow:** Estimate size → check free space → optionally stop app → copy config → dump DB → tar user data → create tar.gz → optionally encrypt → atomic rename. App restarts automatically after export if it was stopped. + +**Import flow:** Decrypt if needed → extract → prepare stack dir (create new or `compose down --volumes` for existing) → restore config (re-encrypt app.yaml with current server key) → restore user data (HDD or volumes) → restore DB (start DB service, wait for ready, import dump) → start full stack → refresh UI. + +**Architecture:** `internal/appexport/` package with `ExportStackProvider` adapter interface (same pattern as `backup.StackDataProvider`). `exportAdapter` in `main.go` bridges `stacks.Manager` to the provider. + +**API endpoints:** `/api/export/estimate`, `/api/export/start`, `/api/export/status`, `/api/export/bundles`, `/api/export/manifest`, `/api/export/import`, `/api/export/import/status`. + +**UI:** Export button on app info page, standalone import page at `/import` accessible from the stacks page header. + +--- + +### 3. Backup System The backup system implements a **3-2-1 backup architecture**. Each tier is a **complete, self-sufficient backup** — any single tier can fully restore an app. @@ -441,7 +463,7 @@ not just those with HDD data. Non-HDD apps can configure destination, method, an --- -### 3. Storage Management +### 4. Storage Management The storage subsystem handles the full lifecycle of external storage: detection, initialization, path registration, and data migration. @@ -554,7 +576,7 @@ Continuously monitors registered storage paths for disconnection/reconnection (p --- -### 4. Monitoring & Health +### 5. Monitoring & Health #### System Health Checks (`internal/monitor/healthcheck.go`) @@ -610,7 +632,7 @@ State-based alerts displayed on all pages: --- -### 5. Notifications +### 6. Notifications #### Hub Event System (`internal/notify/notifier.go`) @@ -660,7 +682,7 @@ Notification preferences (email, enabled events, cooldown hours) are: --- -### 6. Update Management +### 7. Update Management #### App Catalog Sync @@ -807,7 +829,7 @@ self_update: --- -### 7. Authentication & Settings +### 8. Authentication & Settings #### Session Auth (`internal/web/auth.go`) @@ -868,7 +890,7 @@ Five sections: --- -### 8. Central Hub Reporting +### 9. Central Hub Reporting #### Report Push (`internal/report/`) @@ -923,7 +945,7 @@ The hub service (separate Go app in the `felhom.eu` repo) provides: - Color coding: green (<30min), yellow (30-60min), red (>60min since last report) - 90-day report + event retention with daily prune at 04:30 Budapest time -### 9. First-Run Setup Wizard +### 10. First-Run Setup Wizard When the controller starts with no valid customer configuration (`customer.id` empty), it enters **setup mode** — a web-based wizard that handles all initial configuration. This replaces the old interactive shell wizard in `docker-setup.sh`. @@ -1010,7 +1032,7 @@ During setup wizard drive scan, both current and historical backups are discover Generates `recovery-info.txt` on the system data partition with customer ID, Hub URL, retrieval password, and recovery instructions in Hungarian. Updated on startup and after config changes. Also displayed on the Settings page in a "Vészhelyzeti információk" section. -### 10. Disaster Recovery +### 11. Disaster Recovery When a system drive fails and is replaced, the recovery flow uses the setup wizard: @@ -1040,7 +1062,7 @@ When a system drive fails and is replaced, the recovery flow uses the setup wiza --- -### 11. Asset Sync +### 12. Asset Sync App assets (logos, screenshots) are managed centrally by the Hub and downloaded to each controller via a daily sync process. This decouples asset updates from controller image rebuilds — new app icons only require a Hub redeploy. @@ -1096,7 +1118,7 @@ The Hub serves three asset types per app: --- -### 12. Debug Mode +### 13. Debug Mode When `logging.level: "debug"` is set in `controller.yaml`, the controller exposes a full diagnostic dashboard at `/debug` with 9 testing sections. All debug endpoints are gated — at `info` level, the sidebar link disappears and all `/api/debug/*` routes return 404. @@ -1123,9 +1145,31 @@ When `logging.level: "debug"` is set in `controller.yaml`, the controller expose - **DebugCallbacks**: 7 closures wired from main.go for operations needing modules not on Server struct (hub push, infra backup, connectivity tests, telemetry preview). - **Telemetry debug**: `GetTelemetryPreview` callback calls `report.BuildAppTelemetryForDebug()` (exported wrapper around the private `buildAppTelemetrySection()`). Result renders as a table with collapsible raw JSON. Available regardless of hub configuration. +#### Per-Module Debug Logging + +When `logging.level: "debug"`, every module emits detailed `[DEBUG] [module]` prefixed log lines. Each module with stateful debug (struct-based) exposes a `SetDebug(bool)` method, wired from `main.go`. Modules without a struct use package-level `DebugLogger` variables (e.g., `system.DebugLogger`). + +| Module | Debug Field | Prefix | Key Areas | +|--------|------------|--------|-----------| +| `stacks` | `cfg.Logging.Level` | `[DEBUG] [stacks]` | Stack CRUD, compose commands, env vars, HDD mounts, encryption migration, health probes | +| `backup` | `ResticManager.debug` | `[DEBUG] [restic]` / `[DEBUG] [backup]` | Restic commands, snapshot operations, restore scanning, drive mounting | +| `cloudflare` | `Client.debug` + `GeoSyncManager.debug` | `[CF-DEBUG]` / `[DEBUG] [cloudflare]` | API requests/responses, WAF rule CRUD, zone resolution, geo sync diff | +| `integrations` | `Manager.debug` | `[DEBUG] [integrations]` | Toggle apply/revoke timing, lifecycle hooks, config reapply | +| `system` | `DebugLogger` | `[DEBUG] [system]` | Memory/disk/CPU/load/temp collection, mount probing, USB detection | +| `monitor` | `Pinger.debug` | `[DEBUG] [pinger]` | Health ping URLs, retry attempts, response codes | +| `settings` | `Settings.debug` | `[DEBUG] [settings]` | Load/save sizes, storage path ops, geo/integration state changes | +| `scheduler` | `Scheduler.debug` | `[DEBUG] [sched]` | Job registration, execution timing, daily schedule calculations | +| `web` | `cfg.Logging.Level` | `[DEBUG] [web]` | HTTP requests, auth decisions, session management, storage API ops | +| `api` | `Router.debug` | `[DEBUG] [api]` | API routing, handler entry points, request details | +| `selfupdate` | `Updater.debug` | `[DEBUG] [selfupdate]` | Version checks, update preconditions, docker pull timing | +| `assets` | `Syncer.debug` | `[DEBUG] [assets]` | Manifest fetch, hash comparison, file download timing | +| `storage` | logger-based | `[DEBUG] [storage]` | Disk scanning, formatting, attach, drive migration | +| `metrics` | logger-based | `[DEBUG] [metrics]` | Per-container log scanning, error/warning counts | +| `appexport` | `Exporter.debug` | `[DEBUG] [appexport]` | Export/import steps, crypto operations, bundle scanning | + --- -### 13. Geo-Restriction +### 14. Geo-Restriction Country-based access control via **Cloudflare WAF Custom Rules**. The controller manages WAF rules in the `http_request_firewall_custom` phase to block requests from non-allowed countries. Rules are identified by a `[felhom-geo]` description prefix — other WAF rules are never touched. @@ -1223,7 +1267,7 @@ All mutating endpoints trigger an async Cloudflare sync. The `/api/geo/` path ac --- -### 14. App-to-App Integrations +### 15. App-to-App Integrations Generic framework for connecting deployed applications to each other. Provider apps declare available integrations in `.felhom.yml`, and users enable/disable them via toggle switches on the provider's deploy/settings page ("Beállítások"). diff --git a/controller/cmd/controller/main.go b/controller/cmd/controller/main.go index 89b68ee..6272bae 100644 --- a/controller/cmd/controller/main.go +++ b/controller/cmd/controller/main.go @@ -9,6 +9,7 @@ import ( "log" "net/http" "os" + "os/exec" "os/signal" "path/filepath" "syscall" @@ -18,6 +19,7 @@ import ( "strings" "gitea.dooplex.hu/admin/felhom-controller/internal/api" + "gitea.dooplex.hu/admin/felhom-controller/internal/appexport" "gitea.dooplex.hu/admin/felhom-controller/internal/assets" "gitea.dooplex.hu/admin/felhom-controller/internal/backup" cf "gitea.dooplex.hu/admin/felhom-controller/internal/cloudflare" @@ -71,6 +73,11 @@ func main() { logger, logBuffer := setupLogger(cfg) + // --- Wire system package debug logging --- + if cfg.Logging.Level == "debug" { + system.DebugLogger = logger + } + // --- Setup mode: if no customer ID configured, run setup wizard --- if setup.NeedsSetup(cfg) { logger.Printf("[INFO] felhom-controller %s — setup mode", Version) @@ -87,6 +94,7 @@ func main() { if err != nil { logger.Fatalf("[FATAL] Failed to load settings from %s: %v", settingsPath, err) } + sett.SetDebug(cfg.Logging.Level == "debug") // --- Auto-discover storage paths from deployed apps --- discoveredPaths := discoverHDDPaths(cfg.Paths.StacksDir, logger) @@ -159,6 +167,7 @@ func main() { // --- Initialize health pinger (legacy, will be removed) --- pinger := monitor.NewPinger(&cfg.Monitoring, logger) + pinger.SetDebug(cfg.Logging.Level == "debug") // Deprecation notice for ping UUIDs uuids := cfg.Monitoring.PingUUIDs @@ -215,6 +224,7 @@ func main() { // --- Initialize scheduler --- sched := scheduler.New(logger) + sched.SetDebug(cfg.Logging.Level == "debug") // Existing periodic tasks (migrated from ad-hoc goroutines) sched.Every("status-refresh", 30*time.Second, func(ctx context.Context) error { @@ -614,6 +624,7 @@ func main() { cfClient := cf.New(cfg.Infrastructure.CFAPIToken, logger, cfg.Logging.Level == "debug") geoStacks := &geoStackAdapter{mgr: stackMgr, domain: cfg.Customer.Domain} geoSync = cf.NewGeoSyncManager(cfClient, sett, cfg.Customer.Domain, geoStacks, logger) + geoSync.SetDebug(cfg.Logging.Level == "debug") apiRouter.SetGeoSync(geoSync) // Re-sync geo rules when apps are deployed/removed @@ -651,11 +662,19 @@ func main() { // --- Initialize integration manager --- integrationStacks := &integrationStackAdapter{mgr: stackMgr} integrationMgr := integrations.NewManager(sett, integrationStacks, cfg.Customer.Domain, cfg.Paths.StacksDir, encKey, logger) + integrationMgr.SetDebug(cfg.Logging.Level == "debug") apiRouter.SetIntegrationManager(integrationMgr) + // --- Initialize app exporter --- + exportProv := &exportAdapter{mgr: stackMgr, encKey: encKey} + appExporter := appexport.NewExporter(exportProv, logger, Version) + appExporter.SetDebug(cfg.Logging.Level == "debug") + apiRouter.SetDebug(cfg.Logging.Level == "debug") + // --- Initialize web server --- webServer := web.NewServer(cfg, stackMgr, cpuCollector, backupMgr, crossDriveRunner, sched, sett, alertMgr, notifier, updater, logger, Version) webServer.SetEncryptionKey(encKey) + webServer.SetAppExporter(appExporter) webServer.SetIntegrationManager(integrationMgr) webServer.SetStorageWatchdog(storageWatchdog) if assetsSyncer != nil { @@ -773,6 +792,8 @@ func main() { mux.HandleFunc("/api/health", apiRouter.HealthHandler) // Storage API routes handled by web server (longer prefix takes precedence over /api/) mux.Handle("/api/storage/", webServer.RequireAuth(webServer.CsrfProtect(http.HandlerFunc(webServer.ServeStorageAPI)))) + // App export/import API routes handled by web server + mux.Handle("/api/export/", webServer.RequireAuth(webServer.CsrfProtect(http.HandlerFunc(webServer.ServeExportAPI)))) // Debug API routes handled by web server (debug-mode gating inside handler) mux.Handle("/api/debug/", webServer.RequireAuth(webServer.CsrfProtect(http.HandlerFunc(webServer.ServeDebugAPI)))) // Self-update API — accepts session auth OR hub API key (for external triggering) @@ -1063,6 +1084,158 @@ func (a *driveMigrateStackAdapter) StackExists(name string) bool { return ok } +// exportAdapter implements appexport.ExportStackProvider using stacks.Manager. +type exportAdapter struct { + mgr *stacks.Manager + encKey []byte +} + +func (a *exportAdapter) GetStackDir(name string) (string, bool) { + s, ok := a.mgr.GetStack(name) + if !ok { + return "", false + } + return filepath.Dir(s.ComposePath), true +} + +func (a *exportAdapter) GetStackComposePath(name string) (string, bool) { + s, ok := a.mgr.GetStack(name) + if !ok { + return "", false + } + return s.ComposePath, true +} + +func (a *exportAdapter) GetStackHDDMounts(name string) []string { + s, ok := a.mgr.GetStack(name) + if !ok { + return nil + } + stackDir := filepath.Dir(s.ComposePath) + appCfg := stacks.LoadAppConfig(stackDir) + if appCfg != nil && appCfg.Env["HDD_PATH"] != "" { + return stacks.ParseComposeHDDMounts(s.ComposePath, appCfg.Env["HDD_PATH"]) + } + return nil +} + +func (a *exportAdapter) GetStackHDDPath(name string) string { + s, ok := a.mgr.GetStack(name) + if !ok { + return "" + } + stackDir := filepath.Dir(s.ComposePath) + appCfg := stacks.LoadAppConfig(stackDir) + if appCfg != nil && appCfg.Env["HDD_PATH"] != "" { + return filepath.Clean(appCfg.Env["HDD_PATH"]) + } + return "" +} + +func (a *exportAdapter) IsStackRunning(name string) bool { + s, ok := a.mgr.GetStack(name) + return ok && s.State == stacks.StateRunning +} + +func (a *exportAdapter) StopStack(name string) error { + return a.mgr.StopStack(name) +} + +func (a *exportAdapter) StartStack(name string) error { + return a.mgr.StartStack(name) +} + +func (a *exportAdapter) GetStackDisplayName(name string) string { + s, ok := a.mgr.GetStack(name) + if !ok { + return name + } + return s.Meta.DisplayName +} + +func (a *exportAdapter) GetStackNeedsHDD(name string) bool { + s, ok := a.mgr.GetStack(name) + return ok && s.Meta.Resources.NeedsHDD +} + +func (a *exportAdapter) GetDockerVolumes(name string) []string { + s, ok := a.mgr.GetStack(name) + if !ok { + return nil + } + vols := backup.ParseComposeNamedVolumes(s.ComposePath) + var names []string + for _, v := range vols { + names = append(names, v.Name) + } + return names +} + +func (a *exportAdapter) IsStackDeployed(name string) bool { + s, ok := a.mgr.GetStack(name) + return ok && s.Deployed +} + +func (a *exportAdapter) GetDecryptedEnv(name string) map[string]string { + s, ok := a.mgr.GetStack(name) + if !ok { + return nil + } + stackDir := filepath.Dir(s.ComposePath) + cfg := stacks.LoadAppConfigDecrypted(stackDir, a.encKey) + if cfg == nil { + return nil + } + return cfg.Env +} + +func (a *exportAdapter) GetStacksBaseDir() string { + return a.mgr.GetStacksBaseDir() +} + +func (a *exportAdapter) SaveEncryptedAppConfig(stackDir string, env map[string]string) error { + meta := stacks.LoadMetadata(stackDir) + sensitiveVars := stacks.SensitiveEnvVars(&meta) + cfg := &stacks.AppConfig{ + Deployed: true, + DeployedAt: time.Now().Format(time.RFC3339), + Env: env, + } + return stacks.SaveAppConfig(stackDir, cfg, a.encKey, sensitiveVars) +} + +func (a *exportAdapter) RefreshStacks() error { + return a.mgr.RefreshStatus() +} + +func (a *exportAdapter) RemoveStackVolumes(name string) error { + s, ok := a.mgr.GetStack(name) + if !ok { + return fmt.Errorf("stack %q not found", name) + } + stackDir := filepath.Dir(s.ComposePath) + + // Build env from decrypted app config + cmdEnv := os.Environ() + appCfg := stacks.LoadAppConfigDecrypted(stackDir, a.encKey) + if appCfg != nil { + for k, v := range appCfg.Env { + cmdEnv = append(cmdEnv, k+"="+v) + } + } + + ctx, cancel := context.WithTimeout(context.Background(), 2*time.Minute) + defer cancel() + cmd := exec.CommandContext(ctx, "docker", "compose", "down", "--volumes") + cmd.Dir = stackDir + cmd.Env = cmdEnv + out, err := cmd.CombinedOutput() + if err != nil { + return fmt.Errorf("compose down --volumes: %s — %w", strings.TrimSpace(string(out)), err) + } + return nil +} + // pushInfraBackup builds and sends the infrastructure snapshot to the Hub. func pushInfraBackup(cfg *config.Config, sett *settings.Settings, stackProv *stackAdapter, pusher *report.Pusher, logger *log.Logger) { diff --git a/controller/internal/api/geo.go b/controller/internal/api/geo.go index 8a303ad..50f13f0 100644 --- a/controller/internal/api/geo.go +++ b/controller/internal/api/geo.go @@ -34,6 +34,7 @@ func (r *Router) geoStatus(w http.ResponseWriter, _ *http.Request) { func (r *Router) geoUpdateSettings(w http.ResponseWriter, req *http.Request) { limitBody(w, req) + r.dbg("geoUpdateSettings: contentLength=%d", req.ContentLength) var body struct { Enabled bool `json:"enabled"` diff --git a/controller/internal/api/router.go b/controller/internal/api/router.go index 67b9edb..6088fb7 100644 --- a/controller/internal/api/router.go +++ b/controller/internal/api/router.go @@ -59,6 +59,19 @@ type Router struct { // App-to-app integration manager (nil if not configured) integrationMgr *integrations.Manager + + debug bool +} + +// SetDebug enables or disables debug logging for API routing. +func (r *Router) SetDebug(on bool) { + r.debug = on +} + +func (r *Router) dbg(format string, args ...interface{}) { + if r.debug { + r.logger.Printf("[DEBUG] [api] "+format, args...) + } } // SetAssetsSyncer sets the Hub asset syncer for on-demand sync triggers. @@ -92,6 +105,8 @@ func (r *Router) ServeHTTP(w http.ResponseWriter, req *http.Request) { path := strings.TrimPrefix(req.URL.Path, "/api") path = strings.TrimSuffix(path, "/") + r.dbg("%s %s (path=%s)", req.Method, req.URL.Path, path) + switch { // GET /api/stacks case path == "/stacks" && req.Method == http.MethodGet: @@ -282,6 +297,7 @@ func (r *Router) ServeHTTP(w http.ResponseWriter, req *http.Request) { r.geoRemoveAppOverride(w, req, extractName(path, "/geo/override")) default: + r.dbg("no matching route: %s %s", req.Method, path) writeJSON(w, http.StatusNotFound, apiResponse{OK: false, Error: "endpoint not found"}) } } @@ -340,6 +356,7 @@ func (r *Router) getDeployFields(w http.ResponseWriter, _ *http.Request, name st func (r *Router) deployStack(w http.ResponseWriter, req *http.Request, name string) { limitBody(w, req) r.logger.Printf("[API] Deploy requested for stack: %s", name) + r.dbg("deployStack: name=%s contentLength=%d", name, req.ContentLength) var body struct { Values map[string]string `json:"values"` @@ -396,6 +413,7 @@ func (r *Router) deployStack(w http.ResponseWriter, req *http.Request, name stri func (r *Router) actionStack(w http.ResponseWriter, action, name string) { r.logger.Printf("[API] %s requested for stack: %s", action, name) + r.dbg("actionStack: action=%s name=%s", action, name) // Protected stacks only allow restart — block all other actions if r.cfg.IsProtectedStack(name) && action != "restart" { @@ -587,6 +605,7 @@ func (r *Router) removeStack(w http.ResponseWriter, req *http.Request, name stri } limitBody(w, req) r.logger.Printf("[API] Remove requested for stack: %s", name) + r.dbg("removeStack: name=%s", name) var body struct { RemoveHDDData bool `json:"remove_hdd_data"` @@ -596,6 +615,7 @@ func (r *Router) removeStack(w http.ResponseWriter, req *http.Request, name stri body.RemoveHDDData = false body.RemoveBackups = false } + r.dbg("removeStack: name=%s removeHDDData=%v removeBackups=%v", name, body.RemoveHDDData, body.RemoveBackups) // Compute backup paths to remove if requested var backupPaths []string @@ -750,12 +770,14 @@ func (r *Router) backupStatus(w http.ResponseWriter, _ *http.Request) { } func (r *Router) triggerBackup(w http.ResponseWriter, _ *http.Request) { + r.dbg("triggerBackup: backupMgr=%v", r.backupMgr != nil) if r.backupMgr == nil { writeJSON(w, http.StatusBadRequest, apiResponse{OK: false, Error: "Backup not configured"}) return } if r.backupMgr.IsRunning() { + r.dbg("triggerBackup: backup already running, rejecting") writeJSON(w, http.StatusConflict, apiResponse{OK: false, Error: "Mentés már folyamatban"}) return } @@ -1130,6 +1152,7 @@ func (r *Router) selfupdateTrigger(w http.ResponseWriter, _ *http.Request) { // --- Config apply handler --- func (r *Router) configApply(w http.ResponseWriter, req *http.Request) { + r.dbg("configApply: contentLength=%d remoteAddr=%s", req.ContentLength, req.RemoteAddr) // Read YAML body (limit to 1MB) body, err := io.ReadAll(io.LimitReader(req.Body, 1<<20)) if err != nil { diff --git a/controller/internal/appexport/crypto.go b/controller/internal/appexport/crypto.go new file mode 100644 index 0000000..59f46bd --- /dev/null +++ b/controller/internal/appexport/crypto.go @@ -0,0 +1,228 @@ +package appexport + +import ( + "crypto/aes" + "crypto/cipher" + "crypto/hmac" + "crypto/rand" + "crypto/sha256" + "errors" + "fmt" + "io" + "os" + + "golang.org/x/crypto/scrypt" +) + +const ( + magicHeader = "FABE" // Felhom App Bundle Encrypted + scryptN = 1 << 15 // 32768 + scryptR = 8 + scryptP = 1 + saltSize = 32 + aesKeySize = 32 + hmacKeySize = 32 + ivSize = aes.BlockSize // 16 +) + +// deriveKeys derives an AES-256 key and HMAC-SHA256 key from password + salt. +func deriveKeys(password string, salt []byte) (aesKey, hmacKey []byte, err error) { + derived, err := scrypt.Key([]byte(password), salt, scryptN, scryptR, scryptP, aesKeySize+hmacKeySize) + if err != nil { + return nil, nil, err + } + return derived[:aesKeySize], derived[aesKeySize:], nil +} + +// IsEncryptedFAB checks if a file starts with the "FABE" magic header. +func IsEncryptedFAB(path string) (bool, error) { + f, err := os.Open(path) + if err != nil { + return false, err + } + defer f.Close() + + magic := make([]byte, 4) + n, err := f.Read(magic) + if err != nil || n < 4 { + return false, nil + } + return string(magic) == magicHeader, nil +} + +// EncryptFile encrypts a plaintext file with a password. +// Uses AES-256-CTR + HMAC-SHA256 with scrypt key derivation. +// Format: "FABE" (4) || salt (32) || IV (16) || encrypted_data || HMAC-SHA256 (32) +func EncryptFile(inputPath, outputPath, password string) error { + in, err := os.Open(inputPath) + if err != nil { + return fmt.Errorf("open input: %w", err) + } + defer in.Close() + + out, err := os.Create(outputPath) + if err != nil { + return fmt.Errorf("create output: %w", err) + } + defer out.Close() + + salt := make([]byte, saltSize) + if _, err := rand.Read(salt); err != nil { + return fmt.Errorf("generating salt: %w", err) + } + iv := make([]byte, ivSize) + if _, err := rand.Read(iv); err != nil { + return fmt.Errorf("generating IV: %w", err) + } + + aesKey, hmKey, err := deriveKeys(password, salt) + if err != nil { + return fmt.Errorf("deriving keys: %w", err) + } + + block, err := aes.NewCipher(aesKey) + if err != nil { + return err + } + stream := cipher.NewCTR(block, iv) + mac := hmac.New(sha256.New, hmKey) + + // Write header (magic is NOT in HMAC; salt + IV are) + if _, err := out.Write([]byte(magicHeader)); err != nil { + return err + } + mac.Write(salt) + if _, err := out.Write(salt); err != nil { + return err + } + mac.Write(iv) + if _, err := out.Write(iv); err != nil { + return err + } + + // Encrypt and stream data + buf := make([]byte, 64*1024) + for { + n, readErr := in.Read(buf) + if n > 0 { + encrypted := make([]byte, n) + stream.XORKeyStream(encrypted, buf[:n]) + mac.Write(encrypted) + if _, err := out.Write(encrypted); err != nil { + return err + } + } + if readErr == io.EOF { + break + } + if readErr != nil { + return fmt.Errorf("read: %w", readErr) + } + } + + // Append HMAC tag + if _, err := out.Write(mac.Sum(nil)); err != nil { + return err + } + return out.Sync() +} + +// DecryptFile decrypts an encrypted .fab file with a password. +// Returns a clear error if the password is wrong or the file is corrupted. +func DecryptFile(inputPath, outputPath, password string) error { + in, err := os.Open(inputPath) + if err != nil { + return fmt.Errorf("open input: %w", err) + } + defer in.Close() + + // Verify magic header + magic := make([]byte, 4) + if _, err := io.ReadFull(in, magic); err != nil { + return fmt.Errorf("reading header: %w", err) + } + if string(magic) != magicHeader { + return errors.New("not an encrypted FAB file") + } + + // Read salt and IV + salt := make([]byte, saltSize) + if _, err := io.ReadFull(in, salt); err != nil { + return fmt.Errorf("reading salt: %w", err) + } + iv := make([]byte, ivSize) + if _, err := io.ReadFull(in, iv); err != nil { + return fmt.Errorf("reading IV: %w", err) + } + + // Calculate data size (total - header - HMAC tag) + stat, err := in.Stat() + if err != nil { + return err + } + headerSize := int64(4 + saltSize + ivSize) + tagSize := int64(sha256.Size) + dataSize := stat.Size() - headerSize - tagSize + if dataSize < 0 { + return errors.New("file too small to be valid") + } + + aesKey, hmKey, err := deriveKeys(password, salt) + if err != nil { + return fmt.Errorf("deriving keys: %w", err) + } + + mac := hmac.New(sha256.New, hmKey) + mac.Write(salt) + mac.Write(iv) + + block, err := aes.NewCipher(aesKey) + if err != nil { + return err + } + stream := cipher.NewCTR(block, iv) + + out, err := os.Create(outputPath) + if err != nil { + return fmt.Errorf("create output: %w", err) + } + defer out.Close() + + // Decrypt data section + buf := make([]byte, 64*1024) + remaining := dataSize + for remaining > 0 { + toRead := int64(len(buf)) + if toRead > remaining { + toRead = remaining + } + n, readErr := in.Read(buf[:toRead]) + if n > 0 { + mac.Write(buf[:n]) + decrypted := make([]byte, n) + stream.XORKeyStream(decrypted, buf[:n]) + if _, err := out.Write(decrypted); err != nil { + return err + } + remaining -= int64(n) + } + if readErr == io.EOF { + break + } + if readErr != nil { + return fmt.Errorf("read: %w", readErr) + } + } + + // Verify HMAC tag + storedMAC := make([]byte, sha256.Size) + if _, err := io.ReadFull(in, storedMAC); err != nil { + return fmt.Errorf("reading HMAC: %w", err) + } + if !hmac.Equal(mac.Sum(nil), storedMAC) { + os.Remove(outputPath) + return errors.New("jelszó hibás vagy a fájl sérült") + } + + return out.Sync() +} diff --git a/controller/internal/appexport/estimate.go b/controller/internal/appexport/estimate.go new file mode 100644 index 0000000..a2128cc --- /dev/null +++ b/controller/internal/appexport/estimate.go @@ -0,0 +1,177 @@ +package appexport + +import ( + "context" + "fmt" + "os" + "os/exec" + "path/filepath" + "strings" + "time" +) + +// ExportEstimate holds pre-export size and space estimation. +type ExportEstimate struct { + ConfigSizeBytes int64 `json:"config_size_bytes"` + ConfigSizeHuman string `json:"config_size_human"` + DataSizeBytes int64 `json:"data_size_bytes"` + DataSizeHuman string `json:"data_size_human"` + TotalSizeBytes int64 `json:"total_size_bytes"` + TotalSizeHuman string `json:"total_size_human"` + EstimatedMinutes int `json:"estimated_minutes"` + DestFreeBytes int64 `json:"dest_free_bytes"` + DestFreeHuman string `json:"dest_free_human"` + FitsOnDest bool `json:"fits_on_dest"` +} + +// EstimateExport calculates size estimates for an app export. +func (e *Exporter) EstimateExport(stackName, destDrive string) (*ExportEstimate, error) { + stackDir, ok := e.provider.GetStackDir(stackName) + if !ok { + return nil, fmt.Errorf("stack %q not found", stackName) + } + + e.debugf("EstimateExport: stack=%s stackDir=%s destDrive=%s", stackName, stackDir, destDrive) + est := &ExportEstimate{} + + // Config size: sum of all files in the stack directory + est.ConfigSizeBytes = dirSize(stackDir) + est.ConfigSizeHuman = humanizeBytes(est.ConfigSizeBytes) + e.debugf("EstimateExport: configSize=%s (%d bytes)", est.ConfigSizeHuman, est.ConfigSizeBytes) + + // Data size: HDD bind mounts or Docker volumes + if e.provider.GetStackNeedsHDD(stackName) { + mounts := e.provider.GetStackHDDMounts(stackName) + e.debugf("EstimateExport: HDD mounts: %v", mounts) + for _, mount := range mounts { + mountSize := duBytes(mount) + e.debugf("EstimateExport: mount %s = %s", mount, humanizeBytes(mountSize)) + est.DataSizeBytes += mountSize + } + } else { + volumes := e.provider.GetDockerVolumes(stackName) + e.debugf("EstimateExport: Docker volumes: %v", volumes) + for _, vol := range volumes { + volSize := dockerVolumeSize(vol) + e.debugf("EstimateExport: volume %s = %s", vol, humanizeBytes(volSize)) + est.DataSizeBytes += volSize + } + } + est.DataSizeHuman = humanizeBytes(est.DataSizeBytes) + + est.TotalSizeBytes = est.ConfigSizeBytes + est.DataSizeBytes + est.TotalSizeHuman = humanizeBytes(est.TotalSizeBytes) + + // Rough time estimate: ~500 MB/min for HDDs, minimum 1 minute + minutes := int(est.TotalSizeBytes / (500 * 1024 * 1024)) + if minutes < 1 { + minutes = 1 + } + est.EstimatedMinutes = minutes + + // Destination free space + exportDir := ExportDir(destDrive) + os.MkdirAll(exportDir, 0755) + est.DestFreeBytes = diskFree(exportDir) + est.DestFreeHuman = humanizeBytes(est.DestFreeBytes) + + // Need ~10% overhead for tar.gz metadata + compression margin + needed := est.TotalSizeBytes + est.TotalSizeBytes/10 + est.FitsOnDest = est.DestFreeBytes >= needed + + e.debugf("EstimateExport: total=%s free=%s fits=%v needed=%s minutes=%d", + est.TotalSizeHuman, est.DestFreeHuman, est.FitsOnDest, humanizeBytes(needed), est.EstimatedMinutes) + + return est, nil +} + +// dirSize returns the total size of all files in a directory (non-recursive for config dirs). +func dirSize(dir string) int64 { + var total int64 + entries, err := os.ReadDir(dir) + if err != nil { + return 0 + } + for _, e := range entries { + if e.IsDir() { + continue + } + info, err := e.Info() + if err != nil { + continue + } + total += info.Size() + } + return total +} + +// duBytes runs du -sb on a path and returns the byte count. +func duBytes(path string) int64 { + ctx, cancel := context.WithTimeout(context.Background(), 30*time.Second) + defer cancel() + out, err := exec.CommandContext(ctx, "du", "-sb", path).Output() + if err != nil { + return 0 + } + var size int64 + fmt.Sscanf(strings.Fields(string(out))[0], "%d", &size) + return size +} + +// dockerVolumeSize estimates the size of a Docker named volume. +func dockerVolumeSize(volumeName string) int64 { + ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) + defer cancel() + // Use docker system df -v and parse, or inspect the volume mount path + out, err := exec.CommandContext(ctx, "docker", "volume", "inspect", + "--format", "{{.Mountpoint}}", volumeName).Output() + if err != nil { + return 0 + } + mountpoint := strings.TrimSpace(string(out)) + if mountpoint == "" { + return 0 + } + return duBytes(mountpoint) +} + +// diskFree returns available bytes on the filesystem containing path. +func diskFree(path string) int64 { + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + out, err := exec.CommandContext(ctx, "df", "--output=avail", "-B1", path).Output() + if err != nil { + return 0 + } + lines := strings.Split(strings.TrimSpace(string(out)), "\n") + if len(lines) < 2 { + return 0 + } + var size int64 + fmt.Sscanf(strings.TrimSpace(lines[1]), "%d", &size) + return size +} + +// ExportDir returns the exports directory on a drive. +func ExportDir(drivePath string) string { + return filepath.Join(drivePath, "felhom-data", "exports") +} + +// humanizeBytes converts bytes to human-readable format. +func humanizeBytes(b int64) string { + const ( + KB = 1024 + MB = KB * 1024 + GB = MB * 1024 + ) + switch { + case b >= GB: + return fmt.Sprintf("%.1f GB", float64(b)/float64(GB)) + case b >= MB: + return fmt.Sprintf("%.1f MB", float64(b)/float64(MB)) + case b >= KB: + return fmt.Sprintf("%.1f KB", float64(b)/float64(KB)) + default: + return fmt.Sprintf("%d B", b) + } +} diff --git a/controller/internal/appexport/export.go b/controller/internal/appexport/export.go new file mode 100644 index 0000000..6b5d867 --- /dev/null +++ b/controller/internal/appexport/export.go @@ -0,0 +1,793 @@ +package appexport + +import ( + "archive/tar" + "compress/gzip" + "context" + "fmt" + "io" + "log" + "os" + "os/exec" + "path/filepath" + "strings" + "sync" + "time" + + "gitea.dooplex.hu/admin/felhom-controller/internal/backup" +) + +// Step tracks one step of an export/import operation. +type Step struct { + Label string `json:"label"` + Status string `json:"status"` // "pending", "running", "done", "failed" + Error string `json:"error,omitempty"` +} + +// Job tracks an in-progress export or import operation. +type Job struct { + mu sync.RWMutex + + StackName string `json:"stack_name"` + DisplayName string `json:"display_name"` + Steps []Step `json:"steps"` + Running bool `json:"running"` + Done bool `json:"done"` + Error string `json:"error,omitempty"` + OutputPath string `json:"output_path,omitempty"` + OutputSize string `json:"output_size,omitempty"` + JobType string `json:"job_type"` // "export" or "import" +} + +// Snapshot returns a thread-safe copy for JSON serialization. +func (j *Job) Snapshot() map[string]interface{} { + j.mu.RLock() + defer j.mu.RUnlock() + steps := make([]Step, len(j.Steps)) + copy(steps, j.Steps) + return map[string]interface{}{ + "ok": true, + "running": j.Running, + "done": j.Done, + "error": j.Error, + "steps": steps, + "output_path": j.OutputPath, + "output_size": j.OutputSize, + "stack_name": j.StackName, + "display_name": j.DisplayName, + "job_type": j.JobType, + } +} + +func (j *Job) setStep(idx int, status, errMsg string) { + j.mu.Lock() + defer j.mu.Unlock() + if idx < len(j.Steps) { + j.Steps[idx].Status = status + j.Steps[idx].Error = errMsg + } +} + +// ExportRequest holds user-provided parameters for an export. +type ExportRequest struct { + StackName string + DestDrive string // drive mount path (e.g., "/mnt/hdd_1") + Password string // empty = no encryption + StopApp bool // stop app before export +} + +// Exporter manages app export/import operations. +type Exporter struct { + provider ExportStackProvider + logger *log.Logger + version string + debug bool + + mu sync.Mutex + activeJob *Job +} + +// NewExporter creates a new export/import engine. +func NewExporter(provider ExportStackProvider, logger *log.Logger, version string) *Exporter { + return &Exporter{ + provider: provider, + logger: logger, + version: version, + } +} + +// SetDebug enables or disables verbose debug logging. +func (e *Exporter) SetDebug(debug bool) { + e.debug = debug +} + +// debugf logs a message only when debug mode is enabled. +func (e *Exporter) debugf(format string, args ...interface{}) { + if e.debug { + e.logger.Printf("[DEBUG] [appexport] "+format, args...) + } +} + +// IsRunning returns true if an export/import is in progress. +func (e *Exporter) IsRunning() bool { + e.mu.Lock() + defer e.mu.Unlock() + return e.activeJob != nil && e.activeJob.Running +} + +// GetActiveJob returns the current job (for status polling). +func (e *Exporter) GetActiveJob() *Job { + e.mu.Lock() + defer e.mu.Unlock() + return e.activeJob +} + +// StartExport validates and starts an async export. Returns error if blocked. +func (e *Exporter) StartExport(req ExportRequest) error { + e.mu.Lock() + if e.activeJob != nil && e.activeJob.Running { + e.mu.Unlock() + e.debugf("StartExport rejected: another job is already running") + return fmt.Errorf("export or import already in progress") + } + + if !e.provider.IsStackDeployed(req.StackName) { + e.mu.Unlock() + e.debugf("StartExport rejected: stack %q is not deployed", req.StackName) + return fmt.Errorf("stack %q is not deployed", req.StackName) + } + + e.debugf("StartExport: stack=%q dest=%q password=%v stopApp=%v", + req.StackName, req.DestDrive, req.Password != "", req.StopApp) + + steps := []Step{ + {Label: "Előkészítés", Status: "pending"}, + {Label: "Konfiguráció mentése", Status: "pending"}, + {Label: "Adatbázis mentése", Status: "pending"}, + {Label: "Felhasználói adatok", Status: "pending"}, + {Label: "Csomag készítése", Status: "pending"}, + } + if req.Password != "" { + steps = append(steps, Step{Label: "Titkosítás", Status: "pending"}) + } + + job := &Job{ + StackName: req.StackName, + DisplayName: e.provider.GetStackDisplayName(req.StackName), + Steps: steps, + Running: true, + JobType: "export", + } + e.activeJob = job + e.mu.Unlock() + + go e.executeExport(req, job) + return nil +} + +func (e *Exporter) executeExport(req ExportRequest, job *Job) { + exportStart := time.Now() + e.debugf("=== EXPORT START: stack=%q dest=%q encrypted=%v stopApp=%v ===", + req.StackName, req.DestDrive, req.Password != "", req.StopApp) + + defer func() { + job.mu.Lock() + job.Running = false + job.Done = true + job.mu.Unlock() + e.debugf("=== EXPORT END: stack=%q elapsed=%v ===", req.StackName, time.Since(exportStart)) + }() + + step := 0 + + // --- Step 0: Preparation --- + job.setStep(step, "running", "") + stepStart := time.Now() + + destDir := ExportDir(req.DestDrive) + e.debugf("export dest dir: %s", destDir) + if err := os.MkdirAll(destDir, 0755); err != nil { + e.failJob(job, step, fmt.Sprintf("Nem sikerült létrehozni az export könyvtárat: %v", err)) + return + } + + // Check free space + est, err := e.EstimateExport(req.StackName, req.DestDrive) + if err != nil { + e.debugf("estimate error (non-fatal): %v", err) + } else { + e.debugf("estimate: config=%s data=%s total=%s destFree=%s fits=%v", + est.ConfigSizeHuman, est.DataSizeHuman, est.TotalSizeHuman, est.DestFreeHuman, est.FitsOnDest) + if !est.FitsOnDest { + e.failJob(job, step, fmt.Sprintf("Nincs elég hely: szükséges ~%s, szabad %s", + est.TotalSizeHuman, est.DestFreeHuman)) + return + } + } + + // Optionally stop the app + wasRunning := false + if req.StopApp && e.provider.IsStackRunning(req.StackName) { + wasRunning = true + e.logger.Printf("[INFO] Export: stopping %s", req.StackName) + e.debugf("stopping stack %s before export", req.StackName) + if err := e.provider.StopStack(req.StackName); err != nil { + e.logger.Printf("[WARN] Export: could not stop %s: %v", req.StackName, err) + } else { + e.debugf("stack %s stopped successfully", req.StackName) + } + } else { + e.debugf("skip stop: stopApp=%v isRunning=%v", req.StopApp, e.provider.IsStackRunning(req.StackName)) + } + // Always restart after export if we stopped it + if wasRunning { + defer func() { + e.logger.Printf("[INFO] Export: restarting %s", req.StackName) + e.debugf("restarting stack %s after export", req.StackName) + if err := e.provider.StartStack(req.StackName); err != nil { + e.logger.Printf("[WARN] Export: could not restart %s: %v", req.StackName, err) + } else { + e.debugf("stack %s restarted successfully", req.StackName) + } + }() + } + + e.debugf("step 0 (preparation) done in %v", time.Since(stepStart)) + job.setStep(step, "done", "") + step++ + + // --- Step 1: Config files --- + job.setStep(step, "running", "") + stepStart = time.Now() + + tmpDir, err := os.MkdirTemp("", "felhom-export-*") + if err != nil { + e.failJob(job, step, fmt.Sprintf("Temp könyvtár hiba: %v", err)) + return + } + e.debugf("temp dir: %s", tmpDir) + defer os.RemoveAll(tmpDir) + + configDir := filepath.Join(tmpDir, "config") + if err := os.MkdirAll(configDir, 0755); err != nil { + e.failJob(job, step, err.Error()) + return + } + + stackDir, ok := e.provider.GetStackDir(req.StackName) + if !ok { + e.failJob(job, step, "Stack könyvtár nem található") + return + } + e.debugf("stack dir: %s", stackDir) + + configFiles, err := copyStackConfig(stackDir, configDir, req.StackName, e.provider) + if err != nil { + e.failJob(job, step, fmt.Sprintf("Konfiguráció mentése sikertelen: %v", err)) + return + } + e.debugf("config files copied: %v (%d files)", configFiles, len(configFiles)) + e.debugf("step 1 (config) done in %v", time.Since(stepStart)) + + job.setStep(step, "done", "") + step++ + + // --- Step 2: Database dump --- + job.setStep(step, "running", "") + stepStart = time.Now() + + dbDir := filepath.Join(tmpDir, "database") + os.MkdirAll(dbDir, 0755) + + manifest := &Manifest{ + Version: ManifestVersion, + AppName: req.StackName, + DisplayName: e.provider.GetStackDisplayName(req.StackName), + ExportedAt: time.Now().UTC(), + ControllerVer: e.version, + NeedsHDD: e.provider.GetStackNeedsHDD(req.StackName), + Encrypted: req.Password != "", + ConfigFiles: configFiles, + } + e.debugf("manifest: app=%s display=%s needsHDD=%v encrypted=%v", + manifest.AppName, manifest.DisplayName, manifest.NeedsHDD, manifest.Encrypted) + + dbDumped := e.dumpDatabase(req.StackName, dbDir, manifest) + if !dbDumped { + e.debugf("no database found for %s — skipping DB step", req.StackName) + os.Remove(dbDir) + } else { + e.debugf("database dumped: type=%s", manifest.DBType) + // Log the dump file size + entries, _ := os.ReadDir(dbDir) + for _, entry := range entries { + if info, err := entry.Info(); err == nil { + e.debugf(" db dump file: %s (%s)", entry.Name(), humanizeBytes(info.Size())) + } + } + } + e.debugf("step 2 (database) done in %v", time.Since(stepStart)) + + job.setStep(step, "done", "") + step++ + + // --- Step 3: User data --- + job.setStep(step, "running", "") + stepStart = time.Now() + + dataDir := filepath.Join(tmpDir, "data") + os.MkdirAll(dataDir, 0755) + + if e.provider.GetStackNeedsHDD(req.StackName) { + e.debugf("exporting HDD data for %s", req.StackName) + e.exportHDDData(req.StackName, dataDir, manifest) + e.debugf("HDD data exported: subdirs=%v hasData=%v", manifest.HDDSubdirs, manifest.HasHDDData) + } else { + e.debugf("exporting Docker volumes for %s", req.StackName) + e.exportVolumeData(req.StackName, dataDir, manifest) + e.debugf("volume data exported: volumes=%v hasData=%v", manifest.VolumeNames, manifest.HasVolumeData) + } + e.debugf("step 3 (user data) done in %v", time.Since(stepStart)) + + job.setStep(step, "done", "") + step++ + + // --- Step 4: Create .fab bundle --- + job.setStep(step, "running", "") + stepStart = time.Now() + + // Calculate total size + manifest.TotalSizeBytes = calcDirSize(tmpDir) + e.debugf("total bundle content size: %s (%d bytes)", humanizeBytes(manifest.TotalSizeBytes), manifest.TotalSizeBytes) + + // Write manifest.json to tmpDir root + manifestData, err := manifest.Marshal() + if err != nil { + e.failJob(job, step, fmt.Sprintf("Manifest hiba: %v", err)) + return + } + e.debugf("manifest JSON: %d bytes", len(manifestData)) + if err := os.WriteFile(filepath.Join(tmpDir, "manifest.json"), manifestData, 0644); err != nil { + e.failJob(job, step, err.Error()) + return + } + + timestamp := time.Now().Format("20060102-150405") + fabName := fmt.Sprintf("%s_%s.fab", req.StackName, timestamp) + fabPath := filepath.Join(destDir, fabName) + e.debugf("target .fab path: %s", fabPath) + + // Build tar.gz (to .tmp if encrypting, to final path if not) + targetPath := fabPath + if req.Password != "" { + targetPath = fabPath + ".tgz.tmp" + } else { + targetPath = fabPath + ".tmp" + } + + e.debugf("creating tar.gz: %s", targetPath) + tgzStart := time.Now() + if err := createTarGz(targetPath, tmpDir); err != nil { + os.Remove(targetPath) + e.failJob(job, step, fmt.Sprintf("Csomag készítése sikertelen: %v", err)) + return + } + if tgzInfo, err := os.Stat(targetPath); err == nil { + e.debugf("tar.gz created: %s (%s) in %v", targetPath, humanizeBytes(tgzInfo.Size()), time.Since(tgzStart)) + } + + job.setStep(step, "done", "") + step++ + + // --- Step 5: Encrypt (optional) --- + if req.Password != "" { + job.setStep(step, "running", "") + encStart := time.Now() + + encPath := fabPath + ".tmp" + e.debugf("encrypting: %s → %s", targetPath, encPath) + if err := EncryptFile(targetPath, encPath, req.Password); err != nil { + os.Remove(targetPath) + e.failJob(job, step, fmt.Sprintf("Titkosítás sikertelen: %v", err)) + return + } + os.Remove(targetPath) + targetPath = encPath + if encInfo, err := os.Stat(encPath); err == nil { + e.debugf("encryption done: %s in %v", humanizeBytes(encInfo.Size()), time.Since(encStart)) + } + + job.setStep(step, "done", "") + } + + // Atomic rename to final path + e.debugf("atomic rename: %s → %s", targetPath, fabPath) + if err := os.Rename(targetPath, fabPath); err != nil { + e.failJob(job, step, fmt.Sprintf("Fájl átnevezés sikertelen: %v", err)) + return + } + + // Record result + stat, _ := os.Stat(fabPath) + job.mu.Lock() + job.OutputPath = fabPath + if stat != nil { + job.OutputSize = humanizeBytes(stat.Size()) + } + job.mu.Unlock() + + e.logger.Printf("[INFO] Export completed: %s → %s (%s) in %v", req.StackName, fabPath, job.OutputSize, time.Since(exportStart)) +} + +func (e *Exporter) failJob(job *Job, stepIdx int, msg string) { + job.setStep(stepIdx, "failed", msg) + job.mu.Lock() + job.Error = msg + job.mu.Unlock() + e.logger.Printf("[ERROR] Export/import failed at step %d: %s", stepIdx, msg) + e.debugf("FAIL at step %d: %s", stepIdx, msg) +} + +// GetDebugInfo returns diagnostic information about the exporter state. +func (e *Exporter) GetDebugInfo() map[string]interface{} { + e.mu.Lock() + defer e.mu.Unlock() + + info := map[string]interface{}{ + "debug_enabled": e.debug, + "version": e.version, + "has_active_job": e.activeJob != nil, + } + + if e.activeJob != nil { + info["active_job"] = e.activeJob.Snapshot() + } + + return info +} + +// copyStackConfig copies all relevant config files from the stack dir. +// app.yaml is saved with decrypted (plaintext) secrets for portability. +func copyStackConfig(stackDir, configDir, stackName string, provider ExportStackProvider) ([]string, error) { + var copied []string + + entries, err := os.ReadDir(stackDir) + if err != nil { + return nil, err + } + + for _, entry := range entries { + if entry.IsDir() { + continue + } + name := entry.Name() + // Skip temp files + if strings.HasSuffix(name, ".tmp") { + continue + } + + src := filepath.Join(stackDir, name) + dst := filepath.Join(configDir, name) + + // app.yaml: save with plaintext secrets + if name == "app.yaml" { + env := provider.GetDecryptedEnv(stackName) + if env != nil { + if err := writeDecryptedAppYaml(dst, env); err != nil { + return nil, fmt.Errorf("writing decrypted app.yaml: %w", err) + } + copied = append(copied, name) + continue + } + } + + // Copy file as-is + if err := copyFile(src, dst); err != nil { + return nil, fmt.Errorf("copying %s: %w", name, err) + } + copied = append(copied, name) + } + + return copied, nil +} + +// writeDecryptedAppYaml writes a plaintext app.yaml with the given env map. +func writeDecryptedAppYaml(dst string, env map[string]string) error { + var sb strings.Builder + sb.WriteString("# Exported by felhom-controller — plaintext secrets\n") + sb.WriteString("deployed: true\n") + sb.WriteString("env:\n") + for k, v := range env { + // YAML-safe: quote values + sb.WriteString(fmt.Sprintf(" %s: %q\n", k, v)) + } + return os.WriteFile(dst, []byte(sb.String()), 0644) +} + +// dumpDatabase discovers and dumps the database for a stack. +func (e *Exporter) dumpDatabase(stackName, dbDir string, manifest *Manifest) bool { + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Minute) + defer cancel() + + e.debugf("discovering databases (looking for stack %s)...", stackName) + dbs, err := backup.DiscoverDatabases(ctx, e.logger, e.debug) + if err != nil { + e.logger.Printf("[WARN] Export: DB discovery error: %v", err) + return false + } + e.debugf("found %d databases total", len(dbs)) + for i := range dbs { + e.debugf(" db[%d]: stack=%s container=%s type=%s", i, dbs[i].StackName, dbs[i].ContainerName, dbs[i].DBType) + } + + var stackDB *backup.DiscoveredDB + for i := range dbs { + if dbs[i].StackName == stackName { + stackDB = &dbs[i] + break + } + } + if stackDB == nil { + e.debugf("no database container found for stack %s", stackName) + return false + } + e.debugf("matched DB: container=%s type=%s", stackDB.ContainerName, stackDB.DBType) + + dumpStart := time.Now() + result := backup.DumpOne(ctx, *stackDB, dbDir, e.logger, e.debug) + if result.Error != nil { + e.logger.Printf("[WARN] Export: DB dump failed for %s: %v", stackName, result.Error) + return false + } + e.debugf("DB dump completed in %v: %s", time.Since(dumpStart), result.FilePath) + + // Gzip the dump + if result.FilePath != "" { + gzPath := result.FilePath + ".gz" + gzStart := time.Now() + if err := gzipFile(result.FilePath, gzPath); err != nil { + e.logger.Printf("[WARN] Export: gzip dump failed: %v", err) + } else { + if origInfo, _ := os.Stat(result.FilePath); origInfo != nil { + if gzInfo, _ := os.Stat(gzPath); gzInfo != nil { + e.debugf("gzip: %s → %s (ratio %.1f%%) in %v", + humanizeBytes(origInfo.Size()), humanizeBytes(gzInfo.Size()), + float64(gzInfo.Size())/float64(origInfo.Size())*100, time.Since(gzStart)) + } + } + os.Remove(result.FilePath) + } + } + + manifest.HasDatabase = true + manifest.DBType = string(stackDB.DBType) + + return true +} + +// exportHDDData copies HDD bind mount data for the export. +func (e *Exporter) exportHDDData(stackName, dataDir string, manifest *Manifest) { + hddDir := filepath.Join(dataDir, "hdd") + os.MkdirAll(hddDir, 0755) + + mounts := e.provider.GetStackHDDMounts(stackName) + e.debugf("HDD mounts for %s: %v (%d total)", stackName, mounts, len(mounts)) + if len(mounts) == 0 { + e.debugf("no HDD mounts — skipping HDD data export") + return + } + + for _, mount := range mounts { + if _, err := os.Stat(mount); os.IsNotExist(err) { + e.debugf("HDD mount %s does not exist — skipping", mount) + continue + } + subdir := filepath.Base(mount) + manifest.HDDSubdirs = append(manifest.HDDSubdirs, subdir) + + tarPath := filepath.Join(hddDir, subdir+".tar") + e.debugf("tarring HDD mount: %s → %s", mount, tarPath) + tarStart := time.Now() + if err := tarDirectory(mount, tarPath); err != nil { + e.logger.Printf("[WARN] Export: failed to tar %s: %v", mount, err) + } else { + if info, _ := os.Stat(tarPath); info != nil { + e.debugf("HDD tar complete: %s (%s) in %v", subdir, humanizeBytes(info.Size()), time.Since(tarStart)) + } + } + } + manifest.HasHDDData = len(manifest.HDDSubdirs) > 0 +} + +// exportVolumeData exports Docker named volumes for apps without HDD storage. +func (e *Exporter) exportVolumeData(stackName, dataDir string, manifest *Manifest) { + volDir := filepath.Join(dataDir, "volumes") + os.MkdirAll(volDir, 0755) + + volumes := e.provider.GetDockerVolumes(stackName) + e.debugf("Docker volumes for %s: %v (%d total)", stackName, volumes, len(volumes)) + if len(volumes) == 0 { + e.debugf("no Docker volumes — skipping volume data export") + return + } + + for _, volName := range volumes { + tarPath := filepath.Join(volDir, volName+".tar") + e.debugf("exporting volume %s via docker run alpine tar...", volName) + volStart := time.Now() + + ctx, cancel := context.WithTimeout(context.Background(), 10*time.Minute) + cmd := exec.CommandContext(ctx, "docker", "run", "--rm", + "-v", volName+":/vol:ro", + "-v", volDir+":/out", + "alpine", "tar", "cf", "/out/"+volName+".tar", "-C", "/vol", ".") + out, err := cmd.CombinedOutput() + cancel() + + if err != nil { + e.logger.Printf("[WARN] Export: volume %s export failed: %s — %v", + volName, strings.TrimSpace(string(out)), err) + e.debugf("volume %s export failed: %s", volName, strings.TrimSpace(string(out))) + os.Remove(tarPath) + continue + } + if info, _ := os.Stat(tarPath); info != nil { + e.debugf("volume %s exported: %s in %v", volName, humanizeBytes(info.Size()), time.Since(volStart)) + } + manifest.VolumeNames = append(manifest.VolumeNames, volName) + } + manifest.HasVolumeData = len(manifest.VolumeNames) > 0 +} + +// createTarGz creates a gzipped tar archive of a directory. +func createTarGz(outputPath, sourceDir string) error { + outFile, err := os.Create(outputPath) + if err != nil { + return err + } + defer outFile.Close() + + gw := gzip.NewWriter(outFile) + defer gw.Close() + + tw := tar.NewWriter(gw) + defer tw.Close() + + return filepath.Walk(sourceDir, func(path string, info os.FileInfo, err error) error { + if err != nil { + return err + } + + // Get path relative to sourceDir + relPath, err := filepath.Rel(sourceDir, path) + if err != nil { + return err + } + if relPath == "." { + return nil + } + + header, err := tar.FileInfoHeader(info, "") + if err != nil { + return err + } + header.Name = relPath + + if err := tw.WriteHeader(header); err != nil { + return err + } + + if info.IsDir() { + return nil + } + + f, err := os.Open(path) + if err != nil { + return err + } + defer f.Close() + _, err = io.Copy(tw, f) + return err + }) +} + +// tarDirectory creates a tar (not gzipped) of a directory's contents. +func tarDirectory(sourceDir, outputPath string) error { + outFile, err := os.Create(outputPath) + if err != nil { + return err + } + defer outFile.Close() + + tw := tar.NewWriter(outFile) + defer tw.Close() + + return filepath.Walk(sourceDir, func(path string, info os.FileInfo, err error) error { + if err != nil { + return err + } + relPath, err := filepath.Rel(sourceDir, path) + if err != nil { + return err + } + if relPath == "." { + return nil + } + + header, err := tar.FileInfoHeader(info, "") + if err != nil { + return err + } + header.Name = relPath + + if err := tw.WriteHeader(header); err != nil { + return err + } + + if info.IsDir() { + return nil + } + + f, err := os.Open(path) + if err != nil { + return err + } + defer f.Close() + _, err = io.Copy(tw, f) + return err + }) +} + +// gzipFile compresses a file with gzip. +func gzipFile(src, dst string) error { + in, err := os.Open(src) + if err != nil { + return err + } + defer in.Close() + + out, err := os.Create(dst) + if err != nil { + return err + } + defer out.Close() + + gw := gzip.NewWriter(out) + defer gw.Close() + + _, err = io.Copy(gw, in) + return err +} + +// copyFile copies a file from src to dst. +func copyFile(src, dst string) error { + in, err := os.Open(src) + if err != nil { + return err + } + defer in.Close() + + out, err := os.Create(dst) + if err != nil { + return err + } + defer out.Close() + + if _, err := io.Copy(out, in); err != nil { + return err + } + return out.Sync() +} + +// calcDirSize recursively calculates total file size in a directory. +func calcDirSize(dir string) int64 { + var total int64 + filepath.Walk(dir, func(_ string, info os.FileInfo, err error) error { + if err != nil || info.IsDir() { + return nil + } + total += info.Size() + return nil + }) + return total +} diff --git a/controller/internal/appexport/manifest.go b/controller/internal/appexport/manifest.go new file mode 100644 index 0000000..937af37 --- /dev/null +++ b/controller/internal/appexport/manifest.go @@ -0,0 +1,42 @@ +package appexport + +import ( + "encoding/json" + "time" +) + +// ManifestVersion is the current bundle format version. +const ManifestVersion = 1 + +// Manifest is the JSON metadata stored inside a .fab file. +type Manifest struct { + Version int `json:"version"` + AppName string `json:"app_name"` + DisplayName string `json:"display_name"` + ExportedAt time.Time `json:"exported_at"` + ControllerVer string `json:"controller_version"` + NeedsHDD bool `json:"needs_hdd"` + Encrypted bool `json:"encrypted"` + HasDatabase bool `json:"has_database"` + HasHDDData bool `json:"has_hdd_data"` + HasVolumeData bool `json:"has_volume_data"` + DBType string `json:"db_type,omitempty"` + TotalSizeBytes int64 `json:"total_size_bytes"` + ConfigFiles []string `json:"config_files"` + VolumeNames []string `json:"volume_names,omitempty"` + HDDSubdirs []string `json:"hdd_subdirs,omitempty"` +} + +// Marshal returns the manifest as indented JSON. +func (m *Manifest) Marshal() ([]byte, error) { + return json.MarshalIndent(m, "", " ") +} + +// UnmarshalManifest parses a manifest from JSON bytes. +func UnmarshalManifest(data []byte) (*Manifest, error) { + var m Manifest + if err := json.Unmarshal(data, &m); err != nil { + return nil, err + } + return &m, nil +} diff --git a/controller/internal/appexport/provider.go b/controller/internal/appexport/provider.go new file mode 100644 index 0000000..47968b1 --- /dev/null +++ b/controller/internal/appexport/provider.go @@ -0,0 +1,52 @@ +// Package appexport provides per-app export/import via .fab bundles. +// A .fab file is a tar.gz (optionally password-encrypted) containing an app's +// config, database dump, and all user data — everything needed to restore +// the app to its current state. +package appexport + +// ExportStackProvider provides stack data without circular imports. +// Implemented by exportAdapter in main.go (same pattern as backup.StackDataProvider). +type ExportStackProvider interface { + // GetStackDir returns the stack's directory path (e.g., /opt/docker/stacks/nextcloud). + GetStackDir(name string) (string, bool) + // GetStackComposePath returns the compose file path. + GetStackComposePath(name string) (string, bool) + // GetStackHDDMounts returns resolved HDD bind mount host paths for the stack. + GetStackHDDMounts(name string) []string + // GetStackHDDPath returns the raw HDD_PATH env var from app.yaml. + GetStackHDDPath(name string) string + // IsStackRunning returns true if the stack has running containers. + IsStackRunning(name string) bool + // StopStack stops the stack via docker compose down. + StopStack(name string) error + // StartStack starts the stack via docker compose up -d. + StartStack(name string) error + // GetStackDisplayName returns the human-readable name from .felhom.yml. + GetStackDisplayName(name string) string + // GetStackNeedsHDD returns true if the app requires HDD storage. + GetStackNeedsHDD(name string) bool + // GetDockerVolumes returns named Docker volume names from the compose file. + GetDockerVolumes(name string) []string + // IsStackDeployed returns true if the stack has a saved app.yaml config. + IsStackDeployed(name string) bool + // GetDecryptedEnv returns the decrypted env var map from app.yaml. + GetDecryptedEnv(name string) map[string]string + + // --- Import-specific methods --- + + // GetStacksBaseDir returns the base directory where stacks live (e.g., /opt/docker/stacks). + GetStacksBaseDir() string + // SaveEncryptedAppConfig saves app.yaml with re-encrypted sensitive fields. + // env is the plaintext env map from the bundle; encryption uses the current server key. + SaveEncryptedAppConfig(stackDir string, env map[string]string) error + // RefreshStacks rescans all stacks and refreshes container state. + RefreshStacks() error + // RemoveStackVolumes stops the stack and removes its named Docker volumes. + RemoveStackVolumes(name string) error +} + +// DrivePathInfo holds a registered storage path and its label. +type DrivePathInfo struct { + Path string + Label string +} diff --git a/controller/internal/appexport/restore.go b/controller/internal/appexport/restore.go new file mode 100644 index 0000000..eb23853 --- /dev/null +++ b/controller/internal/appexport/restore.go @@ -0,0 +1,1119 @@ +package appexport + +import ( + "archive/tar" + "compress/gzip" + "context" + "fmt" + "io" + "os" + "os/exec" + "path/filepath" + "strconv" + "strings" + "time" +) + +// ScannedBundle describes a .fab file found on a storage drive. +type ScannedBundle struct { + Path string `json:"path"` + FileName string `json:"file_name"` + AppName string `json:"app_name"` + DisplayName string `json:"display_name"` + ExportedAt string `json:"exported_at"` + SizeBytes int64 `json:"size_bytes"` + SizeHuman string `json:"size_human"` + Encrypted bool `json:"encrypted"` + NeedsHDD bool `json:"needs_hdd"` + HasDB bool `json:"has_db"` + DrivePath string `json:"drive_path"` + DriveLabel string `json:"drive_label"` +} + +// ImportRequest holds user-provided parameters for an import. +type ImportRequest struct { + FABPath string // full path to .fab file + Password string // empty for unencrypted bundles +} + +// ScanForBundles scans export directories on all registered drives for .fab files. +// Pass a non-nil logger to enable debug output. +func ScanForBundles(drives []DrivePathInfo) []ScannedBundle { + var bundles []ScannedBundle + + for _, drive := range drives { + exportDir := ExportDir(drive.Path) + entries, err := os.ReadDir(exportDir) + if err != nil { + continue + } + + for _, entry := range entries { + if entry.IsDir() || !strings.HasSuffix(entry.Name(), ".fab") { + continue + } + + path := filepath.Join(exportDir, entry.Name()) + info, err := entry.Info() + if err != nil { + continue + } + + bundle := ScannedBundle{ + Path: path, + FileName: entry.Name(), + SizeBytes: info.Size(), + SizeHuman: humanizeBytes(info.Size()), + DrivePath: drive.Path, + DriveLabel: drive.Label, + } + + // Check encryption + encrypted, _ := IsEncryptedFAB(path) + bundle.Encrypted = encrypted + + // Try to read manifest for metadata (unencrypted only) + var manifest *Manifest + if !encrypted { + manifest, _ = ReadManifestFromFAB(path) + } + + if manifest != nil { + bundle.AppName = manifest.AppName + bundle.DisplayName = manifest.DisplayName + bundle.ExportedAt = manifest.ExportedAt.Format("2006-01-02 15:04") + bundle.NeedsHDD = manifest.NeedsHDD + bundle.HasDB = manifest.HasDatabase + } else { + // Parse app name from filename: {appname}_{timestamp}.fab + name := strings.TrimSuffix(entry.Name(), ".fab") + if idx := strings.LastIndex(name, "_"); idx > 0 { + bundle.AppName = name[:idx] + } else { + bundle.AppName = name + } + bundle.ExportedAt = info.ModTime().Format("2006-01-02 15:04") + } + + bundles = append(bundles, bundle) + } + } + + return bundles +} + +// ScanForStaleTempFiles finds stale .fab.tmp and .tgz.tmp files in export directories. +func ScanForStaleTempFiles(drives []DrivePathInfo) []string { + var stale []string + for _, drive := range drives { + exportDir := ExportDir(drive.Path) + entries, err := os.ReadDir(exportDir) + if err != nil { + continue + } + for _, entry := range entries { + if entry.IsDir() { + continue + } + name := entry.Name() + if strings.HasSuffix(name, ".tmp") || strings.HasSuffix(name, ".tgz.tmp") { + stale = append(stale, filepath.Join(exportDir, name)) + } + } + } + return stale +} + +// ReadManifestFromFAB reads the manifest from an unencrypted .fab file. +func ReadManifestFromFAB(fabPath string) (*Manifest, error) { + f, err := os.Open(fabPath) + if err != nil { + return nil, err + } + defer f.Close() + + gr, err := gzip.NewReader(f) + if err != nil { + return nil, fmt.Errorf("not a valid gzip: %w", err) + } + defer gr.Close() + + tr := tar.NewReader(gr) + for { + hdr, err := tr.Next() + if err == io.EOF { + return nil, fmt.Errorf("manifest.json not found in bundle") + } + if err != nil { + return nil, err + } + if hdr.Name == "manifest.json" { + data, err := io.ReadAll(tr) + if err != nil { + return nil, err + } + return UnmarshalManifest(data) + } + } +} + +// ReadManifestFromEncryptedFAB decrypts and reads the manifest from an encrypted .fab file. +func ReadManifestFromEncryptedFAB(fabPath, password string) (*Manifest, error) { + tmpFile, err := os.CreateTemp("", "fab-manifest-*.tgz") + if err != nil { + return nil, err + } + tmpPath := tmpFile.Name() + tmpFile.Close() + defer os.Remove(tmpPath) + + if err := DecryptFile(fabPath, tmpPath, password); err != nil { + return nil, fmt.Errorf("visszafejtés sikertelen: %w", err) + } + + return ReadManifestFromFAB(tmpPath) +} + +// StartImport validates and starts an async import. Returns error if blocked. +func (e *Exporter) StartImport(req ImportRequest) error { + e.mu.Lock() + if e.activeJob != nil && e.activeJob.Running { + e.mu.Unlock() + e.debugf("StartImport rejected: another job is already running") + return fmt.Errorf("export or import already in progress") + } + + // Validate file exists + info, err := os.Stat(req.FABPath) + if err != nil { + e.mu.Unlock() + e.debugf("StartImport rejected: file not found: %s", req.FABPath) + return fmt.Errorf("bundle file not found: %w", err) + } + + e.debugf("StartImport: path=%s size=%s encrypted=%v", + req.FABPath, humanizeBytes(info.Size()), req.Password != "") + + steps := []Step{ + {Label: "Csomag megnyitása", Status: "pending"}, + {Label: "Alkalmazás előkészítése", Status: "pending"}, + {Label: "Konfiguráció visszaállítása", Status: "pending"}, + {Label: "Felhasználói adatok visszaállítása", Status: "pending"}, + {Label: "Adatbázis visszaállítása", Status: "pending"}, + {Label: "Alkalmazás indítása", Status: "pending"}, + } + + job := &Job{ + StackName: filepath.Base(req.FABPath), + Steps: steps, + Running: true, + JobType: "import", + } + e.activeJob = job + e.mu.Unlock() + + go e.executeImport(req, job) + return nil +} + +func (e *Exporter) executeImport(req ImportRequest, job *Job) { + importStart := time.Now() + e.debugf("=== IMPORT START: path=%s encrypted=%v ===", req.FABPath, req.Password != "") + + defer func() { + job.mu.Lock() + job.Running = false + job.Done = true + job.mu.Unlock() + e.debugf("=== IMPORT END: elapsed=%v ===", time.Since(importStart)) + }() + + step := 0 + + // --- Step 0: Open bundle --- + job.setStep(step, "running", "") + stepStart := time.Now() + + encrypted, _ := IsEncryptedFAB(req.FABPath) + e.debugf("bundle encrypted: %v", encrypted) + tgzPath := req.FABPath + + // Decrypt if needed + if encrypted { + if req.Password == "" { + e.failJob(job, step, "Titkosított csomag — jelszó szükséges") + return + } + tmp, err := os.CreateTemp("", "fab-import-*.tgz") + if err != nil { + e.failJob(job, step, fmt.Sprintf("Temp fájl hiba: %v", err)) + return + } + tmpPath := tmp.Name() + tmp.Close() + defer os.Remove(tmpPath) + + e.debugf("decrypting bundle to %s", tmpPath) + decStart := time.Now() + if err := DecryptFile(req.FABPath, tmpPath, req.Password); err != nil { + e.failJob(job, step, fmt.Sprintf("Visszafejtés sikertelen: %v", err)) + return + } + if decInfo, _ := os.Stat(tmpPath); decInfo != nil { + e.debugf("decrypted in %v: %s", time.Since(decStart), humanizeBytes(decInfo.Size())) + } + tgzPath = tmpPath + } + + // Extract tar.gz to temp dir + tmpDir, err := os.MkdirTemp("", "felhom-import-*") + if err != nil { + e.failJob(job, step, fmt.Sprintf("Temp könyvtár hiba: %v", err)) + return + } + e.debugf("temp dir: %s", tmpDir) + defer os.RemoveAll(tmpDir) + + e.debugf("extracting tar.gz from %s", tgzPath) + extractStart := time.Now() + if err := extractTarGz(tgzPath, tmpDir); err != nil { + e.failJob(job, step, fmt.Sprintf("Csomag kicsomagolása sikertelen: %v", err)) + return + } + e.debugf("tar.gz extracted in %v", time.Since(extractStart)) + + // Log extracted contents + if e.debug { + filepath.Walk(tmpDir, func(path string, info os.FileInfo, err error) error { + if err != nil { + return nil + } + rel, _ := filepath.Rel(tmpDir, path) + if info.IsDir() { + e.debugf(" [dir] %s/", rel) + } else { + e.debugf(" [file] %s (%s)", rel, humanizeBytes(info.Size())) + } + return nil + }) + } + + // Read manifest + manifestData, err := os.ReadFile(filepath.Join(tmpDir, "manifest.json")) + if err != nil { + e.failJob(job, step, "manifest.json nem található a csomagban") + return + } + manifest, err := UnmarshalManifest(manifestData) + if err != nil { + e.failJob(job, step, fmt.Sprintf("Manifest hiba: %v", err)) + return + } + + e.debugf("manifest: app=%s display=%s version=%d controller=%s needsHDD=%v", + manifest.AppName, manifest.DisplayName, manifest.Version, manifest.ControllerVer, manifest.NeedsHDD) + e.debugf("manifest: hasDB=%v dbType=%s hasHDD=%v hasVolume=%v totalSize=%s", + manifest.HasDatabase, manifest.DBType, manifest.HasHDDData, manifest.HasVolumeData, + humanizeBytes(manifest.TotalSizeBytes)) + e.debugf("manifest: configFiles=%v volumes=%v hddSubdirs=%v", + manifest.ConfigFiles, manifest.VolumeNames, manifest.HDDSubdirs) + + // Update job with app info + job.mu.Lock() + job.StackName = manifest.AppName + job.DisplayName = manifest.DisplayName + job.mu.Unlock() + + e.logger.Printf("[INFO] Import: opening bundle for %s (%s)", manifest.AppName, manifest.DisplayName) + e.debugf("step 0 (open bundle) done in %v", time.Since(stepStart)) + + job.setStep(step, "done", "") + step++ + + // --- Step 1: Prepare app --- + job.setStep(step, "running", "") + stepStart = time.Now() + + stacksDir := e.provider.GetStacksBaseDir() + stackDir := filepath.Join(stacksDir, manifest.AppName) + e.debugf("stacksDir=%s stackDir=%s", stacksDir, stackDir) + + isDeployed := e.provider.IsStackDeployed(manifest.AppName) + isRunning := false + if isDeployed { + isRunning = e.provider.IsStackRunning(manifest.AppName) + } + e.debugf("existing stack: deployed=%v running=%v", isDeployed, isRunning) + + if isDeployed { + if isRunning { + e.logger.Printf("[INFO] Import: removing existing stack %s (with volumes)", manifest.AppName) + e.debugf("removing existing stack with volumes") + if err := e.provider.RemoveStackVolumes(manifest.AppName); err != nil { + e.logger.Printf("[WARN] Import: failed to remove stack volumes: %v", err) + e.debugf("RemoveStackVolumes failed: %v — trying just StopStack", err) + _ = e.provider.StopStack(manifest.AppName) + } else { + e.debugf("stack volumes removed successfully") + } + } else { + e.debugf("stack is deployed but not running — will overwrite config in place") + } + } else { + e.debugf("creating new stack directory: %s", stackDir) + if err := os.MkdirAll(stackDir, 0755); err != nil { + e.failJob(job, step, fmt.Sprintf("Könyvtár létrehozása sikertelen: %v", err)) + return + } + } + + e.debugf("step 1 (prepare app) done in %v", time.Since(stepStart)) + job.setStep(step, "done", "") + step++ + + // --- Step 2: Restore config --- + job.setStep(step, "running", "") + stepStart = time.Now() + + configDir := filepath.Join(tmpDir, "config") + e.debugf("restoring config from %s → %s", configDir, stackDir) + env, err := e.restoreConfig(configDir, stackDir, manifest) + if err != nil { + e.failJob(job, step, fmt.Sprintf("Konfiguráció visszaállítása sikertelen: %v", err)) + return + } + e.debugf("config restored: %d env vars", len(env)) + if e.debug { + for k := range env { + e.debugf(" env: %s=%s", k, maskSecret(k, env[k])) + } + } + + e.debugf("step 2 (restore config) done in %v", time.Since(stepStart)) + job.setStep(step, "done", "") + step++ + + // --- Step 3: Restore user data --- + job.setStep(step, "running", "") + stepStart = time.Now() + + composePath := filepath.Join(stackDir, "docker-compose.yml") + + if manifest.HasHDDData { + e.debugf("restoring HDD data: subdirs=%v", manifest.HDDSubdirs) + if err := e.restoreHDDData(tmpDir, manifest, composePath, env); err != nil { + e.failJob(job, step, fmt.Sprintf("HDD adatok visszaállítása sikertelen: %v", err)) + return + } + } else { + e.debugf("no HDD data in bundle — skipping") + } + + if manifest.HasVolumeData { + e.debugf("restoring Docker volumes: %v", manifest.VolumeNames) + if err := e.restoreVolumeData(tmpDir, manifest); err != nil { + e.failJob(job, step, fmt.Sprintf("Docker volume visszaállítása sikertelen: %v", err)) + return + } + } else { + e.debugf("no volume data in bundle — skipping") + } + + e.debugf("step 3 (restore user data) done in %v", time.Since(stepStart)) + job.setStep(step, "done", "") + step++ + + // --- Step 4: Restore database --- + job.setStep(step, "running", "") + stepStart = time.Now() + + if manifest.HasDatabase { + e.debugf("restoring database: type=%s", manifest.DBType) + if err := e.restoreDatabase(manifest, tmpDir, composePath, stackDir, env); err != nil { + e.failJob(job, step, fmt.Sprintf("Adatbázis visszaállítása sikertelen: %v", err)) + return + } + e.debugf("database restored successfully") + } else { + e.debugf("no database in bundle — skipping") + } + + e.debugf("step 4 (restore database) done in %v", time.Since(stepStart)) + job.setStep(step, "done", "") + step++ + + // --- Step 5: Start app --- + job.setStep(step, "running", "") + stepStart = time.Now() + + e.debugf("starting stack %s", manifest.AppName) + if err := e.provider.StartStack(manifest.AppName); err != nil { + e.failJob(job, step, fmt.Sprintf("Alkalmazás indítása sikertelen: %v", err)) + return + } + e.debugf("stack started in %v", time.Since(stepStart)) + + // Refresh stack list so UI sees the new/updated app + e.debugf("refreshing stack list") + if err := e.provider.RefreshStacks(); err != nil { + e.logger.Printf("[WARN] Import: refresh stacks failed: %v", err) + e.debugf("RefreshStacks error: %v", err) + } else { + e.debugf("stack list refreshed") + } + + job.setStep(step, "done", "") + + e.logger.Printf("[INFO] Import completed: %s (%s) in %v", manifest.AppName, manifest.DisplayName, time.Since(importStart)) +} + +// maskSecret masks sensitive env var values for debug logging. +func maskSecret(key, value string) string { + lower := strings.ToLower(key) + if strings.Contains(lower, "password") || strings.Contains(lower, "secret") || + strings.Contains(lower, "token") || strings.Contains(lower, "key") { + if len(value) <= 3 { + return "***" + } + return value[:2] + "***" + } + return value +} + +// restoreConfig extracts config files to the stack directory and re-encrypts app.yaml. +// Returns the plaintext env map for use in subsequent steps. +func (e *Exporter) restoreConfig(configDir, stackDir string, manifest *Manifest) (map[string]string, error) { + entries, err := os.ReadDir(configDir) + if err != nil { + return nil, fmt.Errorf("reading config dir: %w", err) + } + + e.debugf("restoreConfig: %d entries in config dir", len(entries)) + var env map[string]string + + for _, entry := range entries { + if entry.IsDir() { + continue + } + + src := filepath.Join(configDir, entry.Name()) + dst := filepath.Join(stackDir, entry.Name()) + + // app.yaml: read plaintext env, then re-encrypt via provider + if entry.Name() == "app.yaml" { + e.debugf("restoreConfig: reading plaintext app.yaml from bundle") + env, err = readPlaintextAppYaml(src) + if err != nil { + return nil, fmt.Errorf("reading app.yaml: %w", err) + } + e.debugf("restoreConfig: app.yaml has %d env vars, re-encrypting via provider", len(env)) + if err := e.provider.SaveEncryptedAppConfig(stackDir, env); err != nil { + return nil, fmt.Errorf("saving encrypted app.yaml: %w", err) + } + e.debugf("restoreConfig: app.yaml re-encrypted and saved") + continue + } + + // Copy other config files as-is + if info, _ := entry.Info(); info != nil { + e.debugf("restoreConfig: copying %s (%s)", entry.Name(), humanizeBytes(info.Size())) + } + if err := copyFile(src, dst); err != nil { + return nil, fmt.Errorf("copying %s: %w", entry.Name(), err) + } + } + + return env, nil +} + +// readPlaintextAppYaml parses the plaintext app.yaml written by the export. +func readPlaintextAppYaml(path string) (map[string]string, error) { + data, err := os.ReadFile(path) + if err != nil { + return nil, err + } + + env := make(map[string]string) + inEnv := false + + for _, line := range strings.Split(string(data), "\n") { + trimmed := strings.TrimSpace(line) + if trimmed == "" || strings.HasPrefix(trimmed, "#") { + continue + } + + if trimmed == "env:" { + inEnv = true + continue + } + + if inEnv && strings.HasPrefix(line, " ") { + parts := strings.SplitN(trimmed, ":", 2) + if len(parts) == 2 { + key := strings.TrimSpace(parts[0]) + val := strings.TrimSpace(parts[1]) + // Remove Go-style quotes (written by writeDecryptedAppYaml with %q) + if len(val) >= 2 && val[0] == '"' && val[len(val)-1] == '"' { + if unquoted, err := strconv.Unquote(val); err == nil { + val = unquoted + } + } + env[key] = val + } + } else if inEnv && !strings.HasPrefix(line, " ") { + inEnv = false + } + } + + return env, nil +} + +// restoreHDDData extracts HDD bind mount data from the bundle. +func (e *Exporter) restoreHDDData(tmpDir string, manifest *Manifest, composePath string, env map[string]string) error { + hddDir := filepath.Join(tmpDir, "data", "hdd") + + // Resolve HDD mount paths from compose file + hddPath := env["HDD_PATH"] + e.debugf("restoreHDDData: HDD_PATH=%s composePath=%s", hddPath, composePath) + mountByName := make(map[string]string) + + if hddPath != "" { + mounts := resolveHDDMounts(composePath, env) + e.debugf("restoreHDDData: resolved mounts: %v", mounts) + for _, m := range mounts { + mountByName[filepath.Base(m)] = m + } + } else { + e.debugf("restoreHDDData: HDD_PATH is empty — will use fallback paths") + } + + for _, subdir := range manifest.HDDSubdirs { + tarPath := filepath.Join(hddDir, subdir+".tar") + tarInfo, err := os.Stat(tarPath) + if err != nil { + e.logger.Printf("[WARN] Import: HDD tar not found: %s", tarPath) + e.debugf("restoreHDDData: tar not found: %s", tarPath) + continue + } + e.debugf("restoreHDDData: subdir=%s tarSize=%s", subdir, humanizeBytes(tarInfo.Size())) + + destPath := mountByName[subdir] + if destPath == "" { + if filepath.Base(hddPath) == subdir { + destPath = hddPath + } else { + destPath = filepath.Join(hddPath, subdir) + } + e.debugf("restoreHDDData: no mount match for %s, using fallback: %s", subdir, destPath) + } else { + e.debugf("restoreHDDData: mount match for %s → %s", subdir, destPath) + } + + if err := os.MkdirAll(destPath, 0755); err != nil { + return fmt.Errorf("creating %s: %w", destPath, err) + } + + e.logger.Printf("[INFO] Import: extracting HDD data %s → %s", subdir, destPath) + extractStart := time.Now() + if err := extractTar(tarPath, destPath); err != nil { + return fmt.Errorf("extracting %s: %w", subdir, err) + } + e.debugf("restoreHDDData: extracted %s in %v", subdir, time.Since(extractStart)) + } + + return nil +} + +// resolveHDDMounts parses compose volumes for HDD bind mounts and resolves env vars. +func resolveHDDMounts(composePath string, env map[string]string) []string { + data, err := os.ReadFile(composePath) + if err != nil { + return nil + } + + hddPath := env["HDD_PATH"] + if hddPath == "" { + return nil + } + + var mounts []string + seen := make(map[string]bool) + + for _, line := range strings.Split(string(data), "\n") { + trimmed := strings.TrimSpace(line) + if !strings.HasPrefix(trimmed, "- ") { + continue + } + vol := strings.TrimPrefix(trimmed, "- ") + // Parse "host:container" or "host:container:mode" + parts := strings.SplitN(vol, ":", 2) + if len(parts) < 2 { + continue + } + hostPart := parts[0] + if strings.Contains(hostPart, "${HDD_PATH}") { + resolved := strings.ReplaceAll(hostPart, "${HDD_PATH}", hddPath) + resolved = filepath.Clean(resolved) + if !seen[resolved] { + seen[resolved] = true + mounts = append(mounts, resolved) + } + } + } + + return mounts +} + +// restoreVolumeData recreates Docker named volumes from bundle tarballs. +func (e *Exporter) restoreVolumeData(tmpDir string, manifest *Manifest) error { + volDir := filepath.Join(tmpDir, "data", "volumes") + + for _, volName := range manifest.VolumeNames { + tarPath := filepath.Join(volDir, volName+".tar") + tarInfo, err := os.Stat(tarPath) + if err != nil { + e.logger.Printf("[WARN] Import: volume tar not found: %s", tarPath) + e.debugf("restoreVolumeData: tar not found: %s", tarPath) + continue + } + e.debugf("restoreVolumeData: volume=%s tarSize=%s", volName, humanizeBytes(tarInfo.Size())) + + // Create the Docker volume + e.debugf("restoreVolumeData: creating docker volume %s", volName) + ctx, cancel := context.WithTimeout(context.Background(), 30*time.Second) + out, err := exec.CommandContext(ctx, "docker", "volume", "create", volName).CombinedOutput() + cancel() + if err != nil { + return fmt.Errorf("creating volume %s: %s — %w", volName, strings.TrimSpace(string(out)), err) + } + e.debugf("restoreVolumeData: volume %s created: %s", volName, strings.TrimSpace(string(out))) + + // Populate volume from tar + e.logger.Printf("[INFO] Import: populating volume %s", volName) + e.debugf("restoreVolumeData: populating %s via docker run alpine tar xf...", volName) + popStart := time.Now() + ctx, cancel = context.WithTimeout(context.Background(), 10*time.Minute) + out, err = exec.CommandContext(ctx, "docker", "run", "--rm", + "-v", volName+":/vol", + "-v", volDir+":/in:ro", + "alpine", "tar", "xf", "/in/"+volName+".tar", "-C", "/vol").CombinedOutput() + cancel() + if err != nil { + return fmt.Errorf("populating volume %s: %s — %w", volName, strings.TrimSpace(string(out)), err) + } + e.debugf("restoreVolumeData: volume %s populated in %v", volName, time.Since(popStart)) + } + + return nil +} + +// restoreDatabase imports the database dump from the bundle. +func (e *Exporter) restoreDatabase(manifest *Manifest, tmpDir, composePath, stackDir string, env map[string]string) error { + dbDir := filepath.Join(tmpDir, "database") + + // Find the gzipped dump file + dumpGzPath, err := findDumpFile(dbDir) + if err != nil { + e.debugf("restoreDatabase: no dump file found in %s: %v", dbDir, err) + return err + } + if dumpInfo, _ := os.Stat(dumpGzPath); dumpInfo != nil { + e.debugf("restoreDatabase: dump file=%s size=%s", dumpGzPath, humanizeBytes(dumpInfo.Size())) + } + + // Find DB service in compose file + e.debugf("restoreDatabase: parsing compose for DB service: %s", composePath) + dbSvc := findDBServiceInCompose(composePath) + if dbSvc == nil { + e.debugf("restoreDatabase: no DB service found in compose file!") + return fmt.Errorf("no database service found in docker-compose.yml") + } + e.debugf("restoreDatabase: found DB service=%s type=%s container=%s", + dbSvc.ServiceName, dbSvc.DBType, dbSvc.ContainerName) + + // Start only the DB service + e.logger.Printf("[INFO] Import: starting DB service %s (%s)", dbSvc.ServiceName, dbSvc.DBType) + e.debugf("restoreDatabase: docker compose up -d %s", dbSvc.ServiceName) + out, err := composeExecEnv(stackDir, env, "up", "-d", dbSvc.ServiceName) + if err != nil { + e.debugf("restoreDatabase: compose up failed: %s", strings.TrimSpace(string(out))) + return fmt.Errorf("starting DB service: %w", err) + } + e.debugf("restoreDatabase: compose up output: %s", strings.TrimSpace(string(out))) + + // Ensure we stop the DB service after restore (full stack start is in the next step) + defer func() { + e.debugf("restoreDatabase: stopping DB service %s", dbSvc.ServiceName) + out, _ := composeExecEnv(stackDir, env, "stop", dbSvc.ServiceName) + e.debugf("restoreDatabase: compose stop output: %s", strings.TrimSpace(string(out))) + }() + + // Get the container ID + e.debugf("restoreDatabase: getting container ID for service %s", dbSvc.ServiceName) + containerID, err := getComposeContainerID(stackDir, env, dbSvc.ServiceName) + if err != nil { + e.debugf("restoreDatabase: failed to get container ID: %v", err) + return fmt.Errorf("getting container ID: %w", err) + } + e.debugf("restoreDatabase: container ID=%s", containerID) + + // Wait for DB readiness + e.logger.Printf("[INFO] Import: waiting for DB readiness (container %s)", containerID[:12]) + e.debugf("restoreDatabase: waiting for DB readiness...") + waitStart := time.Now() + if err := waitForDB(containerID, dbSvc.DBType, env); err != nil { + e.debugf("restoreDatabase: DB not ready after %v: %v", time.Since(waitStart), err) + return fmt.Errorf("waiting for DB: %w", err) + } + e.debugf("restoreDatabase: DB ready in %v", time.Since(waitStart)) + + // Import the dump + e.logger.Printf("[INFO] Import: importing database dump") + e.debugf("restoreDatabase: importing dump into container %s", containerID[:12]) + importStart := time.Now() + if err := importDBDump(containerID, dumpGzPath, dbSvc.DBType, env); err != nil { + e.debugf("restoreDatabase: import failed after %v: %v", time.Since(importStart), err) + return fmt.Errorf("importing dump: %w", err) + } + e.debugf("restoreDatabase: dump imported in %v", time.Since(importStart)) + + return nil +} + +// findDumpFile finds the gzipped SQL dump in the database directory. +func findDumpFile(dbDir string) (string, error) { + entries, err := os.ReadDir(dbDir) + if err != nil { + return "", fmt.Errorf("reading database dir: %w", err) + } + for _, entry := range entries { + if strings.HasSuffix(entry.Name(), ".sql.gz") || strings.HasSuffix(entry.Name(), ".sql") { + return filepath.Join(dbDir, entry.Name()), nil + } + } + return "", fmt.Errorf("no database dump file found") +} + +// dbServiceInfo describes a database service found in a compose file. +type dbServiceInfo struct { + ServiceName string + DBType string // "postgres" or "mariadb" + ContainerName string +} + +// findDBServiceInCompose parses a compose file to find the database service. +func findDBServiceInCompose(composePath string) *dbServiceInfo { + data, err := os.ReadFile(composePath) + if err != nil { + return nil + } + + inServices := false + currentService := "" + currentImage := "" + currentContainer := "" + + checkAndReturn := func() *dbServiceInfo { + if currentService != "" && currentImage != "" { + return classifyDBImage(currentService, currentImage, currentContainer) + } + return nil + } + + for _, line := range strings.Split(string(data), "\n") { + trimmed := strings.TrimSpace(line) + + // Top-level section detection + if len(line) > 0 && line[0] != ' ' && line[0] != '#' { + if strings.HasPrefix(trimmed, "services:") { + inServices = true + } else { + // Leaving services section — check last service + if info := checkAndReturn(); info != nil { + return info + } + inServices = false + } + continue + } + + if !inServices { + continue + } + + // Service name: 2-space indent, ends with colon, no further nesting + if strings.HasPrefix(line, " ") && !strings.HasPrefix(line, " ") && + strings.HasSuffix(trimmed, ":") && !strings.Contains(trimmed, " ") { + // Check previous service + if info := checkAndReturn(); info != nil { + return info + } + currentService = strings.TrimSuffix(trimmed, ":") + currentImage = "" + currentContainer = "" + continue + } + + // Properties at 4+ space indent + if strings.HasPrefix(trimmed, "image:") { + currentImage = strings.TrimSpace(strings.TrimPrefix(trimmed, "image:")) + } + if strings.HasPrefix(trimmed, "container_name:") { + currentContainer = strings.TrimSpace(strings.TrimPrefix(trimmed, "container_name:")) + } + } + + // Check last service + return checkAndReturn() +} + +func classifyDBImage(service, image, container string) *dbServiceInfo { + img := strings.ToLower(image) + if strings.Contains(img, "postgres") { + return &dbServiceInfo{ServiceName: service, DBType: "postgres", ContainerName: container} + } + if strings.Contains(img, "mariadb") || strings.Contains(img, "mysql") { + return &dbServiceInfo{ServiceName: service, DBType: "mariadb", ContainerName: container} + } + return nil +} + +// composeExecEnv runs docker compose in the given stack directory with env vars. +func composeExecEnv(stackDir string, env map[string]string, args ...string) ([]byte, error) { + cmdArgs := append([]string{"compose"}, args...) + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Minute) + defer cancel() + + cmd := exec.CommandContext(ctx, "docker", cmdArgs...) + cmd.Dir = stackDir + cmd.Env = os.Environ() + for k, v := range env { + cmd.Env = append(cmd.Env, k+"="+v) + } + return cmd.CombinedOutput() +} + +// getComposeContainerID returns the container ID for a compose service. +func getComposeContainerID(stackDir string, env map[string]string, service string) (string, error) { + // Wait a moment for the container to be created + time.Sleep(2 * time.Second) + + out, err := composeExecEnv(stackDir, env, "ps", "-q", service) + if err != nil { + return "", fmt.Errorf("compose ps: %w", err) + } + id := strings.TrimSpace(string(out)) + if id == "" { + return "", fmt.Errorf("no container found for service %s", service) + } + // Take the first line in case of multiple + if idx := strings.Index(id, "\n"); idx > 0 { + id = id[:idx] + } + return id, nil +} + +// waitForDB polls until the database is ready to accept connections. +func waitForDB(containerID, dbType string, env map[string]string) error { + timeout := 60 * time.Second + start := time.Now() + + for { + if time.Since(start) > timeout { + return fmt.Errorf("timeout waiting for %s to become ready", dbType) + } + + var cmd *exec.Cmd + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + + switch dbType { + case "postgres": + user := env["POSTGRES_USER"] + if user == "" { + user = "postgres" + } + cmd = exec.CommandContext(ctx, "docker", "exec", containerID, + "pg_isready", "-U", user) + case "mariadb": + password := env["MYSQL_ROOT_PASSWORD"] + if password == "" { + password = env["MARIADB_ROOT_PASSWORD"] + } + cmd = exec.CommandContext(ctx, "docker", "exec", containerID, + "mysqladmin", "ping", "-u", "root", "-p"+password) + default: + cancel() + return fmt.Errorf("unknown DB type: %s", dbType) + } + + err := cmd.Run() + cancel() + if err == nil { + return nil + } + + time.Sleep(2 * time.Second) + } +} + +// importDBDump imports a (possibly gzipped) SQL dump into the running database container. +func importDBDump(containerID, dumpPath, dbType string, env map[string]string) error { + // Open the dump file + f, err := os.Open(dumpPath) + if err != nil { + return err + } + defer f.Close() + + // If gzipped, wrap in gzip reader + var reader io.Reader = f + if strings.HasSuffix(dumpPath, ".gz") { + gr, err := gzip.NewReader(f) + if err != nil { + return fmt.Errorf("opening gzip: %w", err) + } + defer gr.Close() + reader = gr + } + + ctx, cancel := context.WithTimeout(context.Background(), 30*time.Minute) + defer cancel() + + var cmd *exec.Cmd + switch dbType { + case "postgres": + user := env["POSTGRES_USER"] + if user == "" { + user = "postgres" + } + dbName := env["POSTGRES_DB"] + if dbName == "" { + dbName = user + } + cmd = exec.CommandContext(ctx, "docker", "exec", "-i", containerID, + "psql", "-U", user, "-d", dbName) + case "mariadb": + password := env["MYSQL_ROOT_PASSWORD"] + if password == "" { + password = env["MARIADB_ROOT_PASSWORD"] + } + dbName := env["MYSQL_DATABASE"] + if dbName == "" { + dbName = env["MARIADB_DATABASE"] + } + cmd = exec.CommandContext(ctx, "docker", "exec", "-i", containerID, + "mysql", "-u", "root", "-p"+password, dbName) + default: + return fmt.Errorf("unknown DB type: %s", dbType) + } + + cmd.Stdin = reader + out, err := cmd.CombinedOutput() + if err != nil { + return fmt.Errorf("%s import failed: %s — %w", dbType, strings.TrimSpace(string(out)), err) + } + + return nil +} + +// extractTarGz extracts a tar.gz archive to a directory. +func extractTarGz(tgzPath, destDir string) error { + f, err := os.Open(tgzPath) + if err != nil { + return err + } + defer f.Close() + + gr, err := gzip.NewReader(f) + if err != nil { + return err + } + defer gr.Close() + + tr := tar.NewReader(gr) + for { + hdr, err := tr.Next() + if err == io.EOF { + return nil + } + if err != nil { + return err + } + + target := filepath.Join(destDir, hdr.Name) + + // Security: prevent path traversal + if !strings.HasPrefix(filepath.Clean(target), filepath.Clean(destDir)+string(os.PathSeparator)) { + continue + } + + switch hdr.Typeflag { + case tar.TypeDir: + if err := os.MkdirAll(target, os.FileMode(hdr.Mode)); err != nil { + return err + } + case tar.TypeReg: + if err := os.MkdirAll(filepath.Dir(target), 0755); err != nil { + return err + } + outFile, err := os.Create(target) + if err != nil { + return err + } + if _, err := io.Copy(outFile, tr); err != nil { + outFile.Close() + return err + } + outFile.Close() + os.Chmod(target, os.FileMode(hdr.Mode)) + } + } +} + +// extractTar extracts a plain tar archive to a directory. +func extractTar(tarPath, destDir string) error { + f, err := os.Open(tarPath) + if err != nil { + return err + } + defer f.Close() + + tr := tar.NewReader(f) + for { + hdr, err := tr.Next() + if err == io.EOF { + return nil + } + if err != nil { + return err + } + + target := filepath.Join(destDir, hdr.Name) + + // Security: prevent path traversal + if !strings.HasPrefix(filepath.Clean(target), filepath.Clean(destDir)+string(os.PathSeparator)) { + continue + } + + switch hdr.Typeflag { + case tar.TypeDir: + if err := os.MkdirAll(target, os.FileMode(hdr.Mode)); err != nil { + return err + } + case tar.TypeReg: + if err := os.MkdirAll(filepath.Dir(target), 0755); err != nil { + return err + } + outFile, err := os.Create(target) + if err != nil { + return err + } + if _, err := io.Copy(outFile, tr); err != nil { + outFile.Close() + return err + } + outFile.Close() + os.Chmod(target, os.FileMode(hdr.Mode)) + } + } +} diff --git a/controller/internal/assets/syncer.go b/controller/internal/assets/syncer.go index 89dde7a..2d65f9b 100644 --- a/controller/internal/assets/syncer.go +++ b/controller/internal/assets/syncer.go @@ -67,6 +67,12 @@ func New(hubURL, apiKey, assetsDir, fallbackDir string, logger *log.Logger, debu } } +func (s *Syncer) dbg(format string, args ...interface{}) { + if s.debug { + s.logger.Printf("[DEBUG] [assets] "+format, args...) + } +} + // Sync fetches the manifest from the Hub, compares checksums, and downloads // changed/new files. It also removes local files not in the Hub manifest. func (s *Syncer) Sync(ctx context.Context) error { @@ -85,6 +91,7 @@ func (s *Syncer) Sync(ctx context.Context) error { }() s.logger.Println("[INFO] Asset sync starting...") + syncStart := time.Now() if err := os.MkdirAll(s.assetsDir, 0755); err != nil { s.setError(fmt.Errorf("create assets dir: %w", err)) @@ -92,27 +99,24 @@ func (s *Syncer) Sync(ctx context.Context) error { } // 1. Fetch Hub manifest - if s.debug { - s.logger.Printf("[DEBUG] Asset sync: fetching manifest from %s/api/v1/assets/manifest", s.hubURL) - } + s.dbg("fetching manifest from %s/api/v1/assets/manifest", s.hubURL) + manifestStart := time.Now() manifest, err := s.fetchManifest(ctx) if err != nil { s.setError(fmt.Errorf("fetch manifest: %w", err)) return err } - if s.debug { - s.logger.Printf("[DEBUG] Asset sync: manifest has %d files", len(manifest.Files)) - } + s.dbg("manifest fetched in %s: %d files, generated=%s", + time.Since(manifestStart).Round(time.Millisecond), len(manifest.Files), manifest.Generated) // 2. Build local hash map + hashStart := time.Now() localHashes, err := s.buildLocalHashes() if err != nil { s.setError(fmt.Errorf("scan local assets: %w", err)) return err } - if s.debug { - s.logger.Printf("[DEBUG] Asset sync: %d local files found", len(localHashes)) - } + s.dbg("local hash scan: %d files in %s", len(localHashes), time.Since(hashStart).Round(time.Millisecond)) // 3. Download changed/new files hubFiles := make(map[string]bool, len(manifest.Files)) @@ -124,17 +128,22 @@ func (s *Syncer) Sync(ctx context.Context) error { totalBytes += entry.Size if localHash, ok := localHashes[entry.Filename]; ok && localHash == entry.SHA256 { + s.dbg("file %s: hash match (%s), skipping", entry.Filename, entry.SHA256[:12]+"...") skipped++ continue } - if s.debug { - s.logger.Printf("[DEBUG] Asset sync: downloading %s (remote sha256=%s)", entry.Filename, entry.SHA256[:12]+"...") + reason := "new" + if localHash, ok := localHashes[entry.Filename]; ok { + reason = fmt.Sprintf("hash mismatch (local=%s remote=%s)", localHash[:12]+"...", entry.SHA256[:12]+"...") } + s.dbg("file %s: downloading (%s, %d bytes)", entry.Filename, reason, entry.Size) + dlStart := time.Now() if err := s.downloadFile(ctx, entry.Filename); err != nil { s.logger.Printf("[WARN] Failed to download asset %s: %v", entry.Filename, err) continue } + s.dbg("file %s: downloaded in %s", entry.Filename, time.Since(dlStart).Round(time.Millisecond)) downloaded++ } @@ -143,9 +152,7 @@ func (s *Syncer) Sync(ctx context.Context) error { for name := range localHashes { if !hubFiles[name] { path := filepath.Join(s.assetsDir, name) - if s.debug { - s.logger.Printf("[DEBUG] Asset sync: removing stale file %s", name) - } + s.dbg("removing stale file %s", name) if err := os.Remove(path); err != nil { s.logger.Printf("[WARN] Failed to remove stale asset %s: %v", name, err) } else { @@ -169,6 +176,7 @@ func (s *Syncer) Sync(ctx context.Context) error { s.logger.Printf("[INFO] Asset sync complete: %d downloaded, %d unchanged, %d removed (%d total files)", downloaded, skipped, removed, len(manifest.Files)) + s.dbg("sync completed in %s", time.Since(syncStart).Round(time.Millisecond)) return nil } @@ -223,9 +231,11 @@ func (s *Syncer) fetchManifest(ctx context.Context) (*HubManifest, error) { resp, err := s.httpClient.Do(req) if err != nil { + s.dbg("fetchManifest: HTTP request failed: %v", err) return nil, fmt.Errorf("HTTP request: %w", err) } defer resp.Body.Close() + s.dbg("fetchManifest: HTTP %d, content-length=%d", resp.StatusCode, resp.ContentLength) if resp.StatusCode != http.StatusOK { body, _ := io.ReadAll(io.LimitReader(resp.Body, 512)) @@ -270,13 +280,16 @@ func (s *Syncer) downloadFile(ctx context.Context, filename string) error { resp, err := s.httpClient.Do(req) if err != nil { + s.dbg("downloadFile %s: HTTP request failed: %v", filename, err) return err } defer resp.Body.Close() if resp.StatusCode != http.StatusOK { + s.dbg("downloadFile %s: unexpected HTTP %d", filename, resp.StatusCode) return fmt.Errorf("HTTP %d for %s", resp.StatusCode, filename) } + s.dbg("downloadFile %s: HTTP %d, content-length=%d", filename, resp.StatusCode, resp.ContentLength) // Atomic write: write to .tmp, rename dst := filepath.Join(s.assetsDir, filepath.Base(filename)) diff --git a/controller/internal/backup/appdata.go b/controller/internal/backup/appdata.go index 25428da..e7f07b9 100644 --- a/controller/internal/backup/appdata.go +++ b/controller/internal/backup/appdata.go @@ -89,7 +89,7 @@ func DiscoverAppData(provider StackDataProvider, discoveredDBs []DiscoveredDB) [ info.HasHDDData = len(info.HDDPaths) > 0 // Discover Docker named volumes from compose - info.DockerVolumes = parseComposeNamedVolumes(stack.ComposePath) + info.DockerVolumes = ParseComposeNamedVolumes(stack.ComposePath) // Check if app has a DB container (already backed up via DB dump) for _, db := range discoveredDBs { @@ -108,8 +108,8 @@ func DiscoverAppData(provider StackDataProvider, discoveredDBs []DiscoveredDB) [ return result } -// parseComposeNamedVolumes extracts named Docker volumes from a docker-compose.yml. -func parseComposeNamedVolumes(composePath string) []AppDockerVolume { +// ParseComposeNamedVolumes extracts named Docker volumes from a docker-compose.yml. +func ParseComposeNamedVolumes(composePath string) []AppDockerVolume { data, err := os.ReadFile(composePath) if err != nil { return nil diff --git a/controller/internal/backup/backup.go b/controller/internal/backup/backup.go index a2c3b65..c1ce1f6 100644 --- a/controller/internal/backup/backup.go +++ b/controller/internal/backup/backup.go @@ -156,9 +156,11 @@ func NewManager(cfg *config.Config, pinger *monitor.Pinger, sett *settings.Setti if dataDir == "" { dataDir = "/opt/docker/felhom-controller/data" } + restic := NewResticManager(cfg, logger) + restic.SetDebug(cfg.Logging.Level == "debug") return &Manager{ cfg: cfg, - restic: NewResticManager(cfg, logger), + restic: restic, logger: logger, pinger: pinger, settings: sett, diff --git a/controller/internal/backup/restic.go b/controller/internal/backup/restic.go index 05bff34..f82af96 100644 --- a/controller/internal/backup/restic.go +++ b/controller/internal/backup/restic.go @@ -23,6 +23,7 @@ type ResticManager struct { logger *log.Logger customerID string cacheDir string + debug bool } // SnapshotResult holds the outcome of a restic backup. @@ -63,9 +64,17 @@ func NewResticManager(cfg *config.Config, logger *log.Logger) *ResticManager { } } +// SetDebug enables or disables debug logging. +func (r *ResticManager) SetDebug(debug bool) { + r.debug = debug +} + // EnsureInitialized checks if the restic repo exists and initializes it if not. // Also auto-generates the password file if missing. func (r *ResticManager) EnsureInitialized(repoPath string) error { + if r.debug { + r.logger.Printf("[DEBUG] [restic] EnsureInitialized: repoPath=%s, passwordFile=%s", repoPath, r.passwordFile) + } // Ensure password file exists if _, err := os.Stat(r.passwordFile); os.IsNotExist(err) { if err := r.generatePassword(); err != nil { @@ -109,6 +118,9 @@ func (r *ResticManager) Snapshot(repoPath string, paths []string, tags []string) defer cancel() start := time.Now() + if r.debug { + r.logger.Printf("[DEBUG] [restic] Snapshot: repo=%s, paths=%v, tags=%v", repoPath, paths, tags) + } args := []string{"backup", "--json"} for _, tag := range tags { @@ -129,6 +141,9 @@ func (r *ResticManager) Snapshot(repoPath string, paths []string, tags []string) if len(existingPaths) == 0 { return nil, fmt.Errorf("no backup paths exist") } + if r.debug { + r.logger.Printf("[DEBUG] [restic] Snapshot: %d/%d paths exist, backing up: %v", len(existingPaths), len(paths), existingPaths) + } args = append(args, existingPaths...) cmd := r.command(ctx, repoPath, args...) @@ -187,6 +202,11 @@ func (r *ResticManager) Snapshot(repoPath string, paths []string, tags []string) } } + if r.debug { + r.logger.Printf("[DEBUG] [restic] Snapshot: completed in %s, snapshotID=%s, filesNew=%d, filesChanged=%d, dataAdded=%s", + result.Duration, result.SnapshotID, result.FilesNew, result.FilesChanged, result.DataAdded) + } + return result, nil } @@ -195,6 +215,12 @@ func (r *ResticManager) Prune(repoPath string, retention config.RetentionConfig) ctx, cancel := context.WithTimeout(context.Background(), 30*time.Minute) defer cancel() + if r.debug { + r.logger.Printf("[DEBUG] [restic] Prune: repo=%s, keepDaily=%d, keepWeekly=%d, keepMonthly=%d", + repoPath, retention.KeepDaily, retention.KeepWeekly, retention.KeepMonthly) + } + + start := time.Now() args := []string{ "forget", "--keep-daily", fmt.Sprintf("%d", retention.KeepDaily), @@ -209,6 +235,9 @@ func (r *ResticManager) Prune(repoPath string, retention config.RetentionConfig) return fmt.Errorf("restic forget/prune failed: %v — %s", err, truncate(string(out), 200)) } + if r.debug { + r.logger.Printf("[DEBUG] [restic] Prune: completed in %s, output=%d bytes", time.Since(start), len(out)) + } r.logger.Printf("[INFO] Restic prune completed for %s", repoPath) return nil } @@ -218,11 +247,23 @@ func (r *ResticManager) Check(repoPath string) error { ctx, cancel := context.WithTimeout(context.Background(), 30*time.Minute) defer cancel() + if r.debug { + r.logger.Printf("[DEBUG] [restic] Check: repo=%s", repoPath) + } + start := time.Now() + cmd := r.command(ctx, repoPath, "check") out, err := cmd.CombinedOutput() if err != nil { + if r.debug { + r.logger.Printf("[DEBUG] [restic] Check: failed after %s, output=%s", time.Since(start), truncate(string(out), 300)) + } return fmt.Errorf("restic check failed: %v — %s", err, truncate(string(out), 200)) } + + if r.debug { + r.logger.Printf("[DEBUG] [restic] Check: repo=%s OK, completed in %s", repoPath, time.Since(start)) + } return nil } @@ -231,6 +272,10 @@ func (r *ResticManager) ListSnapshots(repoPath string, limit int) ([]SnapshotInf ctx, cancel := context.WithTimeout(context.Background(), 2*time.Minute) defer cancel() + if r.debug { + r.logger.Printf("[DEBUG] [restic] ListSnapshots: repo=%s, limit=%d", repoPath, limit) + } + cmd := r.command(ctx, repoPath, "snapshots", "--json") out, err := cmd.Output() if err != nil { @@ -251,6 +296,11 @@ func (r *ResticManager) ListSnapshots(repoPath string, limit int) ([]SnapshotInf snapshots = snapshots[:limit] } + if r.debug { + r.logger.Printf("[DEBUG] [restic] ListSnapshots: repo=%s, found %d total snapshots, returning %d", + repoPath, len(snapshots), len(snapshots)) + } + return snapshots, nil } @@ -259,6 +309,10 @@ func (r *ResticManager) LatestSnapshot(repoPath string) (*SnapshotInfo, error) { ctx, cancel := context.WithTimeout(context.Background(), 1*time.Minute) defer cancel() + if r.debug { + r.logger.Printf("[DEBUG] [restic] LatestSnapshot: repo=%s", repoPath) + } + cmd := r.command(ctx, repoPath, "snapshots", "--latest", "1", "--json") out, err := cmd.Output() if err != nil { @@ -271,9 +325,17 @@ func (r *ResticManager) LatestSnapshot(repoPath string) (*SnapshotInfo, error) { } if len(snapshots) == 0 { + if r.debug { + r.logger.Printf("[DEBUG] [restic] LatestSnapshot: repo=%s, no snapshots found", repoPath) + } return nil, nil } + if r.debug { + r.logger.Printf("[DEBUG] [restic] LatestSnapshot: repo=%s, id=%s, time=%s, paths=%v", + repoPath, snapshots[0].ID, snapshots[0].Time.Format(time.RFC3339), snapshots[0].Paths) + } + return &snapshots[0], nil } @@ -282,6 +344,11 @@ func (r *ResticManager) Stats(repoPath string) (*RepoStats, error) { ctx, cancel := context.WithTimeout(context.Background(), 2*time.Minute) defer cancel() + if r.debug { + r.logger.Printf("[DEBUG] [restic] Stats: repo=%s", repoPath) + } + start := time.Now() + stats := &RepoStats{} // Get repo size @@ -311,6 +378,15 @@ func (r *ResticManager) Stats(repoPath string) (*RepoStats, error) { } } + if r.debug { + latestID := "none" + if stats.LatestSnapshot != nil { + latestID = stats.LatestSnapshot.ID + } + r.logger.Printf("[DEBUG] [restic] Stats: repo=%s, totalSize=%s, snapshots=%d, latest=%s, took %s", + repoPath, stats.TotalSize, stats.SnapshotCount, latestID, time.Since(start)) + } + return stats, nil } @@ -336,6 +412,12 @@ func (r *ResticManager) RestoreAppData(repoPath string, snapshotID string, paths args = append(args, "--include", p) } + if r.debug { + r.logger.Printf("[DEBUG] [restic] RestoreAppData: repo=%s, snapshot=%s, %d include paths=%v", + repoPath, snapshotID, len(paths), paths) + } + start := time.Now() + r.logger.Printf("[WARN] RESTORE started: repo=%s, snapshot=%s, paths=%v", repoPath, snapshotID, paths) cmd := r.command(ctx, repoPath, args...) @@ -345,14 +427,22 @@ func (r *ResticManager) RestoreAppData(repoPath string, snapshotID string, paths return fmt.Errorf("restic restore failed: %w", err) } + if r.debug { + r.logger.Printf("[DEBUG] [restic] RestoreAppData: completed in %s, output=%d bytes", time.Since(start), len(output)) + } r.logger.Printf("[INFO] RESTORE completed: snapshot=%s, paths=%v", snapshotID, paths) return nil } // RepoExists checks if a restic repo is initialized at the given path. func (r *ResticManager) RepoExists(repoPath string) bool { + exists := false _, err := os.Stat(filepath.Join(repoPath, "config")) - return err == nil + exists = err == nil + if r.debug { + r.logger.Printf("[DEBUG] [restic] RepoExists: repo=%s, exists=%v", repoPath, exists) + } + return exists } // UnlockCommand returns an exec.Cmd that runs restic unlock on the given repo. @@ -361,6 +451,9 @@ func (r *ResticManager) UnlockCommand(ctx context.Context, repoPath string) *exe } func (r *ResticManager) command(ctx context.Context, repoPath string, args ...string) *exec.Cmd { + if r.debug { + r.logger.Printf("[DEBUG] [restic] command: restic %s (repo=%s)", strings.Join(args, " "), repoPath) + } cmd := exec.CommandContext(ctx, "restic", args...) cmd.Env = append(os.Environ(), "RESTIC_REPOSITORY="+repoPath, diff --git a/controller/internal/backup/restore_app_linux.go b/controller/internal/backup/restore_app_linux.go index 84aaa62..9432a0f 100644 --- a/controller/internal/backup/restore_app_linux.go +++ b/controller/internal/backup/restore_app_linux.go @@ -10,19 +10,26 @@ import ( "os/exec" "path/filepath" "strings" + "time" ) // RestoreAppFromBackup restores a single app from its cross-drive backup. // Steps: restore config → verify/restore data → copy DB dumps → docker compose up. func RestoreAppFromBackup(ctx context.Context, app *RestorableApp, stacksDir string, logger *log.Logger) error { stackDir := filepath.Join(stacksDir, app.Name) + start := time.Now() + + logger.Printf("[DEBUG] [backup] RestoreAppFromBackup: app=%s, stackDir=%s, hasConfig=%v, hasData=%v, hasDBDump=%v, hasRsyncData=%v", + app.Name, stackDir, app.HasConfig, app.HasData, app.HasDBDump, app.HasRsyncData) // Step 1: Restore stack config from _config/ backup if app.HasConfig { logger.Printf("[INFO] Restoring config for %s from %s", app.Name, app.ConfigPath) + stepStart := time.Now() if err := restoreConfigDir(ctx, app.ConfigPath, stackDir); err != nil { return fmt.Errorf("restoring config: %w", err) } + logger.Printf("[DEBUG] [backup] RestoreAppFromBackup: config restore for %s completed in %s", app.Name, time.Since(stepStart)) } else { // No config backup — check if stack dir already exists (from catalog sync) if !dirExists(stackDir) { @@ -35,20 +42,29 @@ func RestoreAppFromBackup(ctx context.Context, app *RestorableApp, stacksDir str if app.NeedsHDD && !app.HasData && app.HasRsyncData { // App data is missing but rsync backup exists — restore it logger.Printf("[INFO] Restoring user data for %s from rsync backup", app.Name) + stepStart := time.Now() if err := restoreUserData(ctx, app, logger); err != nil { logger.Printf("[WARN] User data restore failed for %s: %v", app.Name, err) // Non-fatal: app might still start without all data + } else { + logger.Printf("[DEBUG] [backup] RestoreAppFromBackup: user data restore for %s completed in %s", app.Name, time.Since(stepStart)) } } else if app.HasData { logger.Printf("[INFO] App data for %s found at %s — no restore needed", app.Name, app.DataPath) + } else { + logger.Printf("[DEBUG] [backup] RestoreAppFromBackup: %s — no user data to restore (needsHDD=%v, hasData=%v, hasRsyncData=%v)", + app.Name, app.NeedsHDD, app.HasData, app.HasRsyncData) } // Step 3: Copy DB dumps to primary backup location if app.HasDBDump { logger.Printf("[INFO] Restoring DB dumps for %s", app.Name) + stepStart := time.Now() if err := restoreDBDumps(app, logger); err != nil { logger.Printf("[WARN] DB dump restore failed for %s: %v", app.Name, err) // Non-fatal + } else { + logger.Printf("[DEBUG] [backup] RestoreAppFromBackup: DB dump restore for %s completed in %s", app.Name, time.Since(stepStart)) } } @@ -62,22 +78,30 @@ func RestoreAppFromBackup(ctx context.Context, app *RestorableApp, stacksDir str } composeDir := filepath.Dir(composePath) + logger.Printf("[DEBUG] [backup] RestoreAppFromBackup: %s using compose file %s", app.Name, composePath) logger.Printf("[INFO] Pulling images for %s", app.Name) + pullStart := time.Now() pullCmd := exec.CommandContext(ctx, "docker", "compose", "-f", composePath, "pull") pullCmd.Dir = composeDir if out, err := pullCmd.CombinedOutput(); err != nil { logger.Printf("[WARN] docker compose pull failed for %s: %v (%s)", app.Name, err, strings.TrimSpace(string(out))) // Non-fatal: might work with cached images + } else { + logger.Printf("[DEBUG] [backup] RestoreAppFromBackup: docker compose pull for %s completed in %s", app.Name, time.Since(pullStart)) } logger.Printf("[INFO] Starting %s", app.Name) + upStart := time.Now() upCmd := exec.CommandContext(ctx, "docker", "compose", "-f", composePath, "up", "-d") upCmd.Dir = composeDir if out, err := upCmd.CombinedOutput(); err != nil { return fmt.Errorf("docker compose up: %v (%s)", err, strings.TrimSpace(string(out))) } + logger.Printf("[DEBUG] [backup] RestoreAppFromBackup: %s fully restored and started in %s", app.Name, time.Since(start)) + logger.Printf("[DEBUG] [backup] RestoreAppFromBackup: docker compose up for %s completed in %s", app.Name, time.Since(upStart)) + return nil } @@ -103,6 +127,8 @@ func restoreUserData(ctx context.Context, app *RestorableApp, logger *log.Logger return fmt.Errorf("no rsync data path or HDD path") } + logger.Printf("[DEBUG] [backup] restoreUserData: app=%s, rsyncPath=%s, hddPath=%s", app.Name, app.RsyncDataPath, app.HDDPath) + // The rsync backup contains the app's data directories. // Walk the backup dir and rsync each subdirectory (excluding _config/_db) // back to the app's HDD data directory. @@ -112,10 +138,12 @@ func restoreUserData(ctx context.Context, app *RestorableApp, logger *log.Logger } dataDir := AppDataDir(app.HDDPath, app.Name) + logger.Printf("[DEBUG] [backup] restoreUserData: %s — target dataDir=%s, %d entries in backup", app.Name, dataDir, len(entries)) if err := os.MkdirAll(dataDir, 0755); err != nil { return fmt.Errorf("creating data dir: %w", err) } + restored := 0 for _, e := range entries { name := e.Name() if name == "_config" || name == "_db" || strings.HasPrefix(name, ".") { @@ -132,9 +160,12 @@ func restoreUserData(ctx context.Context, app *RestorableApp, logger *log.Logger continue } dst = strings.TrimRight(dst, "/") + "/" + logger.Printf("[DEBUG] [backup] restoreUserData: %s — rsync dir %s → %s", app.Name, src, dst) cmd := exec.CommandContext(ctx, "rsync", "-a", src, dst) if out, err := cmd.CombinedOutput(); err != nil { logger.Printf("[WARN] rsync data %s: %v (%s)", name, err, strings.TrimSpace(string(out))) + } else { + restored++ } } else { // Single file — copy directly @@ -143,12 +174,16 @@ func restoreUserData(ctx context.Context, app *RestorableApp, logger *log.Logger logger.Printf("[WARN] Cannot read %s: %v", src, err) continue } + logger.Printf("[DEBUG] [backup] restoreUserData: %s — copying file %s (%d bytes)", app.Name, name, len(data)) if err := os.WriteFile(dst, data, 0644); err != nil { logger.Printf("[WARN] Cannot write %s: %v", dst, err) + } else { + restored++ } } } + logger.Printf("[DEBUG] [backup] restoreUserData: %s — restored %d items", app.Name, restored) return nil } @@ -170,6 +205,7 @@ func restoreDBDumps(app *RestorableApp, logger *log.Logger) error { } destDir := AppDBDumpPath(drivePath, app.Name) + logger.Printf("[DEBUG] [backup] restoreDBDumps: app=%s, src=%s, destDir=%s", app.Name, app.DBDumpPath, destDir) if err := os.MkdirAll(destDir, 0755); err != nil { return fmt.Errorf("creating dump dir: %w", err) } @@ -179,6 +215,7 @@ func restoreDBDumps(app *RestorableApp, logger *log.Logger) error { return err } + copied := 0 for _, e := range entries { if e.IsDir() { continue @@ -190,11 +227,15 @@ func restoreDBDumps(app *RestorableApp, logger *log.Logger) error { logger.Printf("[WARN] Cannot read dump %s: %v", e.Name(), err) continue } + logger.Printf("[DEBUG] [backup] restoreDBDumps: %s — copying %s (%d bytes)", app.Name, e.Name(), len(data)) if err := os.WriteFile(dst, data, 0644); err != nil { logger.Printf("[WARN] Cannot write dump %s: %v", e.Name(), err) + } else { + copied++ } } + logger.Printf("[DEBUG] [backup] restoreDBDumps: %s — copied %d dump files", app.Name, copied) return nil } diff --git a/controller/internal/backup/restore_drives_linux.go b/controller/internal/backup/restore_drives_linux.go index 25e583c..68743e7 100644 --- a/controller/internal/backup/restore_drives_linux.go +++ b/controller/internal/backup/restore_drives_linux.go @@ -25,22 +25,38 @@ import ( // Returns the list of successfully mounted final mount paths. func MountDrivesFromLayout(ctx context.Context, layout DiskLayout, logger *log.Logger) ([]string, error) { if len(layout.Mounts) == 0 { + logger.Printf("[DEBUG] [backup] MountDrivesFromLayout: no mounts in layout, nothing to do") return nil, nil } + logger.Printf("[DEBUG] [backup] MountDrivesFromLayout: processing %d mount entries from disk layout", len(layout.Mounts)) + // Get current block devices with UUIDs uuidToDevice, err := scanBlockDeviceUUIDs(ctx) if err != nil { return nil, fmt.Errorf("scanning block devices: %w", err) } + logger.Printf("[DEBUG] [backup] MountDrivesFromLayout: discovered %d block devices with UUIDs", len(uuidToDevice)) + for uuid, dev := range uuidToDevice { + uuidShort := uuid + if len(uuidShort) > 12 { + uuidShort = uuidShort[:12] + } + logger.Printf("[DEBUG] [backup] MountDrivesFromLayout: device %s → UUID=%s...", dev, uuidShort) + } + var mounted []string for _, dm := range layout.Mounts { if dm.UUID == "" { + logger.Printf("[DEBUG] [backup] MountDrivesFromLayout: skipping mount entry with empty UUID (label=%s)", dm.Label) continue } + logger.Printf("[DEBUG] [backup] MountDrivesFromLayout: processing %s (UUID=%s, mountPoint=%s, rawMount=%s, fsType=%s)", + dm.Label, dm.UUID, dm.MountPoint, dm.RawMount, dm.FSType) + // Find matching device by UUID device := uuidToDevice[dm.UUID] if device == "" { @@ -72,12 +88,15 @@ func MountDrivesFromLayout(ctx context.Context, layout DiskLayout, logger *log.L // Mount using the appropriate pattern if dm.RawMount != "" && dm.BindSubdir != "" { // Two-layer HDD mount: raw → bind + logger.Printf("[DEBUG] [backup] MountDrivesFromLayout: %s — two-layer mount (raw=%s, bindSubdir=%s)", + dm.Label, dm.RawMount, dm.BindSubdir) if err := mountRawAndBind(ctx, device, dm, logger); err != nil { logger.Printf("[ERROR] Failed to mount %s: %v", dm.Label, err) continue } } else { // Simple direct mount (e.g., sys_drive) + logger.Printf("[DEBUG] [backup] MountDrivesFromLayout: %s — direct mount to %s", dm.Label, dm.MountPoint) if err := mountDirect(ctx, device, dm, logger); err != nil { logger.Printf("[ERROR] Failed to mount %s: %v", dm.Label, err) continue @@ -93,10 +112,11 @@ func MountDrivesFromLayout(ctx context.Context, layout DiskLayout, logger *log.L logger.Printf("[INFO] Successfully mounted %s at %s", dm.Label, finalMount) } + logger.Printf("[DEBUG] [backup] MountDrivesFromLayout: done — %d/%d drives mounted", len(mounted), len(layout.Mounts)) return mounted, nil } -// scanBlockDeviceUUIDs runs lsblk + blkid to build a UUID → device path map. +// scanBlockDeviceUUIDs runs lsblk + blkid to build a UUID -> device path map. func scanBlockDeviceUUIDs(ctx context.Context) (map[string]string, error) { // First try lsblk with UUID output out, err := exec.CommandContext(ctx, "lsblk", "-J", "-o", "NAME,UUID,FSTYPE,MOUNTPOINT").Output() @@ -172,10 +192,12 @@ func mountDirect(ctx context.Context, device string, dm DiskMount, logger *log.L // Use host device path if available devPath := hostDevPath(device) + logger.Printf("[DEBUG] [backup] mountDirect: mount -t %s -o noatime %s %s", dm.FSType, devPath, dm.MountPoint) cmd := exec.CommandContext(ctx, "mount", "-t", dm.FSType, "-o", "noatime", devPath, dm.MountPoint) if out, err := cmd.CombinedOutput(); err != nil { return fmt.Errorf("mount %s: %s: %w", devPath, strings.TrimSpace(string(out)), err) } + logger.Printf("[DEBUG] [backup] mountDirect: %s mounted successfully at %s", devPath, dm.MountPoint) return nil } @@ -187,12 +209,14 @@ func mountRawAndBind(ctx context.Context, device string, dm DiskMount, logger *l } devPath := hostDevPath(device) + logger.Printf("[DEBUG] [backup] mountRawAndBind: layer 1 — mount -t %s -o noatime %s %s", dm.FSType, devPath, dm.RawMount) cmd := exec.CommandContext(ctx, "mount", "-t", dm.FSType, "-o", "noatime", devPath, dm.RawMount) if out, err := cmd.CombinedOutput(); err != nil { - return fmt.Errorf("raw mount %s → %s: %s: %w", devPath, dm.RawMount, strings.TrimSpace(string(out)), err) + return fmt.Errorf("raw mount %s -> %s: %s: %w", devPath, dm.RawMount, strings.TrimSpace(string(out)), err) } + logger.Printf("[DEBUG] [backup] mountRawAndBind: layer 1 OK — %s mounted at %s", devPath, dm.RawMount) - // Layer 2: bind mount (subdir → final mount point) + // Layer 2: bind mount (subdir -> final mount point) bindSrc := filepath.Join(dm.RawMount, dm.BindSubdir) if err := os.MkdirAll(bindSrc, 0755); err != nil { return fmt.Errorf("creating bind source dir: %w", err) @@ -201,10 +225,12 @@ func mountRawAndBind(ctx context.Context, device string, dm DiskMount, logger *l return fmt.Errorf("creating final mount point: %w", err) } + logger.Printf("[DEBUG] [backup] mountRawAndBind: layer 2 — mount --bind %s %s", bindSrc, dm.MountPoint) cmd = exec.CommandContext(ctx, "mount", "--bind", bindSrc, dm.MountPoint) if out, err := cmd.CombinedOutput(); err != nil { - return fmt.Errorf("bind mount %s → %s: %s: %w", bindSrc, dm.MountPoint, strings.TrimSpace(string(out)), err) + return fmt.Errorf("bind mount %s -> %s: %s: %w", bindSrc, dm.MountPoint, strings.TrimSpace(string(out)), err) } + logger.Printf("[DEBUG] [backup] mountRawAndBind: layer 2 OK — %s bound to %s", bindSrc, dm.MountPoint) return nil } @@ -213,6 +239,8 @@ func mountRawAndBind(ctx context.Context, device string, dm DiskMount, logger *l func addDRFstabEntries(dm DiskMount, logger *log.Logger) error { const fstabPath = "/host-fstab" + logger.Printf("[DEBUG] [backup] addDRFstabEntries: checking fstab for %s (UUID=%s)", dm.Label, dm.UUID) + data, err := os.ReadFile(fstabPath) if err != nil { return fmt.Errorf("reading fstab: %w", err) @@ -222,6 +250,7 @@ func addDRFstabEntries(dm DiskMount, logger *log.Logger) error { // Skip if UUID already in fstab (idempotent) if strings.Contains(content, dm.UUID) { + logger.Printf("[DEBUG] [backup] addDRFstabEntries: UUID %s already in fstab — skipping", dm.UUID) return nil } diff --git a/controller/internal/backup/restore_scan.go b/controller/internal/backup/restore_scan.go index cf84f78..ded9180 100644 --- a/controller/internal/backup/restore_scan.go +++ b/controller/internal/backup/restore_scan.go @@ -163,6 +163,9 @@ func ScanDrivesForBackups(mountedPaths []string, stacks []InfraStackInfo, logger Status: "pending", } + logger.Printf("[DEBUG] [backup] ScanDrivesForBackups: scanning %d mount paths, %d stacks from manifest", + len(mountedPaths), len(stacks)) + // Build drive info and find backup directories type driveBackup struct { drivePath string @@ -181,6 +184,8 @@ func ScanDrivesForBackups(mountedPaths []string, stacks []InfraStackInfo, logger Available: avail, } + logger.Printf("[DEBUG] [backup] ScanDrivesForBackups: checking drive %s (label=%s, available=%v)", mp, label, avail) + secPath := SecondaryBackupPath(mp) if dirExists(secPath) { di.HasBackup = true @@ -195,6 +200,8 @@ func ScanDrivesForBackups(mountedPaths []string, stacks []InfraStackInfo, logger plan.Drives = append(plan.Drives, di) } + logger.Printf("[DEBUG] [backup] ScanDrivesForBackups: found %d drives with backup data", len(backupDrives)) + // For each stack from the manifest, look for backup data on drives for _, stack := range stacks { app := RestorableApp{ @@ -205,12 +212,16 @@ func ScanDrivesForBackups(mountedPaths []string, stacks []InfraStackInfo, logger Status: "pending", } + logger.Printf("[DEBUG] [backup] ScanDrivesForBackups: scanning for app %s (needsHDD=%v, hddPath=%s)", + stack.Name, stack.NeedsHDD, stack.HDDPath) + // Check if app data exists directly on HDD (common case: HDD survived) if stack.HDDPath != "" { dataDir := AppDataDir(stack.HDDPath, stack.Name) if dirExists(dataDir) { app.HasData = true app.DataPath = dataDir + logger.Printf("[DEBUG] [backup] ScanDrivesForBackups: %s — live data found at %s", stack.Name, dataDir) } } @@ -224,6 +235,8 @@ func ScanDrivesForBackups(mountedPaths []string, stacks []InfraStackInfo, logger // Found a backup for this app app.DrivePath = db.drivePath app.DriveLabel = db.label + logger.Printf("[DEBUG] [backup] ScanDrivesForBackups: %s — backup found on drive %s at %s", + stack.Name, db.label, rsyncBase) // Check for _config/ (stack compose directory backup) configDir := filepath.Join(rsyncBase, "_config") @@ -245,6 +258,9 @@ func ScanDrivesForBackups(mountedPaths []string, stacks []InfraStackInfo, logger app.RsyncDataPath = rsyncBase } + logger.Printf("[DEBUG] [backup] ScanDrivesForBackups: %s — config=%v, dbDump=%v, rsyncData=%v", + stack.Name, app.HasConfig, app.HasDBDump, app.HasRsyncData) + break // use first drive with backup for this app } diff --git a/controller/internal/cloudflare/geosync.go b/controller/internal/cloudflare/geosync.go index 006dcb5..91819cf 100644 --- a/controller/internal/cloudflare/geosync.go +++ b/controller/internal/cloudflare/geosync.go @@ -23,6 +23,7 @@ type GeoSyncManager struct { domain string stacks StackLister logger *log.Logger + debug bool mu sync.Mutex running bool @@ -39,6 +40,11 @@ func NewGeoSyncManager(client *Client, sett *settings.Settings, domain string, s } } +// SetDebug enables or disables debug logging for the geo sync manager. +func (g *GeoSyncManager) SetDebug(debug bool) { + g.debug = debug +} + // IsRunning returns true if a sync operation is in progress. func (g *GeoSyncManager) IsRunning() bool { g.mu.Lock() @@ -75,17 +81,28 @@ func (g *GeoSyncManager) Sync(ctx context.Context) error { // 1. Resolve zone ID (use cached value if available) zoneID := geo.ZoneID if zoneID == "" { + if g.debug { + g.logger.Printf("[DEBUG] [cloudflare] Zone ID not cached, resolving via API for domain %s", g.domain) + } var err error zoneID, err = g.client.GetZoneID(ctx, g.domain) if err != nil { g.saveError(zoneID, "", err.Error()) return fmt.Errorf("resolve zone: %w", err) } + if g.debug { + g.logger.Printf("[DEBUG] [cloudflare] Resolved zone ID: %s", zoneID) + } + } else if g.debug { + g.logger.Printf("[DEBUG] [cloudflare] Using cached zone ID: %s", zoneID) } // 2. Get or create the custom WAF ruleset rulesetID := geo.RulesetID if rulesetID == "" { + if g.debug { + g.logger.Printf("[DEBUG] [cloudflare] Ruleset ID not cached, looking up for zone %s", zoneID) + } var err error rulesetID, err = g.client.GetCustomRulesetID(ctx, zoneID) if err != nil { @@ -93,12 +110,20 @@ func (g *GeoSyncManager) Sync(ctx context.Context) error { return fmt.Errorf("get ruleset: %w", err) } if rulesetID == "" { + if g.debug { + g.logger.Printf("[DEBUG] [cloudflare] No existing custom ruleset found, creating new one") + } rulesetID, err = g.client.CreateCustomRuleset(ctx, zoneID) if err != nil { g.saveError(zoneID, "", err.Error()) return fmt.Errorf("create ruleset: %w", err) } } + if g.debug { + g.logger.Printf("[DEBUG] [cloudflare] Using ruleset ID: %s", rulesetID) + } + } else if g.debug { + g.logger.Printf("[DEBUG] [cloudflare] Using cached ruleset ID: %s", rulesetID) } // 3. List existing felhom-managed rules @@ -107,9 +132,21 @@ func (g *GeoSyncManager) Sync(ctx context.Context) error { g.saveError(zoneID, rulesetID, err.Error()) return fmt.Errorf("list existing rules: %w", err) } + if g.debug { + g.logger.Printf("[DEBUG] [cloudflare] Found %d existing felhom rules", len(existing)) + for _, r := range existing { + g.logger.Printf("[DEBUG] [cloudflare] existing: %s (id=%s)", r.Description, r.ID) + } + } // 4. Build desired rules desired := g.buildDesiredRules(geo) + if g.debug { + g.logger.Printf("[DEBUG] [cloudflare] Built %d desired rules", len(desired)) + for _, d := range desired { + g.logger.Printf("[DEBUG] [cloudflare] desired: %s", d.description) + } + } // 5. Diff and apply if err := g.applyDiff(ctx, zoneID, rulesetID, existing, desired); err != nil { @@ -134,24 +171,41 @@ func (g *GeoSyncManager) deleteAllRules(ctx context.Context, geo *settings.GeoRe } if zoneID == "" || rulesetID == "" { + if g.debug { + g.logger.Printf("[DEBUG] [cloudflare] deleteAllRules: no cached zone/ruleset IDs, nothing to clean up") + } // No cached IDs — nothing to clean up return nil } + if g.debug { + g.logger.Printf("[DEBUG] [cloudflare] deleteAllRules: listing rules for zone=%s ruleset=%s", zoneID, rulesetID) + } + existing, err := g.client.GetFelhomRules(ctx, zoneID, rulesetID) if err != nil { g.logger.Printf("[GEO] Warning: could not list rules for cleanup: %v", err) return nil } + if g.debug { + g.logger.Printf("[DEBUG] [cloudflare] deleteAllRules: found %d felhom rules to delete", len(existing)) + } + + deleted := 0 for _, r := range existing { if err := g.client.DeleteRule(ctx, zoneID, rulesetID, r.ID); err != nil { g.logger.Printf("[GEO] Warning: could not delete rule %s: %v", r.ID, err) + } else { + deleted++ } } if len(existing) > 0 { g.logger.Printf("[GEO] Deleted %d felhom-geo rules (feature disabled)", len(existing)) + if g.debug { + g.logger.Printf("[DEBUG] [cloudflare] deleteAllRules: successfully deleted %d/%d rules", deleted, len(existing)) + } } g.saveError(zoneID, rulesetID, "") @@ -169,6 +223,9 @@ func (g *GeoSyncManager) buildDesiredRules(geo *settings.GeoRestriction) []desir var rules []desiredRule hostnames := g.stacks.GetDeployedHostnames() + if g.debug { + g.logger.Printf("[DEBUG] [cloudflare] buildDesiredRules: %d deployed hostnames from stacks", len(hostnames)) + } // Collect app hostnames that have overrides (to exclude from global rule) var excludeHostnames []string @@ -177,6 +234,9 @@ func (g *GeoSyncManager) buildDesiredRules(geo *settings.GeoRestriction) []desir for appName, override := range geo.AppOverrides { hostname, ok := hostnames[appName] if !ok { + if g.debug { + g.logger.Printf("[DEBUG] [cloudflare] buildDesiredRules: skipping override for %q (not deployed)", appName) + } continue // app not deployed, skip } overrideApps[appName] = true @@ -189,15 +249,24 @@ func (g *GeoSyncManager) buildDesiredRules(geo *settings.GeoRestriction) []desir }) } + if g.debug && len(overrideApps) > 0 { + g.logger.Printf("[DEBUG] [cloudflare] buildDesiredRules: %d app overrides active (deployed)", len(overrideApps)) + } + // Sort exclude hostnames for deterministic expression sort.Strings(excludeHostnames) // Global rule (excludes apps with their own rules) + globalExpr := BuildGlobalExpression(geo.AllowedCountries, excludeHostnames) rules = append(rules, desiredRule{ description: globalRuleDesc, - expression: BuildGlobalExpression(geo.AllowedCountries, excludeHostnames), + expression: globalExpr, }) + if g.debug { + g.logger.Printf("[DEBUG] [cloudflare] buildDesiredRules: global rule expression: %s", globalExpr) + } + return rules } @@ -220,13 +289,21 @@ func (g *GeoSyncManager) applyDiff(ctx context.Context, zoneID, rulesetID string if ex, ok := existingByDesc[d.description]; ok { // Rule exists — check if expression changed if ex.Expression != d.expression { + if g.debug { + g.logger.Printf("[DEBUG] [cloudflare] applyDiff: updating rule %q (id=%s) — expression changed", d.description, ex.ID) + } r := newBlockRule(d.description, d.expression) if err := g.client.UpdateRule(ctx, zoneID, rulesetID, ex.ID, r); err != nil { return fmt.Errorf("update rule %q: %w", d.description, err) } + } else if g.debug { + g.logger.Printf("[DEBUG] [cloudflare] applyDiff: rule %q unchanged, skipping", d.description) } } else { // New rule — create + if g.debug { + g.logger.Printf("[DEBUG] [cloudflare] applyDiff: creating new rule %q", d.description) + } r := newBlockRule(d.description, d.expression) if _, err := g.client.CreateRule(ctx, zoneID, rulesetID, r); err != nil { return fmt.Errorf("create rule %q: %w", d.description, err) @@ -237,6 +314,9 @@ func (g *GeoSyncManager) applyDiff(ctx context.Context, zoneID, rulesetID string // Delete rules that are no longer desired for _, ex := range existing { if _, ok := desiredByDesc[ex.Description]; !ok { + if g.debug { + g.logger.Printf("[DEBUG] [cloudflare] applyDiff: deleting obsolete rule %q (id=%s)", ex.Description, ex.ID) + } if err := g.client.DeleteRule(ctx, zoneID, rulesetID, ex.ID); err != nil { return fmt.Errorf("delete rule %q: %w", ex.Description, err) } diff --git a/controller/internal/cloudflare/waf.go b/controller/internal/cloudflare/waf.go index d2fcc06..e2ddac5 100644 --- a/controller/internal/cloudflare/waf.go +++ b/controller/internal/cloudflare/waf.go @@ -71,12 +71,23 @@ func (c *Client) GetCustomRulesetID(ctx context.Context, zoneID string) (string, return "", fmt.Errorf("decode rulesets: %w", err) } + if c.debug { + c.logger.Printf("[CF-DEBUG] GetCustomRulesetID: found %d rulesets for zone %s", len(rulesets), zoneID) + } + for _, rs := range rulesets { if rs.Phase == wafPhase { + if c.debug { + c.logger.Printf("[CF-DEBUG] GetCustomRulesetID: matched ruleset %s (phase=%s)", rs.ID, wafPhase) + } return rs.ID, nil } } + if c.debug { + c.logger.Printf("[CF-DEBUG] GetCustomRulesetID: no ruleset with phase %s found", wafPhase) + } + return "", nil } @@ -119,6 +130,10 @@ func (c *Client) GetRules(ctx context.Context, zoneID, rulesetID string) ([]rule return nil, fmt.Errorf("decode rules: %w", err) } + if c.debug { + c.logger.Printf("[CF-DEBUG] GetRules: %d total rules in ruleset %s", len(rs.Rules), rulesetID) + } + return rs.Rules, nil } @@ -141,6 +156,10 @@ func (c *Client) GetFelhomRules(ctx context.Context, zoneID, rulesetID string) ( } } + if c.debug { + c.logger.Printf("[CF-DEBUG] GetFelhomRules: %d felhom rules out of %d total", len(result), len(rules)) + } + return result, nil } @@ -163,6 +182,13 @@ func (c *Client) CreateRule(ctx context.Context, zoneID, rulesetID string, r rul for _, created := range rs.Rules { if created.Description == r.Description { c.logger.Printf("[CF] Created rule %q → %s", r.Description, created.ID) + if c.debug { + expr := r.Expression + if len(expr) > 120 { + expr = expr[:120] + "..." + } + c.logger.Printf("[CF-DEBUG] CreateRule: expression: %s", expr) + } return created.ID, nil } } @@ -178,6 +204,13 @@ func (c *Client) UpdateRule(ctx context.Context, zoneID, rulesetID, ruleID strin return fmt.Errorf("update rule %s: %w", ruleID, err) } c.logger.Printf("[CF] Updated rule %q (%s)", r.Description, ruleID) + if c.debug { + expr := r.Expression + if len(expr) > 120 { + expr = expr[:120] + "..." + } + c.logger.Printf("[CF-DEBUG] UpdateRule: expression: %s", expr) + } return nil } diff --git a/controller/internal/cloudflare/zone.go b/controller/internal/cloudflare/zone.go index d3dced0..75851f2 100644 --- a/controller/internal/cloudflare/zone.go +++ b/controller/internal/cloudflare/zone.go @@ -16,7 +16,14 @@ type zone struct { // GetZoneID resolves the Cloudflare zone ID for a domain. // It tries the exact domain first, then strips subdomains progressively. func (c *Client) GetZoneID(ctx context.Context, domain string) (string, error) { + if c.debug { + c.logger.Printf("[CF-DEBUG] GetZoneID: looking up zone for domain %q", domain) + } + // Try exact domain first (e.g., "demo-felhom.eu") + if c.debug { + c.logger.Printf("[CF-DEBUG] GetZoneID: trying exact domain %q", domain) + } id, err := c.lookupZone(ctx, domain) if err != nil { return "", err @@ -32,6 +39,9 @@ func (c *Client) GetZoneID(ctx context.Context, domain string) (string, error) { if parent == "" { break } + if c.debug { + c.logger.Printf("[CF-DEBUG] GetZoneID: trying parent domain %q", parent) + } id, err = c.lookupZone(ctx, parent) if err != nil { return "", err diff --git a/controller/internal/integrations/lifecycle.go b/controller/internal/integrations/lifecycle.go index 1ebcd42..71e4368 100644 --- a/controller/internal/integrations/lifecycle.go +++ b/controller/internal/integrations/lifecycle.go @@ -20,6 +20,10 @@ func (m *Manager) OnStackStop(_ context.Context, stackName string) { all[k] = v } + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] OnStackStop: stack=%s integrationsFound=%d", stackName, len(all)) + } + for key, state := range all { if !state.Enabled || state.Status == "disabled" { continue @@ -41,6 +45,9 @@ func (m *Manager) OnStackStop(_ context.Context, stackName string) { continue } + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] OnStackStop: revoking %s", key) + } if err := handler.Revoke(ac); err != nil { m.logger.Printf("[WARN] Integration revoke on stop failed for %s: %v", key, err) } @@ -59,6 +66,9 @@ func (m *Manager) OnStackStop(_ context.Context, stackName string) { // Re-applies integrations that were previously enabled but are not currently active. // Waits briefly for the stack manager to refresh container state. func (m *Manager) OnStackStart(_ context.Context, stackName string) { + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] OnStackStart: stack=%s, waiting 5s for state refresh", stackName) + } // Brief delay so the stack manager's periodic status refresh // picks up the new container state (runs every 30s). time.Sleep(5 * time.Second) @@ -72,6 +82,10 @@ func (m *Manager) OnStackStart(_ context.Context, stackName string) { all[k] = v } + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] OnStackStart: stack=%s integrationsFound=%d", stackName, len(all)) + } + for key, state := range all { if !state.Enabled || state.Status == "active" { continue @@ -86,11 +100,17 @@ func (m *Manager) OnStackStart(_ context.Context, stackName string) { // StateStarting = container running but healthcheck hasn't passed yet — still connectable. provStack, pOk := m.stacks.GetStack(provider) if !pOk || !provStack.Deployed || !isStackUp(provStack.State) { + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] OnStackStart: skipping %s — provider %s not up (found=%v deployed=%v state=%v)", key, provider, pOk, pOk && provStack.Deployed, func() stacks.ContainerState { if pOk { return provStack.State }; return "" }()) + } continue } if target != "filebrowser" { tgtStack, tOk := m.stacks.GetStack(target) if !tOk || !tgtStack.Deployed || !isStackUp(tgtStack.State) { + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] OnStackStart: skipping %s — target %s not up (found=%v deployed=%v state=%v)", key, target, tOk, tOk && tgtStack.Deployed, func() stacks.ContainerState { if tOk { return tgtStack.State }; return "" }()) + } continue } } @@ -100,6 +120,10 @@ func (m *Manager) OnStackStart(_ context.Context, stackName string) { continue } + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] OnStackStart: re-applying %s (currentStatus=%s)", key, state.Status) + } + ac, err := m.buildApplyContext(provider, target) if err != nil { m.logger.Printf("[WARN] Cannot re-apply integration %s on start: %v", key, err) @@ -138,6 +162,10 @@ func (m *Manager) OnStackRemove(_ context.Context, stackName string) { all[k] = v } + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] OnStackRemove: stack=%s integrationsFound=%d", stackName, len(all)) + } + for key, state := range all { provider, target, ok := ParseIntegrationKey(key) if !ok { @@ -145,6 +173,9 @@ func (m *Manager) OnStackRemove(_ context.Context, stackName string) { } if state.Enabled { + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] OnStackRemove: revoking enabled integration %s", key) + } handler, hOk := m.handlers[key] if hOk { ac, _ := m.buildApplyContext(provider, target) diff --git a/controller/internal/integrations/manager.go b/controller/internal/integrations/manager.go index 8cf8c01..5e1fcc3 100644 --- a/controller/internal/integrations/manager.go +++ b/controller/internal/integrations/manager.go @@ -31,6 +31,7 @@ type Manager struct { handlers map[string]Handler // key: "provider:target" -> Handler mu sync.Mutex // serialize apply/revoke operations + debug bool } // NewManager creates an integration manager and registers built-in handlers. @@ -47,9 +48,28 @@ func NewManager(sett *settings.Settings, sp StackProvider, domain, stacksDir str // Register built-in handlers m.RegisterHandler("onlyoffice:filebrowser", &OnlyOfficeFileBrowserHandler{}) m.RegisterHandler("onlyoffice:nextcloud", &OnlyOfficeNextcloudHandler{}) + + if m.isDebug() { + keys := make([]string, 0, len(m.handlers)) + for k := range m.handlers { + keys = append(keys, k) + } + m.logger.Printf("[DEBUG] [integrations] NewManager: registered handlers: %v", keys) + } + return m } +// SetDebug enables or disables debug logging. +func (m *Manager) SetDebug(debug bool) { + m.debug = debug +} + +// isDebug returns whether debug logging is enabled. +func (m *Manager) isDebug() bool { + return m.debug +} + // RegisterHandler registers a handler for a provider:target integration key. func (m *Manager) RegisterHandler(key string, h Handler) { m.handlers[key] = h @@ -61,6 +81,10 @@ func (m *Manager) Toggle(ctx context.Context, provider, target string, enable bo defer m.mu.Unlock() key := IntegrationKey(provider, target) + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] Toggle: key=%s provider=%s target=%s enable=%v", key, provider, target, enable) + } + handler, ok := m.handlers[key] if !ok { return settings.IntegrationState{}, fmt.Errorf("nincs kezelő a(z) %s integrációhoz", key) @@ -75,6 +99,9 @@ func (m *Manager) Toggle(ctx context.Context, provider, target string, enable bo if enable { // Validate: provider must be deployed and running provStack, pOk := m.stacks.GetStack(provider) + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] Toggle: provider %s found=%v deployed=%v state=%v", provider, pOk, pOk && provStack.Deployed, func() stacks.ContainerState { if pOk { return provStack.State }; return "" }()) + } if !pOk || !provStack.Deployed { return state, fmt.Errorf("a szolgáltató alkalmazás (%s) nincs telepítve", provider) } @@ -85,6 +112,9 @@ func (m *Manager) Toggle(ctx context.Context, provider, target string, enable bo // Validate: target must be deployed and running (filebrowser is infra, always present) if target != "filebrowser" { tgtStack, tOk := m.stacks.GetStack(target) + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] Toggle: target %s found=%v deployed=%v state=%v", target, tOk, tOk && tgtStack.Deployed, func() stacks.ContainerState { if tOk { return tgtStack.State }; return "" }()) + } if !tOk || !tgtStack.Deployed { return state, fmt.Errorf("a célalkalmazás (%s) nincs telepítve", target) } @@ -93,7 +123,11 @@ func (m *Manager) Toggle(ctx context.Context, provider, target string, enable bo } } + start := time.Now() if err := handler.Apply(ac); err != nil { + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] Toggle: Apply failed for %s in %v: %v", key, time.Since(start), err) + } state.Enabled = true state.Status = "error" state.LastError = err.Error() @@ -101,15 +135,22 @@ func (m *Manager) Toggle(ctx context.Context, provider, target string, enable bo _ = m.sett.SetIntegrationState(key, state) return state, fmt.Errorf("integráció alkalmazása sikertelen: %w", err) } + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] Toggle: Apply succeeded for %s in %v", key, time.Since(start)) + } state.Enabled = true state.Status = "active" state.EnabledAt = time.Now().UTC().Format(time.RFC3339) m.logger.Printf("[INFO] Integration %s enabled", key) } else { + start := time.Now() if err := handler.Revoke(ac); err != nil { m.logger.Printf("[WARN] Integration revoke failed for %s: %v", key, err) state.LastError = err.Error() } + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] Toggle: Revoke for %s completed in %v", key, time.Since(start)) + } state.Enabled = false state.Status = "disabled" m.logger.Printf("[INFO] Integration %s disabled", key) @@ -128,6 +169,10 @@ func (m *Manager) ListForProvider(providerSlug string) []StatusInfo { return nil } + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] ListForProvider: provider=%s integrationDefs=%d", providerSlug, len(provStack.Meta.Integrations)) + } + var result []StatusInfo for _, idef := range provStack.Meta.Integrations { key := IntegrationKey(providerSlug, idef.Target) @@ -171,6 +216,11 @@ func (m *Manager) buildApplyContext(provider, target string) (*ApplyContext, err // Load decrypted env from provider's app.yaml provEnv := m.loadDecryptedEnv(provStack) + if m.isDebug() { + envKeyCount := len(provEnv) + m.logger.Printf("[DEBUG] [integrations] buildApplyContext: provider=%s target=%s domain=%s envKeys=%d", provider, target, m.domain, envKeyCount) + } + provMeta := provStack.Meta return &ApplyContext{ ProviderName: provider, @@ -192,6 +242,9 @@ func (m *Manager) ReapplyConfigForTarget(targetName string) { defer m.mu.Unlock() all := m.sett.GetIntegrationsForTarget(targetName) + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] ReapplyConfigForTarget: target=%s integrations=%d", targetName, len(all)) + } for key, state := range all { if !state.Enabled || state.Status == "disabled" { continue @@ -207,6 +260,10 @@ func (m *Manager) ReapplyConfigForTarget(targetName string) { continue } + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] ReapplyConfigForTarget: reapplying %s (status=%s)", key, state.Status) + } + ac, err := m.buildApplyContext(provider, target) if err != nil { m.logger.Printf("[WARN] Cannot build context for integration %s reapply: %v", key, err) @@ -218,12 +275,18 @@ func (m *Manager) ReapplyConfigForTarget(targetName string) { if err := handler.Apply(ac); err != nil { m.logger.Printf("[WARN] Integration config reapply failed for %s: %v", key, err) + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] ReapplyConfigForTarget: %s failed: %v", key, err) + } state.Status = "error" state.LastError = err.Error() _ = m.sett.SetIntegrationState(key, state) continue } + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] ReapplyConfigForTarget: %s succeeded", key) + } state.Status = "active" state.LastError = "" _ = m.sett.SetIntegrationState(key, state) @@ -241,5 +304,8 @@ func (m *Manager) loadDecryptedEnv(s *stacks.Stack) map[string]string { if m.encKey != nil { cfg.Env = crypto.DecryptMap(m.encKey, cfg.Env) } + if m.isDebug() { + m.logger.Printf("[DEBUG] [integrations] loadDecryptedEnv: stack=%s envKeys=%d", s.Name, len(cfg.Env)) + } return cfg.Env } diff --git a/controller/internal/integrations/onlyoffice_filebrowser.go b/controller/internal/integrations/onlyoffice_filebrowser.go index 63079e8..0139e88 100644 --- a/controller/internal/integrations/onlyoffice_filebrowser.go +++ b/controller/internal/integrations/onlyoffice_filebrowser.go @@ -25,6 +25,10 @@ func (h *OnlyOfficeFileBrowserHandler) Apply(ac *ApplyContext) error { } configPath := filepath.Join(ac.StacksDir, "filebrowser", "config.yaml") + officeURL := fmt.Sprintf("https://%s.%s", subdomain, ac.Domain) + + ac.Logger.Printf("[DEBUG] [integrations] OnlyOfficeFileBrowser.Apply: jwtSecretPresent=%v subdomain=%s configPath=%s officeURL=%s", jwtSecret != "", subdomain, configPath, officeURL) + configData, err := os.ReadFile(configPath) if err != nil { return fmt.Errorf("FileBrowser config olvasási hiba: %w", err) @@ -33,7 +37,6 @@ func (h *OnlyOfficeFileBrowserHandler) Apply(ac *ApplyContext) error { // Remove any existing integrations section, then append the new one configStr := removeIntegrationsSection(string(configData)) - officeURL := fmt.Sprintf("https://%s.%s", subdomain, ac.Domain) internalURL := "http://onlyoffice:80" integrationsBlock := fmt.Sprintf("integrations:\n office:\n url: %q\n internalUrl: %q\n secret: %q\n viewOnly: false\n", @@ -57,6 +60,8 @@ func (h *OnlyOfficeFileBrowserHandler) Apply(ac *ApplyContext) error { func (h *OnlyOfficeFileBrowserHandler) Revoke(ac *ApplyContext) error { configPath := filepath.Join(ac.StacksDir, "filebrowser", "config.yaml") + ac.Logger.Printf("[DEBUG] [integrations] OnlyOfficeFileBrowser.Revoke: configPath=%s", configPath) + configData, err := os.ReadFile(configPath) if err != nil { if os.IsNotExist(err) { @@ -66,7 +71,9 @@ func (h *OnlyOfficeFileBrowserHandler) Revoke(ac *ApplyContext) error { } cleaned := removeIntegrationsSection(string(configData)) - if cleaned == string(configData) { + hadIntegrations := cleaned != string(configData) + ac.Logger.Printf("[DEBUG] [integrations] OnlyOfficeFileBrowser.Revoke: integrationsSectionFound=%v", hadIntegrations) + if !hadIntegrations { return nil // no integrations section, nothing to remove } diff --git a/controller/internal/metrics/logscanner.go b/controller/internal/metrics/logscanner.go index 2512136..f09bc88 100644 --- a/controller/internal/metrics/logscanner.go +++ b/controller/internal/metrics/logscanner.go @@ -54,15 +54,26 @@ func ScanContainerLogs(containerNames []string, since time.Duration, logger *log return []ContainerLogSummary{} } + dbg := func(format string, args ...interface{}) { + if logger != nil { + logger.Printf("[DEBUG] [metrics] logscanner: "+format, args...) + } + } + + dbg("starting log scan for %d containers (since %s)", len(containerNames), since) start := time.Now() results := make([]ContainerLogSummary, 0, len(containerNames)) for _, name := range containerNames { + cStart := time.Now() summary := scanOneContainer(name, since, logger) + dbg("scanned %s: errors=%d warnings=%d issues=%d (took %s)", + name, summary.ErrorCount, summary.WarnCount, len(summary.RecentIssues), time.Since(cStart).Round(time.Millisecond)) results = append(results, summary) } elapsed := time.Since(start) + dbg("log scan completed: %d containers in %s", len(containerNames), elapsed.Round(time.Millisecond)) if elapsed > 5*time.Minute && logger != nil { logger.Printf("[WARN] Log scan took %s (>5min) for %d containers", elapsed.Round(time.Second), len(containerNames)) } diff --git a/controller/internal/monitor/pinger.go b/controller/internal/monitor/pinger.go index 4090190..d43a490 100644 --- a/controller/internal/monitor/pinger.go +++ b/controller/internal/monitor/pinger.go @@ -17,6 +17,7 @@ type Pinger struct { httpClient *http.Client logger *log.Logger enabled bool + debug bool } // NewPinger creates a new Pinger from monitoring config. @@ -31,18 +32,32 @@ func NewPinger(cfg *config.MonitoringConfig, logger *log.Logger) *Pinger { } } +// SetDebug enables or disables debug logging for the pinger. +func (p *Pinger) SetDebug(debug bool) { + p.debug = debug +} + // Ping sends a success signal with optional diagnostic body. func (p *Pinger) Ping(uuid string, body string) error { + if p.debug { + p.logger.Printf("[DEBUG] [pinger] Ping uuid=%s body_len=%d", uuid, len(body)) + } return p.send(uuid, "", body) } // Fail sends a failure signal with diagnostic body. func (p *Pinger) Fail(uuid string, body string) error { + if p.debug { + p.logger.Printf("[DEBUG] [pinger] Fail uuid=%s body=%q", uuid, body) + } return p.send(uuid, "/fail", body) } // Start sends a "job started" signal (for duration tracking). func (p *Pinger) Start(uuid string) error { + if p.debug { + p.logger.Printf("[DEBUG] [pinger] Start uuid=%s", uuid) + } return p.send(uuid, "/start", "") } @@ -56,10 +71,16 @@ func (p *Pinger) send(uuid, suffix, body string) error { } url := fmt.Sprintf("%s/ping/%s%s", p.baseURL, uuid, suffix) + if p.debug { + p.logger.Printf("[DEBUG] [pinger] send url=%s", url) + } var lastErr error for attempt := 0; attempt < 3; attempt++ { if attempt > 0 { + if p.debug { + p.logger.Printf("[DEBUG] [pinger] retry attempt=%d uuid=%s", attempt+1, uuid) + } time.Sleep(2 * time.Second) } @@ -81,7 +102,14 @@ func (p *Pinger) send(uuid, suffix, body string) error { } resp.Body.Close() + if p.debug { + p.logger.Printf("[DEBUG] [pinger] response status=%d uuid=%s", resp.StatusCode, uuid) + } + if resp.StatusCode >= 200 && resp.StatusCode < 300 { + if p.debug { + p.logger.Printf("[DEBUG] [pinger] success uuid=%s", uuid) + } return nil } lastErr = fmt.Errorf("HTTP %d", resp.StatusCode) diff --git a/controller/internal/scheduler/scheduler.go b/controller/internal/scheduler/scheduler.go index 705fa90..1ee2882 100644 --- a/controller/internal/scheduler/scheduler.go +++ b/controller/internal/scheduler/scheduler.go @@ -44,12 +44,26 @@ type Scheduler struct { mu sync.Mutex jobs []*Job logger *log.Logger + debug bool ctx context.Context cancel context.CancelFunc wg sync.WaitGroup started bool } +// SetDebug enables or disables debug logging. +func (s *Scheduler) SetDebug(on bool) { + s.mu.Lock() + defer s.mu.Unlock() + s.debug = on +} + +func (s *Scheduler) dbg(format string, args ...interface{}) { + if s.debug { + s.logger.Printf("[DEBUG] [sched] "+format, args...) + } +} + // New creates a new Scheduler. func New(logger *log.Logger) *Scheduler { return &Scheduler{ @@ -75,6 +89,7 @@ func (s *Scheduler) Every(name string, interval time.Duration, fn JobFunc) { } s.jobs = append(s.jobs, job) s.logger.Printf("[SCHED] Registered periodic job: %s (every %s)", name, interval) + s.dbg("periodic job registered: name=%q interval=%s totalJobs=%d", name, interval, len(s.jobs)) if s.started { s.wg.Add(1) @@ -103,6 +118,7 @@ func (s *Scheduler) Daily(name string, timeStr string, fn JobFunc) { nextRun := nextDailyRun(timeStr) s.logger.Printf("[SCHED] Daily job %s scheduled for %s", name, nextRun.Format("2006-01-02 15:04 MST")) + s.dbg("daily job registered: name=%q schedule=%q nextRun=%s totalJobs=%d", name, timeStr, nextRun.Format(time.RFC3339), len(s.jobs)) if s.started { s.wg.Add(1) @@ -132,6 +148,23 @@ func (s *Scheduler) Start(ctx context.Context) { } s.logger.Printf("[SCHED] Scheduler started with %d jobs", len(s.jobs)) + s.dbg("scheduler started: periodic=%d daily=%d", func() int { + n := 0 + for _, j := range s.jobs { + if j.Interval > 0 { + n++ + } + } + return n + }(), func() int { + n := 0 + for _, j := range s.jobs { + if j.Schedule != "" { + n++ + } + } + return n + }()) s.mu.Unlock() } @@ -200,10 +233,13 @@ func (s *Scheduler) runDailyJob(job *Job) { waitDuration = 0 } + s.dbg("daily job %s: next run at %s (waiting %s)", job.Name, nextRun.Format("2006-01-02 15:04:05 MST"), waitDuration.Round(time.Second)) + timer := time.NewTimer(waitDuration) select { case <-s.ctx.Done(): timer.Stop() + s.dbg("daily job %s: context cancelled, stopping", job.Name) return case <-timer.C: s.executeJob(job, false) @@ -241,6 +277,7 @@ func (s *Scheduler) executeJob(job *Job, quiet bool) { if !quiet { s.logger.Printf("[SCHED] Running job: %s", job.Name) } + s.dbg("job %s: execution starting", job.Name) start := time.Now() err := job.Fn(s.ctx) @@ -253,9 +290,11 @@ func (s *Scheduler) executeJob(job *Job, quiet bool) { if err != nil { s.logger.Printf("[WARN] Job %s failed: %v (took %s)", job.Name, err, elapsed.Round(time.Millisecond)) + s.dbg("job %s: failed after %s: %v", job.Name, elapsed.Round(time.Millisecond), err) } else if !quiet { s.logger.Printf("[SCHED] Job %s completed (took %s)", job.Name, elapsed.Round(time.Millisecond)) } + s.dbg("job %s: finished in %s (err=%v)", job.Name, elapsed.Round(time.Millisecond), err) } // parseDailyTime parses "HH:MM" and returns hour and minute. diff --git a/controller/internal/selfupdate/updater.go b/controller/internal/selfupdate/updater.go index 6ffb0da..4c45078 100644 --- a/controller/internal/selfupdate/updater.go +++ b/controller/internal/selfupdate/updater.go @@ -62,6 +62,12 @@ func NewUpdater(cfg *config.SelfUpdateConfig, gitCfg *config.GitConfig, currentV } } +func (u *Updater) dbg(format string, args ...interface{}) { + if u.debug { + u.logger.Printf("[DEBUG] [selfupdate] "+format, args...) + } +} + // SetBackupRunningCheck sets the callback to check if a backup is in progress. func (u *Updater) SetBackupRunningCheck(fn func() bool) { u.mu.Lock() @@ -140,10 +146,10 @@ func (u *Updater) CheckForUpdate() CheckResult { result.UpdateAvailable = true } - if u.debug { - u.logger.Printf("[DEBUG] [SELFUPDATE] Version comparison: current=%s, latest=%s, cmp=%d, updateAvailable=%v", - u.currentVer, latestStr, cmp, result.UpdateAvailable) - } + u.dbg("version comparison: current=%s (%d.%d.%d), latest=%s (%d.%d.%d), cmp=%d, updateAvailable=%v", + u.currentVer, currentVer.Major, currentVer.Minor, currentVer.Patch, + latestStr, latestVer.Major, latestVer.Minor, latestVer.Patch, + cmp, result.UpdateAvailable) u.mu.Lock() u.latestVersion = latestStr @@ -163,9 +169,7 @@ func (u *Updater) queryRegistry() (string, error) { // Gitea registry V2: GET /v2///tags/list url := fmt.Sprintf("https://gitea.dooplex.hu/v2/%s/tags/list", registryImagePath(u.cfg.Image)) - if u.debug { - u.logger.Printf("[DEBUG] [SELFUPDATE] Registry API URL: %s (user: %s)", url, u.gitCfg.Username) - } + u.dbg("queryRegistry: url=%s user=%s", url, u.gitCfg.Username) req, err := http.NewRequest("GET", url, nil) if err != nil { @@ -176,9 +180,11 @@ func (u *Updater) queryRegistry() (string, error) { client := &http.Client{Timeout: 15 * time.Second} resp, err := client.Do(req) if err != nil { + u.dbg("queryRegistry: HTTP request failed: %v", err) return "", fmt.Errorf("HTTP request failed: %w", err) } defer resp.Body.Close() + u.dbg("queryRegistry: HTTP %d", resp.StatusCode) if resp.StatusCode == 401 { return "", fmt.Errorf("authentication failed (401)") @@ -195,9 +201,7 @@ func (u *Updater) queryRegistry() (string, error) { return "", fmt.Errorf("decoding response: %w", err) } - if u.debug { - u.logger.Printf("[DEBUG] [SELFUPDATE] Registry returned %d tags: %v", len(tagsResp.Tags), tagsResp.Tags) - } + u.dbg("queryRegistry: %d tags returned: %v", len(tagsResp.Tags), tagsResp.Tags) // Find highest semver tag var highest *Version @@ -293,9 +297,11 @@ func (u *Updater) DryRun() *DryRunResult { // TriggerUpdate starts the self-update process. Returns error immediately if // preconditions fail. The actual update runs in a goroutine. func (u *Updater) TriggerUpdate(initiatedBy string) error { + u.dbg("TriggerUpdate: initiatedBy=%s currentVer=%s", initiatedBy, u.currentVer) u.mu.Lock() if u.updateRunning { u.mu.Unlock() + u.dbg("TriggerUpdate: rejected — update already running") return fmt.Errorf("Frissítés már folyamatban") } @@ -334,6 +340,7 @@ func (u *Updater) TriggerUpdate(initiatedBy string) error { previousImage := fmt.Sprintf("%s:%s", u.cfg.Image, u.currentVer) u.logger.Printf("[INFO] Starting self-update: %s → %s (initiated by: %s)", u.currentVer, targetVersion, initiatedBy) + u.dbg("TriggerUpdate: target=%s image=%s previousImage=%s", targetVersion, targetImage, previousImage) go u.performUpdate(targetVersion, targetImage, previousImage, initiatedBy) @@ -348,6 +355,7 @@ func (u *Updater) performUpdate(targetVersion, targetImage, previousImage, initi u.mu.Unlock() }() + u.dbg("performUpdate: starting — target=%s image=%s", targetVersion, targetImage) // 1. Write pending state state := &UpdateState{ Status: "pending", @@ -364,7 +372,9 @@ func (u *Updater) performUpdate(targetVersion, targetImage, previousImage, initi } // 2. Docker pull + u.dbg("performUpdate: step 2 — docker pull %s", targetImage) u.logger.Printf("[INFO] Pulling image: %s", targetImage) + pullStart := time.Now() pullOut, pullErr := runCommand("docker", "pull", targetImage) if pullErr != nil { state.Status = "failed" @@ -375,8 +385,10 @@ func (u *Updater) performUpdate(targetVersion, targetImage, previousImage, initi return } u.logger.Printf("[INFO] Image pulled successfully: %s", targetImage) + u.dbg("performUpdate: docker pull completed in %s", time.Since(pullStart).Round(time.Millisecond)) // 3. Update compose file (replace image tag) + u.dbg("performUpdate: step 3 — updating compose file %s", u.composePath) if err := u.updateComposeFile(targetImage); err != nil { state.Status = "failed" state.Error = fmt.Sprintf("compose update failed: %v", err) @@ -388,6 +400,7 @@ func (u *Updater) performUpdate(targetVersion, targetImage, previousImage, initi u.logger.Printf("[INFO] Compose file updated with new image: %s", targetImage) // 4. Docker compose up -d (this kills the current container) + u.dbg("performUpdate: step 4 — docker compose up -d") u.logger.Printf("[INFO] Running docker compose up -d — container will restart") composeDir := strings.TrimSuffix(u.composePath, "/docker-compose.yml") upOut, upErr := runCommand("docker", "compose", "-f", u.composePath, "-p", "felhom-controller", "up", "-d") @@ -417,12 +430,12 @@ func (u *Updater) updateComposeFile(newImage string) error { // Replace image line: "image: gitea.dooplex.hu/admin/felhom-controller:..." → new image re := regexp.MustCompile(`(image:\s*)gitea\.dooplex\.hu/admin/felhom-controller:\S+`) - if u.debug { - // Log old image line for debugging - oldMatch := re.Find(data) - if oldMatch != nil { - u.logger.Printf("[DEBUG] [SELFUPDATE] Compose file edit: %q → %q", string(oldMatch), "image: "+newImage) - } + // Log old image line for debugging + oldMatch := re.Find(data) + if oldMatch != nil { + u.dbg("updateComposeFile: %q → %q", string(oldMatch), "image: "+newImage) + } else { + u.dbg("updateComposeFile: no matching image line found in %s", u.composePath) } newData := re.ReplaceAll(data, []byte("${1}"+newImage)) @@ -447,6 +460,7 @@ func (u *Updater) updateComposeFile(newImage string) error { // Called once from main.go before the scheduler starts. // Returns the state if a pending update was detected, nil otherwise. func (u *Updater) VerifyStartup() *UpdateState { + u.dbg("VerifyStartup: checking update state in %s", u.dataDir) state, err := LoadState(u.dataDir) if err != nil { u.logger.Printf("[WARN] Failed to load update state on startup: %v — clearing", err) @@ -454,8 +468,10 @@ func (u *Updater) VerifyStartup() *UpdateState { return nil } if state == nil || state.Status != "pending" { + u.dbg("VerifyStartup: no pending update (state=%v)", state) return nil } + u.dbg("VerifyStartup: pending update found — target=%s previous=%s", state.TargetVersion, state.PreviousVersion) // Compare current version with target currentVer, curErr := ParseVersion(u.currentVer) diff --git a/controller/internal/settings/settings.go b/controller/internal/settings/settings.go index 36d392a..3dd7eef 100644 --- a/controller/internal/settings/settings.go +++ b/controller/internal/settings/settings.go @@ -14,9 +14,10 @@ import ( // Settings holds customer-modifiable overrides and cached state. // Persisted as a single JSON file (settings.json) in the data directory. type Settings struct { - mu sync.RWMutex `json:"-"` - path string `json:"-"` - log *log.Logger `json:"-"` + mu sync.RWMutex `json:"-"` + path string `json:"-"` + log *log.Logger `json:"-"` + debug bool `json:"-"` // Auth PasswordHash string `json:"password_hash,omitempty"` // bcrypt hash, overrides controller.yaml @@ -156,6 +157,11 @@ type DBValidationCache struct { Error string `json:"error,omitempty"` } +// SetDebug enables or disables debug logging for settings operations. +func (s *Settings) SetDebug(debug bool) { + s.debug = debug +} + // Load reads settings from the given file path. // Returns empty Settings if the file doesn't exist (not an error). func Load(path string, logger *log.Logger) (*Settings, error) { @@ -178,6 +184,10 @@ func Load(path string, logger *log.Logger) (*Settings, error) { } logger.Printf("[DEBUG] Settings loaded from %s", path) + if s.debug { + s.log.Printf("[DEBUG] [settings] loaded: storage_paths=%d integrations=%d pending_events=%d", + len(s.StoragePaths), len(s.Integrations), len(s.PendingEvents)) + } s.migrateResticToRsync() return s, nil } @@ -226,7 +236,9 @@ func (s *Settings) save() error { return fmt.Errorf("renaming settings file: %w", err) } - s.log.Printf("[DEBUG] Settings saved to %s", s.path) + if s.debug { + s.log.Printf("[DEBUG] [settings] saved to %s (%d bytes)", s.path, len(data)) + } return nil } @@ -435,6 +447,9 @@ func (s *Settings) GetSchedulableStoragePaths() []StoragePath { func (s *Settings) AddStoragePath(sp StoragePath) error { s.mu.Lock() defer s.mu.Unlock() + if s.debug { + s.log.Printf("[DEBUG] [settings] AddStoragePath path=%q label=%q default=%v", sp.Path, sp.Label, sp.IsDefault) + } for _, existing := range s.StoragePaths { if existing.Path == sp.Path { return fmt.Errorf("storage path %q already registered", sp.Path) @@ -453,6 +468,9 @@ func (s *Settings) AddStoragePath(sp StoragePath) error { func (s *Settings) RemoveStoragePath(path string) error { s.mu.Lock() defer s.mu.Unlock() + if s.debug { + s.log.Printf("[DEBUG] [settings] RemoveStoragePath path=%q", path) + } var kept []StoragePath for _, sp := range s.StoragePaths { if sp.Path != path { @@ -515,6 +533,10 @@ func (s *Settings) AutoDiscoverStoragePaths(discoveredPaths []string, fallbackHD s.mu.Lock() defer s.mu.Unlock() + if s.debug { + s.log.Printf("[DEBUG] [settings] AutoDiscoverStoragePaths discovered=%v fallback=%q existing=%d", discoveredPaths, fallbackHDDPath, len(s.StoragePaths)) + } + if len(s.StoragePaths) > 0 { return // already configured } @@ -572,6 +594,9 @@ func InferStorageLabel(path string) string { func (s *Settings) SetDisconnected(path string, disconnected bool, stoppedStacks []string) error { s.mu.Lock() defer s.mu.Unlock() + if s.debug { + s.log.Printf("[DEBUG] [settings] SetDisconnected path=%q disconnected=%v stopped_stacks=%d", path, disconnected, len(stoppedStacks)) + } for i := range s.StoragePaths { if s.StoragePaths[i].Path == path { s.StoragePaths[i].Disconnected = disconnected @@ -679,6 +704,9 @@ func (s *Settings) ClearStoppedStacks(path string) error { func (s *Settings) SetDecommissioned(path, migratedTo string) error { s.mu.Lock() defer s.mu.Unlock() + if s.debug { + s.log.Printf("[DEBUG] [settings] SetDecommissioned path=%q migrated_to=%q", path, migratedTo) + } for i := range s.StoragePaths { if s.StoragePaths[i].Path == path { s.StoragePaths[i].Decommissioned = true @@ -811,6 +839,9 @@ func (s *Settings) SetRetrievalPassword(password string) error { func (s *Settings) AddPendingEvent(event PendingEvent) error { s.mu.Lock() defer s.mu.Unlock() + if s.debug { + s.log.Printf("[DEBUG] [settings] AddPendingEvent type=%q severity=%q", event.EventType, event.Severity) + } s.PendingEvents = append(s.PendingEvents, event) return s.save() } @@ -822,6 +853,9 @@ func (s *Settings) DrainPendingEvents() []PendingEvent { if len(s.PendingEvents) == 0 { return nil } + if s.debug { + s.log.Printf("[DEBUG] [settings] DrainPendingEvents count=%d", len(s.PendingEvents)) + } events := make([]PendingEvent, len(s.PendingEvents)) copy(events, s.PendingEvents) s.PendingEvents = nil @@ -862,6 +896,13 @@ func (s *Settings) GetGeoRestriction() *GeoRestriction { func (s *Settings) SetGeoRestriction(geo *GeoRestriction) error { s.mu.Lock() defer s.mu.Unlock() + if s.debug { + if geo == nil { + s.log.Printf("[DEBUG] [settings] SetGeoRestriction geo=nil (clearing)") + } else { + s.log.Printf("[DEBUG] [settings] SetGeoRestriction enabled=%v countries=%d", geo.Enabled, len(geo.AllowedCountries)) + } + } if geo == nil { s.GeoRestriction = nil return s.save() @@ -953,6 +994,9 @@ func (s *Settings) GetIntegrationState(key string) (IntegrationState, bool) { func (s *Settings) SetIntegrationState(key string, state IntegrationState) error { s.mu.Lock() defer s.mu.Unlock() + if s.debug { + s.log.Printf("[DEBUG] [settings] SetIntegrationState key=%q status=%q enabled=%v", key, state.Status, state.Enabled) + } if s.Integrations == nil { s.Integrations = make(map[string]IntegrationState) } diff --git a/controller/internal/stacks/delete.go b/controller/internal/stacks/delete.go index 3224785..2d50f7d 100644 --- a/controller/internal/stacks/delete.go +++ b/controller/internal/stacks/delete.go @@ -71,6 +71,10 @@ func ProtectedHDDPaths(hddPath string) map[string]bool { // DeleteStack removes an orphaned stack: stops containers, removes volumes, // optionally removes HDD data, and deletes the stack directory. func (m *Manager) DeleteStack(name string, removeHDDData bool) (*DeleteResponse, error) { + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] DeleteStack called: name=%q, removeHDDData=%v", name, removeHDDData) + } + // Safety: never delete protected stacks if m.cfg.IsProtectedStack(name) { return nil, fmt.Errorf("stack %q is protected and cannot be deleted", name) @@ -81,6 +85,11 @@ func (m *Manager) DeleteStack(name string, removeHDDData bool) (*DeleteResponse, return nil, fmt.Errorf("stack %q not found", name) } + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] DeleteStack %s: state=%s, deployed=%v, orphaned=%v, deploying=%v", + name, stack.State, stack.Deployed, stack.Orphaned, stack.Deploying) + } + // Must be orphaned if !stack.Orphaned { return nil, fmt.Errorf("stack %q is not orphaned — only orphaned stacks can be deleted", name) @@ -108,11 +117,20 @@ func (m *Manager) DeleteStack(name string, removeHDDData bool) (*DeleteResponse, // Step 1: Parse compose file for HDD bind mounts hddMounts := ParseComposeHDDMounts(stack.ComposePath, hddPath) + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] DeleteStack %s: found %d HDD mounts from compose file", name, len(hddMounts)) + for i, mount := range hddMounts { + m.logger.Printf("[DEBUG] [stacks] DeleteStack %s: HDD mount[%d]=%s", name, i, mount) + } + } // Step 2: Run docker compose down --rmi local --volumes // H14: Return error if docker compose down fails — continuing would leave orphaned containers. env := m.stackEnv(stackDir) output, err := m.composeExecCustomEnv(stackDir, env, "down", "--rmi", "local", "--volumes") + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] DeleteStack %s: compose down output: %s", name, truncateStr(output, 500)) + } if err != nil { m.logger.Printf("[ERROR] docker compose down for %s failed: %v (output: %s)", name, err, truncateStr(output, 200)) return resp, fmt.Errorf("docker compose down failed for %s: %w", name, err) @@ -137,12 +155,18 @@ func (m *Manager) DeleteStack(name string, removeHDDData bool) (*DeleteResponse, } if _, err := os.Stat(cleanPath); os.IsNotExist(err) { + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] DeleteStack %s: HDD path does not exist, skipping: %s", name, cleanPath) + } continue // path doesn't exist, nothing to do } if removeHDDData { // Get size before removal sizeHuman := getDirSizeHuman(cleanPath) + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] DeleteStack %s: removing HDD path %s (%s)", name, cleanPath, sizeHuman) + } if err := os.RemoveAll(cleanPath); err != nil { m.logger.Printf("[ERROR] Failed to remove HDD data %s: %v", cleanPath, err) } else { @@ -151,11 +175,17 @@ func (m *Manager) DeleteStack(name string, removeHDDData bool) (*DeleteResponse, } } else { sizeHuman := getDirSizeHuman(cleanPath) + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] DeleteStack %s: preserving HDD path %s (%s)", name, cleanPath, sizeHuman) + } resp.HDDPathsPreserved = append(resp.HDDPathsPreserved, fmt.Sprintf("%s (%s)", cleanPath, sizeHuman)) } } // Step 5: Remove stack directory + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] DeleteStack %s: removing stack directory %s", name, stackDir) + } if err := os.RemoveAll(stackDir); err != nil { m.logger.Printf("[ERROR] Failed to remove stack directory %s: %v", stackDir, err) return resp, fmt.Errorf("failed to remove stack directory: %w", err) @@ -188,12 +218,19 @@ func (m *Manager) GetStackHDDData(name string) (*HDDDataResponse, error) { } if hddPath == "" { + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] GetStackHDDData %s: no HDD path configured, returning empty", name) + } return resp, nil } mounts := ParseComposeHDDMounts(stack.ComposePath, hddPath) protected := ProtectedHDDPaths(hddPath) + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] GetStackHDDData %s: found %d raw HDD mounts from compose", name, len(mounts)) + } + for _, mount := range mounts { cleanPath := filepath.Clean(mount) @@ -221,6 +258,14 @@ func (m *Manager) GetStackHDDData(name string) (*HDDDataResponse, error) { } resp.HasHDDData = len(resp.HDDPaths) > 0 + + if m.isDebug() { + for _, p := range resp.HDDPaths { + m.logger.Printf("[DEBUG] [stacks] GetStackHDDData %s: path=%s exists=%v size=%s", name, p.Path, p.Exists, p.SizeHuman) + } + m.logger.Printf("[DEBUG] [stacks] GetStackHDDData %s: hasHDDData=%v, %d paths returned", name, resp.HasHDDData, len(resp.HDDPaths)) + } + return resp, nil } @@ -229,6 +274,10 @@ func (m *Manager) GetStackHDDData(name string) (*HDDDataResponse, error) { // so the stack reverts to "not deployed" state. The template files (docker-compose.yml, // .felhom.yml) are preserved so the user can redeploy. func (m *Manager) RemoveStack(name string, removeHDDData bool, backupPathsToRemove []string) (*RemoveResponse, error) { + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] RemoveStack called: name=%q, removeHDDData=%v, backupPathsToRemove=%d", name, removeHDDData, len(backupPathsToRemove)) + } + // Safety: never remove protected stacks if m.cfg.IsProtectedStack(name) { return nil, fmt.Errorf("stack %q is protected and cannot be removed", name) @@ -239,6 +288,11 @@ func (m *Manager) RemoveStack(name string, removeHDDData bool, backupPathsToRemo return nil, fmt.Errorf("stack %q not found", name) } + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] RemoveStack %s: state=%s, deployed=%v, orphaned=%v, deploying=%v", + name, stack.State, stack.Deployed, stack.Orphaned, stack.Deploying) + } + // Must be deployed if !stack.Deployed { return nil, fmt.Errorf("stack %q is not deployed", name) @@ -266,10 +320,19 @@ func (m *Manager) RemoveStack(name string, removeHDDData bool, backupPathsToRemo // Step 1: Parse compose file for HDD bind mounts hddMounts := ParseComposeHDDMounts(stack.ComposePath, hddPath) + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] RemoveStack %s: found %d HDD mounts from compose file", name, len(hddMounts)) + for i, mount := range hddMounts { + m.logger.Printf("[DEBUG] [stacks] RemoveStack %s: HDD mount[%d]=%s", name, i, mount) + } + } // Step 2: Run docker compose down --volumes (keep images for potential redeploy) env := m.stackEnv(stackDir) output, err := m.composeExecCustomEnv(stackDir, env, "down", "--volumes") + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] RemoveStack %s: compose down output: %s", name, truncateStr(output, 500)) + } if err != nil { m.logger.Printf("[ERROR] docker compose down for %s failed: %v (output: %s)", name, err, truncateStr(output, 200)) return resp, fmt.Errorf("docker compose down failed for %s: %w", name, err) @@ -293,11 +356,17 @@ func (m *Manager) RemoveStack(name string, removeHDDData bool, backupPathsToRemo } if _, err := os.Stat(cleanPath); os.IsNotExist(err) { + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] RemoveStack %s: HDD path does not exist, skipping: %s", name, cleanPath) + } continue } if removeHDDData { sizeHuman := getDirSizeHuman(cleanPath) + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] RemoveStack %s: removing HDD path %s (%s)", name, cleanPath, sizeHuman) + } if err := os.RemoveAll(cleanPath); err != nil { m.logger.Printf("[ERROR] Failed to remove HDD data %s: %v", cleanPath, err) } else { @@ -306,12 +375,18 @@ func (m *Manager) RemoveStack(name string, removeHDDData bool, backupPathsToRemo } } else { sizeHuman := getDirSizeHuman(cleanPath) + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] RemoveStack %s: preserving HDD path %s (%s)", name, cleanPath, sizeHuman) + } resp.HDDPathsPreserved = append(resp.HDDPathsPreserved, fmt.Sprintf("%s (%s)", cleanPath, sizeHuman)) } } // Step 5: Handle backup data cleanup backupsBase := filepath.Join(hddPath, felhomDataDir, "backups") + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] RemoveStack %s: processing %d backup paths for removal (base=%s)", name, len(backupPathsToRemove), backupsBase) + } for _, bkPath := range backupPathsToRemove { cleanPath := filepath.Clean(bkPath) // Validate path is under the expected backups directory @@ -333,6 +408,9 @@ func (m *Manager) RemoveStack(name string, removeHDDData bool, backupPathsToRemo // Step 6: Remove app.yaml only (keep template files for redeploy) appYAMLPath := filepath.Join(stackDir, "app.yaml") + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] RemoveStack %s: removing app.yaml at %s", name, appYAMLPath) + } if err := os.Remove(appYAMLPath); err != nil && !os.IsNotExist(err) { m.logger.Printf("[ERROR] Failed to remove %s: %v", appYAMLPath, err) return resp, fmt.Errorf("failed to remove app.yaml: %w", err) @@ -368,6 +446,9 @@ func (m *Manager) GetStackBackupData(name string, drivePath string) (*BackupData } if drivePath == "" { + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] GetStackBackupData %s: no drive path provided, returning empty", name) + } return resp, nil } @@ -379,6 +460,12 @@ func (m *Manager) GetStackBackupData(name string, drivePath string) (*BackupData rsyncPath := filepath.Join(drivePath, felhomDataDir, "backups", "secondary", name, "rsync") resp.BackupPaths = append(resp.BackupPaths, buildPathInfo(rsyncPath)) + if m.isDebug() { + for _, p := range resp.BackupPaths { + m.logger.Printf("[DEBUG] [stacks] GetStackBackupData %s: checked path=%s exists=%v size=%s", name, p.Path, p.Exists, p.SizeHuman) + } + } + for _, p := range resp.BackupPaths { if p.Exists { resp.HasBackups = true @@ -386,6 +473,10 @@ func (m *Manager) GetStackBackupData(name string, drivePath string) (*BackupData } } + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] GetStackBackupData %s: hasBackups=%v", name, resp.HasBackups) + } + return resp, nil } diff --git a/controller/internal/stacks/deploy.go b/controller/internal/stacks/deploy.go index 7c0b0e6..3509af3 100644 --- a/controller/internal/stacks/deploy.go +++ b/controller/internal/stacks/deploy.go @@ -375,6 +375,10 @@ func (m *Manager) runComposeDeploy(name, stackDir string, env map[string]string, // UpdateStackConfig updates non-locked fields for a deployed stack. func (m *Manager) UpdateStackConfig(name string, values map[string]string) error { + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] UpdateStackConfig called: name=%q, %d values to update", name, len(values)) + } + stack, ok := m.GetStack(name) if !ok { return fmt.Errorf("stack %q not found", name) @@ -396,13 +400,21 @@ func (m *Manager) UpdateStackConfig(name string, values map[string]string) error } meta := LoadMetadata(stackDir) + var changedKeys []string for key, val := range values { if lockedSet[key] { return fmt.Errorf("field %q is locked and cannot be changed after deployment", key) } + if appCfg.Env[key] != val { + changedKeys = append(changedKeys, key) + } appCfg.Env[key] = val } + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] UpdateStackConfig %s: changed keys: [%s], locked keys: %d", name, strings.Join(changedKeys, ", "), len(lockedSet)) + } + if err := SaveAppConfig(stackDir, appCfg, m.encKey, SensitiveEnvVars(&meta)); err != nil { return fmt.Errorf("saving updated config: %w", err) } @@ -445,6 +457,10 @@ func (m *Manager) GetDeployFields(name string) (*Metadata, *AppConfig, error) { // UpdateOptionalConfig updates optional env vars in app.yaml and restarts the stack if deployed. // Only updates env vars that are listed in the metadata's optional_config sections. func (m *Manager) UpdateOptionalConfig(stackName string, values map[string]string) error { + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] UpdateOptionalConfig called: stack=%q, %d values provided", stackName, len(values)) + } + stack, ok := m.GetStack(stackName) if !ok { return fmt.Errorf("stack %q not found", stackName) @@ -461,6 +477,14 @@ func (m *Manager) UpdateOptionalConfig(stackName string, values map[string]strin return fmt.Errorf("no optional config fields defined for %s", stackName) } + if m.isDebug() { + allowedKeys := make([]string, 0, len(allowed)) + for k := range allowed { + allowedKeys = append(allowedKeys, k) + } + m.logger.Printf("[DEBUG] [stacks] UpdateOptionalConfig %s: allowed fields: [%s]", stackName, strings.Join(allowedKeys, ", ")) + } + // Load existing app.yaml (or create empty one) stackDir := filepath.Dir(stack.ComposePath) appCfg := LoadAppConfig(stackDir) @@ -564,12 +588,14 @@ func LoadAppConfig(stackDir string) *AppConfig { } cfg := &AppConfig{} if err := yaml.Unmarshal(data, cfg); err != nil { + log.Printf("[DEBUG] [stacks] LoadAppConfig: failed to parse %s: %v", path, err) return nil } return cfg } func SaveAppConfig(stackDir string, cfg *AppConfig, encKey []byte, sensitiveVars []string) error { + encryptedCount := 0 // Clone env and encrypt sensitive values saveCfg := &AppConfig{ Deployed: cfg.Deployed, @@ -585,6 +611,7 @@ func SaveAppConfig(stackDir string, cfg *AppConfig, encKey []byte, sensitiveVars if encKey != nil && sensitiveSet[k] && !crypto.IsEncrypted(v) && v != "" { if enc, err := crypto.Encrypt(encKey, v); err == nil { saveCfg.Env[k] = enc + encryptedCount++ continue } else { // H10 fix: log encryption failure — value will be saved in plaintext. @@ -594,6 +621,9 @@ func SaveAppConfig(stackDir string, cfg *AppConfig, encKey []byte, sensitiveVars saveCfg.Env[k] = v } + log.Printf("[DEBUG] [stacks] SaveAppConfig: saving %s — %d env vars, %d encrypted, %d sensitive fields", + stackDir, len(saveCfg.Env), encryptedCount, len(sensitiveVars)) + data, err := yaml.Marshal(saveCfg) if err != nil { return fmt.Errorf("marshaling app config: %w", err) @@ -617,7 +647,11 @@ func SaveAppConfig(stackDir string, cfg *AppConfig, encKey []byte, sensitiveVars // LoadAppConfigDecrypted loads app.yaml and decrypts any encrypted values. func LoadAppConfigDecrypted(stackDir string, encKey []byte) *AppConfig { cfg := LoadAppConfig(stackDir) - if cfg == nil || encKey == nil { + if cfg == nil { + return cfg + } + if encKey == nil { + log.Printf("[DEBUG] [stacks] LoadAppConfigDecrypted: no encryption key, returning raw config for %s", stackDir) return cfg } cfg.Env = crypto.DecryptMap(encKey, cfg.Env) @@ -686,6 +720,10 @@ func generateValue(spec string) (string, error) { // yet in app.yaml and auto-generates values for secret/domain fields. // Called after sync (for updated stacks) and on startup (for all deployed stacks). func (m *Manager) InjectMissingFields(stackNames []string) { + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] InjectMissingFields: checking %d stacks", len(stackNames)) + } + for _, name := range stackNames { stack, ok := m.GetStack(name) if !ok { @@ -696,9 +734,17 @@ func (m *Manager) InjectMissingFields(stackNames []string) { meta := LoadMetadata(stackDir) appCfg := LoadAppConfig(stackDir) if appCfg == nil || !appCfg.Deployed { + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] InjectMissingFields: skipping %s (not deployed or no app config)", name) + } continue } + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] InjectMissingFields: checking stack %s — %d deploy fields, %d existing env vars", + name, len(meta.DeployFields), len(appCfg.Env)) + } + var injected []string for _, field := range meta.DeployFields { if _, exists := appCfg.Env[field.EnvVar]; exists { diff --git a/controller/internal/stacks/healthprobe.go b/controller/internal/stacks/healthprobe.go index 97a8218..d8873bf 100644 --- a/controller/internal/stacks/healthprobe.go +++ b/controller/internal/stacks/healthprobe.go @@ -24,6 +24,8 @@ func (m *Manager) RunHealthProbes() error { // Phase 1: collect targets (under lock) m.mu.RLock() var targets []probeTarget + skippedNotDue := 0 + skippedNoContainer := 0 for name, stack := range m.stacks { if stack.State != StateRunning && stack.State != StateUnhealthy { continue @@ -43,6 +45,12 @@ func (m *Manager) RunHealthProbes() error { effectiveInterval = 10 * time.Second } if time.Since(stack.HealthProbe.LastCheck) < effectiveInterval { + skippedNotDue++ + if m.isDebug() { + sinceLastCheck := time.Since(stack.HealthProbe.LastCheck).Round(time.Second) + m.logger.Printf("[DEBUG] [stacks] RunHealthProbes: skipping %s — last check %s ago, effective interval %s, healthy=%v", + name, sinceLastCheck, effectiveInterval, stack.HealthProbe.Healthy) + } continue } } @@ -50,6 +58,7 @@ func (m *Manager) RunHealthProbes() error { // Find the main container to probe (matching stack name) containerName := findProbeContainer(name, stack.Containers) if containerName == "" { + skippedNoContainer++ continue } @@ -61,6 +70,11 @@ func (m *Manager) RunHealthProbes() error { } m.mu.RUnlock() + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] RunHealthProbes: collected %d targets (%d skipped not due, %d skipped no container)", + len(targets), skippedNotDue, skippedNoContainer) + } + if len(targets) == 0 { return nil } diff --git a/controller/internal/stacks/manager.go b/controller/internal/stacks/manager.go index beb3620..d4d1e8a 100644 --- a/controller/internal/stacks/manager.go +++ b/controller/internal/stacks/manager.go @@ -117,15 +117,33 @@ func (m *Manager) SetEncryptionKey(key []byte) { m.encKey = key } +// GetStacksBaseDir returns the base directory where stacks live. +func (m *Manager) GetStacksBaseDir() string { + return m.cfg.Paths.StacksDir +} + // MigrateEncryption re-saves app.yaml for deployed stacks that still have // plaintext values in sensitive fields. Called once on startup. func (m *Manager) MigrateEncryption() { m.mu.Lock() defer m.mu.Unlock() if m.encKey == nil { + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] MigrateEncryption: no encryption key set, skipping") + } return } + if m.isDebug() { + deployedCount := 0 + for _, s := range m.stacks { + if s.Deployed { + deployedCount++ + } + } + m.logger.Printf("[DEBUG] [stacks] MigrateEncryption: checking %d deployed stacks for plaintext sensitive values", deployedCount) + } + migrated := 0 for _, s := range m.stacks { if !s.Deployed { @@ -141,6 +159,11 @@ func (m *Manager) MigrateEncryption() { if len(sensitive) == 0 { continue } + + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] MigrateEncryption: checking stack %q (%d sensitive fields)", s.Name, len(sensitive)) + } + needsMigration := false for _, envVar := range sensitive { if v, ok := appCfg.Env[envVar]; ok && v != "" && !crypto.IsEncrypted(v) { @@ -149,6 +172,9 @@ func (m *Manager) MigrateEncryption() { } } if needsMigration { + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] MigrateEncryption: stack %q needs migration — re-saving with encryption", s.Name) + } if err := SaveAppConfig(stackDir, appCfg, m.encKey, sensitive); err != nil { m.logger.Printf("[WARN] Encryption migration failed for %s: %v", s.Name, err) } else { @@ -229,6 +255,10 @@ func (m *Manager) ScanStacks() error { appCfg := LoadAppConfig(stackDir) deployed := appCfg != nil && appCfg.Deployed + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] ScanStacks: found stack %q deployed=%v composePath=%s", name, deployed, composePath) + } + if existing, ok := m.stacks[name]; ok { existing.ComposePath = composePath existing.Meta = meta @@ -261,6 +291,13 @@ func (m *Manager) ScanStacks() error { // Detect orphaned stacks (deployed but no longer in catalog) catalogTemplates := m.getCatalogTemplateSlugs() + if m.isDebug() { + if catalogTemplates != nil { + m.logger.Printf("[DEBUG] [stacks] ScanStacks: catalog has %d template slugs for orphan detection", len(catalogTemplates)) + } else { + m.logger.Printf("[DEBUG] [stacks] ScanStacks: catalog templates unavailable, skipping orphan detection") + } + } if catalogTemplates != nil { orphanCount := 0 for _, stack := range m.stacks { @@ -271,6 +308,9 @@ func (m *Manager) ScanStacks() error { stack.Orphaned = !catalogTemplates[stack.Name] if stack.Orphaned { orphanCount++ + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] ScanStacks: stack %q is orphaned (deployed but not in catalog)", stack.Name) + } } } if orphanCount > 0 { @@ -306,6 +346,7 @@ func (m *Manager) refreshStatusLocked() error { projectContainers := make(map[string][]ContainerInfo) + totalContainers := 0 for _, line := range strings.Split(strings.TrimSpace(output), "\n") { if line == "" { continue @@ -322,6 +363,11 @@ func (m *Manager) refreshStatusLocked() error { Status: parts[3], } projectContainers[parts[4]] = append(projectContainers[parts[4]], ci) + totalContainers++ + } + + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] refreshStatusLocked: docker ps returned %d containers across %d projects", totalContainers, len(projectContainers)) } for name, stack := range m.stacks { @@ -346,6 +392,10 @@ func (m *Manager) refreshStatusLocked() error { stack.State = StateUnhealthy } + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] refreshStatusLocked: stack %q → state=%s containers=%d", name, stack.State, len(stack.Containers)) + } + stack.LastUpdated = time.Now() } @@ -569,12 +619,20 @@ func (m *Manager) StartStack(name string) error { return fmt.Errorf("stack %q not found", name) } + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] StartStack %s: current state=%s deployed=%v", name, stack.State, stack.Deployed) + } + m.logger.Printf("[INFO] Starting stack: %s", name) start := time.Now() dir := filepath.Dir(stack.ComposePath) env := m.stackEnv(dir) + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] StartStack %s: prepared %d env vars for compose", name, len(env)) + } + if _, err := m.composeExecCustomEnv(dir, env, "up", "-d"); err != nil { m.logger.Printf("[ERROR] Stack %s start failed after %.1fs: %v", name, time.Since(start).Seconds(), err) return fmt.Errorf("starting stack %s: %w", name, err) @@ -604,6 +662,10 @@ func (m *Manager) StopStack(name string) error { return fmt.Errorf("stack %q not found", name) } + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] StopStack %s: current state=%s deployed=%v containers=%d", name, stack.State, stack.Deployed, len(stack.Containers)) + } + m.logger.Printf("[INFO] Stopping stack: %s", name) start := time.Now() dir := filepath.Dir(stack.ComposePath) @@ -623,6 +685,10 @@ func (m *Manager) RestartStack(name string) error { return fmt.Errorf("stack %q not found", name) } + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] RestartStack %s: current state=%s deployed=%v containers=%d", name, stack.State, stack.Deployed, len(stack.Containers)) + } + m.logger.Printf("[INFO] Restarting stack: %s", name) start := time.Now() dir := filepath.Dir(stack.ComposePath) @@ -997,5 +1063,8 @@ func (m *Manager) getCatalogTemplateSlugs() map[string]bool { } } } + if m.isDebug() { + m.logger.Printf("[DEBUG] [stacks] getCatalogTemplateSlugs: found %d template slugs in %s", len(slugs), cacheDir) + } return slugs } \ No newline at end of file diff --git a/controller/internal/storage/attach_linux.go b/controller/internal/storage/attach_linux.go index c5a1558..3661d0a 100644 --- a/controller/internal/storage/attach_linux.go +++ b/controller/internal/storage/attach_linux.go @@ -188,7 +188,7 @@ func FinalizeAttach(req AttachRequest, progress chan<- FormatProgress) (string, } dbg := func(format string, args ...interface{}) { if req.Logger != nil && req.Debug { - req.Logger.Printf("[DEBUG] FinalizeAttach: "+format, args...) + req.Logger.Printf("[DEBUG] [storage] FinalizeAttach: "+format, args...) } } diff --git a/controller/internal/storage/format_linux.go b/controller/internal/storage/format_linux.go index c6f5ac5..941d4a5 100644 --- a/controller/internal/storage/format_linux.go +++ b/controller/internal/storage/format_linux.go @@ -31,7 +31,7 @@ func FormatAndMount(req FormatRequest, progress chan<- FormatProgress) (string, } dbg := func(format string, args ...interface{}) { if req.Logger != nil && req.Debug { - req.Logger.Printf("[DEBUG] FormatAndMount: "+format, args...) + req.Logger.Printf("[DEBUG] [storage] FormatAndMount: "+format, args...) } } diff --git a/controller/internal/storage/migrate.go b/controller/internal/storage/migrate.go index 7641024..01894bf 100644 --- a/controller/internal/storage/migrate.go +++ b/controller/internal/storage/migrate.go @@ -87,7 +87,7 @@ func MigrateAppData( dbg := func(format string, args ...interface{}) { if req.Logger != nil && req.Debug { - req.Logger.Printf("[DEBUG] MigrateAppData: "+format, args...) + req.Logger.Printf("[DEBUG] [storage] MigrateAppData: "+format, args...) } } diff --git a/controller/internal/storage/migrate_drive.go b/controller/internal/storage/migrate_drive.go index 1bfad44..55acb6b 100644 --- a/controller/internal/storage/migrate_drive.go +++ b/controller/internal/storage/migrate_drive.go @@ -101,6 +101,16 @@ func (tx *migrationTx) rollback() { // MigrateDrive performs a full drive migration, moving all apps from source to dest. func (dm *DriveMigrator) MigrateDrive(ctx context.Context, req DriveMigrateRequest, progress chan<- DriveMigrateProgress) error { start := time.Now() + debug := dm.Logger != nil + + dbg := func(format string, args ...interface{}) { + if debug { + dm.Logger.Printf("[DEBUG] [storage] MigrateDrive: "+format, args...) + } + } + _ = dbg // used below + + dbg("starting drive migration: source=%s dest=%s", req.SourcePath, req.DestPath) send := func(step, msg string, pct int) { progress <- DriveMigrateProgress{ @@ -175,6 +185,14 @@ func (dm *DriveMigrator) MigrateDrive(ctx context.Context, req DriveMigrateReque } } + dbg("found %d apps on source drive: %v", len(appsToMigrate), func() []string { + names := make([]string, len(appsToMigrate)) + for i, a := range appsToMigrate { + names[i] = a.Name + } + return names + }()) + if len(appsToMigrate) == 0 { return fail("A forrás meghajtón nincs telepített alkalmazás", fmt.Errorf("no apps on source")) } @@ -230,6 +248,7 @@ func (dm *DriveMigrator) MigrateDrive(ctx context.Context, req DriveMigrateReque ) } + dbg("estimated data: %s (%d bytes), free on dest: %s (%d bytes)", bytesHuman(totalBytes), totalBytes, bytesHuman(freeBytes), freeBytes) dm.Logger.Printf("[INFO] Drive migration: %s (%s) → %s (%s), %d apps, ~%s data", req.SourcePath, srcLabel, req.DestPath, dstLabel, len(appsToMigrate), bytesHuman(totalBytes)) @@ -330,11 +349,13 @@ func (dm *DriveMigrator) MigrateDrive(ctx context.Context, req DriveMigrateReque if err := rsyncCmd.Wait(); err != nil { stderrWg.Wait() + dbg("rsync failed after %s: %v — stderr: %s", time.Since(start).Round(time.Second), err, stderrBuf.String()) send("rolling_back", "rsync sikertelen, visszagörgetés...", 0) tx.rollback() return fail("Adatmásolás sikertelen", fmt.Errorf("rsync failed: %w — %s", err, stderrBuf.String())) } stderrWg.Wait() + dbg("rsync completed in %s", time.Since(start).Round(time.Second)) // --- Step 3: Verify copy --- send("verifying", "Másolat ellenőrzése...", 62) @@ -351,6 +372,7 @@ func (dm *DriveMigrator) MigrateDrive(ctx context.Context, req DriveMigrateReque // --- Step 4: Update all app configs --- send("configuring", "Konfiguráció frissítése...", 65) + dbg("updating HDD_PATH for %d apps", len(appsToMigrate)) var configuredApps []string for i, app := range appsToMigrate { // Guard: verify app still exists diff --git a/controller/internal/storage/scan_linux.go b/controller/internal/storage/scan_linux.go index 0923b42..d496605 100644 --- a/controller/internal/storage/scan_linux.go +++ b/controller/internal/storage/scan_linux.go @@ -11,6 +11,7 @@ import ( "path/filepath" "strconv" "strings" + "time" "gitea.dooplex.hu/admin/felhom-controller/internal/util" ) @@ -199,7 +200,7 @@ func partitionToParentDisk(devPath string) string { func enrichWithBlkid(disks []BlockDevice, logger *log.Logger, debug bool) { dbg := func(format string, args ...interface{}) { if debug && logger != nil { - logger.Printf("[DEBUG] enrichWithBlkid: "+format, args...) + logger.Printf("[DEBUG] [storage] enrichWithBlkid: "+format, args...) } } @@ -241,10 +242,13 @@ func enrichWithBlkid(disks []BlockDevice, logger *log.Logger, debug bool) { func ScanDisks(logger *log.Logger, debug bool) (*ScanResult, error) { dbg := func(format string, args ...interface{}) { if debug && logger != nil { - logger.Printf("[DEBUG] ScanDisks: "+format, args...) + logger.Printf("[DEBUG] [storage] ScanDisks: "+format, args...) } } + dbg("starting disk scan") + scanStart := time.Now() + out, err := exec.Command( "lsblk", "-J", "-b", "-o", "NAME,PATH,SIZE,TYPE,FSTYPE,MOUNTPOINT,MODEL,RM", @@ -337,5 +341,7 @@ func ScanDisks(logger *log.Logger, debug bool) (*ScanResult, error) { enrichWithBlkid(result.AvailableDisks, logger, debug) enrichWithBlkid(result.SystemDisks, logger, debug) + dbg("disk scan completed in %s", time.Since(scanStart).Round(time.Millisecond)) + return result, nil } diff --git a/controller/internal/system/cpu_linux.go b/controller/internal/system/cpu_linux.go index 1a65c07..8098a39 100644 --- a/controller/internal/system/cpu_linux.go +++ b/controller/internal/system/cpu_linux.go @@ -30,6 +30,7 @@ func NewCPUCollector(sampleRate time.Duration) *CPUCollector { // Start begins background CPU sampling. func (c *CPUCollector) Start(ctx context.Context) { ctx, c.cancel = context.WithCancel(ctx) + debugf("[DEBUG] [system] CPUCollector.Start: sampleRate=%s", c.sampleRate) go c.loop(ctx) } @@ -48,10 +49,12 @@ func (c *CPUCollector) CPUPercent() float64 { } func (c *CPUCollector) loop(ctx context.Context) { + firstSample := true for { // Read first sample idle1, total1, err := readCPUStat() if err != nil { + debugf("[DEBUG] [system] CPUCollector: readCPUStat error: %v", err) select { case <-ctx.Done(): return @@ -82,6 +85,11 @@ func (c *CPUCollector) loop(ctx context.Context) { c.mu.Lock() c.cpuPercent = percent c.mu.Unlock() + + if firstSample { + debugf("[DEBUG] [system] CPUCollector: first sample — cpu=%.1f%% (idle=%d total=%d)", percent, idleDelta, totalDelta) + firstSample = false + } } } } diff --git a/controller/internal/system/info.go b/controller/internal/system/info.go index 1bd88f5..5fe28e4 100644 --- a/controller/internal/system/info.go +++ b/controller/internal/system/info.go @@ -1,5 +1,19 @@ package system +import "log" + +// DebugLogger, when non-nil, enables debug-level logging for the system package. +// Set this to the application's *log.Logger when config logging.level == "debug". +// When nil, no debug output is emitted. +var DebugLogger *log.Logger + +// debugf logs a formatted message if DebugLogger is set. +func debugf(format string, args ...any) { + if DebugLogger != nil { + DebugLogger.Printf(format, args...) + } +} + // SystemInfo holds system resource usage information. type SystemInfo struct { TotalMemMB uint64 `json:"total_mem_mb"` diff --git a/controller/internal/system/info_linux.go b/controller/internal/system/info_linux.go index 00be761..1b0091d 100644 --- a/controller/internal/system/info_linux.go +++ b/controller/internal/system/info_linux.go @@ -10,12 +10,16 @@ import ( "sort" "strings" "syscall" + "time" ) // GetInfo reads system memory, disk, CPU, load, and temperature info. // hddPath is the mount path for external HDD; if empty, HDD info is skipped. // cpuCollector provides the latest CPU usage sample; may be nil. func GetInfo(hddPath string, cpuCollector *CPUCollector) SystemInfo { + start := time.Now() + debugf("[DEBUG] [system] GetInfo starting (hddPath=%q, hasCPUCollector=%v)", hddPath, cpuCollector != nil) + info := SystemInfo{} // --- Memory from /proc/meminfo --- @@ -41,6 +45,15 @@ func GetInfo(hddPath string, cpuCollector *CPUCollector) SystemInfo { info.CPUPercent = cpuCollector.CPUPercent() } + debugf("[DEBUG] [system] GetInfo done in %s — mem=%dMB/%dMB (%.1f%%), rootDisk=%.1fGB/%.1fGB (%.1f%%), load=%.2f/%.2f/%.2f, temp=%.1f°C (%s), cpu=%.1f%%", + time.Since(start).Round(time.Millisecond), + info.UsedMemMB, info.TotalMemMB, info.MemPercent, + info.DiskUsedGB, info.DiskTotalGB, info.DiskPercent, + info.LoadAvg1, info.LoadAvg5, info.LoadAvg15, + info.TemperatureCelsius, info.TemperatureSource, + info.CPUPercent, + ) + return info } @@ -67,6 +80,7 @@ func GetMemoryMB() (totalMB, usedMB int, err error) { func readMemInfo(info *SystemInfo) { f, err := os.Open("/proc/meminfo") if err != nil { + debugf("[DEBUG] [system] readMemInfo: failed to open /proc/meminfo: %v", err) return } defer f.Close() @@ -91,6 +105,10 @@ func readMemInfo(info *SystemInfo) { info.AvailMemMB = availKB / 1024 info.UsedMemMB = info.TotalMemMB - info.AvailMemMB info.MemPercent = float64(info.UsedMemMB) / float64(info.TotalMemMB) * 100 + debugf("[DEBUG] [system] readMemInfo: totalKB=%d availKB=%d → total=%dMB avail=%dMB used=%dMB (%.1f%%)", + totalKB, availKB, info.TotalMemMB, info.AvailMemMB, info.UsedMemMB, info.MemPercent) + } else { + debugf("[DEBUG] [system] readMemInfo: could not parse MemTotal from /proc/meminfo") } } @@ -116,6 +134,7 @@ func parseMemLine(line string) uint64 { func readDiskUsage(path string, totalGB, usedGB, availGB *float64, percent *float64) { var stat syscall.Statfs_t if err := syscall.Statfs(path, &stat); err != nil { + debugf("[DEBUG] [system] readDiskUsage: statfs(%q) failed: %v", path, err) return } @@ -131,15 +150,20 @@ func readDiskUsage(path string, totalGB, usedGB, availGB *float64, percent *floa if total > 0 { *percent = float64(used) / float64(total) * 100 } + debugf("[DEBUG] [system] readDiskUsage: path=%q bsize=%d total=%.1fGB used=%.1fGB avail=%.1fGB (%.1f%%)", + path, bsize, *totalGB, *usedGB, *availGB, *percent) } // readLoadAvg reads 1/5/15 minute load averages from /proc/loadavg. func readLoadAvg(info *SystemInfo) { data, err := os.ReadFile("/proc/loadavg") if err != nil { + debugf("[DEBUG] [system] readLoadAvg: failed to read /proc/loadavg: %v", err) return } fmt.Sscanf(string(data), "%f %f %f", &info.LoadAvg1, &info.LoadAvg5, &info.LoadAvg15) + debugf("[DEBUG] [system] readLoadAvg: raw=%q → 1m=%.2f 5m=%.2f 15m=%.2f", + strings.TrimSpace(string(data)), info.LoadAvg1, info.LoadAvg5, info.LoadAvg15) } // readTemperature reads CPU/SoC temperature from thermal zones. @@ -149,6 +173,7 @@ func readTemperature(info *SystemInfo) { for _, prefix := range prefixes { if readThermalZones(prefix, info) { + debugf("[DEBUG] [system] readTemperature: found via thermal_zone at %s — %.1f°C (%s)", prefix, info.TemperatureCelsius, info.TemperatureSource) return } } @@ -156,9 +181,12 @@ func readTemperature(info *SystemInfo) { // Fallback: try hwmon for _, prefix := range prefixes { if readHwmon(prefix, info) { + debugf("[DEBUG] [system] readTemperature: found via hwmon at %s — %.1f°C (%s)", prefix, info.TemperatureCelsius, info.TemperatureSource) return } } + + debugf("[DEBUG] [system] readTemperature: no temperature source found") } func readThermalZones(sysPrefix string, info *SystemInfo) bool { @@ -169,6 +197,7 @@ func readThermalZones(sysPrefix string, info *SystemInfo) bool { } sort.Strings(matches) + debugf("[DEBUG] [system] readThermalZones: %s — found %d zones", sysPrefix, len(matches)) var maxTemp float64 var maxSource string diff --git a/controller/internal/system/mounts_linux.go b/controller/internal/system/mounts_linux.go index f2c6de4..97c733d 100644 --- a/controller/internal/system/mounts_linux.go +++ b/controller/internal/system/mounts_linux.go @@ -65,6 +65,7 @@ type DiskUsageInfo struct { func GetDiskUsage(path string) *DiskUsageInfo { var stat syscall.Statfs_t if err := syscall.Statfs(path, &stat); err != nil { + debugf("[DEBUG] [system] GetDiskUsage: statfs(%q) failed: %v", path, err) return nil } @@ -84,6 +85,8 @@ func GetDiskUsage(path string) *DiskUsageInfo { } info.TotalHuman = formatGB(info.TotalGB) info.UsedHuman = formatGB(info.UsedGB) + debugf("[DEBUG] [system] GetDiskUsage: path=%q total=%s used=%s avail=%.1fGB (%.1f%%)", + path, info.TotalHuman, info.UsedHuman, info.AvailGB, info.UsedPercent) return info } @@ -105,10 +108,12 @@ type FSInfo struct { func GetFSInfo(path string) *FSInfo { out, err := exec.Command("findmnt", "-n", "-o", "SOURCE,FSTYPE", "--target", path).Output() if err != nil { + debugf("[DEBUG] [system] GetFSInfo: findmnt(%q) failed: %v", path, err) return nil } fields := strings.Fields(strings.TrimSpace(string(out))) if len(fields) < 2 { + debugf("[DEBUG] [system] GetFSInfo: findmnt(%q) returned unexpected output: %q", path, strings.TrimSpace(string(out))) return nil } info := &FSInfo{ @@ -117,6 +122,7 @@ func GetFSInfo(path string) *FSInfo { } // Try to get disk model from sysfs info.Model = diskModel(info.Device) + debugf("[DEBUG] [system] GetFSInfo: path=%q device=%s fstype=%s model=%q", path, info.Device, info.FSType, info.Model) return info } @@ -136,6 +142,7 @@ type DestinationHealth struct { // CheckBackupDestination performs tiered validation of a cross-drive backup destination. // Returns a DestinationHealth describing any issues found. func CheckBackupDestination(path string) DestinationHealth { + debugf("[DEBUG] [system] CheckBackupDestination: path=%q", path) h := DestinationHealth{Severity: "ok"} // Tier 1: path must exist @@ -143,6 +150,7 @@ func CheckBackupDestination(path string) DestinationHealth { h.Warning = "A cél tárhely (" + path + ") nem létezik!" h.Blocked = true h.Severity = "critical" + debugf("[DEBUG] [system] CheckBackupDestination: path=%q — tier1 FAIL (not exists)", path) return h } h.Exists = true @@ -152,6 +160,7 @@ func CheckBackupDestination(path string) DestinationHealth { h.Warning = "A cél tárhely (" + path + ") nem írható! Ellenőrizd a jogosultságokat." h.Blocked = true h.Severity = "critical" + debugf("[DEBUG] [system] CheckBackupDestination: path=%q — tier2 FAIL (not writable)", path) return h } h.Writable = true @@ -165,9 +174,11 @@ func CheckBackupDestination(path string) DestinationHealth { "Meghajtóhiba esetén az eredeti adat és a mentés is elveszhet. " + "Külső meghajtó használata javasolt." h.Severity = "warning" + debugf("[DEBUG] [system] CheckBackupDestination: path=%q — tier3 WARN (same block device as /)", path) // Don't return early — also check disk usage } else { h.MountPoint = true + debugf("[DEBUG] [system] CheckBackupDestination: path=%q — tier3 OK (different block device)", path) } // Tier 4: disk usage checks @@ -199,6 +210,8 @@ func CheckBackupDestination(path string) DestinationHealth { } } + debugf("[DEBUG] [system] CheckBackupDestination: path=%q — result: severity=%s blocked=%v freeGB=%.1f usedPct=%.1f%%", + path, h.Severity, h.Blocked, h.FreeGB, h.UsedPercent) return h } @@ -256,8 +269,11 @@ type ProbeResult struct { // ProbeStoragePath checks if a storage path is responsive. // Uses a goroutine with a 3-second timeout to avoid blocking on dead mounts. func ProbeStoragePath(path string) ProbeResult { + start := time.Now() + // Quick check: does the path exist at all? if _, err := os.Lstat(path); os.IsNotExist(err) { + debugf("[DEBUG] [system] ProbeStoragePath: path=%q — not exists (%s)", path, time.Since(start).Round(time.Millisecond)) return ProbeResult{Status: ProbeDisconnected, Err: err} } @@ -273,17 +289,22 @@ func ProbeStoragePath(path string) ProbeResult { select { case res := <-ch: + elapsed := time.Since(start).Round(time.Millisecond) if res.err == nil { + debugf("[DEBUG] [system] ProbeStoragePath: path=%q — connected (%s)", path, elapsed) return ProbeResult{Status: ProbeConnected} } errStr := res.err.Error() if strings.Contains(errStr, "transport endpoint") || strings.Contains(errStr, "input/output error") || strings.Contains(errStr, "no such device") { + debugf("[DEBUG] [system] ProbeStoragePath: path=%q — disconnected: %v (%s)", path, res.err, elapsed) return ProbeResult{Status: ProbeDisconnected, Err: res.err} } + debugf("[DEBUG] [system] ProbeStoragePath: path=%q — disconnected (other error): %v (%s)", path, res.err, elapsed) return ProbeResult{Status: ProbeDisconnected, Err: res.err} case <-time.After(3 * time.Second): + debugf("[DEBUG] [system] ProbeStoragePath: path=%q — TIMEOUT (3s)", path) return ProbeResult{Status: ProbeTimeout, Err: fmt.Errorf("stat timed out after 3s")} } } @@ -302,11 +323,11 @@ func IsUSBDevice(devicePath string) bool { if err != nil { continue } - if strings.Contains(link, "/usb") { - return true - } - return false // found the sysfs entry, but not USB + isUSB := strings.Contains(link, "/usb") + debugf("[DEBUG] [system] IsUSBDevice: device=%q disk=%q sysfs=%s → usb=%v", devicePath, disk, link, isUSB) + return isUSB } + debugf("[DEBUG] [system] IsUSBDevice: device=%q disk=%q — no sysfs entry found", devicePath, disk) return false } diff --git a/controller/internal/web/auth.go b/controller/internal/web/auth.go index fc0227c..05eadb5 100644 --- a/controller/internal/web/auth.go +++ b/controller/internal/web/auth.go @@ -53,6 +53,9 @@ func (s *Server) RequireAuth(next http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { // Skip auth if no password is configured if !s.authEnabled() { + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] auth: no password configured, passing through %s %s", r.Method, r.URL.Path) + } next.ServeHTTP(w, r) return } @@ -77,6 +80,13 @@ func (s *Server) RequireAuth(next http.Handler) http.Handler { cookie, err := r.Cookie(sessionCookieName) if err != nil || !s.isValidSession(cookie.Value) { + if s.isDebug() { + reason := "no cookie" + if err == nil { + reason = "invalid/expired session" + } + s.logger.Printf("[DEBUG] [web] auth: rejected %s %s from %s (%s)", r.Method, r.URL.Path, r.RemoteAddr, reason) + } if strings.HasPrefix(r.URL.Path, "/api/") { w.Header().Set("Content-Type", "application/json") w.WriteHeader(http.StatusUnauthorized) @@ -92,6 +102,9 @@ func (s *Server) RequireAuth(next http.Handler) http.Handler { return } + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] auth: valid session for %s %s", r.Method, r.URL.Path) + } next.ServeHTTP(w, r) }) } @@ -101,6 +114,10 @@ func (s *Server) handleLogin(w http.ResponseWriter, r *http.Request) { password := r.FormValue("password") nextURL := r.FormValue("next") + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] login attempt from %s (X-Forwarded-For: %s)", r.RemoteAddr, r.Header.Get("X-Forwarded-For")) + } + if password == "" { s.renderLogin(w, "Kérjük adja meg a jelszót", "") return @@ -147,6 +164,10 @@ func (s *Server) handleLogin(w http.ResponseWriter, r *http.Request) { delete(s.loginAttempts, ip) s.loginAttemptMu.Unlock() + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] login successful from %s, creating session", ip) + } + token := s.createSession() isSecure := r.TLS != nil || r.Header.Get("X-Forwarded-Proto") == "https" http.SetCookie(w, &http.Cookie{ @@ -174,6 +195,9 @@ func (s *Server) handleLogout(w http.ResponseWriter, r *http.Request) { http.Redirect(w, r, "/", http.StatusFound) return } + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] logout from %s", r.RemoteAddr) + } if cookie, err := r.Cookie(sessionCookieName); err == nil { s.sessionsMu.Lock() delete(s.sessions, cookie.Value) @@ -197,8 +221,13 @@ func (s *Server) createSession() string { expiresAt: time.Now().Add(sessionMaxAge), csrfToken: csrfToken, } + sessionCount := len(s.sessions) s.sessionsMu.Unlock() + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] session created, expires=%s, active_sessions=%d", time.Now().Add(sessionMaxAge).Format(time.RFC3339), sessionCount) + } + return token } @@ -225,8 +254,12 @@ func (s *Server) isValidSession(token string) bool { // Used after password change. func (s *Server) invalidateAllSessions() { s.sessionsMu.Lock() + count := len(s.sessions) s.sessions = make(map[string]*session) s.sessionsMu.Unlock() + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] invalidated all sessions (cleared %d)", count) + } } func (s *Server) cleanupSessions() { @@ -239,12 +272,18 @@ func (s *Server) cleanupSessions() { case <-ticker.C: s.sessionsMu.Lock() now := time.Now() + expired := 0 for t, sess := range s.sessions { if now.After(sess.expiresAt) { delete(s.sessions, t) + expired++ } } + remaining := len(s.sessions) s.sessionsMu.Unlock() + if s.isDebug() && expired > 0 { + s.logger.Printf("[DEBUG] [web] session cleanup: expired=%d remaining=%d", expired, remaining) + } } } } diff --git a/controller/internal/web/handler_debug.go b/controller/internal/web/handler_debug.go index 867aea1..36be00a 100644 --- a/controller/internal/web/handler_debug.go +++ b/controller/internal/web/handler_debug.go @@ -13,6 +13,7 @@ import ( "strings" "time" + "gitea.dooplex.hu/admin/felhom-controller/internal/appexport" "gitea.dooplex.hu/admin/felhom-controller/internal/backup" "gitea.dooplex.hu/admin/felhom-controller/internal/monitor" "gitea.dooplex.hu/admin/felhom-controller/internal/report" @@ -100,6 +101,14 @@ func (s *Server) handleDebugAPI(w http.ResponseWriter, r *http.Request) { case subpath == "logs" && r.Method == http.MethodGet: s.debugLogBuffer(w, r) + // Section 9: App Export/Import + case subpath == "appexport/status" && r.Method == http.MethodGet: + s.debugAppExportStatus(w, r) + case subpath == "appexport/bundles" && r.Method == http.MethodGet: + s.debugAppExportBundles(w, r) + case subpath == "appexport/cleanup" && r.Method == http.MethodPost: + s.debugAppExportCleanup(w, r) + default: http.NotFound(w, r) } @@ -725,3 +734,90 @@ func (s *Server) debugLogBuffer(w http.ResponseWriter, r *http.Request) { "total": total, }) } + +// ── Section 9: App Export/Import ───────────────────────────────────── + +func (s *Server) debugAppExportStatus(w http.ResponseWriter, r *http.Request) { + if s.appExporter == nil { + writeDebugJSON(w, http.StatusOK, true, "", map[string]interface{}{ + "available": false, + }) + return + } + + info := s.appExporter.GetDebugInfo() + + // Scan for bundles + drives := s.storageDriveList() + bundles := appexport.ScanForBundles(drives) + + // Scan for stale temp files + staleFiles := appexport.ScanForStaleTempFiles(drives) + + info["bundle_count"] = len(bundles) + info["stale_temp_files"] = staleFiles + info["stale_temp_count"] = len(staleFiles) + info["available"] = true + + // Export dirs + exportDirs := make([]map[string]interface{}, 0, len(drives)) + for _, d := range drives { + dir := appexport.ExportDir(d.Path) + dirInfo := map[string]interface{}{ + "path": dir, + "label": d.Label, + } + if stat, err := os.Stat(dir); err == nil { + dirInfo["exists"] = true + dirInfo["modified"] = stat.ModTime() + } else { + dirInfo["exists"] = false + } + exportDirs = append(exportDirs, dirInfo) + } + info["export_dirs"] = exportDirs + + writeDebugJSON(w, http.StatusOK, true, "", info) +} + +func (s *Server) debugAppExportBundles(w http.ResponseWriter, r *http.Request) { + if s.appExporter == nil { + writeDebugJSON(w, http.StatusBadRequest, false, "App export not available", nil) + return + } + + drives := s.storageDriveList() + bundles := appexport.ScanForBundles(drives) + + writeDebugJSON(w, http.StatusOK, true, + fmt.Sprintf("%d csomag található", len(bundles)), + map[string]interface{}{"bundles": bundles}) +} + +func (s *Server) debugAppExportCleanup(w http.ResponseWriter, r *http.Request) { + if s.appExporter == nil { + writeDebugJSON(w, http.StatusBadRequest, false, "App export not available", nil) + return + } + + drives := s.storageDriveList() + staleFiles := appexport.ScanForStaleTempFiles(drives) + + if len(staleFiles) == 0 { + writeDebugJSON(w, http.StatusOK, true, "Nincs eltávolítandó temp fájl", nil) + return + } + + removed := 0 + for _, f := range staleFiles { + if err := os.Remove(f); err != nil { + s.logger.Printf("[WARN] Failed to remove stale temp file %s: %v", f, err) + } else { + s.logger.Printf("[INFO] Removed stale temp file: %s", f) + removed++ + } + } + + writeDebugJSON(w, http.StatusOK, true, + fmt.Sprintf("%d/%d temp fájl eltávolítva", removed, len(staleFiles)), nil) +} diff --git a/controller/internal/web/handler_export.go b/controller/internal/web/handler_export.go new file mode 100644 index 0000000..2d680f1 --- /dev/null +++ b/controller/internal/web/handler_export.go @@ -0,0 +1,356 @@ +package web + +import ( + "encoding/json" + "net/http" + "path/filepath" + "strings" + + "gitea.dooplex.hu/admin/felhom-controller/internal/appexport" +) + +// ServeExportAPI dispatches /api/export/* endpoints. +func (s *Server) ServeExportAPI(w http.ResponseWriter, r *http.Request) { + path := r.URL.Path + + switch { + // GET /api/export/estimate?stack=X&drive=Y + case path == "/api/export/estimate" && r.Method == http.MethodGet: + s.apiExportEstimate(w, r) + + // POST /api/export/start + case path == "/api/export/start" && r.Method == http.MethodPost: + s.apiExportStart(w, r) + + // GET /api/export/status + case path == "/api/export/status" && r.Method == http.MethodGet: + s.apiExportStatus(w, r) + + // GET /api/export/bundles — scan for .fab files on all drives + case path == "/api/export/bundles" && r.Method == http.MethodGet: + s.apiExportBundles(w, r) + + // POST /api/export/manifest — read manifest from a .fab file + case path == "/api/export/manifest" && r.Method == http.MethodPost: + s.apiExportManifest(w, r) + + // POST /api/export/import — start async import + case path == "/api/export/import" && r.Method == http.MethodPost: + s.apiImportStart(w, r) + + // GET /api/export/import/status — poll import progress + case path == "/api/export/import/status" && r.Method == http.MethodGet: + s.apiImportStatus(w, r) + + default: + http.NotFound(w, r) + } +} + +// exportPageHandler renders the export form for a specific app. +func (s *Server) exportPageHandler(w http.ResponseWriter, r *http.Request, name string) { + if s.appExporter == nil { + http.Error(w, "App export not available", http.StatusServiceUnavailable) + return + } + + stack, ok := s.stackMgr.GetStack(name) + if !ok || !stack.Deployed { + http.NotFound(w, r) + return + } + + // Build drive list for the dropdown + drives := s.storageDriveList() + + data := map[string]interface{}{ + "Stack": stack, + "Drives": drives, + } + s.executeTemplate(w, r, "app_export", data) +} + +// importPageHandler renders the import page (standalone, not tied to a stack). +func (s *Server) importPageHandler(w http.ResponseWriter, r *http.Request) { + if s.appExporter == nil { + http.Error(w, "App import not available", http.StatusServiceUnavailable) + return + } + + drives := s.storageDriveList() + bundles := appexport.ScanForBundles(drives) + + data := map[string]interface{}{ + "Bundles": bundles, + } + s.executeTemplate(w, r, "app_import", data) +} + +// apiExportEstimate returns size estimation for an export. +func (s *Server) apiExportEstimate(w http.ResponseWriter, r *http.Request) { + if s.appExporter == nil { + jsonError(w, "App export not available", http.StatusServiceUnavailable) + return + } + + stackName := r.URL.Query().Get("stack") + drive := r.URL.Query().Get("drive") + s.logger.Printf("[DEBUG] [handler_export] apiExportEstimate: stack=%q drive=%q", stackName, drive) + if stackName == "" || drive == "" { + jsonError(w, "Missing stack or drive parameter", http.StatusBadRequest) + return + } + + if !s.isValidDrivePath(drive) { + s.logger.Printf("[DEBUG] [handler_export] apiExportEstimate: invalid drive path %q", drive) + jsonError(w, "Invalid drive path", http.StatusBadRequest) + return + } + + est, err := s.appExporter.EstimateExport(stackName, drive) + if err != nil { + s.logger.Printf("[DEBUG] [handler_export] apiExportEstimate error: %v", err) + jsonError(w, err.Error(), http.StatusInternalServerError) + return + } + + s.logger.Printf("[DEBUG] [handler_export] apiExportEstimate: total=%s free=%s fits=%v", + est.TotalSizeHuman, est.DestFreeHuman, est.FitsOnDest) + jsonResponse(w, map[string]interface{}{ + "ok": true, + "data": est, + }) +} + +// apiExportStart starts an async export. +func (s *Server) apiExportStart(w http.ResponseWriter, r *http.Request) { + if s.appExporter == nil { + jsonError(w, "App export not available", http.StatusServiceUnavailable) + return + } + + var req struct { + StackName string `json:"stack_name"` + DestDrive string `json:"dest_drive"` + Password string `json:"password"` + StopApp bool `json:"stop_app"` + } + if err := json.NewDecoder(r.Body).Decode(&req); err != nil { + s.logger.Printf("[DEBUG] [handler_export] apiExportStart: invalid body: %v", err) + jsonError(w, "Invalid request body", http.StatusBadRequest) + return + } + + s.logger.Printf("[DEBUG] [handler_export] apiExportStart: stack=%q drive=%q encrypted=%v stopApp=%v", + req.StackName, req.DestDrive, req.Password != "", req.StopApp) + + if req.StackName == "" || req.DestDrive == "" { + jsonError(w, "Missing stack_name or dest_drive", http.StatusBadRequest) + return + } + + if !s.isValidDrivePath(req.DestDrive) { + s.logger.Printf("[DEBUG] [handler_export] apiExportStart: invalid drive path %q", req.DestDrive) + jsonError(w, "Invalid drive path", http.StatusBadRequest) + return + } + + err := s.appExporter.StartExport(appexport.ExportRequest{ + StackName: req.StackName, + DestDrive: req.DestDrive, + Password: req.Password, + StopApp: req.StopApp, + }) + if err != nil { + s.logger.Printf("[DEBUG] [handler_export] apiExportStart error: %v", err) + jsonError(w, err.Error(), http.StatusConflict) + return + } + + s.logger.Printf("[INFO] Export started for %s to %s", req.StackName, req.DestDrive) + jsonResponse(w, map[string]interface{}{"ok": true}) +} + +// apiExportStatus returns current export/import job status. +func (s *Server) apiExportStatus(w http.ResponseWriter, r *http.Request) { + if s.appExporter == nil { + jsonError(w, "App export not available", http.StatusServiceUnavailable) + return + } + + job := s.appExporter.GetActiveJob() + if job == nil { + jsonResponse(w, map[string]interface{}{ + "ok": true, + "running": false, + "done": false, + }) + return + } + + jsonResponse(w, job.Snapshot()) +} + +// apiExportBundles scans all drives for .fab bundles. +func (s *Server) apiExportBundles(w http.ResponseWriter, r *http.Request) { + if s.appExporter == nil { + jsonError(w, "App export not available", http.StatusServiceUnavailable) + return + } + + drives := s.storageDriveList() + bundles := appexport.ScanForBundles(drives) + + jsonResponse(w, map[string]interface{}{ + "ok": true, + "bundles": bundles, + }) +} + +// apiExportManifest reads and returns the manifest from a .fab file. +func (s *Server) apiExportManifest(w http.ResponseWriter, r *http.Request) { + if s.appExporter == nil { + jsonError(w, "App export not available", http.StatusServiceUnavailable) + return + } + + var req struct { + Path string `json:"path"` + Password string `json:"password"` + } + if err := json.NewDecoder(r.Body).Decode(&req); err != nil { + jsonError(w, "Invalid request body", http.StatusBadRequest) + return + } + + if req.Path == "" { + jsonError(w, "Missing path", http.StatusBadRequest) + return + } + + s.logger.Printf("[DEBUG] [handler_export] apiExportManifest: path=%q hasPassword=%v", req.Path, req.Password != "") + + // Security: validate path is within a registered exports directory + if !s.isValidExportPath(req.Path) { + s.logger.Printf("[DEBUG] [handler_export] apiExportManifest: invalid path %q", req.Path) + jsonError(w, "Invalid bundle path", http.StatusBadRequest) + return + } + + encrypted, _ := appexport.IsEncryptedFAB(req.Path) + s.logger.Printf("[DEBUG] [handler_export] apiExportManifest: encrypted=%v", encrypted) + + var manifest *appexport.Manifest + var err error + if encrypted { + if req.Password == "" { + s.logger.Printf("[DEBUG] [handler_export] apiExportManifest: encrypted, needs password") + jsonResponse(w, map[string]interface{}{ + "ok": true, + "encrypted": true, + "needs_password": true, + }) + return + } + manifest, err = appexport.ReadManifestFromEncryptedFAB(req.Path, req.Password) + } else { + manifest, err = appexport.ReadManifestFromFAB(req.Path) + } + + if err != nil { + s.logger.Printf("[DEBUG] [handler_export] apiExportManifest: error: %v", err) + jsonError(w, err.Error(), http.StatusBadRequest) + return + } + + s.logger.Printf("[DEBUG] [handler_export] apiExportManifest: app=%s display=%s size=%d", + manifest.AppName, manifest.DisplayName, manifest.TotalSizeBytes) + jsonResponse(w, map[string]interface{}{ + "ok": true, + "manifest": manifest, + }) +} + +// apiImportStart starts an async import. +func (s *Server) apiImportStart(w http.ResponseWriter, r *http.Request) { + if s.appExporter == nil { + jsonError(w, "App import not available", http.StatusServiceUnavailable) + return + } + + var req struct { + Path string `json:"path"` + Password string `json:"password"` + } + if err := json.NewDecoder(r.Body).Decode(&req); err != nil { + s.logger.Printf("[DEBUG] [handler_export] apiImportStart: invalid body: %v", err) + jsonError(w, "Invalid request body", http.StatusBadRequest) + return + } + + s.logger.Printf("[DEBUG] [handler_export] apiImportStart: path=%q hasPassword=%v", req.Path, req.Password != "") + + if req.Path == "" { + jsonError(w, "Missing path", http.StatusBadRequest) + return + } + + if !s.isValidExportPath(req.Path) { + s.logger.Printf("[DEBUG] [handler_export] apiImportStart: invalid path %q", req.Path) + jsonError(w, "Invalid bundle path", http.StatusBadRequest) + return + } + + err := s.appExporter.StartImport(appexport.ImportRequest{ + FABPath: req.Path, + Password: req.Password, + }) + if err != nil { + s.logger.Printf("[DEBUG] [handler_export] apiImportStart error: %v", err) + jsonError(w, err.Error(), http.StatusConflict) + return + } + + s.logger.Printf("[INFO] Import started from %s", req.Path) + jsonResponse(w, map[string]interface{}{"ok": true}) +} + +// apiImportStatus returns current import job status (same as export status). +func (s *Server) apiImportStatus(w http.ResponseWriter, r *http.Request) { + s.apiExportStatus(w, r) +} + +// storageDriveList converts settings StoragePaths to appexport DrivePathInfo. +func (s *Server) storageDriveList() []appexport.DrivePathInfo { + paths := s.settings.GetStoragePaths() + drives := make([]appexport.DrivePathInfo, 0, len(paths)) + for _, sp := range paths { + drives = append(drives, appexport.DrivePathInfo{ + Path: sp.Path, + Label: sp.Label, + }) + } + return drives +} + +// isValidDrivePath checks if a path is a registered storage path. +func (s *Server) isValidDrivePath(path string) bool { + for _, sp := range s.settings.GetStoragePaths() { + if sp.Path == path { + return true + } + } + return false +} + +// isValidExportPath checks if a file path is within a registered exports directory. +func (s *Server) isValidExportPath(filePath string) bool { + cleanPath := filepath.Clean(filePath) + for _, sp := range s.settings.GetStoragePaths() { + exportDir := appexport.ExportDir(sp.Path) + if strings.HasPrefix(cleanPath, filepath.Clean(exportDir)+string(filepath.Separator)) { + return true + } + } + return false +} diff --git a/controller/internal/web/handler_restore.go b/controller/internal/web/handler_restore.go index 7c920e8..7be5a69 100644 --- a/controller/internal/web/handler_restore.go +++ b/controller/internal/web/handler_restore.go @@ -11,10 +11,16 @@ import ( // restorePageHandler renders the full-page DR restore UI. func (s *Server) restorePageHandler(w http.ResponseWriter, r *http.Request) { + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] restorePageHandler: rendering restore page") + } s.restoreMu.RLock() plan := s.restorePlan if plan == nil { s.restoreMu.RUnlock() + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] restorePageHandler: no restore plan, redirecting to /") + } http.Redirect(w, r, "/", http.StatusFound) return } @@ -26,6 +32,9 @@ func (s *Server) restorePageHandler(w http.ResponseWriter, r *http.Request) { copy(drives, plan.Drives) status := plan.GetStatus() s.restoreMu.RUnlock() + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] restorePageHandler: customer=%s apps=%d drives=%d status=%s", customerID, len(apps), len(drives), status) + } data := map[string]interface{}{ "Title": "Katasztrófa utáni visszaállítás", @@ -44,6 +53,9 @@ func (s *Server) restorePageHandler(w http.ResponseWriter, r *http.Request) { // apiRestoreStatus returns the current restore plan status as JSON. func (s *Server) apiRestoreStatus(w http.ResponseWriter, r *http.Request) { + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] apiRestoreStatus: status poll from %s", r.RemoteAddr) + } s.restoreMu.RLock() plan := s.restorePlan if plan == nil { @@ -60,6 +72,9 @@ func (s *Server) apiRestoreStatus(w http.ResponseWriter, r *http.Request) { // apiRestoreAll starts restoring all pending apps sequentially. func (s *Server) apiRestoreAll(w http.ResponseWriter, r *http.Request) { + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] apiRestoreAll: restore-all requested from %s", r.RemoteAddr) + } s.restoreMu.RLock() plan := s.restorePlan s.restoreMu.RUnlock() @@ -68,6 +83,9 @@ func (s *Server) apiRestoreAll(w http.ResponseWriter, r *http.Request) { return } if !plan.TryStartRestore() { + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] apiRestoreAll: restore already in progress, rejecting") + } jsonError(w, "restore already in progress", http.StatusConflict) return } @@ -81,6 +99,9 @@ func (s *Server) apiRestoreAll(w http.ResponseWriter, r *http.Request) { // apiRestoreSkip exits restore mode without restoring. func (s *Server) apiRestoreSkip(w http.ResponseWriter, r *http.Request) { + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] apiRestoreSkip: skip requested from %s", r.RemoteAddr) + } s.restoreMu.RLock() plan := s.restorePlan s.restoreMu.RUnlock() @@ -101,6 +122,7 @@ func (s *Server) apiRestoreSkip(w http.ResponseWriter, r *http.Request) { // executeAllRestores runs the restore for each pending app sequentially. func (s *Server) executeAllRestores() { s.logger.Println("[INFO] Starting DR restore for all apps") + restoreStart := time.Now() s.restoreMu.RLock() plan := s.restorePlan @@ -117,6 +139,9 @@ func (s *Server) executeAllRestores() { pendingCount++ } } + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] executeAllRestores: %d pending apps to restore", pendingCount) + } if s.notifier != nil { s.notifier.NotifyDRStarted(pendingCount) } @@ -130,6 +155,7 @@ func (s *Server) executeAllRestores() { plan.UpdateApp(app.Name, "restoring", "") s.logger.Printf("[INFO] Restoring app %s (%s)", app.Name, app.DisplayName) + appStart := time.Now() ctx, cancel := context.WithTimeout(context.Background(), 10*time.Minute) err := backup.RestoreAppFromBackup(ctx, app, s.cfg.Paths.StacksDir, s.logger) @@ -138,16 +164,25 @@ func (s *Server) executeAllRestores() { if err != nil { plan.UpdateApp(app.Name, "failed", err.Error()) s.logger.Printf("[ERROR] Restore failed for %s: %v", app.Name, err) + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] executeAllRestores: app=%s failed after %s", app.Name, time.Since(appStart)) + } failCount++ } else { plan.UpdateApp(app.Name, "done", "") s.logger.Printf("[INFO] Restore completed for %s", app.Name) + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] executeAllRestores: app=%s completed in %s", app.Name, time.Since(appStart)) + } successCount++ } } plan.SetStatus("done") s.logger.Println("[INFO] All app restores completed") + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] executeAllRestores: total=%d success=%d fail=%d elapsed=%s", pendingCount, successCount, failCount, time.Since(restoreStart)) + } // Push DR completion event if s.notifier != nil { diff --git a/controller/internal/web/handlers.go b/controller/internal/web/handlers.go index 71ea4c9..99831e2 100644 --- a/controller/internal/web/handlers.go +++ b/controller/internal/web/handlers.go @@ -276,8 +276,14 @@ func (s *Server) logsHandler(w http.ResponseWriter, r *http.Request, name string } func (s *Server) deployHandler(w http.ResponseWriter, r *http.Request, name string) { + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] deployHandler: stack=%s method=%s", name, r.Method) + } meta, appCfg, err := s.stackMgr.GetDeployFields(name) if err != nil { + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] deployHandler: stack=%s not found: %v", name, err) + } http.NotFound(w, r) return } @@ -953,6 +959,10 @@ func (s *Server) buildAppBackupRows( func (s *Server) settingsCrossBackupHandler(w http.ResponseWriter, r *http.Request, name string) { _ = r.ParseForm() + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] settingsCrossBackupHandler: stack=%s from %s", name, r.RemoteAddr) + } + enabled := r.FormValue("cross_drive_enabled") == "on" // Preserve existing runtime status fields and config when disabling @@ -1023,6 +1033,10 @@ func (s *Server) backupRestoreHandler(w http.ResponseWriter, r *http.Request) { stackName := r.FormValue("stack_name") snapshotID := r.FormValue("snapshot_id") + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] backupRestoreHandler: stack=%s snapshot=%s from %s", stackName, snapshotID, r.RemoteAddr) + } + if stackName == "" || snapshotID == "" { http.Redirect(w, r, "/backups?flash_error=Hi%C3%A1nyz%C3%B3+param%C3%A9terek", http.StatusFound) return @@ -1035,13 +1049,21 @@ func (s *Server) backupRestoreHandler(w http.ResponseWriter, r *http.Request) { s.logger.Printf("[WARN] Restore requested: stack=%s, snapshot=%s from %s", stackName, snapshotID, r.RemoteAddr) + start := time.Now() if err := s.backupMgr.RestoreApp(stackName, snapshotID); err != nil { s.logger.Printf("[ERROR] Restore failed: %v", err) + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] backupRestoreHandler: stack=%s failed after %s", stackName, time.Since(start)) + } errMsg := url.QueryEscape("Visszaállítás sikertelen: " + err.Error()) http.Redirect(w, r, "/backups?flash_error="+errMsg, http.StatusFound) return } + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] backupRestoreHandler: stack=%s completed in %s", stackName, time.Since(start)) + } + msg := url.QueryEscape(stackName + " visszaállítva (" + snapshotID + ").") http.Redirect(w, r, "/backups?flash="+msg, http.StatusFound) } @@ -1167,11 +1189,18 @@ func (s *Server) settingsPasswordHandler(w http.ResponseWriter, r *http.Request) newPassword := r.FormValue("new_password") confirmPassword := r.FormValue("confirm_password") + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] settingsPasswordHandler: password change attempt from %s", r.RemoteAddr) + } + data := s.settingsData() // Validate current password effectiveHash := s.effectivePasswordHash() if err := bcrypt.CompareHashAndPassword([]byte(effectiveHash), []byte(currentPassword)); err != nil { + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] settingsPasswordHandler: current password mismatch from %s", r.RemoteAddr) + } data["PasswordError"] = "Hibás jelenlegi jelszó" s.executeTemplate(w, r, "settings", data) return @@ -1221,6 +1250,10 @@ func (s *Server) settingsPasswordHandler(w http.ResponseWriter, r *http.Request) func (s *Server) settingsNotificationsHandler(w http.ResponseWriter, r *http.Request) { _ = r.ParseForm() + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] settingsNotificationsHandler: updating notification prefs from %s", r.RemoteAddr) + } + email := strings.TrimSpace(r.FormValue("notification_email")) cooldownStr := r.FormValue("cooldown_hours") cooldownHours := 6 @@ -1410,6 +1443,10 @@ func (s *Server) settingsStorageAddHandler(w http.ResponseWriter, r *http.Reques label := strings.TrimSpace(r.FormValue("storage_label")) isDefault := r.FormValue("storage_default") == "true" + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] settingsStorageAddHandler: path=%s label=%q default=%v from %s", path, label, isDefault, r.RemoteAddr) + } + if label == "" { label = settings.InferStorageLabel(path) } @@ -1476,6 +1513,10 @@ func (s *Server) settingsStorageRemoveHandler(w http.ResponseWriter, r *http.Req _ = r.ParseForm() path := r.FormValue("storage_path") + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] settingsStorageRemoveHandler: path=%s from %s", path, r.RemoteAddr) + } + data := s.settingsData() // Check: apps using this path @@ -1518,6 +1559,10 @@ func (s *Server) settingsStorageDefaultHandler(w http.ResponseWriter, r *http.Re _ = r.ParseForm() path := r.FormValue("storage_path") + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] settingsStorageDefaultHandler: path=%s from %s", path, r.RemoteAddr) + } + if err := s.settings.SetDefaultStoragePath(path); err != nil { s.logger.Printf("[ERROR] Failed to set default storage path: %v", err) http.Redirect(w, r, "/settings", http.StatusFound) @@ -1531,6 +1576,10 @@ func (s *Server) settingsStorageSchedulableHandler(w http.ResponseWriter, r *htt path := r.FormValue("storage_path") schedulable := r.FormValue("schedulable") == "true" + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] settingsStorageSchedulableHandler: path=%s schedulable=%v from %s", path, schedulable, r.RemoteAddr) + } + if err := s.settings.SetSchedulable(path, schedulable); err != nil { s.logger.Printf("[ERROR] Failed to update schedulable: %v", err) http.Redirect(w, r, "/settings", http.StatusFound) @@ -1544,6 +1593,10 @@ func (s *Server) settingsStorageLabelHandler(w http.ResponseWriter, r *http.Requ path := r.FormValue("storage_path") label := strings.TrimSpace(r.FormValue("storage_label")) + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] settingsStorageLabelHandler: path=%s label=%q from %s", path, label, r.RemoteAddr) + } + if label == "" || len(label) > 50 { data := s.settingsData() data["StorageError"] = "A megnevezés nem lehet üres és legfeljebb 50 karakter." diff --git a/controller/internal/web/server.go b/controller/internal/web/server.go index 83bcf96..f666be2 100644 --- a/controller/internal/web/server.go +++ b/controller/internal/web/server.go @@ -12,6 +12,7 @@ import ( "sync" "time" + "gitea.dooplex.hu/admin/felhom-controller/internal/appexport" "gitea.dooplex.hu/admin/felhom-controller/internal/assets" "gitea.dooplex.hu/admin/felhom-controller/internal/backup" "gitea.dooplex.hu/admin/felhom-controller/internal/config" @@ -78,6 +79,9 @@ type Server struct { // App-to-app integration manager (optional) integrationMgr *integrations.Manager + // App export/import engine (optional) + appExporter *appexport.Exporter + // Debug mode support logBuffer *LogBuffer debugCallbacks *DebugCallbacks @@ -102,6 +106,13 @@ func NewServer(cfg *config.Config, stackMgr *stacks.Manager, cpuCollector *syste loginAttempts: make(map[string]*loginAttempt), done: make(chan struct{}), } + + if cfg.Logging.Level == "debug" { + logger.Printf("[DEBUG] [web] NewServer: initializing web server v%s", version) + logger.Printf("[DEBUG] [web] NewServer: backup=%v crossDrive=%v scheduler=%v alertMgr=%v notifier=%v updater=%v", + backupMgr != nil, crossDrive != nil, sched != nil, alertMgr != nil, notif != nil, updater != nil) + } + s.loadTemplates() go s.cleanupSessions() @@ -138,6 +149,10 @@ func (s *Server) loadTemplates() { s.tmpl = template.Must( template.New("").Funcs(s.templateFuncMap()).ParseFS(templateFS, "templates/*.html"), ) + if s.isDebug() { + names := s.tmpl.Templates() + s.logger.Printf("[DEBUG] [web] loadTemplates: loaded %d templates", len(names)) + } } // SetRestoreState puts the server into DR restore mode with the given plan. @@ -190,6 +205,11 @@ func (s *Server) SetDebugCallbacks(dc *DebugCallbacks) { s.debugCallbacks = dc } +// SetAppExporter sets the app export/import engine. +func (s *Server) SetAppExporter(e *appexport.Exporter) { + s.appExporter = e +} + // SetStartTime records the controller start time for uptime calculation. func (s *Server) SetStartTime(t time.Time) { s.startTime = t @@ -221,6 +241,10 @@ func (s *Server) InRestoreMode() bool { func (s *Server) ServeHTTP(w http.ResponseWriter, r *http.Request) { path := r.URL.Path + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] ServeHTTP: %s %s from %s", r.Method, path, r.RemoteAddr) + } + // DR restore mode: intercept all routes except restore page, static, and restore API if s.InRestoreMode() { switch { @@ -283,6 +307,10 @@ func (s *Server) ServeHTTP(w http.ResponseWriter, r *http.Request) { s.storageAttachHandler(w, r) case path == "/settings/storage/migrate-drive": s.migrateDrivePageHandler(w, r) + case strings.HasPrefix(path, "/stacks/") && strings.HasSuffix(path, "/export"): + name := strings.TrimPrefix(path, "/stacks/") + name = strings.TrimSuffix(name, "/export") + s.exportPageHandler(w, r, name) case strings.HasPrefix(path, "/stacks/") && strings.HasSuffix(path, "/migrate"): name := strings.TrimPrefix(path, "/stacks/") name = strings.TrimSuffix(name, "/migrate") @@ -295,6 +323,8 @@ func (s *Server) ServeHTTP(w http.ResponseWriter, r *http.Request) { name := strings.TrimPrefix(path, "/stacks/") name = strings.TrimSuffix(name, "/deploy") s.deployHandler(w, r, name) + case path == "/import": + s.importPageHandler(w, r) case path == "/static/style.css": s.serveCSSHandler(w, r) case path == "/static/chart.min.js": @@ -324,6 +354,9 @@ func (s *Server) ServeHTTP(w http.ResponseWriter, r *http.Request) { // the controller host (felhom.DOMAIN) pass through normally. func (s *Server) CatchAllMiddleware(next http.Handler) http.Handler { controllerHost := "felhom." + s.cfg.Customer.Domain + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] CatchAllMiddleware: controller host=%s", controllerHost) + } return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { host := r.Host if idx := strings.LastIndex(host, ":"); idx != -1 { @@ -335,6 +368,9 @@ func (s *Server) CatchAllMiddleware(next http.Handler) http.Handler { next.ServeHTTP(w, r) return } + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] CatchAllMiddleware: non-controller host=%s, serving catch-all page", host) + } s.serveCatchAll(w, r, host) }) } @@ -405,6 +441,9 @@ func (s *Server) findStackBySubdomain(subdomain string) (*stacks.Stack, bool) { // ServeStorageAPI handles /api/storage/* routes (JSON API for disk operations). func (s *Server) ServeStorageAPI(w http.ResponseWriter, r *http.Request) { + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] ServeStorageAPI: %s %s from %s", r.Method, r.URL.Path, r.RemoteAddr) + } s.storageAPIHandler(w, r) } diff --git a/controller/internal/web/storage_handlers.go b/controller/internal/web/storage_handlers.go index 664e3c0..a1d5291 100644 --- a/controller/internal/web/storage_handlers.go +++ b/controller/internal/web/storage_handlers.go @@ -151,6 +151,10 @@ func (s *Server) storageInitHandler(w http.ResponseWriter, r *http.Request) { func (s *Server) storageAPIHandler(w http.ResponseWriter, r *http.Request) { path := r.URL.Path + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] storageAPI: %s %s from %s", r.Method, path, r.RemoteAddr) + } + switch { case path == "/api/storage/scan" && r.Method == http.MethodPost: s.storageScanAPIHandler(w, r) @@ -197,12 +201,18 @@ func (s *Server) storageAPIHandler(w http.ResponseWriter, r *http.Request) { // storageScanAPIHandler handles POST /api/storage/scan. func (s *Server) storageScanAPIHandler(w http.ResponseWriter, r *http.Request) { + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] storageScan: scanning disks") + } result, err := storage.ScanDisks(s.logger, s.cfg.Logging.Level == "debug") if err != nil { s.logger.Printf("[ERROR] storageScan: %v", err) jsonError(w, "Meghajtók keresése sikertelen: "+err.Error(), http.StatusInternalServerError) return } + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] storageScan: found %d available disks, %d system disks", len(result.AvailableDisks), len(result.SystemDisks)) + } jsonResponse(w, map[string]interface{}{ "ok": true, "available": result.AvailableDisks, @@ -226,6 +236,11 @@ func (s *Server) storageInitAPIHandler(w http.ResponseWriter, r *http.Request) { return } + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] storageInit: device=%s mountName=%s label=%q partition=%v default=%v from %s", + req.DevicePath, req.MountName, req.Label, req.CreatePartition, req.SetDefault, r.RemoteAddr) + } + if req.Confirm != "FORMÁZÁS" { jsonError(w, "Megerősítés szükséges: írja be 'FORMÁZÁS'", http.StatusBadRequest) return @@ -432,6 +447,10 @@ func (s *Server) storageMigrateAPIHandler(w http.ResponseWriter, r *http.Request return } + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] storageMigrate: stack=%s target=%s from %s", req.StackName, req.TargetPath, r.RemoteAddr) + } + if req.StackName == "" || req.TargetPath == "" { jsonError(w, "Hiányos paraméterek", http.StatusBadRequest) return @@ -794,6 +813,10 @@ func (s *Server) staleDataCleanupHandler(w http.ResponseWriter, r *http.Request) return } + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] staleDataCleanup: stack=%s stalePath=%s from %s", req.StackName, req.StalePath, r.RemoteAddr) + } + if req.StackName == "" || req.StalePath == "" { jsonError(w, "Hiányos paraméterek", http.StatusBadRequest) return @@ -915,6 +938,10 @@ func (s *Server) storageAttachMountRawHandler(w http.ResponseWriter, r *http.Req return } + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] storageAttachMountRaw: device=%s from %s", req.DevicePath, r.RemoteAddr) + } + // Hold lock across entire cleanup+mount+set to prevent races s.diskJobMu.Lock() if s.activeRawMount != "" { @@ -1021,6 +1048,11 @@ func (s *Server) storageAttachAPIHandler(w http.ResponseWriter, r *http.Request) return } + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] storageAttach: device=%s mountName=%s subPath=%s label=%q default=%v from %s", + req.DevicePath, req.MountName, req.SubPath, req.Label, req.SetDefault, r.RemoteAddr) + } + if req.DevicePath == "" || req.MountName == "" || req.SubPath == "" { jsonError(w, "Hiányos paraméterek", http.StatusBadRequest) return @@ -1164,6 +1196,10 @@ func (s *Server) storageDisconnectHandler(w http.ResponseWriter, r *http.Request return } + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] storageDisconnect: path=%s from %s", req.Path, r.RemoteAddr) + } + if s.storageWatchdog == nil { jsonError(w, "Szolgáltatás nem elérhető", http.StatusServiceUnavailable) return @@ -1172,6 +1208,9 @@ func (s *Server) storageDisconnectHandler(w http.ResponseWriter, r *http.Request // Check if USB device (only USB drives can be safely disconnected) fsInfo := system.GetFSInfo(req.Path) if fsInfo != nil && fsInfo.Device != "" && !system.IsUSBDevice(fsInfo.Device) { + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] storageDisconnect: path=%s device=%s is not USB, rejecting", req.Path, fsInfo.Device) + } jsonError(w, "Csak USB meghajtó választható le biztonságosan", http.StatusBadRequest) return } @@ -1183,6 +1222,10 @@ func (s *Server) storageDisconnectHandler(w http.ResponseWriter, r *http.Request return } + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] storageDisconnect: path=%s success, stopped %d stacks", req.Path, len(stoppedStacks)) + } + jsonResponse(w, map[string]interface{}{ "ok": true, "message": "A meghajtó biztonságosan eltávolítható.", @@ -1205,6 +1248,10 @@ func (s *Server) storageReconnectHandler(w http.ResponseWriter, r *http.Request) return } + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] storageReconnect: path=%s from %s", req.Path, r.RemoteAddr) + } + if s.storageWatchdog == nil { jsonError(w, "Szolgáltatás nem elérhető", http.StatusServiceUnavailable) return @@ -1217,6 +1264,10 @@ func (s *Server) storageReconnectHandler(w http.ResponseWriter, r *http.Request) return } + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] storageReconnect: path=%s success, previously stopped stacks=%v", req.Path, stoppedStacks) + } + jsonResponse(w, map[string]interface{}{ "ok": true, "message": "Meghajtó sikeresen csatlakoztatva.", @@ -1239,6 +1290,10 @@ func (s *Server) storageRestartAppsHandler(w http.ResponseWriter, r *http.Reques return } + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] storageRestartApps: path=%s from %s", req.Path, r.RemoteAddr) + } + if s.storageWatchdog == nil { jsonError(w, "Szolgáltatás nem elérhető", http.StatusServiceUnavailable) return @@ -1246,11 +1301,17 @@ func (s *Server) storageRestartAppsHandler(w http.ResponseWriter, r *http.Reques // Validate drive is connected if s.settings.IsDisconnected(req.Path) { + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] storageRestartApps: path=%s is disconnected, rejecting", req.Path) + } jsonError(w, "A meghajtó jelenleg leválasztva — először csatlakoztassa", http.StatusBadRequest) return } started, failed := s.storageWatchdog.RestartStoppedApps(req.Path) + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] storageRestartApps: path=%s started=%v failed=%v", req.Path, started, failed) + } jsonResponse(w, map[string]interface{}{ "ok": true, "started": started, @@ -1387,6 +1448,10 @@ func (s *Server) driveMigrateAPIHandler(w http.ResponseWriter, r *http.Request) return } + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] driveMigrate: source=%s dest=%s from %s", req.SourcePath, req.DestPath, r.RemoteAddr) + } + if req.SourcePath == "" || req.DestPath == "" { jsonError(w, "Hiányos paraméterek", http.StatusBadRequest) return @@ -1497,6 +1562,10 @@ func (s *Server) decommissionRemoveHandler(w http.ResponseWriter, r *http.Reques req.Path = r.FormValue("storage_path") } + if s.isDebug() { + s.logger.Printf("[DEBUG] [web] decommissionRemove: path=%s from %s", req.Path, r.RemoteAddr) + } + if req.Path == "" { jsonError(w, "Hiányzó útvonal", http.StatusBadRequest) return diff --git a/controller/internal/web/templates/app_export.html b/controller/internal/web/templates/app_export.html new file mode 100644 index 0000000..2cf5156 --- /dev/null +++ b/controller/internal/web/templates/app_export.html @@ -0,0 +1,223 @@ +{{define "app_export"}} +{{template "layout_start" .}} + +
+
+ ← Alkalmazások +

{{.Stack.Meta.DisplayName}} — Exportálás

+
+
+ +
+

Mentés helye

+ + + + +

Jelszó (opcionális)

+
+ + +
+ + + + +
+ + + + + + + +{{template "layout_end" .}} +{{end}} diff --git a/controller/internal/web/templates/app_import.html b/controller/internal/web/templates/app_import.html new file mode 100644 index 0000000..b7b142d --- /dev/null +++ b/controller/internal/web/templates/app_import.html @@ -0,0 +1,287 @@ +{{define "app_import"}} +{{template "layout_start" .}} + +
+
+ ← Alkalmazások +

Alkalmazás importálás

+
+
+ +{{if not .Bundles}} +
+

Nem található .fab csomag a regisztrált tárolókon.

+

Exportálj egy alkalmazást az alkalmazás oldaláról, vagy másolj egy .fab fájlt a {tároló}/felhom-data/exports/ könyvtárba.

+
+{{else}} +
+ + + + + + + + + + + + + {{range .Bundles}} + + + + + + + + + {{end}} + +
AlkalmazásDátumMéretTárolóTitkos
{{if .DisplayName}}{{.DisplayName}}{{else}}{{.AppName}}{{end}}{{.ExportedAt}}{{.SizeHuman}}{{if .DriveLabel}}{{.DriveLabel}}{{else}}{{.DrivePath}}{{end}}{{if .Encrypted}}🔒{{end}}
+
+{{end}} + + + + + + + + + + + +{{template "layout_end" .}} +{{end}} diff --git a/controller/internal/web/templates/app_info.html b/controller/internal/web/templates/app_info.html index 86c6ffc..6358046 100644 --- a/controller/internal/web/templates/app_info.html +++ b/controller/internal/web/templates/app_info.html @@ -15,6 +15,7 @@ {{if .Stack.Orphaned}} {{else}} + Exportálás Beállítások {{end}} {{else}} diff --git a/controller/internal/web/templates/debug.html b/controller/internal/web/templates/debug.html index 08b2dff..f517381 100644 --- a/controller/internal/web/templates/debug.html +++ b/controller/internal/web/templates/debug.html @@ -184,6 +184,27 @@ + +
+
+

Alkalmazás Export/Import

+ ▶ +
+ +
+
@@ -285,6 +306,7 @@ function loadSectionData(id) { case 'telemetry': break; // no auto-load, user triggers manually case 'selfupdate': loadSelfUpdateStatus(); break; case 'dr': loadDRStatus(); break; + case 'appexport': loadAppExportStatus(); break; case 'logs': initLogViewer(); break; } } @@ -693,6 +715,137 @@ function renderTelemetryDetail(data) { detail.style.display = 'block'; } +// ── Section 9: App Export/Import ── +function loadAppExportStatus() { + document.getElementById('appexport-status').innerHTML = 'Betöltés...'; + fetch('/api/debug/appexport/status', {headers: csrfHeaders()}).then(function(r){return r.json()}).then(function(data) { + if (!data.ok) { document.getElementById('appexport-status').innerHTML = 'Nem elérhető'; return; } + renderAppExportStatus(data.data); + }).catch(function(e) { + document.getElementById('appexport-status').innerHTML = 'Hiba: ' + e.message + ''; + }); +} +function renderAppExportStatus(d) { + if (!d.available) { + document.getElementById('appexport-status').innerHTML = 'App export modul nem elérhető'; + return; + } + var html = '
'; + html += '
Debug mód
' + (d.debug_enabled ? 'Aktív' : 'Inaktív') + '
'; + html += '
Verzió
' + (d.version||'-') + '
'; + html += '
Csomagok
' + (d.bundle_count||0) + ' db
'; + html += '
Temp fájlok
' + (d.stale_temp_count||0) + ' db'; + if (d.stale_temp_count > 0) html += ' ⚠'; + html += '
'; + html += '
'; + + // Active job + if (d.has_active_job && d.active_job) { + var j = d.active_job; + html += '

Aktív feladat

'; + html += '
'; + html += '
Típus
' + (j.job_type||'-') + '
'; + html += '
Stack
' + (j.display_name || j.stack_name || '-') + '
'; + html += '
Állapot
' + (j.running ? '🔄 Fut' : j.done ? '✅ Kész' : '⏸ Várakozik') + '
'; + if (j.error) html += '
Hiba
' + escapeHtml(j.error) + '
'; + if (j.output_path) html += '
Kimenet
' + escapeHtml(j.output_path) + '
'; + if (j.output_size) html += '
Méret
' + j.output_size + '
'; + html += '
'; + if (j.steps && j.steps.length > 0) { + html += '
'; + j.steps.forEach(function(s) { + var icon = s.status === 'done' ? '✓' : s.status === 'running' ? '⟳' : s.status === 'failed' ? '✗' : '○'; + var cls = s.status === 'failed' ? 'color:var(--danger)' : s.status === 'done' ? 'color:var(--success)' : s.status === 'running' ? 'color:var(--primary)' : 'color:var(--text-muted)'; + html += '
' + icon + ' ' + escapeHtml(s.label); + if (s.error) html += ' (' + escapeHtml(s.error) + ')'; + html += '
'; + }); + html += '
'; + } + } + + // Export dirs + if (d.export_dirs && d.export_dirs.length > 0) { + html += '

Export könyvtárak

'; + html += ''; + d.export_dirs.forEach(function(dir) { + html += ''; + }); + html += '
ÚtvonalCimkeLétezik
' + escapeHtml(dir.path) + '' + (dir.label||'-') + '' + (dir.exists ? '✅' : '❌') + '
'; + } + + // Stale temp files + if (d.stale_temp_files && d.stale_temp_files.length > 0) { + html += '

Elavult temp fájlok

'; + html += '
    '; + d.stale_temp_files.forEach(function(f) { + html += '
  • ' + escapeHtml(f) + '
    • '; + }); + html += '
'; + } + + document.getElementById('appexport-status').innerHTML = html; + + // Auto-refresh if a job is running + if (d.has_active_job && d.active_job && d.active_job.running) { + startPolling('appexport', 2000, function() { + fetch('/api/debug/appexport/status', {headers: csrfHeaders()}).then(function(r){return r.json()}).then(function(data) { + if (data.ok) renderAppExportStatus(data.data); + }).catch(function(){}); + }); + } +} +function scanAppBundles() { + var btn = document.getElementById('btn-appexport-scan'); + var result = document.getElementById('btn-appexport-scan-result'); + btn.disabled = true; + btn.textContent = 'Keresés...'; + result.className = 'debug-result'; + result.textContent = ''; + fetch('/api/debug/appexport/bundles', {headers: csrfHeaders()}).then(function(r){return r.json()}).then(function(data) { + if (data.ok) { + result.className = 'debug-result debug-result-ok'; + result.textContent = data.message; + if (data.data && data.data.bundles) { + renderAppBundles(data.data.bundles); + } + } else { + result.className = 'debug-result debug-result-error'; + result.textContent = data.error || 'Hiba'; + } + }).catch(function(e) { + result.className = 'debug-result debug-result-error'; + result.textContent = 'Hálózati hiba: ' + e.message; + }).finally(function() { + btn.disabled = false; + btn.textContent = btn.dataset.label; + }); +} +function renderAppBundles(bundles) { + var container = document.getElementById('appexport-bundles'); + if (!bundles || bundles.length === 0) { + container.innerHTML = 'Nem található .fab csomag.'; + container.style.display = 'block'; + return; + } + var html = ''; + bundles.forEach(function(b) { + html += ''; + html += ''; + html += ''; + html += ''; + html += ''; + html += ''; + html += ''; + html += ''; + html += ''; + html += ''; + }); + html += '
AlkalmazásDátumMéretTárolóTitkosDBHDDElérés
' + escapeHtml(b.display_name || b.app_name) + '' + (b.exported_at || '-') + '' + (b.size_human || '-') + '' + escapeHtml(b.drive_label || b.drive_path) + '' + (b.encrypted ? '🔒' : '-') + '' + (b.has_db ? '✅' : '-') + '' + (b.needs_hdd ? '✅' : '-') + '' + escapeHtml(b.path) + '
'; + container.innerHTML = html; + container.style.display = 'block'; +} + // ── Helpers ── function fmtTime(ts) { if (!ts) return '-'; diff --git a/controller/internal/web/templates/stacks.html b/controller/internal/web/templates/stacks.html index 343e1e9..840495b 100644 --- a/controller/internal/web/templates/stacks.html +++ b/controller/internal/web/templates/stacks.html @@ -4,6 +4,7 @@

Alkalmazások

{{.Domain}} + Importálás