logging_utils.py

   1 #!/usr/bin/env python3
   2 # -*- coding: utf-8 -*-
   3
   4 # © Copyright 2021-2022, Scott Gasch
   5
   6 """Utilities related to logging."""
   7
   8 import collections
   9 import contextlib
  10 import datetime
  11 import enum
  12 import io
  13 import logging
  14 import os
  15 import random
  16 import sys
  17 from logging.config import fileConfig
  18 from logging.handlers import RotatingFileHandler, SysLogHandler
  19 from typing import Any, Callable, Dict, Iterable, List, Optional
  20
  21 import pytz
  22 from overrides import overrides
  23
  24 # This module is commonly used by others in here and should avoid
  25 # taking any unnecessary dependencies back on them.
  26 import argparse_utils
  27 import config
  28
  29 cfg = config.add_commandline_args(f'Logging ({__file__})', 'Args related to logging')
  30 cfg.add_argument(
  31     '--logging_config_file',
  32     type=argparse_utils.valid_filename,
  33     default=None,
  34     metavar='FILENAME',
  35     help='Config file containing the logging setup, see: https://docs.python.org/3/howto/logging.html#logging-advanced-tutorial',
  36 )
  37 cfg.add_argument(
  38     '--logging_level',
  39     type=str,
  40     default='INFO',
  41     choices=['NOTSET', 'DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL'],
  42     metavar='LEVEL',
  43     help='The global default level below which to squelch log messages; see also --lmodule',
  44 )
  45 cfg.add_argument(
  46     '--logging_format',
  47     type=str,
  48     default=None,
  49     help='The format for lines logged via the logger module.  See: https://docs.python.org/3/library/logging.html#formatter-objects',
  50 )
  51 cfg.add_argument(
  52     '--logging_date_format',
  53     type=str,
  54     default='%Y/%m/%dT%H:%M:%S.%f%z',
  55     metavar='DATEFMT',
  56     help='The format of any dates in --logging_format.',
  57 )
  58 cfg.add_argument(
  59     '--logging_console',
  60     action=argparse_utils.ActionNoYes,
  61     default=True,
  62     help='Should we log to the console (stderr)',
  63 )
  64 cfg.add_argument(
  65     '--logging_filename',
  66     type=str,
  67     default=None,
  68     metavar='FILENAME',
  69     help='The filename of the logfile to write.',
  70 )
  71 cfg.add_argument(
  72     '--logging_filename_maxsize',
  73     type=int,
  74     default=(1024 * 1024),
  75     metavar='#BYTES',
  76     help='The maximum size (in bytes) to write to the logging_filename.',
  77 )
  78 cfg.add_argument(
  79     '--logging_filename_count',
  80     type=int,
  81     default=7,
  82     metavar='COUNT',
  83     help='The number of logging_filename copies to keep before deleting.',
  84 )
  85 cfg.add_argument(
  86     '--logging_syslog',
  87     action=argparse_utils.ActionNoYes,
  88     default=False,
  89     help='Should we log to localhost\'s syslog.',
  90 )
  91 cfg.add_argument(
  92     '--logging_syslog_facility',
  93     type=str,
  94     default='USER',
  95     choices=[
  96         'NOTSET',
  97         'AUTH',
  98         'AUTH_PRIV',
  99         'CRON',
 100         'DAEMON',
 101         'FTP',
 102         'KERN',
 103         'LPR',
 104         'MAIL',
 105         'NEWS',
 106         'SYSLOG',
 107         'USER',
 108         'UUCP',
 109         'LOCAL0',
 110         'LOCAL1',
 111         'LOCAL2',
 112         'LOCAL3',
 113         'LOCAL4',
 114         'LOCAL5',
 115         'LOCAL6',
 116         'LOCAL7',
 117     ],
 118     metavar='SYSLOG_FACILITY_LIST',
 119     help='The default syslog message facility identifier',
 120 )
 121 cfg.add_argument(
 122     '--logging_debug_threads',
 123     action=argparse_utils.ActionNoYes,
 124     default=False,
 125     help='Should we prepend pid/tid data to all log messages?',
 126 )
 127 cfg.add_argument(
 128     '--logging_debug_modules',
 129     action=argparse_utils.ActionNoYes,
 130     default=False,
 131     help='Should we prepend module/function data to all log messages?',
 132 )
 133 cfg.add_argument(
 134     '--logging_info_is_print',
 135     action=argparse_utils.ActionNoYes,
 136     default=False,
 137     help='logging.info also prints to stdout.',
 138 )
 139 cfg.add_argument(
 140     '--logging_squelch_repeats',
 141     action=argparse_utils.ActionNoYes,
 142     default=True,
 143     help='Do we allow code to indicate that it wants to squelch repeated logging messages or should we always log?',
 144 )
 145 cfg.add_argument(
 146     '--logging_probabilistically',
 147     action=argparse_utils.ActionNoYes,
 148     default=True,
 149     help='Do we allow probabilistic logging (for code that wants it) or should we always log?',
 150 )
 151 # See also: OutputMultiplexer
 152 cfg.add_argument(
 153     '--logging_captures_prints',
 154     action=argparse_utils.ActionNoYes,
 155     default=False,
 156     help='When calling print, also log.info automatically.',
 157 )
 158 cfg.add_argument(
 159     '--lmodule',
 160     type=str,
 161     metavar='<SCOPE>=<LEVEL>[,<SCOPE>=<LEVEL>...]',
 162     help=(
 163         'Allows per-scope logging levels which override the global level set with --logging-level.'
 164         + 'Pass a space separated list of <scope>=<level> where <scope> is one of: module, '
 165         + 'module:function, or :function and <level> is a logging level (e.g. INFO, DEBUG...)'
 166     ),
 167 )
 168 cfg.add_argument(
 169     '--logging_clear_preexisting_handlers',
 170     action=argparse_utils.ActionNoYes,
 171     default=True,
 172     help=(
 173         'Should logging code clear preexisting global logging handlers and thus insist that is '
 174         + 'alone can add handlers.  Use this to work around annoying modules that insert global '
 175         + 'handlers with formats and logging levels you might now want.  Caveat emptor, this may '
 176         + 'cause you to miss logging messages.'
 177     ),
 178 )
 179
 180 BUILT_IN_PRINT = print
 181 LOGGING_INITIALIZED = False
 182
 183
 184 # A map from logging_callsite_id -> count of logged messages.
 185 squelched_logging_counts: Dict[str, int] = {}
 186
 187
 188 def squelch_repeated_log_messages(squelch_after_n_repeats: int) -> Callable:
 189     """
 190     A decorator that marks a function as interested in having the logging
 191     messages that it produces be squelched (ignored) after it logs the
 192     same message more than N times.
 193
 194     Note: this decorator affects *ALL* logging messages produced
 195     within the decorated function.  That said, messages must be
 196     identical in order to be squelched.  For example, if the same line
 197     of code produces different messages (because of, e.g., a format
 198     string), the messages are considered to be different.
 199
 200     """
 201
 202     def squelch_logging_wrapper(f: Callable):
 203         import function_utils
 204
 205         identifier = function_utils.function_identifier(f)
 206         squelched_logging_counts[identifier] = squelch_after_n_repeats
 207         return f
 208
 209     return squelch_logging_wrapper
 210
 211
 212 class SquelchRepeatedMessagesFilter(logging.Filter):
 213     """
 214     A filter that only logs messages from a given site with the same
 215     (exact) message at the same logging level N times and ignores
 216     subsequent attempts to log.
 217
 218     This filter only affects logging messages that repeat more than
 219     a threshold number of times from functions that are tagged with
 220     the @logging_utils.squelched_logging_ok decorator; others are
 221     ignored.
 222
 223     This functionality is enabled by default but can be disabled via
 224     the --no_logging_squelch_repeats commandline flag.
 225
 226     """
 227
 228     def __init__(self) -> None:
 229         super().__init__()
 230         self.counters: collections.Counter = collections.Counter()
 231
 232     @overrides
 233     def filter(self, record: logging.LogRecord) -> bool:
 234         id1 = f'{record.module}:{record.funcName}'
 235         if id1 not in squelched_logging_counts:
 236             return True
 237         threshold = squelched_logging_counts[id1]
 238         logsite = f'{record.pathname}+{record.lineno}+{record.levelno}+{record.msg}'
 239         count = self.counters[logsite]
 240         self.counters[logsite] += 1
 241         return count < threshold
 242
 243
 244 class DynamicPerScopeLoggingLevelFilter(logging.Filter):
 245     """This filter only allows logging messages from an allow list of
 246     module names or module:function names.  Blocks others.
 247
 248     """
 249
 250     @staticmethod
 251     def level_name_to_level(name: str) -> int:
 252         numeric_level = getattr(logging, name, None)
 253         if not isinstance(numeric_level, int):
 254             raise ValueError(f'Invalid level: {name}')
 255         return numeric_level
 256
 257     def __init__(
 258         self,
 259         default_logging_level: int,
 260         per_scope_logging_levels: str,
 261     ) -> None:
 262         super().__init__()
 263         self.valid_levels = set(['NOTSET', 'DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL'])
 264         self.default_logging_level = default_logging_level
 265         self.level_by_scope = {}
 266         if per_scope_logging_levels is not None:
 267             for chunk in per_scope_logging_levels.split(','):
 268                 if '=' not in chunk:
 269                     print(
 270                         f'Malformed lmodule directive: "{chunk}", missing "=".  Ignored.',
 271                         file=sys.stderr,
 272                     )
 273                     continue
 274                 try:
 275                     (scope, level) = chunk.split('=')
 276                 except ValueError:
 277                     print(
 278                         f'Malformed lmodule directive: "{chunk}".  Ignored.',
 279                         file=sys.stderr,
 280                     )
 281                     continue
 282                 scope = scope.strip()
 283                 level = level.strip().upper()
 284                 if level not in self.valid_levels:
 285                     print(
 286                         f'Malformed lmodule directive: "{chunk}", bad level.  Ignored.',
 287                         file=sys.stderr,
 288                     )
 289                     continue
 290                 self.level_by_scope[scope] = DynamicPerScopeLoggingLevelFilter.level_name_to_level(
 291                     level
 292                 )
 293
 294     @overrides
 295     def filter(self, record: logging.LogRecord) -> bool:
 296         # First try to find a logging level by scope (--lmodule)
 297         if len(self.level_by_scope) > 0:
 298             min_level = None
 299             for scope in (
 300                 record.module,
 301                 f'{record.module}:{record.funcName}',
 302                 f':{record.funcName}',
 303             ):
 304                 level = self.level_by_scope.get(scope, None)
 305                 if level is not None:
 306                     if min_level is None or level < min_level:
 307                         min_level = level
 308
 309             # If we found one, use it instead of the global default level.
 310             if min_level is not None:
 311                 return record.levelno >= min_level
 312
 313         # Otherwise, use the global logging level (--logging_level)
 314         return record.levelno >= self.default_logging_level
 315
 316
 317 # A map from function_identifier -> probability of logging (0.0%..100.0%)
 318 probabilistic_logging_levels: Dict[str, float] = {}
 319
 320
 321 def logging_is_probabilistic(probability_of_logging: float) -> Callable:
 322     """
 323     A decorator that indicates that all logging statements within the
 324     scope of a particular (marked) function are not deterministic
 325     (i.e. they do not always unconditionally log) but rather are
 326     probabilistic (i.e. they log N% of the time randomly).
 327
 328     Note that this functionality can be disabled (forcing all logged
 329     messages to produce output) via the --no_logging_probabilistically
 330     cmdline argument.
 331
 332     This affects *ALL* logging statements within the marked function.
 333
 334     """
 335
 336     def probabilistic_logging_wrapper(f: Callable):
 337         import function_utils
 338
 339         identifier = function_utils.function_identifier(f)
 340         probabilistic_logging_levels[identifier] = probability_of_logging
 341         return f
 342
 343     return probabilistic_logging_wrapper
 344
 345
 346 class ProbabilisticFilter(logging.Filter):
 347     """
 348     A filter that logs messages probabilistically (i.e. randomly at some
 349     percent chance).
 350
 351     This filter only affects logging messages from functions that have
 352     been tagged with the @logging_utils.probabilistic_logging decorator.
 353
 354     """
 355
 356     @overrides
 357     def filter(self, record: logging.LogRecord) -> bool:
 358         id1 = f'{record.module}:{record.funcName}'
 359         if id1 not in probabilistic_logging_levels:
 360             return True
 361         threshold = probabilistic_logging_levels[id1]
 362         return (random.random() * 100.0) <= threshold
 363
 364
 365 class OnlyInfoFilter(logging.Filter):
 366     """
 367     A filter that only logs messages produced at the INFO logging
 368     level.  This is used by the logging_info_is_print commandline
 369     option to select a subset of the logging stream to send to a
 370     stdout handler.
 371
 372     """
 373
 374     @overrides
 375     def filter(self, record: logging.LogRecord):
 376         return record.levelno == logging.INFO
 377
 378
 379 class MillisecondAwareFormatter(logging.Formatter):
 380     """
 381     A formatter for adding milliseconds to log messages which, for
 382     whatever reason, the default python logger doesn't do.
 383
 384     """
 385
 386     converter = datetime.datetime.fromtimestamp  # type: ignore
 387
 388     @overrides
 389     def formatTime(self, record, datefmt=None):
 390         ct = MillisecondAwareFormatter.converter(record.created, pytz.timezone("US/Pacific"))
 391         if datefmt:
 392             s = ct.strftime(datefmt)
 393         else:
 394             t = ct.strftime("%Y-%m-%d %H:%M:%S")
 395             s = f"{t},{record.msecs:%03d}"
 396         return s
 397
 398
 399 def log_about_logging(
 400     logger,
 401     default_logging_level,
 402     preexisting_handlers_count,
 403     fmt,
 404     facility_name,
 405 ):
 406     level_name = logging._levelToName.get(default_logging_level, str(default_logging_level))
 407     logger.debug('Initialized global logging; default logging level is %s.', level_name)
 408     if config.config['logging_clear_preexisting_handlers'] and preexisting_handlers_count > 0:
 409         logger.warning(
 410             'Logging cleared %d global handlers (--logging_clear_preexisting_handlers)',
 411             preexisting_handlers_count,
 412         )
 413     logger.debug('Logging format specification is "%s"', fmt)
 414     if config.config['logging_debug_threads']:
 415         logger.debug('...Logging format spec captures tid/pid. (--logging_debug_threads)')
 416     if config.config['logging_debug_modules']:
 417         logger.debug(
 418             '...Logging format spec captures files/functions/lineno. (--logging_debug_modules)'
 419         )
 420     if config.config['logging_syslog']:
 421         logger.debug(
 422             'Logging to syslog as %s with priority mapping based on level. (--logging_syslog)',
 423             facility_name,
 424         )
 425     if config.config['logging_filename']:
 426         logger.debug(
 427             'Logging to file "%s". (--logging_filename)', config.config["logging_filename"]
 428         )
 429         logger.debug(
 430             '...with %d bytes max file size. (--logging_filename_maxsize)',
 431             config.config["logging_filename_maxsize"],
 432         )
 433         logger.debug(
 434             '...and %d rotating backup file count. (--logging_filename_count)',
 435             config.config["logging_filename_count"],
 436         )
 437     if config.config['logging_console']:
 438         logger.debug('Logging to the console (stderr). (--logging_console)')
 439     if config.config['logging_info_is_print']:
 440         logger.debug(
 441             'Logging logger.info messages will be repeated on stdout. (--logging_info_is_print)'
 442         )
 443     if config.config['logging_squelch_repeats']:
 444         logger.debug(
 445             'Logging code allowed to request repeated messages be squelched. (--logging_squelch_repeats)'
 446         )
 447     else:
 448         logger.debug(
 449             'Logging code forbidden to request messages be squelched; all messages logged. (--no_logging_squelch_repeats)'
 450         )
 451     if config.config['logging_probabilistically']:
 452         logger.debug(
 453             'Logging code is allowed to request probabilistic logging. (--logging_probabilistically)'
 454         )
 455     else:
 456         logger.debug(
 457             'Logging code is forbidden to request probabilistic logging; messages always logged. (--no_logging_probabilistically)'
 458         )
 459     if config.config['lmodule']:
 460         logger.debug(
 461             f'Logging dynamic per-module logging enabled. (--lmodule={config.config["lmodule"]})'
 462         )
 463     if config.config['logging_captures_prints']:
 464         logger.debug(
 465             'Logging will capture printed data as logger.info messages. (--logging_captures_prints)'
 466         )
 467
 468
 469 def initialize_logging(logger=None) -> logging.Logger:
 470     global LOGGING_INITIALIZED
 471     if LOGGING_INITIALIZED:
 472         return logging.getLogger()
 473     LOGGING_INITIALIZED = True
 474
 475     if logger is None:
 476         logger = logging.getLogger()
 477
 478     # --logging_clear_preexisting_handlers removes logging handlers
 479     # that were registered by global statements during imported module
 480     # setup.
 481     preexisting_handlers_count = 0
 482     assert config.has_been_parsed()
 483     if config.config['logging_clear_preexisting_handlers']:
 484         while logger.hasHandlers():
 485             logger.removeHandler(logger.handlers[0])
 486             preexisting_handlers_count += 1
 487
 488     # --logging_config_file pulls logging settings from a config file
 489     # skipping the rest of this setup.
 490     if config.config['logging_config_file'] is not None:
 491         fileConfig(config.config['logging_config_file'])
 492         return logger
 493
 494     handlers: List[logging.Handler] = []
 495     handler: Optional[logging.Handler] = None
 496
 497     # Global default logging level (--logging_level); messages below
 498     # this level will be silenced.
 499     default_logging_level = getattr(logging, config.config['logging_level'].upper(), None)
 500     if not isinstance(default_logging_level, int):
 501         raise ValueError(f'Invalid level: {config.config["logging_level"]}')
 502
 503     # Custom or default --logging_format?
 504     if config.config['logging_format']:
 505         fmt = config.config['logging_format']
 506     else:
 507         if config.config['logging_syslog']:
 508             fmt = '%(levelname).1s:%(filename)s[%(process)d]: %(message)s'
 509         else:
 510             fmt = '%(levelname).1s:%(asctime)s: %(message)s'
 511
 512     # --logging_debug_threads and --logging_debug_modules both affect
 513     # the format by prepending information about the pid/tid or
 514     # file/function.
 515     if config.config['logging_debug_threads']:
 516         fmt = f'%(process)d.%(thread)d|{fmt}'
 517     if config.config['logging_debug_modules']:
 518         fmt = f'%(filename)s:%(funcName)s:%(lineno)s|{fmt}'
 519
 520     # --logging_syslog (optionally with --logging_syslog_facility)
 521     # sets up for logging to use the standard system syslogd as a
 522     # sink.
 523     facility_name = None
 524     if config.config['logging_syslog']:
 525         if sys.platform not in ('win32', 'cygwin'):
 526             if config.config['logging_syslog_facility']:
 527                 facility_name = 'LOG_' + config.config['logging_syslog_facility']
 528             facility = SysLogHandler.__dict__.get(facility_name, SysLogHandler.LOG_USER)  # type: ignore
 529             assert facility is not None
 530             handler = SysLogHandler(facility=facility, address='/dev/log')
 531             handler.setFormatter(
 532                 MillisecondAwareFormatter(
 533                     fmt=fmt,
 534                     datefmt=config.config['logging_date_format'],
 535                 )
 536             )
 537             handlers.append(handler)
 538
 539     # --logging_filename (with friends --logging_filename_count and
 540     # --logging_filename_maxsize) set up logging to a file on the
 541     # filesystem with automatic rotation when it gets too big.
 542     if config.config['logging_filename']:
 543         handler = RotatingFileHandler(
 544             config.config['logging_filename'],
 545             maxBytes=config.config['logging_filename_maxsize'],
 546             backupCount=config.config['logging_filename_count'],
 547         )
 548         handler.setFormatter(
 549             MillisecondAwareFormatter(
 550                 fmt=fmt,
 551                 datefmt=config.config['logging_date_format'],
 552             )
 553         )
 554         handlers.append(handler)
 555
 556     # --logging_console is, ahem, logging to the console.
 557     if config.config['logging_console']:
 558         handler = logging.StreamHandler(sys.stderr)
 559         handler.setFormatter(
 560             MillisecondAwareFormatter(
 561                 fmt=fmt,
 562                 datefmt=config.config['logging_date_format'],
 563             )
 564         )
 565         handlers.append(handler)
 566
 567     if len(handlers) == 0:
 568         handlers.append(logging.NullHandler())
 569     for handler in handlers:
 570         logger.addHandler(handler)
 571
 572     # --logging_info_is_print echoes any message to logger.info(x) as
 573     # a print statement on stdout.
 574     if config.config['logging_info_is_print']:
 575         handler = logging.StreamHandler(sys.stdout)
 576         handler.addFilter(OnlyInfoFilter())
 577         logger.addHandler(handler)
 578
 579     # --logging_squelch_repeats allows code to request repeat logging
 580     # messages (identical log site and message contents) to be
 581     # silenced.  Logging code must request this explicitly, it isn't
 582     # automatic.  This option just allows the silencing to happen.
 583     if config.config['logging_squelch_repeats']:
 584         for handler in handlers:
 585             handler.addFilter(SquelchRepeatedMessagesFilter())
 586
 587     # --logging_probabilistically allows code to request
 588     # non-deterministic logging where messages have some probability
 589     # of being produced.  Logging code must request this explicitly.
 590     # This option just allows the non-deterministic behavior to
 591     # happen.  Disabling it will cause every log message to be
 592     # produced.
 593     if config.config['logging_probabilistically']:
 594         for handler in handlers:
 595             handler.addFilter(ProbabilisticFilter())
 596
 597     # --lmodule is a way to have a special logging level for just on
 598     # module or one set of modules that is different than the one set
 599     # globally via --logging_level.
 600     for handler in handlers:
 601         handler.addFilter(
 602             DynamicPerScopeLoggingLevelFilter(
 603                 default_logging_level,
 604                 config.config['lmodule'],
 605             )
 606         )
 607     logger.setLevel(0)
 608     logger.propagate = False
 609
 610     # --logging_captures_prints, if set, will capture and log.info
 611     # anything printed on stdout.
 612     if config.config['logging_captures_prints']:
 613         import builtins
 614
 615         def print_and_also_log(*arg, **kwarg):
 616             f = kwarg.get('file', None)
 617             if f == sys.stderr:
 618                 logger.warning(*arg)
 619             else:
 620                 logger.info(*arg)
 621             BUILT_IN_PRINT(*arg, **kwarg)
 622
 623         builtins.print = print_and_also_log
 624
 625     # At this point the logger is ready, handlers are set up,
 626     # etc... so log about the logging configuration.
 627     log_about_logging(
 628         logger,
 629         default_logging_level,
 630         preexisting_handlers_count,
 631         fmt,
 632         facility_name,
 633     )
 634     return logger
 635
 636
 637 def get_logger(name: str = ""):
 638     logger = logging.getLogger(name)
 639     return initialize_logging(logger)
 640
 641
 642 def tprint(*args, **kwargs) -> None:
 643     """Legacy function for printing a message augmented with thread id
 644     still needed by some code.  Please use --logging_debug_threads in
 645     new code.
 646
 647     """
 648     if config.config['logging_debug_threads']:
 649         from thread_utils import current_thread_id
 650
 651         print(f'{current_thread_id()}', end="")
 652         print(*args, **kwargs)
 653     else:
 654         pass
 655
 656
 657 def dprint(*args, **kwargs) -> None:
 658     """Legacy function used to print to stderr still needed by some code.
 659     Please just use normal logging with --logging_console which
 660     accomplishes the same thing in new code.
 661
 662     """
 663     print(*args, file=sys.stderr, **kwargs)
 664
 665
 666 class OutputMultiplexer(object):
 667     """
 668     A class that broadcasts printed messages to several sinks (including
 669     various logging levels, different files, different file handles,
 670     the house log, etc...).  See also OutputMultiplexerContext for an
 671     easy usage pattern.
 672     """
 673
 674     class Destination(enum.IntEnum):
 675         """Bits in the destination_bitv bitvector.  Used to indicate the
 676         output destination."""
 677
 678         # fmt: off
 679         LOG_DEBUG = 0x01     #  ⎫
 680         LOG_INFO = 0x02      #  ⎪
 681         LOG_WARNING = 0x04   #  ⎬ Must provide logger to the c'tor.
 682         LOG_ERROR = 0x08     #  ⎪
 683         LOG_CRITICAL = 0x10  #  ⎭
 684         FILENAMES = 0x20     # Must provide a filename to the c'tor.
 685         FILEHANDLES = 0x40   # Must provide a handle to the c'tor.
 686         HLOG = 0x80
 687         ALL_LOG_DESTINATIONS = (
 688             LOG_DEBUG | LOG_INFO | LOG_WARNING | LOG_ERROR | LOG_CRITICAL
 689         )
 690         ALL_OUTPUT_DESTINATIONS = 0x8F
 691         # fmt: on
 692
 693     def __init__(
 694         self,
 695         destination_bitv: int,
 696         *,
 697         logger=None,
 698         filenames: Optional[Iterable[str]] = None,
 699         handles: Optional[Iterable[io.TextIOWrapper]] = None,
 700     ):
 701         if logger is None:
 702             logger = logging.getLogger(None)
 703         self.logger = logger
 704
 705         self.f: Optional[List[Any]] = None
 706         if filenames is not None:
 707             self.f = [open(filename, 'wb', buffering=0) for filename in filenames]
 708         else:
 709             if destination_bitv & OutputMultiplexer.Destination.FILENAMES:
 710                 raise ValueError("Filenames argument is required if bitv & FILENAMES")
 711             self.f = None
 712
 713         self.h: Optional[List[Any]] = None
 714         if handles is not None:
 715             self.h = list(handles)
 716         else:
 717             if destination_bitv & OutputMultiplexer.Destination.FILEHANDLES:
 718                 raise ValueError("Handle argument is required if bitv & FILEHANDLES")
 719             self.h = None
 720
 721         self.set_destination_bitv(destination_bitv)
 722
 723     def get_destination_bitv(self):
 724         return self.destination_bitv
 725
 726     def set_destination_bitv(self, destination_bitv: int):
 727         if destination_bitv & self.Destination.FILENAMES and self.f is None:
 728             raise ValueError("Filename argument is required if bitv & FILENAMES")
 729         if destination_bitv & self.Destination.FILEHANDLES and self.h is None:
 730             raise ValueError("Handle argument is required if bitv & FILEHANDLES")
 731         self.destination_bitv = destination_bitv
 732
 733     def print(self, *args, **kwargs):
 734         from string_utils import sprintf, strip_escape_sequences
 735
 736         end = kwargs.pop("end", None)
 737         if end is not None:
 738             if not isinstance(end, str):
 739                 raise TypeError("end must be None or a string")
 740         sep = kwargs.pop("sep", None)
 741         if sep is not None:
 742             if not isinstance(sep, str):
 743                 raise TypeError("sep must be None or a string")
 744         if kwargs:
 745             raise TypeError("invalid keyword arguments to print()")
 746         buf = sprintf(*args, end="", sep=sep)
 747         if sep is None:
 748             sep = " "
 749         if end is None:
 750             end = "\n"
 751         if end == '\n':
 752             buf += '\n'
 753         if self.destination_bitv & self.Destination.FILENAMES and self.f is not None:
 754             for _ in self.f:
 755                 _.write(buf.encode('utf-8'))
 756                 _.flush()
 757
 758         if self.destination_bitv & self.Destination.FILEHANDLES and self.h is not None:
 759             for _ in self.h:
 760                 _.write(buf)
 761                 _.flush()
 762
 763         buf = strip_escape_sequences(buf)
 764         if self.logger is not None:
 765             if self.destination_bitv & self.Destination.LOG_DEBUG:
 766                 self.logger.debug(buf)
 767             if self.destination_bitv & self.Destination.LOG_INFO:
 768                 self.logger.info(buf)
 769             if self.destination_bitv & self.Destination.LOG_WARNING:
 770                 self.logger.warning(buf)
 771             if self.destination_bitv & self.Destination.LOG_ERROR:
 772                 self.logger.error(buf)
 773             if self.destination_bitv & self.Destination.LOG_CRITICAL:
 774                 self.logger.critical(buf)
 775         if self.destination_bitv & self.Destination.HLOG:
 776             hlog(buf)
 777
 778     def close(self):
 779         if self.f is not None:
 780             for _ in self.f:
 781                 _.close()
 782
 783
 784 class OutputMultiplexerContext(OutputMultiplexer, contextlib.ContextDecorator):
 785     """
 786     A context that uses an OutputMultiplexer.  e.g.::
 787
 788         with OutputMultiplexerContext(
 789                 OutputMultiplexer.LOG_INFO |
 790                 OutputMultiplexer.LOG_DEBUG |
 791                 OutputMultiplexer.FILENAMES |
 792                 OutputMultiplexer.FILEHANDLES,
 793                 filenames = [ '/tmp/foo.log', '/var/log/bar.log' ],
 794                 handles = [ f, g ]
 795             ) as mplex:
 796                 mplex.print("This is a log message!")
 797     """
 798
 799     def __init__(
 800         self,
 801         destination_bitv: OutputMultiplexer.Destination,
 802         *,
 803         logger=None,
 804         filenames=None,
 805         handles=None,
 806     ):
 807         super().__init__(
 808             destination_bitv,
 809             logger=logger,
 810             filenames=filenames,
 811             handles=handles,
 812         )
 813
 814     def __enter__(self):
 815         return self
 816
 817     def __exit__(self, etype, value, traceback) -> bool:
 818         super().close()
 819         if etype is not None:
 820             return False
 821         return True
 822
 823
 824 def hlog(message: str) -> None:
 825     """Write a message to the house log (syslog facility local7 priority
 826     info) by calling /usr/bin/logger.  This is pretty hacky but used
 827     by a bunch of code.  Another way to do this would be to use
 828     --logging_syslog and --logging_syslog_facility but I can't
 829     actually say that's easier.
 830
 831     """
 832     message = message.replace("'", "'\"'\"'")
 833     os.system(f"/usr/bin/logger -p local7.info -- '{message}'")
 834
 835
 836 if __name__ == '__main__':
 837     import doctest
 838
 839     doctest.testmod()