admin/felhom-controller
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

fix: standardize log prefixes, remove duplicates, add missing module tags

Browse Source 
Second-pass logging cleanup: consistent [LEVEL] [module] format across
all 41 files. Remove stale prefixes ([CF], [SYNC], [SCHED], [API],
[STORAGE], [HEALTH], [ROLLBACK]). Remove 5 duplicate log lines. Gate
ungated DEBUG lines. Fix wrong log levels (restore start WARN→INFO).

Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>
This commit is contained in:
authentik Default Admin
2026-02-26 21:20:09 +01:00
parent 8e61cd7ec4
commit af1dd14933
41 changed files with 477 additions and 473 deletions
Download Patch File Download Diff File Expand all files Collapse all files
controller/internal/stacks/deploy.go
+17 -18
View File
@@ -161,12 +161,12 @@ func (m *Manager) DeployStack(req DeployRequest) (string, error) {
reservedMB := m.cfg.System.ReservedMemoryMB
totalMB, usedMB, memErr := system.GetMemoryMB()
if memErr != nil {
m.logger.Printf("[WARN] Cannot read system memory: %v — skipping memory check", memErr)
m.logger.Printf("[WARN] [stacks] Cannot read system memory: %v — skipping memory check", memErr)
} else {
usableMB := totalMB - reservedMB
newReqMB := ParseMemoryMB(meta.Resources.MemRequest)
m.logger.Printf("[INFO] Memory check: total=%dMB, reserved=%dMB, usable=%dMB, real_used=%dMB, new_req=%dMB, remaining=%dMB",
m.logger.Printf("[INFO] [stacks] Memory check: total=%dMB, reserved=%dMB, usable=%dMB, real_used=%dMB, new_req=%dMB, remaining=%dMB",
totalMB, reservedMB, usableMB, usedMB, newReqMB, usableMB-usedMB-newReqMB)
// Hard block: real used + new request exceeds usable memory
@@ -309,7 +309,7 @@ func (m *Manager) DeployStack(req DeployRequest) (string, error) {
for k := range env {
envKeys = append(envKeys, k)
}
m.logger.Printf("[INFO] Deploying stack %s with %d env vars: [%s]", req.StackName, len(env), strings.Join(envKeys, ", "))
m.logger.Printf("[INFO] [stacks] Deploying stack %s with %d env vars: [%s]", req.StackName, len(env), strings.Join(envKeys, ", "))
// Check which images are available locally before pulling
if m.isDebug() {
@@ -339,7 +339,7 @@ func (m *Manager) runComposeDeploy(name, stackDir string, env map[string]string,
_, composeErr := m.composeExecWithEnv(stackDir, env, "up", "-d")
if composeErr != nil {
m.logger.Printf("[ERROR] Stack %s deploy failed after %.1fs: %v", name, time.Since(start).Seconds(), composeErr)
m.logger.Printf("[ERROR] [stacks] Stack %s deploy failed after %.1fs: %v", name, time.Since(start).Seconds(), composeErr)
// Revert in-memory and disk state
m.mu.Lock()
if s, ok := m.stacks[name]; ok {
@@ -357,7 +357,7 @@ func (m *Manager) runComposeDeploy(name, stackDir string, env map[string]string,
return
}
m.logger.Printf("[INFO] Stack %s deployed successfully (took %.1fs)", name, time.Since(start).Seconds())
m.logger.Printf("[INFO] [stacks] Stack %s deployed successfully (took %.1fs)", name, time.Since(start).Seconds())
// Clear deploying flag
m.mu.Lock()
@@ -427,7 +427,7 @@ func (m *Manager) UpdateStackConfig(name string, values map[string]string) error
return fmt.Errorf("restarting with new config: %w", err)
}
m.logger.Printf("[INFO] Stack %s config updated and restarted", name)
m.logger.Printf("[INFO] [stacks] Stack %s config updated and restarted", name)
return m.RefreshStatus()
}
@@ -503,13 +503,13 @@ func (m *Manager) UpdateOptionalConfig(stackName string, values map[string]strin
changed := false
for key, val := range values {
if !allowed[key] {
m.logger.Printf("[WARN] Ignoring non-optional env var: %s", key)
m.logger.Printf("[WARN] [stacks] Ignoring non-optional env var: %s", key)
continue
}
if appCfg.Env[key] != val {
appCfg.Env[key] = val
changed = true
m.logger.Printf("[INFO] Updated optional config %s for %s", key, stackName)
m.logger.Printf("[INFO] [stacks] Updated optional config %s for %s", key, stackName)
}
}
@@ -522,12 +522,12 @@ func (m *Manager) UpdateOptionalConfig(stackName string, values map[string]strin
if err := SaveAppConfig(stackDir, appCfg, m.encKey, SensitiveEnvVars(&meta)); err != nil {
return fmt.Errorf("saving app config: %w", err)
}
m.logger.Printf("[INFO] Saved updated app.yaml for %s", stackName)
m.logger.Printf("[INFO] [stacks] Saved updated app.yaml for %s", stackName)
// If deployed, recreate containers to pick up new env vars
// (docker compose restart does NOT pick up new env vars — must use up -d)
if stack.Deployed {
m.logger.Printf("[INFO] Restarting %s to apply new optional config", stackName)
m.logger.Printf("[INFO] [stacks] Restarting %s to apply new optional config", stackName)
env := m.stackEnv(stackDir)
if _, err := m.composeExecCustomEnv(stackDir, env, "up", "-d"); err != nil {
return fmt.Errorf("restart after config update: %w", err)
@@ -591,7 +591,6 @@ func LoadAppConfig(stackDir string) *AppConfig {
cfg := &AppConfig{}
if err := yaml.Unmarshal(data, cfg); err != nil {
log.Printf("[WARN] [stacks] LoadAppConfig: %v", err)
log.Printf("[DEBUG] [stacks] LoadAppConfig: failed to parse %s: %v", path, err)
return nil
}
return cfg
@@ -618,7 +617,7 @@ func SaveAppConfig(stackDir string, cfg *AppConfig, encKey []byte, sensitiveVars
continue
} else {
// H10 fix: log encryption failure — value will be saved in plaintext.
log.Printf("[WARN] Failed to encrypt env var %q: %v — saving as plaintext", k, err)
log.Printf("[WARN] [stacks] Failed to encrypt env var %q: %v — saving as plaintext", k, err)
}
}
saveCfg.Env[k] = v
@@ -763,12 +762,12 @@ func (m *Manager) InjectMissingFields(stackNames []string) {
switch field.Type {
case "secret":
if field.Generate == "" {
m.logger.Printf("[WARN] Stack %s: new secret field %s has no generator — skipping", name, field.EnvVar)
m.logger.Printf("[WARN] [stacks] Stack %s: new secret field %s has no generator — skipping", name, field.EnvVar)
continue
}
value, err := generateValue(field.Generate)
if err != nil {
m.logger.Printf("[ERROR] Stack %s: failed to generate %s: %v", name, field.EnvVar, err)
m.logger.Printf("[ERROR] [stacks] Stack %s: failed to generate %s: %v", name, field.EnvVar, err)
continue
}
appCfg.Env[field.EnvVar] = value
@@ -791,7 +790,7 @@ func (m *Manager) InjectMissingFields(stackNames []string) {
val = meta.Subdomain
}
if val == "" {
m.logger.Printf("[WARN] Stack %s: new subdomain field %s has no default — skipping", name, field.EnvVar)
m.logger.Printf("[WARN] [stacks] Stack %s: new subdomain field %s has no default — skipping", name, field.EnvVar)
continue
}
appCfg.Env[field.EnvVar] = val
@@ -801,16 +800,16 @@ func (m *Manager) InjectMissingFields(stackNames []string) {
injected = append(injected, field.EnvVar)
default:
m.logger.Printf("[WARN] Stack %s: new field %s (type=%s) requires manual configuration", name, field.EnvVar, field.Type)
m.logger.Printf("[WARN] [stacks] Stack %s: new field %s (type=%s) requires manual configuration", name, field.EnvVar, field.Type)
}
}
if len(injected) > 0 {
if err := SaveAppConfig(stackDir, appCfg, m.encKey, SensitiveEnvVars(&meta)); err != nil {
m.logger.Printf("[ERROR] Stack %s: failed to save app.yaml after injection: %v", name, err)
m.logger.Printf("[ERROR] [stacks] Stack %s: failed to save app.yaml after injection: %v", name, err)
continue
}
m.logger.Printf("[SYNC] Stack %s: injected missing fields: %s", name, strings.Join(injected, ", "))
m.logger.Printf("[INFO] [stacks] Stack %s: injected missing fields: %s", name, strings.Join(injected, ", "))
}
}
m.logger.Printf("[INFO] [stacks] InjectMissingFields: processed %d stacks", count)
controller/internal/stacks/manager.go
+29 -30
View File
@@ -96,7 +96,7 @@ func NewManager(cfg *config.Config, logger *log.Logger) (*Manager, error) {
return nil, fmt.Errorf("docker compose not found (tried 'docker compose' and 'docker-compose')")
}
logger.Printf("[INFO] Using compose command: %s", composeCmd)
logger.Printf("[INFO] [stacks] Using compose command: %s", composeCmd)
if err := os.MkdirAll(cfg.Paths.StacksDir, 0755); err != nil {
return nil, fmt.Errorf("creating stacks directory %s: %w", cfg.Paths.StacksDir, err)
@@ -176,14 +176,14 @@ func (m *Manager) MigrateEncryption() {
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)
m.logger.Printf("[WARN] [stacks] Encryption migration failed for %s: %v", s.Name, err)
} else {
migrated++
}
}
}
if migrated > 0 {
m.logger.Printf("[INFO] Encrypted sensitive values in %d app.yaml file(s)", migrated)
m.logger.Printf("[INFO] [stacks] Encrypted sensitive values in %d app.yaml file(s)", migrated)
} else {
m.logger.Printf("[INFO] [stacks] Encryption migration: no stacks needed migration")
}
@@ -316,7 +316,7 @@ func (m *Manager) ScanStacks() error {
}
}
if orphanCount > 0 {
m.logger.Printf("[INFO] Detected %d orphaned stack(s)", orphanCount)
m.logger.Printf("[INFO] [stacks] Detected %d orphaned stack(s)", orphanCount)
}
}
@@ -326,9 +326,8 @@ func (m *Manager) ScanStacks() error {
deployedCount++
}
}
m.logger.Printf("[INFO] Scanned stacks: %d found (%d deployed, %d available)",
m.logger.Printf("[INFO] [stacks] ScanStacks complete: %d stacks found (%d deployed, %d available)",
len(m.stacks), deployedCount, len(m.stacks)-deployedCount)
m.logger.Printf("[INFO] [stacks] ScanStacks complete: %d stacks found", len(m.stacks))
return m.refreshStatusLocked()
}
@@ -628,7 +627,7 @@ func (m *Manager) StartStack(name string) error {
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)
m.logger.Printf("[INFO] [stacks] Starting stack: %s", name)
start := time.Now()
dir := filepath.Dir(stack.ComposePath)
@@ -639,11 +638,11 @@ func (m *Manager) StartStack(name string) error {
}
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)
m.logger.Printf("[ERROR] [stacks] Stack %s start failed after %.1fs: %v", name, time.Since(start).Seconds(), err)
return fmt.Errorf("starting stack %s: %w", name, err)
}
m.logger.Printf("[INFO] Stack %s started successfully (took %.1fs)", name, time.Since(start).Seconds())
m.logger.Printf("[INFO] [stacks] Stack %s started successfully (took %.1fs)", name, time.Since(start).Seconds())
m.logPostStartStatus(name, dir, env)
// Clear stale health probe so refreshStatus won't re-apply an old unhealthy override.
@@ -671,16 +670,16 @@ func (m *Manager) StopStack(name string) error {
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)
m.logger.Printf("[INFO] [stacks] Stopping stack: %s", name)
start := time.Now()
dir := filepath.Dir(stack.ComposePath)
if _, err := m.composeExec(dir, "down"); err != nil {
m.logger.Printf("[ERROR] Stack %s stop failed after %.1fs: %v", name, time.Since(start).Seconds(), err)
m.logger.Printf("[ERROR] [stacks] Stack %s stop failed after %.1fs: %v", name, time.Since(start).Seconds(), err)
return fmt.Errorf("stopping stack %s: %w", name, err)
}
m.logger.Printf("[INFO] Stack %s stopped successfully (took %.1fs)", name, time.Since(start).Seconds())
m.logger.Printf("[INFO] [stacks] Stack %s stopped successfully (took %.1fs)", name, time.Since(start).Seconds())
return m.RefreshStatus()
}
@@ -694,7 +693,7 @@ func (m *Manager) RestartStack(name string) error {
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)
m.logger.Printf("[INFO] [stacks] Restarting stack: %s", name)
start := time.Now()
dir := filepath.Dir(stack.ComposePath)
env := m.stackEnv(dir)
@@ -704,11 +703,11 @@ func (m *Manager) RestartStack(name string) error {
// picked up. Plain "docker compose restart" only sends SIGTERM+start
// to existing containers without re-reading the compose file or env.
if _, err := m.composeExecCustomEnv(dir, env, "up", "-d"); err != nil {
m.logger.Printf("[ERROR] Stack %s restart failed after %.1fs: %v", name, time.Since(start).Seconds(), err)
m.logger.Printf("[ERROR] [stacks] Stack %s restart failed after %.1fs: %v", name, time.Since(start).Seconds(), err)
return fmt.Errorf("restarting stack %s: %w", name, err)
}
m.logger.Printf("[INFO] Stack %s restarted successfully (took %.1fs)", name, time.Since(start).Seconds())
m.logger.Printf("[INFO] [stacks] Stack %s restarted successfully (took %.1fs)", name, time.Since(start).Seconds())
m.logPostStartStatus(name, dir, env)
// Clear stale health probe so refreshStatus won't re-apply an old unhealthy override.
@@ -727,7 +726,7 @@ func (m *Manager) UpdateStack(name string) error {
return fmt.Errorf("stack %q not found", name)
}
m.logger.Printf("[INFO] Updating stack: %s", name)
m.logger.Printf("[INFO] [stacks] Updating stack: %s", name)
start := time.Now()
dir := filepath.Dir(stack.ComposePath)
env := m.stackEnv(dir)
@@ -737,16 +736,16 @@ func (m *Manager) UpdateStack(name string) error {
}
if _, err := m.composeExecCustomEnv(dir, env, "pull"); err != nil {
m.logger.Printf("[ERROR] Stack %s update (pull) failed after %.1fs: %v", name, time.Since(start).Seconds(), err)
m.logger.Printf("[ERROR] [stacks] Stack %s update (pull) failed after %.1fs: %v", name, time.Since(start).Seconds(), err)
return fmt.Errorf("pulling images for %s: %w", name, err)
}
if _, err := m.composeExecCustomEnv(dir, env, "up", "-d", "--remove-orphans"); err != nil {
m.logger.Printf("[ERROR] Stack %s update (up) failed after %.1fs: %v", name, time.Since(start).Seconds(), err)
m.logger.Printf("[ERROR] [stacks] Stack %s update (up) failed after %.1fs: %v", name, time.Since(start).Seconds(), err)
return fmt.Errorf("recreating %s: %w", name, err)
}
m.logger.Printf("[INFO] Stack %s updated successfully (took %.1fs)", name, time.Since(start).Seconds())
m.logger.Printf("[INFO] [stacks] Stack %s updated successfully (took %.1fs)", name, time.Since(start).Seconds())
m.logPostStartStatus(name, dir, env)
return m.RefreshStatus()
}
@@ -765,12 +764,11 @@ func (m *Manager) GetLogs(name string, lines int) (string, error) {
}
m.logger.Printf("[INFO] [stacks] Fetching logs for stack %s (tail=%d)", name, lines)
m.logger.Printf("[DEBUG] Fetching logs for %s (tail %d)", name, lines)
dir := filepath.Dir(stack.ComposePath)
output, err := m.composeExec(dir, "logs", "--tail", fmt.Sprintf("%d", lines), "--no-color")
if err != nil {
m.logger.Printf("[WARN] Failed to fetch logs for %s: %v", name, err)
m.logger.Printf("[WARN] [stacks] Failed to fetch logs for %s: %v", name, err)
return "", fmt.Errorf("getting logs for %s: %w", name, err)
}
@@ -860,13 +858,13 @@ func (m *Manager) composeExecCustomEnv(dir string, env []string, args ...string)
if exitErr, ok := err.(*exec.ExitError); ok {
exitCode = exitErr.ExitCode()
}
m.logger.Printf("[ERROR] Command failed: %s %s (in %s) — exit code %d (took %.1fs)",
m.logger.Printf("[ERROR] [stacks] Command failed: %s %s (in %s) — exit code %d (took %.1fs)",
m.composeCmd, strings.Join(args, " "), dir, exitCode, elapsed.Seconds())
if stdoutStr := truncateStr(stdout.String(), 500); stdoutStr != "" {
m.logger.Printf("[ERROR] stdout: %s", stdoutStr)
m.logger.Printf("[ERROR] [stacks] stdout: %s", stdoutStr)
}
if stderrStr := truncateStr(stderr.String(), 500); stderrStr != "" {
m.logger.Printf("[ERROR] stderr: %s", stderrStr)
m.logger.Printf("[ERROR] [stacks] stderr: %s", stderrStr)
}
return stdout.String(), fmt.Errorf("exit code %d\nstderr: %s", exitCode, truncateStr(stderr.String(), 500))
}
@@ -883,6 +881,7 @@ func (m *Manager) execCommand(name string, args ...string) (string, error) {
cmd.Stderr = &stderr
if err := cmd.Run(); err != nil {
m.logger.Printf("[ERROR] [stacks] execCommand failed: %v", err)
return "", fmt.Errorf("exec %s %s: %w\nstderr: %s", name, strings.Join(args, " "), err, stderr.String())
}
@@ -913,20 +912,20 @@ func (m *Manager) logPostStartStatus(name, stackDir string, env []string) {
output, err := m.composeExecCustomEnv(stackDir, envCopy, "ps", "-a", "--format", "table {{.Name}}\t{{.Image}}\t{{.State}}\t{{.Status}}")
if err != nil {
m.logger.Printf("[WARN] Post-start status check failed for %s: %v", name, err)
m.logger.Printf("[WARN] [stacks] Post-start status check failed for %s: %v", name, err)
return
}
lines := strings.Split(strings.TrimSpace(output), "\n")
if len(lines) <= 1 {
m.logger.Printf("[WARN] Post-start status for %s: no containers found", name)
m.logger.Printf("[WARN] [stacks] Post-start status for %s: no containers found", name)
return
}
m.logger.Printf("[INFO] Stack %s post-start status:", name)
m.logger.Printf("[INFO] [stacks] Stack %s post-start status:", name)
// Skip header line
for _, line := range lines[1:] {
m.logger.Printf("[INFO] %s", line)
m.logger.Printf("[INFO] [stacks] %s", line)
}
}()
}
@@ -962,7 +961,7 @@ func (m *Manager) checkLocalImages(name, stackDir string) {
return
}
m.logger.Printf("[INFO] Deploying stack %s — checking %d images...", name, len(images))
m.logger.Printf("[INFO] [stacks] Deploying stack %s — checking %d images...", name, len(images))
for _, img := range images {
cmd := exec.Command("docker", "image", "inspect", img)
if err := cmd.Run(); err != nil {
@@ -1057,7 +1056,7 @@ func (m *Manager) getCatalogTemplateSlugs() map[string]bool {
cacheDir := filepath.Join(m.cfg.Paths.DataDir, "catalog-cache", "templates")
entries, err := os.ReadDir(cacheDir)
if err != nil {
m.logger.Printf("[WARN] Cannot read catalog cache for orphan detection: %v", err)
m.logger.Printf("[WARN] [stacks] Cannot read catalog cache for orphan detection: %v", err)
return nil
}
slugs := make(map[string]bool, len(entries))