Created by: portnov
I hope, this movement will enhance usability a lot. But, for now only core support of logging was implemented; it is to be supported across the whole codebase yet, see details below.
For users
Sverchok is going to write all it's messages not only to console window, but also:
- to text buffer within Blender's scene (optional)
- to external file somewhere on disk (optional)
It is also possible to specify minimum severity level of messages that you want to see in the log.
So, when/if this (and possibly following PRs) is merged, the recommendation for users to have console window opened while working with Sverchok is going to be replaced with recommendation to have blender's text editor frame opened, which is much friendlier I think.
For developers
The facility is implemented by means of standard python's logging
module. All glue code lies in sverchok.utils.logging
.
The implementation is more or less straightforward; exceptions are:
-
Due to "interesting" order of importing and initializing different things (bpy objects, addon preferences, ...) in blender's python environment, it is not possible to do just
logger = logging.getLogger(__name__)
in the beginning of each module, as many practices say; this is going to lead to exceptions. We have to obtain a logger at each event. To simplify things, a "standard" method familysverchok.utils.logging.debug
,info
,warning
,error
,exception
is introduced (these methods use caller module name as logger name by default):from sverchok.utils.logging import debug def something(): ... debug("got addon") ...
-
It is possible also to use
logging.debug
and siblings if you do not want to bother with logger name, and just write to root logger. -
For base node class, a family of logging methods is provided. So within any node class, you can just replace
print(xxx)
withself.debug(xxx)
. -
It appears to be not possible to initialize output to blender's text buffer during
register()
. So, it is registered at the first call ofsverchok.utils.logging.getLogger()
, i.e. basically at first logged event. -
Due to mentioned initialization order things, there going to be some problems if one wants to replace different prints that are done during initialization with logging calls. I think it is simpler to do not touch these initialization printouts for now.
Example of log output
2017-12-07 23:34:00,558 [INFO] root: Initializing Sverchok logging. Blender version 2.79 (sub 0), Sverchok version (0, 5, 9, 6)
2017-12-07 23:34:00,558 [DEBUG] root: Current log level: DEBUG, log to text buffer: sverchok.log, log to file: sverchok.log
2017-12-07 23:34:00,558 [DEBUG] SvBoxNode: hello from the box
2017-12-07 23:34:09,571 [DEBUG] SvBoxNode: hello from the box
2017-12-07 23:34:09,683 [ERROR] sverchok.core.update_system: Node Rotation had exception: No data passed into socket `Vertices'
Traceback (most recent call last):
File "/home/portnov/.config/blender/2.79/scripts/addons/sverchok-master/core/update_system.py", line 323, in do_update_general
node.process()
File "/home/portnov/.config/blender/2.79/scripts/addons/sverchok-master/nodes/transforms/rotation.py", line 139, in process
Vertices = self.inputs['Vertices'].sv_get()
File "/home/portnov/.config/blender/2.79/scripts/addons/sverchok-master/node_tree.py", line 297, in sv_get
raise SvNoDataError(self)
sverchok.core.socket_data.SvNoDataError: No data passed into socket `Vertices'
What next
As I said in the beginning, this adds only core support of logging. We have a lot of print
-s across the whole codebase. I do not think that it worth the effort to go and replace all of them right now. Instead, I'd propose to update some most used / most verbose parts of code now (either within this PR or in separate, to be discussed). All other code can be updated gradually: just when you are fixing a regular bug in some node, replace all prints in it, it is not going to take much time.
@nortikin @zeffii @DolphinDream please review and test.