Commit | Line | Data |
---|---|---|
3098ca94 CH |
1 | # The software in this package is distributed under the GNU General |
2 | # Public License version 2 (with a special exception described below). | |
3 | # | |
4 | # A copy of GNU General Public License (GPL) is included in this distribution, | |
5 | # in the file COPYING.GPL. | |
6 | # | |
7 | # As a special exception, if other files instantiate templates or use macros | |
8 | # or inline functions from this file, or you compile this file and link it | |
9 | # with other works to produce a work based on this file, this file | |
10 | # does not by itself cause the resulting work to be covered | |
11 | # by the GNU General Public License. | |
12 | # | |
13 | # However the source code for this file must still be made available | |
14 | # in accordance with section (3) of the GNU General Public License. | |
15 | # | |
16 | # This exception does not invalidate any other reasons why a work based | |
17 | # on this file might be covered by the GNU General Public License. | |
f365f614 CH |
18 | # |
19 | # Copyright (c) 2016-2018 Intra2net AG <info@intra2net.com> | |
3098ca94 | 20 | |
2e6f474f | 21 | """ Helpers for logging; featuring: |
3098ca94 | 22 | |
d72f781a CH |
23 | ShortLevelFormatter: provide a 4-char-sized field "shortlevel" for message |
24 | urgency (dbug/info/warn/err /crit) | |
3098ca94 | 25 | |
72fc3d56 | 26 | I2nLogger: logger that provides a notice(), allows omission for str.format |
2e6f474f CH |
27 | and is quite convenient in general |
28 | ||
29 | get_logger: factor for creating I2nLoggers | |
3098ca94 | 30 | |
72fc3d56 | 31 | Further ideas: :: |
3098ca94 CH |
32 | * allow milliseconds in dateformat field (see test_short_level_format) |
33 | * create own basicConfig-like function that uses our classes as default | |
2e6f474f CH |
34 | --> started using I2nLogger constructor and get_logger |
35 | * try to find out module that calls I2nLogger constructor to provide a good | |
36 | default value for name (finding out the current module is a pain in the a..) | |
37 | ||
2713b352 CH |
38 | .. todo:: create unittests from test_* functions at bottom |
39 | .. todo:: think about how to allow different levels per handler | |
40 | .. todo:: do not limit logs by line numbers but by disc size? Warn when at 50%, | |
2e6f474f | 41 | 75%, 90%, 99% of limit? |
3098ca94 CH |
42 | """ |
43 | ||
72fc3d56 CH |
44 | import logging |
45 | from logging import DEBUG, INFO, WARNING, ERROR, CRITICAL, NOTSET | |
216026f6 | 46 | from logging.handlers import RotatingFileHandler |
8fe2dd62 | 47 | from math import log10, floor |
2e6f474f CH |
48 | import sys |
49 | ||
1242b1cf | 50 | from .type_helpers import isstr |
3098ca94 | 51 | |
72fc3d56 | 52 | #: log level half-way between INFO and WARNING |
1d98fafb | 53 | NOTICE = (INFO + WARNING)//2 |
72fc3d56 | 54 | logging.addLevelName(NOTICE, 'NOTICE') |
3098ca94 | 55 | |
72fc3d56 CH |
56 | #: default formatting string for ShortLevelFormatter |
57 | DEFAULT_SHORT_LEVEL_FORMAT = '%(asctime)s:%(msecs)03d %(shortlevel)s| %(msg)s' | |
58 | ||
59 | #: default formatting string for date/time in ShortLevelFormatter | |
60 | DEFAULT_SHORT_LEVEL_DATE_FORMAT = '%H:%M:%S' | |
61 | ||
62 | #: mapping from level name to level int for I2nLogger's set_level | |
63 | LEVEL_DICT = dict(notset=NOTSET, debug=DEBUG, info=INFO, notice=NOTICE, | |
64 | warning=WARNING, error=ERROR, critical=CRITICAL) | |
65 | ||
66 | #: min level allowed in I2nLogger | |
67 | MIN_LEVEL = NOTSET | |
68 | ||
69 | #: max level allowed in I2nLogger | |
70 | MAX_LEVEL = CRITICAL | |
71 | ||
2e6f474f CH |
72 | #: constant for I2nLogger streams argument: stream to stdout |
73 | STDOUT = sys.stdout | |
74 | ||
75 | ||
72fc3d56 | 76 | class ShortLevelFormatter(logging.Formatter): |
3098ca94 | 77 | """ |
d72f781a | 78 | Formatter for logging handlers that allows use of format field "shortlevel" |
3098ca94 CH |
79 | |
80 | using this formatter, you can specify in the log message format string the | |
d72f781a CH |
81 | field "shortlevel" which will introduce in your log messages a 4-char field |
82 | for the log record urgency: "DEBUG" --> "dbug", "INFO" --> "info", | |
3098ca94 CH |
83 | "WARNING" --> "warn", "ERROR" --> "err ", "CRITICAL" --> "crit" |
84 | ||
85 | All other functionality (like other format fields) is inherited from base | |
86 | class Formatter | |
87 | ||
2e6f474f CH |
88 | Most easily used indirectly through :py:class:`I2nLogger` |
89 | (uses this by default) | |
90 | ||
91 | Explicit usage example:: | |
3098ca94 CH |
92 | |
93 | logger = logging.getLogger(__name__) | |
94 | logger.setLevel(logging.DEBUG) | |
95 | handler = logging.StreamHandler() | |
96 | handler.setLevel(logging.DEBUG) | |
d72f781a | 97 | formatter = ShortLevelFormatter('%(shortlevel)s| %(msg)s') |
3098ca94 CH |
98 | handler.setFormatter(formatter) |
99 | logger.addHandler(handler) | |
100 | ||
101 | You can even add new levels:: | |
102 | ||
103 | notice = (logging.INFO + logging.WARNING)/2 | |
104 | formatter.add_level(notice, 'note') | |
105 | logger.log(notice, 'more important than info but no warning nor error') | |
106 | ||
107 | .. seealso:: testing funcion :py:func:`test_short_level_format` | |
108 | """ | |
109 | ||
d72f781a CH |
110 | def __init__(self, fmt=DEFAULT_SHORT_LEVEL_FORMAT, |
111 | datefmt=DEFAULT_SHORT_LEVEL_DATE_FORMAT, *args, **kwargs): | |
3098ca94 CH |
112 | """ creates a new ShortLevelFormatter |
113 | ||
114 | forwards all args to super class Formatter and initializes dict with | |
115 | levelno and short string representations | |
116 | """ | |
d72f781a CH |
117 | self.parent = super(ShortLevelFormatter, self) |
118 | self.parent.__init__(fmt=fmt, datefmt=datefmt, *args, **kwargs) | |
119 | self._shortlevel_dict = {DEBUG: 'dbug', INFO: 'info', WARNING: 'warn', | |
120 | ERROR: 'err ', CRITICAL: 'crit', | |
121 | NOTSET: '----'} | |
3098ca94 CH |
122 | |
123 | def format(self, record): | |
124 | """ create string representation of given log record """ | |
125 | try: | |
d72f781a | 126 | record.shortlevel = self._shortlevel_dict[record.levelno] |
3098ca94 | 127 | except KeyError: |
d72f781a | 128 | record.shortlevel = '????' |
3098ca94 | 129 | |
d72f781a | 130 | return self.parent.format(record) |
3098ca94 | 131 | |
d72f781a | 132 | def add_level(self, levelno, shortlevel_str): |
3098ca94 CH |
133 | """ add a new message urgency level |
134 | ||
135 | :param int levelno: numeric urgency level | |
d72f781a CH |
136 | :param str shortlevel_str: string representation of message urgency; |
137 | should be of length 4 | |
3098ca94 CH |
138 | :returns: nothing |
139 | """ | |
140 | ||
d72f781a | 141 | self._shortlevel_dict[levelno] = shortlevel_str |
3098ca94 CH |
142 | |
143 | ||
2e6f474f CH |
144 | #: memory for all I2nLogger instances in current session to avoid overwrite |
145 | #: used in :py:func:`get_logger` and :py:class:`I2nLogger` constructor | |
146 | _i2n_loggers = {} | |
147 | ||
148 | ||
149 | def get_logger(name, *args, **kwargs): | |
f0d2b744 | 150 | """ factory for :py:class:`I2nLogger`: create new or return existing object |
2e6f474f | 151 | |
f0d2b744 CH |
152 | all args as in :py:class:`I2nLogger` constructor; args will be ignored if |
153 | logger with given name exists already! | |
2e6f474f CH |
154 | """ |
155 | ||
156 | if name in _i2n_loggers: | |
157 | return _i2n_loggers[name] # ignore all args | |
158 | else: | |
159 | return I2nLogger(name, *args, **kwargs) | |
160 | ||
161 | ||
72fc3d56 | 162 | class I2nLogger: |
a72075dc CH |
163 | """ |
164 | A more convenient logger | |
72fc3d56 CH |
165 | |
166 | Features:: | |
2e6f474f | 167 | * can be used without ".format()" as follows:: |
72fc3d56 CH |
168 | |
169 | logger.info('the result is {0}', result) # more convenient than... | |
170 | logger.info('the result is {0}'.format(result)) # ... the original | |
171 | ||
172 | * Has a :py:meth:`Logger.notice` function | |
173 | * Has by default as only handler a :py:class:`logging.StreamHandler` to | |
174 | stdout with a :py:class:`ShortLevelFormatter` | |
175 | * Simplifies setting of logger's logging level using | |
176 | :py:meth:`Logger.set_level`. The level is kept in sync between logger and | |
177 | handlers and can be queried using :py:meth:`get_level` | |
2e6f474f | 178 | (does not work accross logger hierarchies!) |
72fc3d56 | 179 | * can specify name and level and [date]fmt all in constructor |
2e6f474f CH |
180 | * can limit the number of lines this logger will produce to prevent filling |
181 | hard drive with log file | |
182 | (assumes one line per call to log/debug/info/notice/..., | |
183 | only counts calls with priority above this logger's level) | |
184 | * provides shorter method names: dbg, note, warn, err | |
4767d190 | 185 | * adds a NullHandler if `streams` and `files` and `handlers` are all `None` |
216026f6 | 186 | * convenience functions to add most frequently used handlers |
2e6f474f CH |
187 | |
188 | ..note:: Creating multiple instances with the same name is not allowed and | |
189 | will result in an error. Use :py:func:`get_logger` instead of this | |
190 | constructor to avoid such situtations | |
191 | ||
192 | ..note:: Do not change or use the underlying logger or functionality here | |
109c4be3 | 193 | (in particular, get_level) is no longer reliable! |
72fc3d56 CH |
194 | """ |
195 | ||
196 | def __init__(self, name, level=INFO, fmt=DEFAULT_SHORT_LEVEL_FORMAT, | |
2e6f474f | 197 | datefmt=DEFAULT_SHORT_LEVEL_DATE_FORMAT, |
87ed6b66 | 198 | streams=STDOUT, files=None, handlers=None): |
a72075dc CH |
199 | """ |
200 | Creates a I2nLogger; forwards args to logging.getLogger | |
2e6f474f CH |
201 | |
202 | :param str name: name of this logger, best practice is module name | |
203 | :param int level: best use one of the constants DEBUG, INFO NOTICE, | |
204 | WARNING, ERROR | |
205 | :param str fmt: format of log messages, see | |
206 | :py:class:`ShortLevelFormatter` for more help | |
207 | :param str datefmt: format of date added to log messages, see | |
208 | :py:class:`ShortLevelFormatter` for more help | |
209 | :param streams: list/tuple of or a single stream to log to, default is | |
210 | STDOUT (=sys.stdout) | |
87ed6b66 CH |
211 | :type streams: (:py:class:`io.IOBase`) or [:py:class:`io.IOBase`) or |
212 | None | |
2e6f474f | 213 | :param files: list/tuple or single file name to log to |
87ed6b66 CH |
214 | :type files: None or (str) or [str] |
215 | :param handlers: other handlers to customize and use with this logger | |
216 | :type handlers: None or [:py:class:`logging.Handler`] or | |
217 | (:py:class:`logging.Handler`) | |
2e6f474f | 218 | :raise: ValueError if an I2nLogger with the same name exists already |
72fc3d56 | 219 | """ |
2e6f474f CH |
220 | |
221 | # check if an instance with the same name has been created earlier | |
222 | # to prevent conflicts | |
223 | global _i2n_loggers | |
224 | if name in _i2n_loggers: | |
225 | raise ValueError("An I2nLogger with that exact name ('{0}') exists" | |
226 | " already -- use get_logger instead!" | |
227 | .format(name)) | |
228 | ||
72fc3d56 | 229 | self._log = logging.getLogger(name) |
bdf52e22 CH |
230 | if isinstance(level, str): |
231 | level = LEVEL_DICT[level] | |
2e6f474f CH |
232 | self._level = min(MAX_LEVEL, max(MIN_LEVEL, level)) |
233 | self._log.setLevel(self._level) | |
72fc3d56 CH |
234 | |
235 | # remove handlers (sometimes there are mutliple by default) | |
236 | for handler in self._log.handlers: | |
237 | self._log.removeHandler(handler) | |
238 | ||
2e6f474f CH |
239 | # create new handlers and formatter |
240 | if streams is None: | |
79ae7d87 | 241 | streams = [] |
2e6f474f CH |
242 | elif not isinstance(streams, (list, tuple)): |
243 | streams = (streams, ) | |
244 | for stream in streams: | |
245 | formatter = ShortLevelFormatter(fmt=fmt, datefmt=datefmt) | |
246 | formatter.add_level(NOTICE, 'note') | |
247 | new_handler = logging.StreamHandler(stream) | |
248 | new_handler.setFormatter(formatter) | |
249 | new_handler.setLevel(self._level) | |
250 | self._log.addHandler(new_handler) | |
251 | ||
252 | if files is None: | |
253 | files = [] | |
254 | elif not isinstance(files, (list, tuple)): | |
255 | files = (files, ) | |
256 | for file_name in files: | |
257 | formatter = ShortLevelFormatter(fmt=fmt, datefmt=datefmt) | |
258 | formatter.add_level(NOTICE, 'note') | |
259 | new_handler = logging.FileHandler(file_name) | |
260 | new_handler.setFormatter(formatter) | |
261 | new_handler.setLevel(self._level) | |
262 | self._log.addHandler(new_handler) | |
263 | ||
87ed6b66 CH |
264 | if handlers is None: |
265 | handlers = [] | |
266 | elif not isinstance(handlers, (list, tuple)): | |
267 | handlers = (handlers, ) | |
268 | for handler in handlers: | |
269 | formatter = ShortLevelFormatter(fmt=fmt, datefmt=datefmt) | |
270 | formatter.add_level(NOTICE, 'note') | |
271 | handler.setFormatter(formatter) | |
272 | handler.setLevel(self._level) | |
273 | self._log.addHandler(handler) | |
274 | ||
4767d190 CH |
275 | if not self._log.handlers: |
276 | self._log.addHandler(logging.NullHandler()) | |
277 | ||
2e6f474f CH |
278 | # remember that this logger is a I2nLogger |
279 | _i2n_loggers[name] = self | |
280 | ||
281 | def dbg(self, message, *args, **kwargs): | |
bdf52e22 | 282 | self._log_no_test(DEBUG, message, *args, **kwargs) |
72fc3d56 CH |
283 | |
284 | def debug(self, message, *args, **kwargs): | |
bdf52e22 | 285 | self._log_no_test(DEBUG, message, *args, **kwargs) |
72fc3d56 CH |
286 | |
287 | def info(self, message, *args, **kwargs): | |
bdf52e22 | 288 | self._log_no_test(INFO, message, *args, **kwargs) |
72fc3d56 | 289 | |
2e6f474f | 290 | def note(self, message, *args, **kwargs): |
bdf52e22 | 291 | self._log_no_test(NOTICE, message, *args, **kwargs) |
2e6f474f | 292 | |
72fc3d56 | 293 | def notice(self, message, *args, **kwargs): |
bdf52e22 | 294 | self._log_no_test(NOTICE, message, *args, **kwargs) |
72fc3d56 | 295 | |
2e6f474f | 296 | def warn(self, message, *args, **kwargs): |
bdf52e22 | 297 | self._log_no_test(WARNING, message, *args, **kwargs) |
2e6f474f | 298 | |
72fc3d56 | 299 | def warning(self, message, *args, **kwargs): |
bdf52e22 | 300 | self._log_no_test(WARNING, message, *args, **kwargs) |
72fc3d56 | 301 | |
2e6f474f | 302 | def err(self, message, *args, **kwargs): |
bdf52e22 | 303 | self._log_no_test(ERROR, message, *args, **kwargs) |
2e6f474f | 304 | |
72fc3d56 | 305 | def error(self, message, *args, **kwargs): |
bdf52e22 | 306 | self._log_no_test(ERROR, message, *args, **kwargs) |
72fc3d56 | 307 | |
998ae6d7 CH |
308 | def exception(self, message, *args, **kwargs): |
309 | if 'exc_info' in kwargs: | |
310 | self._log_no_test(ERROR, message, *args, **kwargs) | |
311 | else: | |
312 | self._log_no_test(ERROR, message, *args, exc_info=True, **kwargs) | |
313 | ||
72fc3d56 | 314 | def critical(self, message, *args, **kwargs): |
bdf52e22 | 315 | self._log_no_test(CRITICAL, message, *args, **kwargs) |
72fc3d56 CH |
316 | |
317 | def log(self, level, message, *args, **kwargs): | |
bdf52e22 CH |
318 | if isinstance(level, str): |
319 | level = LEVEL_DICT[level.lower()] | |
320 | if level >= self._level: | |
4e993142 CH |
321 | try: |
322 | message_formatted = message.format(*args) | |
323 | except (KeyError, IndexError): | |
324 | message_formatted = '[LOG ARGS!] ' + message | |
325 | self._log.log(level, message_formatted, **kwargs) | |
bdf52e22 CH |
326 | |
327 | def _log_no_test(self, level, message, *args, **kwargs): | |
a72075dc | 328 | """Same as log() but without the isinstance test for internal use.""" |
72fc3d56 | 329 | if level >= self._level: |
4e993142 CH |
330 | try: |
331 | message_formatted = message.format(*args) | |
332 | except (KeyError, IndexError): | |
333 | message_formatted = '[LOG ARGS!] ' + message | |
334 | self._log.log(level, message_formatted, **kwargs) | |
2e6f474f CH |
335 | |
336 | def log_count_if_interesting(self, count, level=INFO, counter_name=None): | |
a72075dc CH |
337 | """ |
338 | Log value of a counter in gradually coarser intervals | |
2e6f474f | 339 | |
a72075dc | 340 | See :py:func:`is_interesting_count` for definition of "interesting". |
2e6f474f CH |
341 | """ |
342 | if is_interesting_count(count): | |
343 | if counter_name: | |
344 | self.log(level, '{0} counter is at {1}', counter_name, count) | |
345 | else: | |
346 | self.log(level, 'Counter is at {0}', count) | |
72fc3d56 CH |
347 | |
348 | def get_level(self): | |
a72075dc | 349 | """Return int level of this logger.""" |
72fc3d56 CH |
350 | return self._level |
351 | ||
352 | def get_level_str(self): | |
a72075dc | 353 | """Returns :py:func:`logging.getLevelName` on :py:meth:`get_level`.""" |
72fc3d56 CH |
354 | return logging.getLevelName(self._level) |
355 | ||
356 | def set_level(self, new_level): | |
a72075dc CH |
357 | """ |
358 | Set level given an int or a str. | |
72fc3d56 CH |
359 | |
360 | :arg new_level: int or str (str is converted to lower case) | |
361 | :raises: KeyError if new_level is a string that is not in | |
362 | :py:data:`LEVEL_DICT` | |
363 | """ | |
364 | if isstr(new_level): | |
365 | self._level = LEVEL_DICT[new_level.lower()] | |
366 | else: | |
2e6f474f | 367 | self._level = min(MAX_LEVEL, max(MIN_LEVEL, new_level)) |
72fc3d56 CH |
368 | self._log.setLevel(self._level) |
369 | for handler in self._log.handlers: | |
370 | handler.setLevel(self._level) | |
371 | ||
216026f6 CH |
372 | def add_handler(self, *args, **kwargs): |
373 | return self._log.addHandler(*args, **kwargs) | |
374 | ||
375 | def add_stream_handler(self, stream=sys.stdout, level='debug'): | |
376 | """ | |
377 | Add a stream handler to the current logger that logs to given stream. | |
378 | ||
379 | Note that the default here is stdout, not the python-default (stderr). | |
380 | """ | |
381 | handler = logging.StreamHandler(stream) | |
382 | handler.setLevel(self._level) | |
383 | self._log.addHandler(handler) | |
384 | ||
385 | def add_syslog_handler(self): | |
386 | """Add a handler that logs to syslog.""" | |
387 | handler = SysLogHandler(address='/dev/log') | |
388 | handler.setLevel(self._level) | |
389 | self._log.addHandler(handler) | |
390 | ||
391 | def add_file_handler(self, filename, mode='a', max_bytes=5*1024*1024, | |
392 | max_rotations=100, **kwargs): | |
393 | """ | |
394 | Add a handler that logs to given file. | |
395 | ||
396 | For convenience creates a | |
397 | :py:class:`logging.handlers.RotatingFileHandler` to avoid huge log | |
398 | files filling up the disc in case of error. | |
399 | ||
400 | :param str mode: Mode with which to open log file; forwarded to handler | |
401 | :param int max_bytes: Max size in bytes of a log file before it is | |
402 | renamed to `[filename].1` and logging continues | |
403 | with an empty `[filename]`. | |
404 | :param int max_rots: Max number of rotated files to keep | |
405 | :param dict kwargs: All other args (e.g. `encoding`) are forwarded to | |
406 | handler constructor. `maxBytes` and `backupCount` | |
407 | are overwritten with `max_bytes` and `max_rots`. | |
408 | """ | |
409 | kwargs['maxBytes'] = max_bytes | |
410 | kwargs['backupCount'] = max_rotations | |
411 | handler = RotatingFileHandler(filename, mode, **kwargs) | |
412 | handler.setLevel(self._level) | |
413 | self._log.addHandler(handler) | |
414 | ||
72fc3d56 | 415 | |
8fe2dd62 | 416 | def n_digits(number): |
a72075dc CH |
417 | """ |
418 | Returns the number of digits a number has in decimal format | |
8fe2dd62 CH |
419 | |
420 | :returns: 1 for 1...9, 2 for 10...99, 3 for 100...999, ... | |
421 | 0 for 0 (and everything else beween -1 and 1) | |
422 | 1 for -1...-9, 2 for -10...-99, ... | |
423 | """ | |
424 | if abs(number) < 1: | |
425 | return 0 | |
426 | else: | |
427 | return floor(log10(abs(number)))+1 | |
428 | ||
a72075dc | 429 | |
8fe2dd62 | 430 | def is_interesting_count(counter): |
a72075dc CH |
431 | """ |
432 | Return True if counter has reached an "interesting" value | |
8fe2dd62 CH |
433 | |
434 | For the counter to be "interesting" becomes ever harder. At first it is | |
435 | easy (returns True for 1,2,3,6,10), then becomes harder (True only for | |
436 | 10,20,30,60,100) and harder (True for 100,200,300,600,1000) and this scheme | |
437 | continues on a logartihmic scale. | |
438 | ||
439 | An example that will print lots in the beginning and then less and less:: | |
440 | ||
441 | counter = 0 | |
442 | while not end_reached(): | |
443 | do_something() | |
444 | if is_interesting_count(counter): | |
445 | log('reached iteration {0}'.format(counter)) | |
446 | counter += 1 | |
447 | ||
a72075dc | 448 | Used by :py:meth:`I2nLogger::log_count_if_interesting`. |
2e6f474f | 449 | |
8fe2dd62 CH |
450 | :returns: True for a few values of counter, False most of the time |
451 | """ | |
2e6f474f | 452 | return float(counter) / 10.**(n_digits(counter)-1.) in (1., 2., 3., 6.) |