Until now, the Python console only displayed Python outputs and Python log messages. Therefore, if a Python command executed a VTK method and that VTK method logged an error or warning, it was not immediately visible for the developer (the developer had to notice the change in the log icon, click on it, and scroll down to see the new message).
In latest Slicer Preview Release (Slicer 5.1.0-2022-10-15 and later), the Python console displays log messages from all sources - Python, Qt, VTK, ITK.
For example:
Old behavior (return value indicates error but no hint on what went wrong):
New behavior:
If the extra messages are not desirable (e.g., because they cause too much distraction for a developer) then the log level can be adjusted in Application Settings → Python → Log level. Default log level is Warning, which means that warnings and error log messages are displayed. Set level to None to prevent displaying any log messages (as it was before). Set level to Debug to show all available messages.
It’s great to see log messages from VTK in the python console as you show in your images above!
@lassoan Is this change supposed to impact the functionality that is the Slicer_BUILD_WIN32_CONSOLE_LAUNCHER option with local Slicer builds? With that option on Windows we would see a console window open in addition to the Slicer main window and that would contain all the logging output from python, Qt, VTK, ITK sources. Currently with the latest Slicer preview, modules that have any python logging do not display these messages to the Win32 console window. These python logging messages are only seen when viewing the actual log file or in the python console (of course as long as the message is within the Application Settings->Python->Log level).
Previously, Slicer relied on standard output for Python logging (the Python logger printed on the standard output and the application logger captured that output). This was too restrictive (it was not possible to make log messages appear in the Python console without appearing twice in the application log). Now they are independently configurable and so the previous limitations are gone.
If you want Python logs to be printed on the process output then you can register a Python log handler to do that, the same way as you would do in any other Python environment.
With these latest changes, is there any value to still have Slicer_BUILD_WIN32_CONSOLE_LAUNCHER as a a default build option if building Python support is a default option which supports viewing all the output on the python console? I’m thinking about some new python Slicer developers that may get confused about where to look for logging output.
For typing Python commands or debugging Python code I would recommend using the Python console.
For checking what happened in the application, the application log viewer has the slight advantages (filtering, grouping, and clearing) compared to the Python console.
For reporting errors, the Help/Report a bug has some advantages (easier to copy all messages, previous sessions are available).
The only use that I see for the process output is when there is no application GUI.
Is there a way to set the Python log level from Python? I looked in slicer.app and didn’t find anything obvious. I have some code that intentionally calls methods that trigger warnings/errors to probe/test a configuration and would like to temporarily disable the logs. Something like:
You can set the Python log level from the Slicer settings:
Using code, slicer.app contains slicer.app.setPythonConsoleLogLevel() which you can use such as slicer.app.setPythonConsoleLogLevel(ctk.ctkErrorLogLevel.Error) to set it to the Error level. Unfortunately it appears that the None level isn’t working correctly from python. This functionality was originally included as part of this commit.
Log level in the Python console is a user preference. Modules can of course can change it, but doing so would upset users. If you want to change the level to avoid excessive amount of error/warning messages then I would recommend to fix the root cause of those.
This is due to the unfortunate naming of the enum. None is a Python keyword that cannot be redefined. We could rename it or add an alias.
How about any of the following ideas? ctk.ctkErrorLogLevel.Null ctk.ctkErrorLogLevel.NoneLog ctk.ctkErrorLogLevel.NoLog ctk.ctkErrorLogLevel.Off ctk.ctkErrorLogLevel.Silent
I agree that module shouldn’t change user preferences. In my case, I’m trying to run some unit tests that will intentionally trigger some warnings and errors while testing the returned values. At that point, all the tests succeed but the user will see multiple errors and warnings. To avoid this confusion, I was wondering if there was a way to temporarily pause the logs. In my initial post, I also asked if there was a way to get the current log level so I could restore it at the end. This is mostly cosmetic so if the feature doesn’t exist it’s not big deal.
During a run of unit tests isn’t it actually desired to see warnings and errors? Your concerns about the user seeing it doesn’t seem to match the type of action because a regular end user isn’t going to be running unit tests.
For testing, you can connect a vtkErrorSink to any VTK class, which captures errors and warnings so that they are not logged. The error sink also counts the messages if each type do that you can easily check if the expected errors/warnings are present. Would this be sufficient for you?
@lassoan vtkErrorSink looks like the perfect fit for unit testing, I will definitely investigate. Thank you for steering me away from the Python console log level.
