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