3 """Utilities related to logging."""
11 from logging.handlers import RotatingFileHandler, SysLogHandler
15 from typing import Iterable, Optional
17 # This module is commonly used by others in here and should avoid
18 # taking any unnecessary dependencies back on them.
22 cfg = config.add_commandline_args(
23 f'Logging ({__file__})',
24 'Args related to logging')
26 '--logging_config_file',
27 type=argparse_utils.valid_filename,
30 help='Config file containing the logging setup, see: https://docs.python.org/3/howto/logging.html#logging-advanced-tutorial',
36 choices=['NOTSET', 'DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL'],
38 help='The level below which to squelch log messages.',
43 default='%(levelname).1s:%(asctime)s: %(message)s',
44 help='The format for lines logged via the logger module.'
47 '--logging_date_format',
49 default='%Y/%m/%dT%H:%M:%S.%f%z',
51 help='The format of any dates in --logging_format.'
55 action=argparse_utils.ActionNoYes,
57 help='Should we log to the console (stderr)',
64 help='The filename of the logfile to write.'
67 '--logging_filename_maxsize',
71 help='The maximum size (in bytes) to write to the logging_filename.'
74 '--logging_filename_count',
78 help='The number of logging_filename copies to keep before deleting.'
82 action=argparse_utils.ActionNoYes,
84 help='Should we log to localhost\'s syslog.'
87 '--logging_debug_threads',
88 action=argparse_utils.ActionNoYes,
90 help='Should we prepend pid/tid data to all log messages?'
93 '--logging_info_is_print',
94 action=argparse_utils.ActionNoYes,
96 help='logging.info also prints to stdout.'
99 '--logging_max_n_times_per_message',
102 help='When set, ignore logged messages from the same site after N.'
105 # See also: OutputMultiplexer
107 '--logging_captures_prints',
108 action=argparse_utils.ActionNoYes,
110 help='When calling print also log.info too'
113 built_in_print = print
116 class OnlyInfoFilter(logging.Filter):
118 A filter that only logs messages produced at the INFO logging level.
120 def filter(self, record):
121 return record.levelno == logging.INFO
124 class OnlyNTimesFilter(logging.Filter):
126 A filter that only logs messages from a given site with the same
127 message at the same logging level N times and ignores subsequent
131 def __init__(self, maximum: int) -> None:
132 self.maximum = maximum
133 self.counters = collections.Counter()
136 def filter(self, record: logging.LogRecord) -> bool:
137 source = f'{record.pathname}+{record.lineno}+{record.levelno}+{record.msg}'
138 count = self.counters[source]
139 self.counters[source] += 1
140 return count < self.maximum
143 class MillisecondAwareFormatter(logging.Formatter):
145 A formatter for adding milliseconds to log messages.
148 converter = datetime.datetime.fromtimestamp
150 def formatTime(self, record, datefmt=None):
151 ct = MillisecondAwareFormatter.converter(
152 record.created, pytz.timezone("US/Pacific")
155 s = ct.strftime(datefmt)
157 t = ct.strftime("%Y-%m-%d %H:%M:%S")
158 s = "%s,%03d" % (t, record.msecs)
162 def initialize_logging(logger=None) -> logging.Logger:
163 assert config.has_been_parsed()
165 logger = logging.getLogger() # Root logger
167 if config.config['logging_config_file'] is not None:
168 logging.config.fileConfig('logging.conf')
172 numeric_level = getattr(
174 config.config['logging_level'].upper(),
177 if not isinstance(numeric_level, int):
178 raise ValueError('Invalid level: %s' % config.config['logging_level'])
180 fmt = config.config['logging_format']
181 if config.config['logging_debug_threads']:
182 fmt = f'%(process)d.%(thread)d|{fmt}'
184 if config.config['logging_syslog']:
185 if sys.platform not in ('win32', 'cygwin'):
186 handler = SysLogHandler()
187 # for k, v in encoded_priorities.items():
188 # handler.encodePriority(k, v)
189 handler.setFormatter(
190 MillisecondAwareFormatter(
192 datefmt=config.config['logging_date_format'],
195 handler.setLevel(numeric_level)
196 handlers.append(handler)
198 if config.config['logging_filename']:
199 handler = RotatingFileHandler(
200 config.config['logging_filename'],
201 maxBytes = config.config['logging_filename_maxsize'],
202 backupCount = config.config['logging_filename_count'],
204 handler.setLevel(numeric_level)
205 handler.setFormatter(
206 MillisecondAwareFormatter(
208 datefmt=config.config['logging_date_format'],
211 handlers.append(handler)
213 if config.config['logging_console']:
214 handler = logging.StreamHandler(sys.stderr)
215 handler.setLevel(numeric_level)
216 handler.setFormatter(
217 MillisecondAwareFormatter(
219 datefmt=config.config['logging_date_format'],
222 handlers.append(handler)
224 if len(handlers) == 0:
225 handlers.append(logging.NullHandler())
227 for handler in handlers:
228 logger.addHandler(handler)
230 if config.config['logging_info_is_print']:
231 handler = logging.StreamHandler(sys.stdout)
232 handler.addFilter(OnlyInfoFilter())
233 logger.addHandler(handler)
235 maximum = config.config['logging_max_n_times_per_message']
237 for handler in handlers:
238 handler.addFilter(OnlyNTimesFilter(maximum))
240 logger.setLevel(numeric_level)
241 logger.propagate = False
243 if config.config['logging_captures_prints']:
245 global built_in_print
247 def print_and_also_log(*arg, **kwarg):
248 f = kwarg.get('file', None)
253 built_in_print(*arg, **kwarg)
254 builtins.print = print_and_also_log
259 def get_logger(name: str = ""):
260 logger = logging.getLogger(name)
261 return initialize_logging(logger)
264 def tprint(*args, **kwargs) -> None:
265 if config.config['logging_debug_threads']:
266 from thread_utils import current_thread_id
267 print(f'{current_thread_id()}', end="")
268 print(*args, **kwargs)
273 def dprint(*args, **kwargs) -> None:
274 print(*args, file=sys.stderr, **kwargs)
277 class OutputMultiplexer(object):
279 class Destination(enum.IntEnum):
280 """Bits in the destination_bitv bitvector. Used to indicate the
281 output destination."""
282 LOG_DEBUG = 0x01 # -\
284 LOG_WARNING = 0x04 # > Should provide logger to the c'tor.
286 LOG_CRITICAL = 0x10 # _/
287 FILENAMES = 0x20 # Must provide a filename to the c'tor.
288 FILEHANDLES = 0x40 # Must provide a handle to the c'tor.
290 ALL_LOG_DESTINATIONS = (
291 LOG_DEBUG | LOG_INFO | LOG_WARNING | LOG_ERROR | LOG_CRITICAL
293 ALL_OUTPUT_DESTINATIONS = 0x8F
296 destination_bitv: int,
299 filenames: Optional[Iterable[str]] = None,
300 handles: Optional[Iterable[io.TextIOWrapper]] = None):
302 logger = logging.getLogger(None)
305 if filenames is not None:
307 open(filename, 'wb', buffering=0) for filename in filenames
310 if destination_bitv & OutputMultiplexer.FILENAMES:
312 "Filenames argument is required if bitv & FILENAMES"
316 if handles is not None:
317 self.h = [handle for handle in handles]
319 if destination_bitv & OutputMultiplexer.Destination.FILEHANDLES:
321 "Handle argument is required if bitv & FILEHANDLES"
325 self.set_destination_bitv(destination_bitv)
327 def get_destination_bitv(self):
328 return self.destination_bitv
330 def set_destination_bitv(self, destination_bitv: int):
331 if destination_bitv & self.Destination.FILENAMES and self.f is None:
333 "Filename argument is required if bitv & FILENAMES"
335 if destination_bitv & self.Destination.FILEHANDLES and self.h is None:
337 "Handle argument is required if bitv & FILEHANDLES"
339 self.destination_bitv = destination_bitv
341 def print(self, *args, **kwargs):
342 from string_utils import sprintf, strip_escape_sequences
343 end = kwargs.pop("end", None)
345 if not isinstance(end, str):
346 raise TypeError("end must be None or a string")
347 sep = kwargs.pop("sep", None)
349 if not isinstance(sep, str):
350 raise TypeError("sep must be None or a string")
352 raise TypeError("invalid keyword arguments to print()")
353 buf = sprintf(*args, end="", sep=sep)
361 self.destination_bitv & self.Destination.FILENAMES and
365 _.write(buf.encode('utf-8'))
369 self.destination_bitv & self.Destination.FILEHANDLES and
376 buf = strip_escape_sequences(buf)
377 if self.logger is not None:
378 if self.destination_bitv & self.Destination.LOG_DEBUG:
379 self.logger.debug(buf)
380 if self.destination_bitv & self.Destination.LOG_INFO:
381 self.logger.info(buf)
382 if self.destination_bitv & self.Destination.LOG_WARNING:
383 self.logger.warning(buf)
384 if self.destination_bitv & self.Destination.LOG_ERROR:
385 self.logger.error(buf)
386 if self.destination_bitv & self.Destination.LOG_CRITICAL:
387 self.logger.critical(buf)
388 if self.destination_bitv & self.Destination.HLOG:
392 if self.f is not None:
397 class OutputMultiplexerContext(OutputMultiplexer, contextlib.ContextDecorator):
399 destination_bitv: OutputMultiplexer.Destination,
413 def __exit__(self, etype, value, traceback) -> bool:
415 if etype is not None:
420 def hlog(message: str) -> None:
421 message = message.replace("'", "'\"'\"'")
422 os.system(f"/usr/bin/logger -p local7.info -- '{message}'")