Third party library works slower inside Slicer's Python shell - why? how to do performance profiling?

Lasio runs slower in Slicer because it logs a crazy amount of messages at debug level. You can disable this by temporarily decreasing the log level by running this command:

import logging
logging.getLogger().setLevel(logging.INFO)

After you have finished with lasio, you can restore the log level to logging.DEBUG.

I haven’t experienced this with other Python packages, so you might report this finding to lasio developers. Maybe they could use their own logger instead of using the root logger (which is set to debug level logging in Slicer).


If you are curious how I’ve found out the root cause of the problem: with profiling. Profilers are invented exactly for pinpointing performance bottlenecks. I’ve used cProfile to collect logs and visualized the results using tuna.

Collect data:

import cProfile
cProfile.run("las=lasio.read(r'c:\Users\andra\Downloads\A_Kerbel.las')", "c:/tmp/las.prof")

Plot results:

pip_install('tuna')
slicer.util._executePythonModule("tuna", ["c:/tmp/las.prof"])

Tuna output:

After adjusting the log level, the debug message logging function disappeared from the call tree and all the time-consuming functions make sense (they are complex and/or frequent operations):

1 Like