--debug-topic for granular debug logging

Especially: disables file-compression logging by default

src/borg/archive.py

@@ -254,6 +254,7 @@ class Archive:
         self.consider_part_files = consider_part_files
         self.pipeline = DownloadPipeline(self.repository, self.key)
         if create:
+            self.file_compression_logger = create_logger('borg.debug.file-compression')
             self.items_buffer = CacheChunkBuffer(self.cache, self.key, self.stats)
             self.chunker = Chunker(self.key.chunk_seed, *chunker_params)
             self.compression_decider1 = CompressionDecider1(compression or CompressionSpec('none'),
@@ -818,7 +819,7 @@ Number of files: {0.stats.nfiles}'''.format(
             item.chunks = chunks
         else:
             compress = self.compression_decider1.decide(path)
-            logger.debug('%s -> compression %s', path, compress['name'])
+            self.file_compression_logger.debug('%s -> compression %s', path, compress['name'])
             with backup_io():
                 fh = Archive._open_rb(path)
             with os.fdopen(fh, 'rb') as fd:

src/borg/archiver.py

@@ -1225,6 +1225,10 @@ class Archiver:
         common_group.add_argument('--debug', dest='log_level',
                                   action='store_const', const='debug', default='warning',
                                   help='enable debug output, work on log level DEBUG')
+        common_group.add_argument('--debug-topic', dest='debug_topics',
+                                  action='append', metavar='TOPIC', default=[],
+                                  help='enable TOPIC debugging (can be specified multiple times). '
+                                       'The logger path is borg.debug.<TOPIC> if TOPIC is not fully qualified.')
         common_group.add_argument('--lock-wait', dest='lock_wait', type=int, metavar='N', default=1,
                                   help='wait for the lock, but max. N seconds (default: %(default)d).')
         common_group.add_argument('--show-version', dest='show_version', action='store_true', default=False,
@@ -2202,11 +2206,20 @@ class Archiver:
             if args.get(option, False):
                 logging.getLogger(logger_name).setLevel('INFO')
 
+    def _setup_topic_debugging(self, args):
+        """Turn on DEBUG level logging for specified --debug-topics."""
+        for topic in args.debug_topics:
+            if '.' not in topic:
+                topic = 'borg.debug.' + topic
+            logger.debug('Enabling debug topic %s', topic)
+            logging.getLogger(topic).setLevel('DEBUG')
+
     def run(self, args):
         os.umask(args.umask)  # early, before opening files
         self.lock_wait = args.lock_wait
         setup_logging(level=args.log_level, is_serve=args.func == self.do_serve)  # do not use loggers before this!
         self._setup_implied_logging(vars(args))
+        self._setup_topic_debugging(args)
         if args.show_version:
             logging.getLogger('borg.output.show-version').info('borgbackup version %s' % __version__)
         self.prerun_checks(logger)

src/borg/helpers.py

@@ -1527,6 +1527,8 @@ class CompressionDecider1:
 
 
 class CompressionDecider2:
+    logger = create_logger('borg.debug.file-compression')
+
     def __init__(self, compression):
         self.compression = compression
 
@@ -1556,7 +1558,7 @@ class CompressionDecider2:
             # that marks such data as uncompressible via compression-type metadata.
             compr_spec = CompressionSpec('none')
         compr_args.update(compr_spec)
-        logger.debug("len(data) == %d, len(lz4(data)) == %d, choosing %s", data_len, cdata_len, compr_spec)
+        self.logger.debug("len(data) == %d, len(lz4(data)) == %d, choosing %s", data_len, cdata_len, compr_spec)
         return compr_args, Chunk(data, **meta)
 
 

src/borg/logger.py

@@ -149,8 +149,13 @@ def create_logger(name=None):
                 if not configured:
                     raise Exception("tried to call a logger before setup_logging() was called")
                 self.__real_logger = logging.getLogger(self.__name)
+                if self.__name.startswith('borg.debug.') and self.__real_logger.level == logging.NOTSET:
+                    self.__real_logger.setLevel('WARNING')
             return self.__real_logger
 
+        def getChild(self, suffix):
+            return LazyLogger(self.__name + '.' + suffix)
+
         def setLevel(self, *args, **kw):
             return self.__logger.setLevel(*args, **kw)