From 5c229639f0a3a581264400268b2aee2a776aa568 Mon Sep 17 00:00:00 2001
From: Dan Helfman <witten@torsion.org>
Date: Wed, 25 Oct 2017 21:47:33 -0700
Subject: [PATCH] Improve clarity of logging spew at high verbosity levels.

---
 NEWS                            |  2 ++
 borgmatic/commands/borgmatic.py | 12 ++++++++++++
 borgmatic/config/validate.py    |  2 ++
 borgmatic/verbosity.py          | 15 +++++++++++++++
 4 files changed, 31 insertions(+)

diff --git a/NEWS b/NEWS
index 1029679..cfac2f2 100644
--- a/NEWS
+++ b/NEWS
@@ -1,4 +1,6 @@
 1.1.9.dev0
+ * #16, #38: Support for user-defined hooks before/after backup, or on error.
+ * #33: Improve clarity of logging spew at high verbosity levels.
  * #29: Support for using tilde in source directory path to reference home directory.
 
 1.1.8
diff --git a/borgmatic/commands/borgmatic.py b/borgmatic/commands/borgmatic.py
index b7c53a3..28d1e0d 100644
--- a/borgmatic/commands/borgmatic.py
+++ b/borgmatic/commands/borgmatic.py
@@ -1,10 +1,15 @@
 from argparse import ArgumentParser
+import logging
 import os
 from subprocess import CalledProcessError
 import sys
 
 from borgmatic.borg import check, create, prune
 from borgmatic.config import collect, convert, validate
+from borgmatic.verbosity import VERBOSITY_SOME, VERBOSITY_LOTS, verbosity_to_log_level
+
+
+logger = logging.getLogger(__name__)
 
 
 LEGACY_CONFIG_PATH = '/etc/borgmatic/config'
@@ -75,13 +80,17 @@ def parse_arguments(*arguments):
 def main():  # pragma: no cover
     try:
         args = parse_arguments(*sys.argv[1:])
+        logging.basicConfig(level=verbosity_to_log_level(args.verbosity), format='%(message)s')
+
         config_filenames = tuple(collect.collect_config_filenames(args.config_paths))
+        logger.debug('Ensuring legacy configuration is upgraded')
         convert.guard_configuration_upgraded(LEGACY_CONFIG_PATH, config_filenames)
 
         if len(config_filenames) == 0:
             raise ValueError('Error: No configuration files found in: {}'.format(' '.join(args.config_paths)))
 
         for config_filename in config_filenames:
+            logger.info('{}: Parsing configuration file'.format(config_filename))
             config = validate.parse_configuration(config_filename, validate.schema_filename())
             (location, storage, retention, consistency) = (
                 config.get(section_name, {})
@@ -93,8 +102,10 @@ def main():  # pragma: no cover
 
             for repository in location['repositories']:
                 if args.prune:
+                    logger.info('{}: Pruning archives'.format(repository))
                     prune.prune_archives(args.verbosity, repository, retention, remote_path=remote_path)
                 if args.create:
+                    logger.info('{}: Creating archive'.format(repository))
                     create.create_archive(
                         args.verbosity,
                         repository,
@@ -102,6 +113,7 @@ def main():  # pragma: no cover
                         storage,
                     )
                 if args.check:
+                    logger.info('{}: Running consistency checks'.format(repository))
                     check.check_archives(args.verbosity, repository, consistency, remote_path=remote_path)
     except (ValueError, OSError, CalledProcessError) as error:
         print(error, file=sys.stderr)
diff --git a/borgmatic/config/validate.py b/borgmatic/config/validate.py
index 3125176..0bac596 100644
--- a/borgmatic/config/validate.py
+++ b/borgmatic/config/validate.py
@@ -38,6 +38,8 @@ def parse_configuration(config_filename, schema_filename):
     Raise FileNotFoundError if the file does not exist, PermissionError if the user does not
     have permissions to read the file, or Validation_error if the config does not match the schema.
     '''
+    logging.getLogger('pykwalify').setLevel(logging.ERROR)
+
     try:
         config = yaml.round_trip_load(open(config_filename))
         schema = yaml.round_trip_load(open(schema_filename))
diff --git a/borgmatic/verbosity.py b/borgmatic/verbosity.py
index 06dfc4c..13b1ecc 100644
--- a/borgmatic/verbosity.py
+++ b/borgmatic/verbosity.py
@@ -1,2 +1,17 @@
+import logging
+
+
 VERBOSITY_SOME = 1
 VERBOSITY_LOTS = 2
+
+
+def verbosity_to_log_level(verbosity):
+    '''
+    Given a borgmatic verbosity value, return the corresponding Python log level.
+    '''
+    return {
+        VERBOSITY_SOME: logging.INFO,
+        VERBOSITY_LOTS: logging.DEBUG,
+    }.get(verbosity, logging.ERROR)
+
+