backup: catch all OSError exceptions while accessing files

We might see these if files change during the scan, for example.

Makefile

@@ -19,7 +19,7 @@ ctrl: test-backup
 .PHONY: test-backup
 test-backup: .venv
 	.venv/bin/mypy backup.py
-	./backup.py | tr '\0' '\n' #-n
+	./backup.py -n
 
 .PHONY: test-setup
 test-setup:

backup.py

@@ -10,7 +10,9 @@ import re
 import sys
 import stat
 import time
+import select
 import pathlib
+import threading
 import subprocess
 
 import typing
@@ -105,19 +107,17 @@ class Backup:
         self.dry_run = dry_run
         self.root_seen: dict[bytes, bool] = {}
 
-        # All logged messages, with severity
+        # Saved log messages
         self.logs: list[tuple[str, str]] = []
 
     def out(self, path: bytes):
         self.outfile.write(path + (b'\n' if self.dry_run else b'\0'))
 
-    def log(self, letter: str, msg: str):
+    def log(self, letter: str, msg: str, bold: bool=False):
         colors = { 'E': 31, 'W': 33, 'I': 36 };
-        if letter in colors:
-            c = colors[letter]
-        else:
-            c = 0
-        sys.stderr.write(f"\033[1;{c}m{letter}:\033[22m {msg}\033[0m\n")
+        c = colors[letter] if letter in colors else 0
+        b = "" if bold else "\033[22m"
+        sys.stderr.write(f"\033[1;{c}m{letter}:{b} {msg}\033[0m\n")
         self.logs.append((letter, msg))
 
     def run(self, outfile: typing.IO[bytes]):
@@ -132,10 +132,10 @@ class Backup:
                 if not stat.S_ISDIR(st.st_mode):
                     raise NotADirectoryError
             except FileNotFoundError:
-                self.log('W', f"ignoring root, does not exist: {pstr(root)}")
+                self.log('E', f"root does not exist: {pstr(root)}")
                 continue
             except NotADirectoryError:
-                self.log('W', f"ignoring root, not a directory: {pstr(root)}")
+                self.log('E', f"root is not a directory: {pstr(root)}")
                 continue
 
             self.log('I', f"processing root {pstr(root)}")
@@ -219,8 +219,8 @@ class Backup:
                     for entry in it:
                         self.scan(path=entry.path, parent_st=st)
 
-        except PermissionError as e:
-            self.log('E', f"can't read {pstr(path)}")
+        except OSError as e:
+            self.log('E', f"can't read {pstr(path)}: {str(e)}")
             return
 
 def main(argv: list[str]):
@@ -229,6 +229,7 @@ def main(argv: list[str]):
     def humansize(string):
         return humanfriendly.parse_size(string)
 
+    # Parse args
     parser = argparse.ArgumentParser(
         prog=argv[0],
         description="Back up the local system using borg",
@@ -239,6 +240,8 @@ def main(argv: list[str]):
                         help="Config file", default=str(base / "config.yaml"))
     parser.add_argument('-b', '--borg',
                         help="Borg command", default=str(base / "borg.sh"))
+    parser.add_argument('-N', '--notify',
+                        help="Notify command", default=str(base / "notify.sh"))
     parser.add_argument('-n', '--dry-run', action="store_true",
                         help="Just print log output, don't run borg")
     parser.add_argument('-d', '--debug', action="store_true",
@@ -247,13 +250,17 @@ def main(argv: list[str]):
     args = parser.parse_args()
     config = Config(args.config)
 
+    # Run backup
     backup = Backup(config, args.dry_run)
+    captured_output: list[bytes] = []
+
     if args.dry_run:
         if args.debug:
             backup.run(sys.stdout.buffer)
         else:
             with open(os.devnull, "wb") as out:
                 backup.run(out)
+        sys.stdout.flush()
     else:
         borg = subprocess.Popen([args.borg,
                                  "create",
@@ -265,13 +272,34 @@ def main(argv: list[str]):
                                  "--compression", "zstd,3",
                                  "--paths-from-stdin",
                                  "--paths-delimiter", "\\0",
-                                 "::'{hostname}-{now:%Y%m%d-%H%M%S}'"],
-                                stdin=subprocess.PIPE)
+                                 "::{hostname}-{now:%Y%m%d-%H%M%S}"],
+                                stdin=subprocess.PIPE,
+                                stdout=subprocess.PIPE,
+                                stderr=subprocess.STDOUT)
         if borg.stdin is None:
             raise Exception("no pipe")
+
+        # Use a thread to capture output
+        def reader_thread(fh):
+            os.set_blocking(fh.fileno(), False)
+            while True:
+                ready = select.select([fh.fileno()], [], [])
+                if not len(ready[0]):
+                    break
+                data = fh.read(8192)
+                if not len(data):
+                    break
+                sys.stdout.buffer.write(data)
+                sys.stdout.flush()
+                captured_output.append(data)
+            fh.close()
+        reader = threading.Thread(target=reader_thread, args=(borg.stdout,))
+        reader.daemon = True
+        reader.start()
+
         try:
             # Give borg some time to start, just to clean up stdout
-            time.sleep(2)
+            time.sleep(1)
             backup.run(borg.stdin)
         except BrokenPipeError:
             sys.stderr.write(f"broken pipe\n")
@@ -281,14 +309,49 @@ def main(argv: list[str]):
             except BrokenPipeError:
                 pass
             borg.wait()
+        reader.join()
         ret = borg.returncode
         if ret < 0:
-            sys.stderr.write(f"error: process exited with signal {-ret}\n")
-            return 1
+            backup.log('E', f"borg exited with signal {-ret}")
         elif ret != 0:
-            sys.stderr.write(f"error: process exited with return code {ret}\n")
-            return ret
+            backup.log('E', f"borg exited with return code {ret}")
 
+    # See if we had any errors
+    warnings = sum(1 for (letter, msg) in backup.logs if letter == 'W')
+    errors = sum(1 for (letter, msg) in backup.logs if letter == 'E')
+
+    if not warnings and not errors:
+        backup.log('I', f"backup successful", bold=True)
+
+    else:
+        if warnings:
+            backup.log('W', f"reported {warnings} warnings", bold=True)
+        if errors:
+            backup.log('E', f"reported {errors} errors", bold=True)
+
+        # Send a notification of errors
+        email = backup.config.notify_email
+        if email and not args.dry_run:
+            backup.log('I', f"sending error notification to {email}")
+
+            # Show all of our warnings and errors
+            body = [ "Backup reported the following warnings and errors:" ]
+            for (letter, msg) in backup.logs:
+                body.append(f"{letter}: {msg}")
+            body_text = "\n".join(body).encode()
+
+            # Followed by borg output
+            body_text += b"\nBorg output:\n" + b"".join(captured_output)
+
+            # Call notify.sh
+            res = subprocess.run([args.notify, email], input=body_text)
+            if res.returncode != 0:
+                backup.log('E', f"failed to send notification")
+                errors += 1
+
+    # Exit with an error code if we had any errors
+    if errors:
+        return 1
     return 0
 
 if __name__ == "__main__":

borg.sh

@@ -0,0 +1,21 @@
+#!/bin/bash
+
+set -e
+. "$(dirname "$0")"/vars.sh
+
+export BORG_PASSCOMMAND="cat ${BORG_DIR}/passphrase"
+export BORG_BASE_DIR=${BORG_DIR}
+export BORG_CACHE_DIR=${BORG_DIR}/cache
+export BORG_CONFIG_DIR=${BORG_DIR}/config
+if [ "$1" = "--rw" ] ; then
+    if [ "$BORG_RW_KEY_ADDED" != "1" ] ; then
+        echo "=== Need SSH key passphrase.  Check Bitwarden for:"
+        echo "===   borg $HOSTNAME / read-write SSH key"
+    fi
+    export BORG_RSH="ssh -F $SSH/config -o BatchMode=no -i $SSH/id_ecdsa"
+    shift
+else
+    export BORG_RSH="ssh -F $SSH/config -i $SSH/id_ecdsa_appendonly"
+fi
+
+exec "${BORG_BIN}" "$@"

config.yaml

@@ -4,7 +4,6 @@
 roots: |
   /
   /boot
-  /efi
   /usr
   /var
 

initial-setup.sh

@@ -72,38 +72,32 @@ setup_venv()
     pipenv install
 }
 
-# Create wrapper to execute borg
-create_borg_wrapper()
+# Create shell script with environment variables
+create_borg_vars()
 {
-    BORG=${BORG_DIR}/borg.sh
+    VARS=${BORG_DIR}/vars.sh
+
+    # These variables are used elsewhere in this script
     BORG_REPO="ssh://${BACKUP_USER}@${BACKUP_HOST}/./${BACKUP_REPO}"
+    BORG=${BORG_DIR}/borg.sh
     SSH=$BORG_DIR/ssh
 
-    cat >"$BORG" <<EOF
-#!/bin/sh
-
+    cat >"$VARS" <<EOF
+export BACKUP_USER=${BACKUP_USER}
+export BACKUP_HOST=${BACKUP_HOST}
+export BACKUP_REPO=${BACKUP_REPO}
+export HOSTNAME=$(hostname)
 export BORG_REPO=${BORG_REPO}
+export BORG_HOST_ID=${HOSTID}
 export BORG_PASSCOMMAND="cat ${BORG_DIR}/passphrase"
 export BORG_HOST_ID=${HOSTID}
-export BORG_BASE_DIR=${BORG_DIR}
-export BORG_CACHE_DIR=${BORG_DIR}/cache
-export BORG_CONFIG_DIR=${BORG_DIR}/config
-if [ "\$1" = "--rw" ] ; then
-    if [ "$BORG_RW_KEY_ADDED" != "1" ] ; then
-        echo "=== Need SSH key passphrase.  Check Bitwarden for:"
-        echo "===   borg $(hostname) / read-write SSH key"
-    fi
-    export BORG_RSH="ssh -F $SSH/config -o BatchMode=no -i $SSH/id_ecdsa"
-    shift
-else
-    export BORG_RSH="ssh -F $SSH/config -i $SSH/id_ecdsa_appendonly"
-fi
-
-exec "${BORG_BIN}" "\$@"
+export BORG_DIR=${BORG_DIR}
+export SSH=${SSH}
+export BORG=${BORG}
+export BORG_BIN=${BORG_BIN}
 EOF
-    chmod +x "$BORG"
     if ! "$BORG" -h >/dev/null ; then
-        error "Can't run the new borg wrapper; does borg work?"
+        error "Can't run the borg wrapper; does borg work?"
     fi
 
 }
@@ -136,6 +130,8 @@ configure_ssh()
     log "Creating SSH keys"
     ssh-keygen -N "" -t ecdsa \
                -C "backup-appendonly@$HOSTID" -f "$SSH/id_ecdsa_appendonly"
+    ssh-keygen -N "" -t ecdsa \
+               -C "backup-notify@$HOSTID" -f "$SSH/id_ecdsa_notify"
     ssh-keygen -N "$PASS_SSH" -t ecdsa \
                -C "backup@$HOSTID" -f "$SSH/id_ecdsa"
 
@@ -173,7 +169,8 @@ EOF
     # Copy SSH keys to the server's authorized_keys file, removing any
     # existing keys with this HOSTID.
     log "Setting up SSH keys on remote host"
-    cmd="borg/borg serve --restrict-to-repository ~/$BACKUP_REPO"
+    REMOTE_BORG="borg/borg"
+    cmd="$REMOTE_BORG serve --restrict-to-repository ~/$BACKUP_REPO"
 
     keys=".ssh/authorized_keys"
     backup="${keys}.old-$(date +%Y%m%d-%H%M%S)"
@@ -182,14 +179,14 @@ EOF
     run_ssh_command "if cmp -s $backup $keys; then rm $backup ; fi"
     run_ssh_command "cat >> .ssh/authorized_keys" <<EOF
 command="$cmd --append-only",restrict $(cat "$SSH/id_ecdsa_appendonly.pub")
-command="borg/notify.sh",restrict $(cat "$SSH/id_ecdsa_appendonly.pub")
+command="borg/notify.sh",restrict $(cat "$SSH/id_ecdsa_notify.pub")
 command="$cmd",restrict $(cat "$SSH/id_ecdsa.pub")
 EOF
 
     # Test that everything worked
     log "Testing SSH login with new key"
     if ! ssh -F "$SSH/config" -i "$SSH/id_ecdsa_appendonly" -T \
-         "${BACKUP_USER}@${BACKUP_HOST}" borg --version </dev/null ; then
+         "${BACKUP_USER}@${BACKUP_HOST}" "$REMOTE_BORG" --version </dev/null ; then
         error "Logging in with a key failed -- is server set up correctly?"
     fi
     log "Remote connection OK!"
@@ -297,7 +294,7 @@ git_setup()
     fi
 
     log "Committing local changes to git"
-    git add README.md borg-backup.service borg-backup.timer borg.sh
+    git add README.md borg-backup.service borg-backup.timer vars.sh
     git commit -a -m "autocommit after initial setup on $(hostname)"
 }
 
@@ -307,7 +304,7 @@ log "  Backup server user: ${BACKUP_USER}"
 log "     Repository path: ${BACKUP_REPO}"
 
 setup_venv
-create_borg_wrapper
+create_borg_vars
 generate_keys
 configure_ssh
 create_repo

notify.sh

@@ -0,0 +1,19 @@
+#!/bin/bash
+
+set -e
+. "$(dirname "$0")"/vars.sh
+
+# Send notification email using a script on the backup host
+# First argument is our hostname, second argument is destination;
+# mail body is provided on stdin.
+
+if tty -s ; then
+    echo 'Refusing to read mail body from terminal'
+    exit 1
+fi
+
+ssh \
+    -F "$SSH/config" \
+    -i "$SSH/id_ecdsa_notify" \
+    "$BACKUP_USER@$BACKUP_HOST" \
+    borg/notify.sh "$HOSTNAME" "$1"

prune.sh

@@ -1,7 +1,7 @@
 #!/bin/bash
 
-BORG="$(dirname "$0")/borg.sh --rw"
 set -e
+. "$(dirname "$0")"/vars.sh
 
 if [ "$BORG_RW_KEY_ADDED" != "1" ] ; then
     echo "Re-executing under a new ssh agent"
@@ -9,10 +9,10 @@ if [ "$BORG_RW_KEY_ADDED" != "1" ] ; then
 fi
 
 echo "=== Please enter SSH key passphrase.  Check Bitwarden for:"
-echo "===   borg basis / read-write SSH key"
+echo "===   borg $HOSTNAME / read-write SSH key"
 ssh-add -v "$(realpath "$(dirname "$0")")/ssh/id_ecdsa"
 
-$BORG prune \
+$BORG --rw prune \
         --verbose \
         --progress \
         --stats \
@@ -21,6 +21,6 @@ $BORG prune \
         --keep-weekly=8 \
         --keep-monthly=-1
 
-$BORG compact \
+$BORG --rw compact \
         --verbose \
         --progress

vars.sh

@@ -0,0 +1,12 @@
+export BACKUP_USER=jim-backups
+export BACKUP_HOST=backup.jim.sh
+export BACKUP_REPO=borg/basis
+export HOSTNAME=basis
+export BORG_REPO="ssh://jim-backups@backup.jim.sh/./borg/basis"
+export BORG_HOST_ID=basis.bacon@91300097352395
+export BORG_PASSCOMMAND="cat /opt/borg/passphrase"
+export BORG_DIR=/opt/borg
+export SSH=/opt/borg/ssh
+export BORG=/opt/borg/borg.sh
+export BORG_BIN=/opt/borg/Borg.bin
+