## 3.2.1

### Fixed
- Backup failures caused by low disk space on the Home Assistant host are now
  reported as such, e.g. "not enough disk space on Home Assistant server
  (1.2 GB free, threshold 2.0 GB)", instead of only "failed to extract backup slug".
- A failed `ha backup new` now includes Home Assistant's own error message in
  the notification and log.

### Changed
- Free space is re-checked after the remote cleanup runs. If it is still below
  `STORAGE_THRESHOLD_KB`, a warning is sent to ntfy/Discord before the backup
  is attempted.
- The remote cleanup now logs how many backups it found, and says when none are
  older than `REMOTE_BACKUP_CLEANUP` days.

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
-```
+    ./ha-backup # looks for home_assistant_backup.conf next to the binary, then in cwd
+    ./ha-backup -config /path/to.conf
 
-```  
-./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,
-// prunes old backups (remote and local) and sends optional ntfy/Discord
-// notifications. Go port of home_assistant_backup.sh.
+// ha-backup v3.2.1: creates a Home Assistant backup over SSH, copies it locally,
+// prunes old backups (remote and local), logs to /var/log and sends optional
+// 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.1"
+var version = "3.2.1"
+
 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,54 +341,75 @@ 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
 	}
 
+	logf("Found %d backup(s) on Home Assistant server.", len(backups))
 	cutoff := time.Now().Add(-time.Duration(days) * 24 * time.Hour)
 	removed := 0
 	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 (none are older than %d days).", days)
 	}
 }
 
 type newBackupResp struct {
+	Result  string `json:"result"`
+	Message string `json:"message"`
 	Data    struct {
 		Slug string `json:"slug"`
 	} `json:"data"`
 	Slug string `json:"slug"`
 }
 
+// describeOutput turns the output of an `ha` command into a short message for
+// error reports: the "message" field of a JSON response if there is one,
+// otherwise the raw text (collapsed to one line and truncated).
+func describeOutput(out string) string {
+	var resp newBackupResp
+	if json.Unmarshal([]byte(out), &resp) == nil && resp.Message != "" {
+		return resp.Message
+	}
+	text := strings.Join(strings.Fields(out), " ")
+	if r := []rune(text); len(r) > 300 {
+		text = string(r[:300]) + "..."
+	}
+	return text
+}
+
 // createBackup creates a backup and returns its slug.
 func (r Remote) createBackup(name string) (string, error) {
 	out, err := r.run("ha backup new --name=" + name + " --raw-json")
 	if err != nil {
+		if d := describeOutput(out); d != "" {
+			return "", fmt.Errorf("failed to create backup on Home Assistant server: %w (Home Assistant said: %s)", err, d)
+		}
 		return "", fmt.Errorf("failed to create backup on Home Assistant server: %w", err)
 	}
 
@@ -335,6 +421,9 @@ func (r Remote) createBackup(name string) (string, error) {
 		if resp.Slug != "" {
 			return strings.TrimSpace(resp.Slug), nil
 		}
+		if resp.Result == "error" && resp.Message != "" {
+			return "", fmt.Errorf("backup creation failed: Home Assistant said: %s", resp.Message)
+		}
 	}
 
 	// Fallback: plain-text "slug: xxxx" line (what the original script parsed).
@@ -346,6 +435,9 @@ func (r Remote) createBackup(name string) (string, error) {
 			}
 		}
 	}
+	if d := describeOutput(out); d != "" {
+		return "", fmt.Errorf("failed to extract backup slug (Home Assistant said: %s)", d)
+	}
 	return "", fmt.Errorf("failed to extract backup slug")
 }
 
@@ -366,12 +458,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 +604,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 +636,75 @@ 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())
 	}
-	if avail < cfg.StorageThresholdKB {
-		fmt.Printf("Disk space is below the threshold (%d KB available, %d KB required). Proceeding with remote backup cleanup...\n",
-			avail, cfg.StorageThresholdKB)
+	logf("Free space: %s (threshold: %s)", humanBytes(avail*1024), humanBytes(cfg.StorageThresholdKB*1024))
+	lowSpace := avail < cfg.StorageThresholdKB
+	if lowSpace {
+		logf("Disk space is below the threshold. Running remote backup cleanup...")
 		removeOldRemoteBackups(remote, notify, cfg.RemoteCleanupDays)
+
+		// Re-check: cleanup may not have freed anything.
+		if a, err := remote.availableKB(); err != nil {
+			logf("Could not re-check free space after cleanup: %v", err)
 		} else {
-		fmt.Println("Sufficient disk space available on Home Assistant server. Skipping remote backup cleanup.")
+			avail = a
+			lowSpace = avail < cfg.StorageThresholdKB
+			logf("Free space after cleanup: %s", humanBytes(avail*1024))
+		}
+		if lowSpace {
+			warn := fmt.Sprintf("Warning: low disk space on Home Assistant server (%s free, threshold %s) and cleanup did not free enough space.",
+				humanBytes(avail*1024), humanBytes(cfg.StorageThresholdKB*1024))
+			logf("%s", warn)
+			notify.Send(warn)
+		}
+	} else {
+		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() + ".")
+		msg := err.Error()
+		if lowSpace {
+			msg = fmt.Sprintf("not enough disk space on Home Assistant server (%s free, threshold %s); %s",
+				humanBytes(avail*1024), humanBytes(cfg.StorageThresholdKB*1024), msg)
+		}
+		fail(msg + ".")
 	}
 	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 +712,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))
 }