diff --git a/README.md b/README.md index bb3c1cd..b79ba86 100644 --- a/README.md +++ b/README.md @@ -56,6 +56,7 @@ General options: --dryrun Don't actually do anything --snapper-config Only operate on a single snapper config given by its name + -v increase verbosity, can be repeated twice Commands: init Initialize (create) the configured borg repositories diff --git a/snapborg/borg.py b/snapborg/borg.py index 1aaceca..debc51c 100644 --- a/snapborg/borg.py +++ b/snapborg/borg.py @@ -3,7 +3,9 @@ import sys from subprocess import CalledProcessError -from .util import restrict_keys, selective_merge +from .util import restrict_keys, selective_merge, init_snapborg_logger + +LOG = init_snapborg_logger(__name__) DEFAULT_REPO_CONFIG = { "storage": { @@ -44,7 +46,7 @@ def init(self, dryrun=False): self.repopath, ] launch_borg(borg_init_invocation, self.passphrase, - print_output=self.is_interactive, dryrun=dryrun) + log_output=self.is_interactive, dryrun=dryrun) def backup(self, backup_name, *paths, exclude_patterns=[], timestamp=None, dryrun=False): @@ -68,14 +70,14 @@ def backup(self, backup_name, *paths, exclude_patterns=[], timestamp=None, dryru launch_borg( borg_invocation, self.passphrase, - print_output=self.is_interactive, + log_output=False, dryrun=dryrun ) def delete(self, backup_name, dryrun=False): borg_delete = ["delete", f"{self.repopath}::{backup_name}"] launch_borg(borg_delete, self.passphrase, - print_output=self.is_interactive, + log_output=self.is_interactive, dryrun=dryrun) def prune(self, override_retention_settings=None, dryrun=False): @@ -92,7 +94,7 @@ def prune(self, override_retention_settings=None, dryrun=False): launch_borg( borg_prune_invocation, self.passphrase, - print_output=self.is_interactive, + log_output=self.is_interactive, dryrun=dryrun ) @@ -132,13 +134,13 @@ def get_password(password): with open(password) as pwfile: password = pwfile.read().strip() except FileNotFoundError: - print("tried to use password as file, but could not find it") + LOG.fatal("tried to use password as file, but could not find it") raise return password -def launch_borg(args, password=None, print_output=False, dryrun=False): +def launch_borg(args, password=None, log_output=False, dryrun=False): """ launch borg and supply the password by environment @@ -147,14 +149,13 @@ def launch_borg(args, password=None, print_output=False, dryrun=False): cmd = ["borg"] + args - if print_output: - print(f"$ {' '.join(cmd)}") + LOG.debug("$ {}".format(' '.join(cmd))) if not dryrun: env = {'BORG_PASSPHRASE': password} if password else {} # TODO: parse output from JSON log lines try: - if print_output: + if log_output: subprocess.run(cmd, env=env, check=True) else: subprocess.check_output(cmd, @@ -162,8 +163,9 @@ def launch_borg(args, password=None, print_output=False, dryrun=False): env=env) except CalledProcessError as e: if e.returncode == 1: + LOG.info(line) # warning(s) happened, don't raise - if not print_output: - print(f"Borg command execution gave warnings:\n{e.output.decode()}") + if log_output: + LOG.info(f"Borg command execution gave warnings:\n{e.output.decode()}") else: raise diff --git a/snapborg/commands/snapborg.py b/snapborg/commands/snapborg.py index 3871c64..6650cf4 100755 --- a/snapborg/commands/snapborg.py +++ b/snapborg/commands/snapborg.py @@ -22,7 +22,9 @@ from ..borg import BorgRepo from ..retention import get_retained_snapshots from ..snapper import SnapperConfig -from ..util import selective_merge +from ..util import selective_merge, init_snapborg_logger, set_loglevel + +LOG = init_snapborg_logger(__name__) DEFAULT_CONFIG = { "configs": [] @@ -45,6 +47,7 @@ def main(): cli.add_argument("--dryrun", action="store_true", help="Don't actually execute commands") cli.add_argument("--snapper-config", default=None, dest="snapper_config", help="The name of a snapper config to operate on") + cli.add_argument("-v", action="count", default=0, help="increase verbosity, can be repeated twice") subp = cli.add_subparsers(dest="mode", required=True) subp.add_parser("prune", help="Prune the borg archives using the retention settings from the " @@ -64,6 +67,7 @@ def main(): "user data") args = cli.parse_args() + set_loglevel(args.v) with open(args.cfg, 'r') as stream: cfg = selective_merge(yaml.safe_load(stream), DEFAULT_CONFIG) @@ -135,24 +139,19 @@ def backup(cfg, snapper_configs, recreate, prune_old_backups, dryrun): """ Backup all given snapper configs, optionally recreating the archives """ - status_map = {} + failures = [] + + LOG.info("Backup results:") for config in snapper_configs: try: backup_config(config, recreate, dryrun) - status_map[config["name"]] = True + LOG.info("\t%s:\tOK", config["name"]) except Exception as e: - status_map[config["name"]] = e - print("\nBackup results:") - has_error = False - for config_name, status in status_map.items(): - if status is True: - print(f"OK {config_name}") - else: - has_error = True - print(f"FAILED {config_name}: {status}") - - if has_error: - raise Exception("Snapborg failed!") + failures.append(e) + LOG.error("\t%s: FAILED - %s", config["name"], e) + + if len(failures) > 0: + raise Exception(failures) elif prune_old_backups: prune(cfg, snapper_configs, dryrun) @@ -161,7 +160,7 @@ def backup_config(config, recreate, dryrun): """ Backup a single snapper config """ - print(f"Backing up snapshots for snapper config '{config['name']}'...") + LOG.info(f"Backing up snapshots for snapper config '{config['name']}'...") snapper_config = None snapshots = None try: @@ -169,7 +168,7 @@ def backup_config(config, recreate, dryrun): # when we have the config, extract the snapshots which are not yet backed up snapshots = snapper_config.get_snapshots() if len(snapshots) == 0: - print("No snapshots from snapper found!") + LOG.warning("No snapshots from snapper found!") return except subprocess.SubprocessError: raise Exception(f"Failed to get snapper config {config['name']}!") @@ -211,7 +210,7 @@ def backup_config(config, recreate, dryrun): def backup_candidate(snapper_config, borg_repo, candidate, recreate, exclude_patterns, dryrun=False): - print(f"Backing up snapshot number {candidate.get_number()} " + LOG.info(f"Backing up snapshot number {candidate.get_number()} " f"from {candidate.get_date().isoformat()}...") path_to_backup = candidate.get_path() backup_name = f"{snapper_config.name}-{candidate.get_number()}-{candidate.get_date().isoformat()}" @@ -224,7 +223,7 @@ def backup_candidate(snapper_config, borg_repo, candidate, recreate, candidate.set_backed_up(dryrun=dryrun) return True except subprocess.CalledProcessError as e: - print(f"Error backing up snapshot number {candidate.get_number()}!\n\t{e}") + LOG.error(f"Error backing up snapshot number {candidate.get_number()}!\n\t{e}") return False @@ -256,5 +255,5 @@ def clean_snapper(cfg, snapper_configs, dryrun): try: main() except Exception as e: - print(f"Snapborg failed: {e}!") + LOG.fatal(f"Snapborg failed: {e}!") sys.exit(1) diff --git a/snapborg/snapper.py b/snapborg/snapper.py index a6398e1..e9d9cd8 100644 --- a/snapborg/snapper.py +++ b/snapborg/snapper.py @@ -5,6 +5,9 @@ from packaging import version +from .util import init_snapborg_logger + +LOG = init_snapborg_logger(__name__) def check_snapper(): """ @@ -34,7 +37,7 @@ def run_snapper(args, config: str = None, dryrun=False): *args ] if dryrun: - print(args_new) + LOG.info(args_new) return None else: output = subprocess.check_output(args_new).decode().strip() @@ -66,7 +69,7 @@ def get_snapshots(self): @classmethod def get(cls, config_name: str): return cls(config_name, run_snapper(["get-config"], config_name)) - + @contextmanager def prevent_cleanup(self, snapshots=None, dryrun=False): """ @@ -78,7 +81,7 @@ def prevent_cleanup(self, snapshots=None, dryrun=False): for s in snapshots: s.prevent_cleanup(dryrun=dryrun) - + try: yield self finally: diff --git a/snapborg/util.py b/snapborg/util.py index 2a1464e..182c0b1 100644 --- a/snapborg/util.py +++ b/snapborg/util.py @@ -1,3 +1,8 @@ +import logging +import os +import sys + + def selective_merge(base_obj, delta_obj, restrict_keys=False): """ Recursively merge dict delta_obj into base_obj by adding all key/value @@ -60,4 +65,31 @@ def split(data, pred): yes.append(d) else: no.append(d) - return (yes, no) \ No newline at end of file + return (yes, no) + + +def set_loglevel(verbosity_level): + loglevel = logging.WARNING + if verbosity_level > 0: + loglevel = logging.INFO + if verbosity_level > 1: + loglevel = logging.DEBUG + + for logger_name in logging.root.manager.loggerDict: + logging.getLogger(logger_name).setLevel(loglevel) + return loglevel + + +def init_snapborg_logger(logger_name): + is_interactive = os.isatty(sys.stdout.fileno()) + logger = logging.getLogger(logger_name) + logger.setLevel(logging.INFO) + if is_interactive: + formatter = logging.Formatter("%(asctime)s - %(levelname)s - %(message)s") + else: + # if running in non-interactive mode, typically through systemd + formatter = logging.Formatter("%(levelname)s - %(name)s:%(lineno)d - %(message)s") + ch = logging.StreamHandler() + ch.setFormatter(formatter) + logger.addHandler(ch) + return logger