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 | |
8fe2dd62 | 46 | from math import log10, floor |
2e6f474f CH |
47 | import sys |
48 | ||
1242b1cf | 49 | from .type_helpers import isstr |
3098ca94 | 50 | |
72fc3d56 | 51 | #: log level half-way between INFO and WARNING |
1d98fafb | 52 | NOTICE = (INFO + WARNING)//2 |
72fc3d56 | 53 | logging.addLevelName(NOTICE, 'NOTICE') |
3098ca94 | 54 | |
72fc3d56 CH |
55 | #: default formatting string for ShortLevelFormatter |
56 | DEFAULT_SHORT_LEVEL_FORMAT = '%(asctime)s:%(msecs)03d %(shortlevel)s| %(msg)s' | |
57 | ||
58 | #: default formatting string for date/time in ShortLevelFormatter | |
59 | DEFAULT_SHORT_LEVEL_DATE_FORMAT = '%H:%M:%S' | |
60 | ||
61 | #: mapping from level name to level int for I2nLogger's set_level | |
62 | LEVEL_DICT = dict(notset=NOTSET, debug=DEBUG, info=INFO, notice=NOTICE, | |
63 | warning=WARNING, error=ERROR, critical=CRITICAL) | |
64 | ||
65 | #: min level allowed in I2nLogger | |
66 | MIN_LEVEL = NOTSET | |
67 | ||
68 | #: max level allowed in I2nLogger | |
69 | MAX_LEVEL = CRITICAL | |
70 | ||
2e6f474f CH |
71 | #: constant for I2nLogger streams argument: stream to stdout |
72 | STDOUT = sys.stdout | |
73 | ||
74 | ||
72fc3d56 | 75 | class ShortLevelFormatter(logging.Formatter): |
3098ca94 | 76 | """ |
d72f781a | 77 | Formatter for logging handlers that allows use of format field "shortlevel" |
3098ca94 CH |
78 | |
79 | using this formatter, you can specify in the log message format string the | |
d72f781a CH |
80 | field "shortlevel" which will introduce in your log messages a 4-char field |
81 | for the log record urgency: "DEBUG" --> "dbug", "INFO" --> "info", | |
3098ca94 CH |
82 | "WARNING" --> "warn", "ERROR" --> "err ", "CRITICAL" --> "crit" |
83 | ||
84 | All other functionality (like other format fields) is inherited from base | |
85 | class Formatter | |
86 | ||
2e6f474f CH |
87 | Most easily used indirectly through :py:class:`I2nLogger` |
88 | (uses this by default) | |
89 | ||
90 | Explicit usage example:: | |
3098ca94 CH |
91 | |
92 | logger = logging.getLogger(__name__) | |
93 | logger.setLevel(logging.DEBUG) | |
94 | handler = logging.StreamHandler() | |
95 | handler.setLevel(logging.DEBUG) | |
d72f781a | 96 | formatter = ShortLevelFormatter('%(shortlevel)s| %(msg)s') |
3098ca94 CH |
97 | handler.setFormatter(formatter) |
98 | logger.addHandler(handler) | |
99 | ||
100 | You can even add new levels:: | |
101 | ||
102 | notice = (logging.INFO + logging.WARNING)/2 | |
103 | formatter.add_level(notice, 'note') | |
104 | logger.log(notice, 'more important than info but no warning nor error') | |
105 | ||
106 | .. seealso:: testing funcion :py:func:`test_short_level_format` | |
107 | """ | |
108 | ||
d72f781a CH |
109 | def __init__(self, fmt=DEFAULT_SHORT_LEVEL_FORMAT, |
110 | datefmt=DEFAULT_SHORT_LEVEL_DATE_FORMAT, *args, **kwargs): | |
3098ca94 CH |
111 | """ creates a new ShortLevelFormatter |
112 | ||
113 | forwards all args to super class Formatter and initializes dict with | |
114 | levelno and short string representations | |
115 | """ | |
d72f781a CH |
116 | self.parent = super(ShortLevelFormatter, self) |
117 | self.parent.__init__(fmt=fmt, datefmt=datefmt, *args, **kwargs) | |
118 | self._shortlevel_dict = {DEBUG: 'dbug', INFO: 'info', WARNING: 'warn', | |
119 | ERROR: 'err ', CRITICAL: 'crit', | |
120 | NOTSET: '----'} | |
3098ca94 CH |
121 | |
122 | def format(self, record): | |
123 | """ create string representation of given log record """ | |
124 | try: | |
d72f781a | 125 | record.shortlevel = self._shortlevel_dict[record.levelno] |
3098ca94 | 126 | except KeyError: |
d72f781a | 127 | record.shortlevel = '????' |
3098ca94 | 128 | |
d72f781a | 129 | return self.parent.format(record) |
3098ca94 | 130 | |
d72f781a | 131 | def add_level(self, levelno, shortlevel_str): |
3098ca94 CH |
132 | """ add a new message urgency level |
133 | ||
134 | :param int levelno: numeric urgency level | |
d72f781a CH |
135 | :param str shortlevel_str: string representation of message urgency; |
136 | should be of length 4 | |
3098ca94 CH |
137 | :returns: nothing |
138 | """ | |
139 | ||
d72f781a | 140 | self._shortlevel_dict[levelno] = shortlevel_str |
3098ca94 CH |
141 | |
142 | ||
2e6f474f CH |
143 | #: memory for all I2nLogger instances in current session to avoid overwrite |
144 | #: used in :py:func:`get_logger` and :py:class:`I2nLogger` constructor | |
145 | _i2n_loggers = {} | |
146 | ||
147 | ||
148 | def get_logger(name, *args, **kwargs): | |
f0d2b744 | 149 | """ factory for :py:class:`I2nLogger`: create new or return existing object |
2e6f474f | 150 | |
f0d2b744 CH |
151 | all args as in :py:class:`I2nLogger` constructor; args will be ignored if |
152 | logger with given name exists already! | |
2e6f474f CH |
153 | """ |
154 | ||
155 | if name in _i2n_loggers: | |
156 | return _i2n_loggers[name] # ignore all args | |
157 | else: | |
158 | return I2nLogger(name, *args, **kwargs) | |
159 | ||
160 | ||
72fc3d56 CH |
161 | class I2nLogger: |
162 | """ a more convenient logger | |
163 | ||
164 | Features:: | |
2e6f474f | 165 | * can be used without ".format()" as follows:: |
72fc3d56 CH |
166 | |
167 | logger.info('the result is {0}', result) # more convenient than... | |
168 | logger.info('the result is {0}'.format(result)) # ... the original | |
169 | ||
170 | * Has a :py:meth:`Logger.notice` function | |
171 | * Has by default as only handler a :py:class:`logging.StreamHandler` to | |
172 | stdout with a :py:class:`ShortLevelFormatter` | |
173 | * Simplifies setting of logger's logging level using | |
174 | :py:meth:`Logger.set_level`. The level is kept in sync between logger and | |
175 | handlers and can be queried using :py:meth:`get_level` | |
2e6f474f | 176 | (does not work accross logger hierarchies!) |
72fc3d56 | 177 | * can specify name and level and [date]fmt all in constructor |
2e6f474f CH |
178 | * can limit the number of lines this logger will produce to prevent filling |
179 | hard drive with log file | |
180 | (assumes one line per call to log/debug/info/notice/..., | |
181 | only counts calls with priority above this logger's level) | |
182 | * provides shorter method names: dbg, note, warn, err | |
4767d190 | 183 | * adds a NullHandler if `streams` and `files` and `handlers` are all `None` |
2e6f474f CH |
184 | |
185 | ..note:: Creating multiple instances with the same name is not allowed and | |
186 | will result in an error. Use :py:func:`get_logger` instead of this | |
187 | constructor to avoid such situtations | |
188 | ||
189 | ..note:: Do not change or use the underlying logger or functionality here | |
109c4be3 | 190 | (in particular, get_level) is no longer reliable! |
72fc3d56 CH |
191 | """ |
192 | ||
193 | def __init__(self, name, level=INFO, fmt=DEFAULT_SHORT_LEVEL_FORMAT, | |
2e6f474f | 194 | datefmt=DEFAULT_SHORT_LEVEL_DATE_FORMAT, |
87ed6b66 | 195 | streams=STDOUT, files=None, handlers=None): |
db4533b3 CH |
196 | """ creates a I2nLogger; forwards args to logging.getLogger |
197 | ||
2e6f474f CH |
198 | |
199 | :param str name: name of this logger, best practice is module name | |
200 | :param int level: best use one of the constants DEBUG, INFO NOTICE, | |
201 | WARNING, ERROR | |
202 | :param str fmt: format of log messages, see | |
203 | :py:class:`ShortLevelFormatter` for more help | |
204 | :param str datefmt: format of date added to log messages, see | |
205 | :py:class:`ShortLevelFormatter` for more help | |
206 | :param streams: list/tuple of or a single stream to log to, default is | |
207 | STDOUT (=sys.stdout) | |
87ed6b66 CH |
208 | :type streams: (:py:class:`io.IOBase`) or [:py:class:`io.IOBase`) or |
209 | None | |
2e6f474f | 210 | :param files: list/tuple or single file name to log to |
87ed6b66 CH |
211 | :type files: None or (str) or [str] |
212 | :param handlers: other handlers to customize and use with this logger | |
213 | :type handlers: None or [:py:class:`logging.Handler`] or | |
214 | (:py:class:`logging.Handler`) | |
2e6f474f | 215 | :raise: ValueError if an I2nLogger with the same name exists already |
72fc3d56 | 216 | """ |
2e6f474f CH |
217 | |
218 | # check if an instance with the same name has been created earlier | |
219 | # to prevent conflicts | |
220 | global _i2n_loggers | |
221 | if name in _i2n_loggers: | |
222 | raise ValueError("An I2nLogger with that exact name ('{0}') exists" | |
223 | " already -- use get_logger instead!" | |
224 | .format(name)) | |
225 | ||
72fc3d56 | 226 | self._log = logging.getLogger(name) |
bdf52e22 CH |
227 | if isinstance(level, str): |
228 | level = LEVEL_DICT[level] | |
2e6f474f CH |
229 | self._level = min(MAX_LEVEL, max(MIN_LEVEL, level)) |
230 | self._log.setLevel(self._level) | |
72fc3d56 CH |
231 | |
232 | # remove handlers (sometimes there are mutliple by default) | |
233 | for handler in self._log.handlers: | |
234 | self._log.removeHandler(handler) | |
235 | ||
2e6f474f CH |
236 | # create new handlers and formatter |
237 | if streams is None: | |
79ae7d87 | 238 | streams = [] |
2e6f474f CH |
239 | elif not isinstance(streams, (list, tuple)): |
240 | streams = (streams, ) | |
241 | for stream in streams: | |
242 | formatter = ShortLevelFormatter(fmt=fmt, datefmt=datefmt) | |
243 | formatter.add_level(NOTICE, 'note') | |
244 | new_handler = logging.StreamHandler(stream) | |
245 | new_handler.setFormatter(formatter) | |
246 | new_handler.setLevel(self._level) | |
247 | self._log.addHandler(new_handler) | |
248 | ||
249 | if files is None: | |
250 | files = [] | |
251 | elif not isinstance(files, (list, tuple)): | |
252 | files = (files, ) | |
253 | for file_name in files: | |
254 | formatter = ShortLevelFormatter(fmt=fmt, datefmt=datefmt) | |
255 | formatter.add_level(NOTICE, 'note') | |
256 | new_handler = logging.FileHandler(file_name) | |
257 | new_handler.setFormatter(formatter) | |
258 | new_handler.setLevel(self._level) | |
259 | self._log.addHandler(new_handler) | |
260 | ||
87ed6b66 CH |
261 | if handlers is None: |
262 | handlers = [] | |
263 | elif not isinstance(handlers, (list, tuple)): | |
264 | handlers = (handlers, ) | |
265 | for handler in handlers: | |
266 | formatter = ShortLevelFormatter(fmt=fmt, datefmt=datefmt) | |
267 | formatter.add_level(NOTICE, 'note') | |
268 | handler.setFormatter(formatter) | |
269 | handler.setLevel(self._level) | |
270 | self._log.addHandler(handler) | |
271 | ||
4767d190 CH |
272 | if not self._log.handlers: |
273 | self._log.addHandler(logging.NullHandler()) | |
274 | ||
2e6f474f CH |
275 | # remember that this logger is a I2nLogger |
276 | _i2n_loggers[name] = self | |
277 | ||
278 | def dbg(self, message, *args, **kwargs): | |
bdf52e22 | 279 | self._log_no_test(DEBUG, message, *args, **kwargs) |
72fc3d56 CH |
280 | |
281 | def debug(self, message, *args, **kwargs): | |
bdf52e22 | 282 | self._log_no_test(DEBUG, message, *args, **kwargs) |
72fc3d56 CH |
283 | |
284 | def info(self, message, *args, **kwargs): | |
bdf52e22 | 285 | self._log_no_test(INFO, message, *args, **kwargs) |
72fc3d56 | 286 | |
2e6f474f | 287 | def note(self, message, *args, **kwargs): |
bdf52e22 | 288 | self._log_no_test(NOTICE, message, *args, **kwargs) |
2e6f474f | 289 | |
72fc3d56 | 290 | def notice(self, message, *args, **kwargs): |
bdf52e22 | 291 | self._log_no_test(NOTICE, message, *args, **kwargs) |
72fc3d56 | 292 | |
2e6f474f | 293 | def warn(self, message, *args, **kwargs): |
bdf52e22 | 294 | self._log_no_test(WARNING, message, *args, **kwargs) |
2e6f474f | 295 | |
72fc3d56 | 296 | def warning(self, message, *args, **kwargs): |
bdf52e22 | 297 | self._log_no_test(WARNING, message, *args, **kwargs) |
72fc3d56 | 298 | |
2e6f474f | 299 | def err(self, message, *args, **kwargs): |
bdf52e22 | 300 | self._log_no_test(ERROR, message, *args, **kwargs) |
2e6f474f | 301 | |
72fc3d56 | 302 | def error(self, message, *args, **kwargs): |
bdf52e22 | 303 | self._log_no_test(ERROR, message, *args, **kwargs) |
72fc3d56 | 304 | |
998ae6d7 CH |
305 | def exception(self, message, *args, **kwargs): |
306 | if 'exc_info' in kwargs: | |
307 | self._log_no_test(ERROR, message, *args, **kwargs) | |
308 | else: | |
309 | self._log_no_test(ERROR, message, *args, exc_info=True, **kwargs) | |
310 | ||
72fc3d56 | 311 | def critical(self, message, *args, **kwargs): |
bdf52e22 | 312 | self._log_no_test(CRITICAL, message, *args, **kwargs) |
72fc3d56 CH |
313 | |
314 | def log(self, level, message, *args, **kwargs): | |
bdf52e22 CH |
315 | if isinstance(level, str): |
316 | level = LEVEL_DICT[level.lower()] | |
317 | if level >= self._level: | |
4e993142 CH |
318 | try: |
319 | message_formatted = message.format(*args) | |
320 | except (KeyError, IndexError): | |
321 | message_formatted = '[LOG ARGS!] ' + message | |
322 | self._log.log(level, message_formatted, **kwargs) | |
bdf52e22 CH |
323 | |
324 | def _log_no_test(self, level, message, *args, **kwargs): | |
325 | """ same as log() but without the isinstance test for internal use""" | |
72fc3d56 | 326 | if level >= self._level: |
4e993142 CH |
327 | try: |
328 | message_formatted = message.format(*args) | |
329 | except (KeyError, IndexError): | |
330 | message_formatted = '[LOG ARGS!] ' + message | |
331 | self._log.log(level, message_formatted, **kwargs) | |
2e6f474f CH |
332 | |
333 | def log_count_if_interesting(self, count, level=INFO, counter_name=None): | |
334 | """ Log value of a counter in gradually coarser intervals | |
335 | ||
336 | see :py:func:`is_interesting_count` for definition of "interesting" | |
337 | """ | |
338 | if is_interesting_count(count): | |
339 | if counter_name: | |
340 | self.log(level, '{0} counter is at {1}', counter_name, count) | |
341 | else: | |
342 | self.log(level, 'Counter is at {0}', count) | |
72fc3d56 CH |
343 | |
344 | def get_level(self): | |
345 | """ return int level of this logger """ | |
346 | return self._level | |
347 | ||
348 | def get_level_str(self): | |
349 | """ returns :py:func:`logging.getLevelName` on :py:meth:`get_level` """ | |
350 | return logging.getLevelName(self._level) | |
351 | ||
352 | def set_level(self, new_level): | |
353 | """ set level given an int or a str | |
354 | ||
355 | :arg new_level: int or str (str is converted to lower case) | |
356 | :raises: KeyError if new_level is a string that is not in | |
357 | :py:data:`LEVEL_DICT` | |
358 | """ | |
359 | if isstr(new_level): | |
360 | self._level = LEVEL_DICT[new_level.lower()] | |
361 | else: | |
2e6f474f | 362 | self._level = min(MAX_LEVEL, max(MIN_LEVEL, new_level)) |
72fc3d56 CH |
363 | self._log.setLevel(self._level) |
364 | for handler in self._log.handlers: | |
365 | handler.setLevel(self._level) | |
366 | ||
367 | ||
8fe2dd62 CH |
368 | def n_digits(number): |
369 | """ returns the number of digits a number has in decimal format | |
370 | ||
371 | :returns: 1 for 1...9, 2 for 10...99, 3 for 100...999, ... | |
372 | 0 for 0 (and everything else beween -1 and 1) | |
373 | 1 for -1...-9, 2 for -10...-99, ... | |
374 | """ | |
375 | if abs(number) < 1: | |
376 | return 0 | |
377 | else: | |
378 | return floor(log10(abs(number)))+1 | |
379 | ||
8fe2dd62 CH |
380 | def is_interesting_count(counter): |
381 | """ return True if counter has reached an "interesting" value | |
382 | ||
383 | For the counter to be "interesting" becomes ever harder. At first it is | |
384 | easy (returns True for 1,2,3,6,10), then becomes harder (True only for | |
385 | 10,20,30,60,100) and harder (True for 100,200,300,600,1000) and this scheme | |
386 | continues on a logartihmic scale. | |
387 | ||
388 | An example that will print lots in the beginning and then less and less:: | |
389 | ||
390 | counter = 0 | |
391 | while not end_reached(): | |
392 | do_something() | |
393 | if is_interesting_count(counter): | |
394 | log('reached iteration {0}'.format(counter)) | |
395 | counter += 1 | |
396 | ||
2e6f474f CH |
397 | Or implicitly using I2nLogger::log_count_if_interesting(counter) |
398 | ||
8fe2dd62 CH |
399 | :returns: True for a few values of counter, False most of the time |
400 | """ | |
401 | ||
2e6f474f | 402 | return float(counter) / 10.**(n_digits(counter)-1.) in (1., 2., 3., 6.) |