Fixed README version

### Added
- File logging to `/var/log/ha-backup.log`. Each line has a full date and time,
  and the file is appended to on every run.
- New `LOG_FILE` setting in `home_assistant_backup.conf`. Set it to a custom
  path, or to `"none"` to disable file logging.
- `ssh`/`scp` error output is also written to the log file.
- Deletions of old local backups are now logged.

### Changed
- All console messages now go through the same logger, so remote cleanup,
  notification failures and config validation errors appear in the log too.
- If the log file can't be opened (for example, no write permission to
  `/var/log`), a warning is printed and the backup continues without file logging.
- The terminal progress bar stays on the console only and is not written to the log.

V3/README.md

@@ -1,26 +1,54 @@
-# ha-backup
+# ha-backup v3.2.0
 
 Go port of `home_assistant_backup.sh`. Uses the same `home_assistant_backup.conf`.
 
 ## Build
-```
+    CGO_ENABLED=0 go build -trimpath -ldflags="-s -w" -o ha-backup .
-CGO_ENABLED=0 go build -trimpath -ldflags="-s -w" -o ha-backup .
+
-```
+Override the version at build time if needed:
+    CGO_ENABLED=0 go build -trimpath -ldflags="-s -w -X main.version=3.1.2" -o ha-backup .
+
+Check the version:
+    ./ha-backup -version
 
 Cross-compile examples:
-```
     GOOS=linux GOARCH=amd64 go build -o ha-backup-linux-amd64 .
     GOOS=linux GOARCH=arm64 go build -o ha-backup-linux-arm64 .   # Raspberry Pi / ARM NAS
+
+
+## Logging
+
+ha-backup writes a log to `/var/log/ha-backup.log` by default. Each line is timestamped, and the file is appended to on every run. The same output is still printed to the console.
+
+### Create the log file
+
+Writing to `/var/log` requires elevated permissions, so create the file once and give ownership to the user that runs the backup. Replace `backupuser` with that user (use `root` if you run it as root):
+
+
+If you'd rather do it in steps:
+
 ```
+sudo touch /var/log/ha-backup.log
+sudo chown backupuser:backupuser /var/log/ha-backup.log
+sudo chmod 640 /var/log/ha-backup.log
+```
+
+If the log file can't be opened, ha-backup prints a warning and continues the backup without file logging.
+
+### Change or disable the log location
+
+Set `LOG_FILE` in `home_assistant_backup.conf`:
+
+```bash
+LOG_FILE="/var/log/ha-backup.log"   # default
+LOG_FILE="/home/backupuser/ha-backup.log"   # custom path
+LOG_FILE="none"                     # disable file logging
+```
+
 
 ## Run
-#### looks for home_assistant_backup.conf next to the binary, then in cwd
+    ./ha-backup # looks for home_assistant_backup.conf next to the binary, then in cwd
-```
+    ./ha-backup -config /path/to.conf
-./ha-backup
-```
 
-```  
-./ha-backup -config /path/to.conf
-```
 
 Requires `ssh` and `scp` on the machine running it. `jq` and `yq` are no longer needed.

V3/home_assistant_backup.conf

@@ -30,3 +30,9 @@ NTFY_TOPIC="NTFY_TOPIC"  # Replace with your ntfy topic
 DISCORD_ENABLED=false  # Set to 'true' to enable Discord notifications
 DISCORD_WEBHOOK_URL="DISCORD_WEBHOOK_URL"  # Replace with your Discord webhook URL
 
+
+## Logging
+# Set the log file location (Default /var/log/ha-backup.log)
+# The file must be writable by the user running ha-backup, see the README
+# Set to "none" to disable logging to a file (console output is unaffected)
+LOG_FILE="/var/log/ha-backup.log"

V3/main.go

@@ -1,6 +1,6 @@
-// ha-backup: creates a Home Assistant backup over SSH, copies it locally,
+// ha-backup v3.2.0: creates a Home Assistant backup over SSH, copies it locally,
-// prunes old backups (remote and local) and sends optional ntfy/Discord
+// prunes old backups (remote and local), logs to /var/log and sends optional
-// notifications. Go port of home_assistant_backup.sh.
+// ntfy/Discord notifications. Go port of home_assistant_backup.sh.
 //
 // Only the standard library is used. The system `ssh` and `scp` binaries are
 // still required (same as the original script), but `jq` and `yq` are not.
@@ -12,6 +12,7 @@ import (
 	"encoding/json"
 	"flag"
 	"fmt"
+	"io"
 	"io/fs"
 	"net/http"
 	"os"
@@ -20,6 +21,7 @@ import (
 	"regexp"
 	"strconv"
 	"strings"
+	"sync"
 	"time"
 )
 
@@ -29,6 +31,14 @@ import (
 
 const defaultConfigName = "home_assistant_backup.conf"
 
+// defaultLogFile is where the log is written unless LOG_FILE says otherwise.
+const defaultLogFile = "/var/log/ha-backup.log"
+
+// version is the release version. It can be overridden at build time with:
+//
+//	go build -ldflags "-X main.version=3.2.0"
+var version = "3.2.0"
+
 type Config struct {
 	SSHKey  string
 	SSHUser string
@@ -41,6 +51,10 @@ type Config struct {
 	LocalCleanupDays   int
 	RemoteCleanupDays  int
 
+	// LogFile is the path of the log file. Set LOG_FILE="none" to disable
+	// file logging.
+	LogFile string
+
 	NtfyEnabled bool
 	NtfyServer  string
 	NtfyTopic   string
@@ -115,6 +129,7 @@ func loadConfig(path string) (*Config, error) {
 		SSHPort:            get("HA_SSH_PORT", ""),
 		BackupDest:         get("BACKUP_DEST", ""),
 		BackupFileLocation: strings.TrimRight(get("BACKUP_FILE_LOCATION", "/backup"), "/"),
+		LogFile:            get("LOG_FILE", defaultLogFile),
 		NtfyEnabled:        get("NTFY_ENABLED", "false") == "true",
 		NtfyServer:         get("NTFY_SERVER", ""),
 		NtfyTopic:          get("NTFY_TOPIC", ""),
@@ -165,6 +180,56 @@ func (c *Config) validate() error {
 	return nil
 }
 
+// ---------------------------------------------------------------------------
+// Logging
+// ---------------------------------------------------------------------------
+
+var (
+	logMu   sync.Mutex
+	logFile *os.File // nil when file logging is disabled or could not be opened
+)
+
+// openLog opens (or creates) the log file in append mode. An empty path or
+// "none" disables file logging. Console output is never affected.
+func openLog(path string) error {
+	if path == "" || strings.EqualFold(path, "none") {
+		return nil
+	}
+	f, err := os.OpenFile(path, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0o640)
+	if err != nil {
+		return err
+	}
+	logMu.Lock()
+	logFile = f
+	logMu.Unlock()
+	return nil
+}
+
+// logf prints a timestamped line to the console and, when enabled, appends a
+// line with a full date and time to the log file.
+func logf(format string, a ...any) {
+	msg := fmt.Sprintf(format, a...)
+	now := time.Now()
+
+	logMu.Lock()
+	defer logMu.Unlock()
+	fmt.Printf("[%s] %s\n", now.Format("15:04:05"), msg)
+	if logFile != nil {
+		fmt.Fprintf(logFile, "%s %s\n", now.Format("2006-01-02 15:04:05"), msg)
+	}
+}
+
+// stderrWriter returns a writer for subprocess stderr that goes to the
+// terminal and, when enabled, to the log file as well.
+func stderrWriter() io.Writer {
+	logMu.Lock()
+	defer logMu.Unlock()
+	if logFile != nil {
+		return io.MultiWriter(os.Stderr, logFile)
+	}
+	return os.Stderr
+}
+
 // ---------------------------------------------------------------------------
 // Notifications
 // ---------------------------------------------------------------------------
@@ -181,12 +246,12 @@ func NewNotifier(cfg *Config) *Notifier {
 func (n *Notifier) post(url, contentType string, body []byte) {
 	resp, err := n.client.Post(url, contentType, bytes.NewReader(body))
 	if err != nil {
-		fmt.Fprintf(os.Stderr, "notification failed (%s): %v\n", url, err)
+		logf("notification failed (%s): %v", url, err)
 		return
 	}
 	resp.Body.Close()
 	if resp.StatusCode >= 300 {
-		fmt.Fprintf(os.Stderr, "notification failed (%s): HTTP %d\n", url, resp.StatusCode)
+		logf("notification failed (%s): HTTP %d", url, resp.StatusCode)
 	}
 }
 
@@ -211,12 +276,12 @@ type Remote struct{ cfg *Config }
 func (r Remote) target() string { return r.cfg.SSHUser + "@" + r.cfg.SSHHost }
 
 // run executes a command on the Home Assistant host and returns its stdout.
-// stderr is passed through to the terminal.
+// stderr is passed through to the terminal (and the log file).
 func (r Remote) run(remoteCmd string) (string, error) {
 	cmd := exec.Command("ssh", "-i", r.cfg.SSHKey, "-p", r.cfg.SSHPort, r.target(), remoteCmd)
 	var out bytes.Buffer
 	cmd.Stdout = &out
-	cmd.Stderr = os.Stderr
+	cmd.Stderr = stderrWriter()
 	err := cmd.Run()
 	return out.String(), err
 }
@@ -225,7 +290,7 @@ func (r Remote) copyFrom(remotePath, localPath string) error {
 	cmd := exec.Command("scp", "-i", r.cfg.SSHKey, "-P", r.cfg.SSHPort,
 		r.target()+":"+remotePath, localPath)
 	cmd.Stdout = os.Stdout
-	cmd.Stderr = os.Stderr
+	cmd.Stderr = stderrWriter()
 	return cmd.Run()
 }
 
@@ -276,11 +341,11 @@ func (r Remote) listBackups() ([]backupEntry, error) {
 }
 
 func removeOldRemoteBackups(r Remote, n *Notifier, days int) {
-	fmt.Printf("Removing backups older than %d days on Home Assistant server...\n", days)
+	logf("Removing backups older than %d days on Home Assistant server...", days)
 
 	backups, err := r.listBackups()
 	if err != nil {
-		fmt.Printf("Error: %v\n", err)
+		logf("Error: %v", err)
 		return
 	}
 
@@ -289,27 +354,27 @@ func removeOldRemoteBackups(r Remote, n *Notifier, days int) {
 	for _, b := range backups {
 		t, err := time.Parse(time.RFC3339Nano, b.Date)
 		if err != nil {
-			fmt.Printf("Skipping backup %s: cannot parse date %q\n", b.Slug, b.Date)
+			logf("Skipping backup %s: cannot parse date %q", b.Slug, b.Date)
 			continue
 		}
 		if !t.Before(cutoff) {
 			continue
 		}
 		if !slugRe.MatchString(b.Slug) {
-			fmt.Printf("Skipping backup with unexpected slug %q\n", b.Slug)
+			logf("Skipping backup with unexpected slug %q", b.Slug)
 			continue
 		}
-		fmt.Printf("Removing backup with slug: %s\n", b.Slug)
+		logf("Removing backup with slug: %s", b.Slug)
 		if _, err := r.run("ha backups remove " + b.Slug); err != nil {
-			fmt.Printf("Failed to remove backup with slug: %s\n", b.Slug)
+			logf("Failed to remove backup with slug: %s", b.Slug)
 			continue
 		}
 		removed++
-		fmt.Printf("Successfully removed backup with slug: %s\n", b.Slug)
+		logf("Successfully removed backup with slug: %s", b.Slug)
 		n.Send("Old backup removed: " + b.Slug)
 	}
 	if removed == 0 {
-		fmt.Println("No old backups found to remove.")
+		logf("No old backups found to remove.")
 	}
 }
 
@@ -366,12 +431,133 @@ func removeOldLocalBackups(dir string, days int) error {
 			return err
 		}
 		if now.Sub(info.ModTime()) >= minAge {
+			logf("Removing old local backup: %s", path)
 			return os.Remove(path)
 		}
 		return nil
 	})
 }
 
+// ---------------------------------------------------------------------------
+// Progress reporting
+// ---------------------------------------------------------------------------
+
+func humanBytes(n int64) string {
+	const unit = 1024
+	if n < unit {
+		return fmt.Sprintf("%d B", n)
+	}
+	div, exp := int64(unit), 0
+	for m := n / unit; m >= unit; m /= unit {
+		div *= unit
+		exp++
+	}
+	return fmt.Sprintf("%.1f %cB", float64(n)/float64(div), "KMGTPE"[exp])
+}
+
+func stdoutIsTerminal() bool {
+	fi, err := os.Stdout.Stat()
+	return err == nil && fi.Mode()&os.ModeCharDevice != 0
+}
+
+// withHeartbeat runs fn and prints a "still running" line every interval so
+// long operations don't look hung.
+func withHeartbeat(label string, interval time.Duration, fn func() error) error {
+	start := time.Now()
+	done := make(chan struct{})
+	go func() {
+		t := time.NewTicker(interval)
+		defer t.Stop()
+		for {
+			select {
+			case <-done:
+				return
+			case <-t.C:
+				logf("%s... still running (%s elapsed)", label, time.Since(start).Round(time.Second))
+			}
+		}
+	}()
+	err := fn()
+	close(done)
+	return err
+}
+
+// remoteSize returns the size in bytes of a file on the HA host (0 if unknown).
+func (r Remote) remoteSize(path string) int64 {
+	out, err := r.run("wc -c < '" + path + "'")
+	if err != nil {
+		return 0
+	}
+	f := strings.Fields(out)
+	if len(f) == 0 {
+		return 0
+	}
+	n, _ := strconv.ParseInt(f[0], 10, 64)
+	return n
+}
+
+// copyWithProgress runs scp while reporting how much has arrived locally.
+// On a terminal it updates a single line (console only, never written to the
+// log file); otherwise (cron, logs) it logs a line every 10 seconds.
+func (r Remote) copyWithProgress(remotePath, localPath string) error {
+	total := r.remoteSize(remotePath)
+	if total > 0 {
+		logf("Backup size on Home Assistant: %s", humanBytes(total))
+	}
+
+	tty := stdoutIsTerminal()
+	interval := 10 * time.Second
+	if tty {
+		interval = time.Second
+	}
+
+	stop := make(chan struct{})
+	stopped := make(chan struct{})
+	start := time.Now()
+	go func() {
+		defer close(stopped)
+		t := time.NewTicker(interval)
+		defer t.Stop()
+		for {
+			select {
+			case <-stop:
+				if tty {
+					fmt.Print("\r\033[K")
+				}
+				return
+			case <-t.C:
+				info, err := os.Stat(localPath)
+				if err != nil {
+					continue
+				}
+				cur := info.Size()
+				secs := time.Since(start).Seconds()
+				speed := int64(0)
+				if secs > 0 {
+					speed = int64(float64(cur) / secs)
+				}
+				var msg string
+				if total > 0 {
+					msg = fmt.Sprintf("Copying: %s / %s (%d%%) at %s/s",
+						humanBytes(cur), humanBytes(total), cur*100/total, humanBytes(speed))
+				} else {
+					msg = fmt.Sprintf("Copying: %s at %s/s", humanBytes(cur), humanBytes(speed))
+				}
+				if tty {
+					fmt.Printf("\r\033[K[%s] %s", time.Now().Format("15:04:05"), msg)
+				} else {
+					logf("%s", msg)
+				}
+			}
+		}
+	}()
+
+	err := r.copyFrom(remotePath, localPath)
+	close(stop)
+	<-stopped
+	return err
+}
+
 // ---------------------------------------------------------------------------
 // main
 // ---------------------------------------------------------------------------
@@ -391,16 +577,29 @@ func findConfig(flagPath string) string {
 
 func main() {
 	confFlag := flag.String("config", "", "path to config file (default: "+defaultConfigName+" next to the binary, then current directory)")
+	versionFlag := flag.Bool("version", false, "print version and exit")
 	flag.Parse()
 
+	if *versionFlag {
+		fmt.Printf("ha-backup v%s\n", version)
+		return
+	}
+
 	confPath := findConfig(*confFlag)
 	cfg, err := loadConfig(confPath)
 	if err != nil {
 		fmt.Printf("Error: cannot load config file %s: %v\n", confPath, err)
 		os.Exit(1)
 	}
+
+	// Open the log file as early as possible so validation errors are logged
+	// too. A failure here (e.g. not running as root) is not fatal.
+	if err := openLog(cfg.LogFile); err != nil {
+		fmt.Fprintf(os.Stderr, "Warning: cannot open log file %s: %v (continuing without file logging)\n", cfg.LogFile, err)
+	}
+
 	if err := cfg.validate(); err != nil {
-		fmt.Printf("Error: %v\n", err)
+		logf("Error: %v", err)
 		os.Exit(1)
 	}
 
@@ -410,41 +609,54 @@ func main() {
 	fail := func(msg string) {
 		full := "Error: " + msg
 		notify.Send(full)
-		fmt.Println(full)
+		logf("%s", full)
 		os.Exit(1)
 	}
 
 	timestamp := time.Now().Format("2006-01-02_15-04-05")
 	start := time.Now()
 
+	logf("ha-backup v%s - backup process started (%s)", version, timestamp)
+	if logFile != nil {
+		logf("Logging to %s", cfg.LogFile)
+	}
 	notify.Send("Backup process started at " + timestamp)
 
 	// Free-space check on the Home Assistant host.
+	logf("Checking free disk space on %s...", cfg.SSHHost)
 	avail, err := remote.availableKB()
 	if err != nil {
 		fail("failed to check disk space on Home Assistant server: " + err.Error())
 	}
+	logf("Free space: %s (threshold: %s)", humanBytes(avail*1024), humanBytes(cfg.StorageThresholdKB*1024))
 	if avail < cfg.StorageThresholdKB {
-		fmt.Printf("Disk space is below the threshold (%d KB available, %d KB required). Proceeding with remote backup cleanup...\n",
+		logf("Disk space is below the threshold. Running remote backup cleanup...")
-			avail, cfg.StorageThresholdKB)
 		removeOldRemoteBackups(remote, notify, cfg.RemoteCleanupDays)
 	} else {
-		fmt.Println("Sufficient disk space available on Home Assistant server. Skipping remote backup cleanup.")
+		logf("Sufficient disk space available. Skipping remote backup cleanup.")
 	}
 
 	// Create the backup.
-	slug, err := remote.createBackup("auto_backup_" + timestamp)
+	logf("Creating backup on Home Assistant (this can take a few minutes)...")
+	var slug string
+	err = withHeartbeat("Creating backup", 10*time.Second, func() (e error) {
+		slug, e = remote.createBackup("auto_backup_" + timestamp)
+		return e
+	})
 	if err != nil {
 		fail(err.Error() + ".")
 	}
 	if !slugRe.MatchString(slug) {
 		fail(fmt.Sprintf("unexpected backup slug %q.", slug))
 	}
+	logf("Backup created with slug: %s", slug)
 	notify.Send("Backup created successfully with slug: " + slug)
 
 	// Copy it locally.
 	backupFile := filepath.Join(cfg.BackupDest, fmt.Sprintf("%s_%s.tar", timestamp, slug))
-	if err := remote.copyFrom(cfg.BackupFileLocation+"/"+slug+".tar", backupFile); err != nil {
+	logf("Copying backup to %s ...", backupFile)
+	copyStart := time.Now()
+	if err := remote.copyWithProgress(cfg.BackupFileLocation+"/"+slug+".tar", backupFile); err != nil {
 		fail("Failed to copy backup to local machine.")
 	}
 
@@ -452,16 +664,19 @@ func main() {
 	if err != nil {
 		fail("Failed to get backup file size.")
 	}
+	logf("Copy complete: %s in %s", humanBytes(info.Size()), time.Since(copyStart).Round(time.Second))
 
 	// Local retention.
+	logf("Cleaning up local backups older than %d days...", cfg.LocalCleanupDays)
 	if err := removeOldLocalBackups(cfg.BackupDest, cfg.LocalCleanupDays); err != nil {
 		fail("Failed to clean up old backups locally: " + err.Error())
 	}
 	notify.Send("Old backups cleaned up successfully.")
 
-	fmt.Println("Backup completed successfully: " + backupFile)
+	logf("Backup completed successfully: %s", backupFile)
 	notify.Send("Backup completed successfully: " + backupFile)
 
 	runtime := int(time.Since(start).Seconds())
+	logf("Total runtime: %d seconds", runtime)
 	notify.Send(fmt.Sprintf("Backup file size: %d bytes. Script runtime: %d seconds.", info.Size(), runtime))
 }