Large discrepancy in logged output in Python vs. Bash Consoles

Support
1

For ease of testing a WIP module, I will often start Slicer from a bash shell, so that I could save its output to a log programmatically. However, when I went to refactor my many print statements into logging calls, I noticed that they no longer appeared. Digging deeper, it seems that calling Slicer from the command line results in a pretty substantial de-sync.

For reference:

The bash console’s output:

image
image812×585 15.4 KB

Slicer’s Python Console:

image
image1031×353 55.4 KB

The code in question:

image
image326×120 6.79 KB

Far as I can tell, the following is happening:

  • Qt logs are properly displayed in both the Python and Bash console
  • print statements are only shown in the Bash console
  • logging statements are only shown in the Python console

Is their something I’m missing? This is on Slicer 5.8.1, called within a ScriptedLoadableModuleWidget and VTKObservationMixin subclass, with get_cart_logger simply being a wrapper for a logging.getLogger call with some tracking strapped on. Any insight on this would be appreciated.

2

Slight correction; only some of the QT logs are placed in the Bash console; the “green” logs are Python only, further confusing things.

3

Have you tried adjusting the user setting for the logging level on the python console? See the following linked thread below:

4

Thank you for your response. I did check that; my “Log level” is currently set to Debug:

image
image795×625 39.8 KB

This is also an ERROR level logging message, so it should appear for any logging whatsoever. And it does; but only in the Python console, not Bash.

5

Console is only available in certain environments (e.g., no console on Windows GUI applications), so Slicer does not depend on it and I would not recommend for debugging.

You can access logs in the application log file (slicer.app.errorLogModel().filePath). You can also add a callback function to the error log model object to get notified when something is logged and can get any log messages like this:

def onEntryAdded(datetime, threadId, logLevel, origin, context, text):
    slicer.util.messageBox(f"[{datetime.toString()}] [{origin}] ({logLevel}) {text}")

slicer.app.errorLogModel().connect('entryAdded(QDateTime,QString,ctkErrorLogLevel::LogLevel,QString,ctkErrorLogContext,QString)', onEntryAdded)