[WIP] pyDKB: common logging system #135
Open
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| """ | ||
|
|
||
| import logging | ||
| from logging import CRITICAL, FATAL, ERROR, WARNING, WARN, INFO, DEBUG, NOTSET |
There was a problem hiding this comment.
@mgolosova
What is the main difference between "critical" and "fatal" errors (especially in pyDKB)? :)
There was a problem hiding this comment.
@anastasiakaida,
I guess this is the answer ;)
mgolosova
force-pushed
the
pyDKB-logging
branch
12 times, most recently
from
cd1b815
to
b8b6b85
Compare
We have individual implementation of logging functionality for some
classes in the library, but there are some disadvantages:
* same functionality is already re-implemented number of times
* ...and must be re-implemented for every module and base class
in the library;
* hardly extendable to provide convenient interface of 'info()', 'error()',
etc. methods;
* does not provide filtering by log level (and can hardly be extended
to be appliable library-wide);
* ...
In other words, there are too many things to be done before current
implementation can become a sound logging system; and as they done,
we might find ourself ending up with something resembling the standard
Python library 'logging'.
However this library does not provide some functionality we would like
to have in our logging system: say, avoiding bare lines (with no
identifiers) -- to simplify parsing its log messages on the supervisor
side -- or TRACE log level.
So here is introduced a wrapper around standard 'logging' module,
which allows us to implement what we miss in the original module -- and still
use all its advantages.
To have logging configuration in the main library file, we have to include
'common' submodule and configure logging before including any other module;
and to cope with `pycodestyle` we should wrap imports into `try/except` clause
(see E402, module level import not at top of file)
Recommended way to use logging:
1) within the library:
```
from pyDKB.common import logging
logger = logging.getLogger(__name__)
...
logger.error("My error message.")
```
2) outside the library:
```
from pyDKB.common import logging
logger = logging.getLogger("myProgramName")
...
logger.error("My error message.")
```
Looks this way: ``` 2018-07-06 11:52:58,540: (DEBUG) Traceback info: (pyDKB) (==) Traceback (most recent call last): (pyDKB) (==) File "pyDKB/__init__.py", line 24, in <module> (pyDKB) (==) import dataflow (pyDKB) (==) File "pyDKB/dataflow/__init__.py", line 6, in <module> (pyDKB) (==) from dkbID import dkbIDs (pyDKB) (==) ImportError: cannot import name dkbIDs (pyDKB) ``` ...instead of: ``` 2018-07-06 11:52:58,540: (DEBUG) Traceback info: (pyDKB) (==) Traceback (most recent call last): (pyDKB) (==) File "pyDKB/__init__.py", line 24, in <module> (pyDKB) (==) import dataflow (pyDKB) (==) File "pyDKB/dataflow/__init__.py", line 6, in <module> (pyDKB) (==) from dkbID import dkbIDs (pyDKB) (==) ImportError: cannot import name dkbIDs (pyDKB) ```
For now we have two main submodules: 'common' and 'dataflow'. If we failed to import 'common', most likely 'dataflow' functionality is broken. If we failed to import 'dataflow', there`s very little can be done without it -- thus it is better to fail immediatly. If one day we need to use submodules independently, it is possible to: * not to import them in library init file OR * not to raise ImportError, leaving only warning message.
As we have `try/except` clause in the library init file, we need not check it whenever it is imported.
As Logger methods can work with tuple value of exc_info, it sounds like a good idea to use this possibility through `traceback()` method as well. In previous version any passed value would be replaced with '1' and thus missed (with `sys.exc_info()` used instead).
Changes: * log messages are now marked with module name (not class name); * datetime in log messages; * inheriting class should rewrite `logger` property at init (to have proper module info in log messages).
As `logLevel` is no longer used, it is removed from the library.
In Python 2.6 available by default version of `logging` module is 0.4.x.x.
In this version:
* `Logger` and `Formatter` are old-style classes, so `super()` doesn't
work (so `object` is added as a second parent class to our classes,
to make then new-style)[1];
* no `Manager.setLoggerClass()` (so we have to set logger class or the
whole module)[2];
* no `Handler.set|get_name()` (so we have to set/get `_name` attribute
manually);
* no `Logger.getChild()` (so for new logger we just directly ask
`manager` of our `root` logger);
[1] As original class was old-style, we can not set manually `__class__`
to a new-style class, we have to re-implement `RootLogger`
functionality from `logging` module and create logger hierarchy
from scratch (not as a sub-hierarchy under `logging.root`).
In fact, it feels a little better than creating sub-hierarchy
and isolate it from the `logging.root` (except that, again, we have
to re-implement the `RootLogger` class).
[2] As we use module-wide settings, any application which uses pyDKB,
importing `logging` module, has same settings -- and if it changes
default Logger class, it can affect pyDKB.
However as loggers are initialized right when the `pyDKB` is
imported, their behaviour will be left unchanged, and it is good.
`*args` are used in other log methods to expand some user-defined format sequences in the message string. As it supposed to be no message in `traceback()`, `*args` are also excessive.
Instead of determinig the suffix every now and then from the format, we can store it in object attribute variable (`_suffix`) and reuse wherever it is needed. As `Formatter` does not support format change on the fly, it is safe enough (suffix won't last longer than the format it was taken from).
Instead of determining suffix every now and again, we can use string formatting and extend every line content to the length of the longest line. Then we simply add suffix to the end of this content.
We do not need to align lines when there's no suffix at all.
...and simplify logic of multiline formatting.
Previously multiline message with arguments would fail with error:
```
>>> pyDKB.logger.error("%(line1)s\n%(line2)s", {"line1": "First line",
... "line2": "Second line"})
Traceback (most recent call last):
File "/usr/lib/python2.6/site-packages/logging/__init__.py", line 723,
in emit
msg = self.format(record)
File "/usr/lib/python2.6/site-packages/logging/__init__.py", line 609,
in format
return fmt.format(record)
File "/home/mgolosova/dkb/Utils/Dataflow/pyDKB/common/_logging.py",
line 162, in format
result = (msg + extra + '\n'.join(lines[1:])) % record.__dict__
KeyError: 'line2'
```
Now the whole message goes to the `logger.Formatter.format()` function,
thus message with argumets works perfectly fine. Then we format the
suffix (as it is definitely the same for every line), and then
`formatExtra()` just adds prefixes for extra lines and suffixes to all
lines. It also saves from specific `formatException()` method, called
from `logger.Formatter.format()`, as we do not need to think about
prefixes and suffixes before the message is fully formatted and appended
with traceback info.
It also affects alignment: now suffix is aligned for all lines, not only
traceback ones.
mgolosova
changed the title
Evildoor
reviewed
Jul 8, 2019
| self._log(TRACE, msg, args, **kwargs) | ||
|
|
||
| def traceback(self, **kwargs): | ||
| """ Log traceback without additionat messages with severity 'DEBUG'. |
Evildoor
reviewed
Jul 8, 2019
|
|
||
|
|
||
| class RootLogger(Logger): | ||
| """ Same as Logger, but must must have `Level` and be the only one. """ |
Evildoor
reviewed
Jul 8, 2019
|
|
||
|
|
||
| def isInitialized(): | ||
| """ Checks if the module (namely, root logger) is initialized. """ |
There was a problem hiding this comment.
Maybe "Check if ...", to conform with the other definitions and "Do X" template?
|
Per DKB meeting on 15.08: |
Evildoor
changed the title
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
Motivation
We have individual implementation of logging functionality for some
classes in the library, but there are some disadvantages:
in the library;
etc. methods;
to be appliable library-wide);
In other words, there are too many things to be done before current
implementation can become a sound logging system; and as they done,
we might find ourself ending up with something resembling the standard
Python library 'logging'.
However this library does not provide some functionality we would like
to have in our logging system: say, avoiding bare lines (with no
identifiers) -- to simplify parsing its log messages on the supervisor
side -- or TRACE log level.
Implementation
Here is introduced a wrapper around standard 'logging' module,
which allows us to implement what we miss in the original module -- and still
use all its advantages.
To have logging configuration in the main library file, we have to include
'common' submodule and configure logging before including any other module;
and to cope with
pycodestylewe should wrap imports intotry/exceptclause(see E402, module level import not at top of file)
Recommended way to use logging
ToDo:
sys.stderr.write().Waiting for #151 (pyDKB stage basic logic fix).