logging_utils.py

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