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