LogService issue with jython script in headless mode

[sebi06]

Hi,

I still encounter the following issue described here:

LogService issue with jython-slim-2.7.2 and scripting-jython-1.0.0.

This issue prevents Fiji execution inside our Docker container when using the latest Fiji. But it works fine with older versions of Fiji inside containers, e.g. it works when using docker pull czsip/fiji_linux64_baseimage:1.3.1 while the latest 1.3.2 throws the error below.

But interestingly log.info('Starting ...') works fine when running the latest Fiji normally on my desktop. But when using the headless mode (inside the container) it throws the error.

(base) C:\Users\testuser\Apeer_Modules\measure_3d_objects_034c0dd4-efa5-4731-9b45-a0ae9306dfc9>docker run -it --rm -v c:\Temp\input:/input -v c:\Temp\output:/output --env-file wfe.env test/apeer_test_3d_measure:latest
Java HotSpot(TM) 64-Bit Server VM warning: ignoring option PermSize=128m; support was removed in 8.0
Java HotSpot(TM) 64-Bit Server VM warning: Using incremental CMS is deprecated and will likely be removed in a future release
[INFO] Overriding BIOP Run Macro...; identifier: command:ch.epfl.biop.macrorunner.B_Run_Macro; jar: file:/Fiji.app/plugins/BIOP/B_Run_Macro-1.0.0-SNAPSHOT.jar
[INFO] Overriding Get Spine From Circle Rois; identifier: command:Cirlces_Based_Spine; jar: file:/Fiji.app/plugins/Max_Inscribed_Circles-1.1.0.jar
[INFO] Overriding Visualise vector field (experimental); identifier: command:net.haesleinhuepf.clijx.piv.visualisation.VisualiseVectorFieldsPlugin; jar: file:/Fiji.app/plugins/clijx_-0.29.1.11.jar
[ERROR] Traceback (most recent call last):
  File "/Fiji.app/scripts/apeer_3d_measure.py", line 220, in <module>
    log.info('Starting ...')
TypeError: 'org.scijava.plugin.PluginInfo' object is not callable

        at org.python.core.Py.TypeError(Py.java:236)
        at org.python.core.PyObject.__call__(PyObject.java:396)
        at org.python.core.PyObjectDerived.__call__(PyObjectDerived.java:1032)
        at org.python.core.PyObject.__call__(PyObject.java:461)
        at org.python.core.PyObject.__call__(PyObject.java:465)
        at org.python.pycode._pyx0.f$0(/Fiji.app/scripts/apeer_3d_measure.py:283)
        at org.python.pycode._pyx0.call_function(/Fiji.app/scripts/apeer_3d_measure.py)
        at org.python.core.PyTableCode.call(PyTableCode.java:173)
        at org.python.core.PyCode.call(PyCode.java:18)
        at org.python.core.Py.runCode(Py.java:1687)
        at org.python.core.__builtin__.eval(__builtin__.java:497)
        at org.python.core.__builtin__.eval(__builtin__.java:501)
        at org.python.util.PythonInterpreter.eval(PythonInterpreter.java:255)
        at org.python.jsr223.PyScriptEngine.eval(PyScriptEngine.java:57)
        at org.python.jsr223.PyScriptEngine.eval(PyScriptEngine.java:31)
        at javax.script.AbstractScriptEngine.eval(AbstractScriptEngine.java:264)
        at org.scijava.script.ScriptModule.run(ScriptModule.java:157)
        at org.scijava.module.ModuleRunner.run(ModuleRunner.java:165)
        at org.scijava.module.ModuleRunner.call(ModuleRunner.java:124)
        at org.scijava.module.ModuleRunner.call(ModuleRunner.java:63)
        at org.scijava.thread.DefaultThreadService.lambda$wrap$2(DefaultThreadService.java:225)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)

[imagejan]

I think this has to be solved on the Jython side, no?

@sebi06 as a workaround, you could try switching to a different scripting language. I guess that would also give you a performance benefit, as jython is not the fastest to startup (in my experience with the Fiji GUI, at least). I'll be happy helping to translate e.g. into Groovy, just open a new forum topic if interested.

[sebi06]

I tested again (trying to use some of my plugins) and now it even does not work in normal desktop mode ...

Learning Groovy is certainly a good idea, but I would have to rewrite a lot of scripts and APEER modules, which is just not feasible.

Started 3d_analytics_adv.py at Tue Oct 20 08:50:50 CEST 2020
Traceback (most recent call last):
  File "C:\Users\m1srh\Documents\Fiji\scripts\3d_analytics_adv.py", line 285, in <module>
    log.info('Starting pipeline ...')
TypeError: 'org.scijava.plugin.PluginInfo' object is not callable

    at org.python.core.Py.TypeError(Py.java:236)
    at org.python.core.PyObject.__call__(PyObject.java:396)
    at org.python.core.PyObjectDerived.__call__(PyObjectDerived.java:1032)
    at org.python.core.PyObject.__call__(PyObject.java:461)
    at org.python.core.PyObject.__call__(PyObject.java:465)
    at org.python.pycode._pyx6.f$0(C:/Users/m1srh/Documents/Fiji/scripts/3d_analytics_adv.py:353)
    at org.python.pycode._pyx6.call_function(C:/Users/m1srh/Documents/Fiji/scripts/3d_analytics_adv.py)
    at org.python.core.PyTableCode.call(PyTableCode.java:173)
    at org.python.core.PyCode.call(PyCode.java:18)
    at org.python.core.Py.runCode(Py.java:1687)
    at org.python.core.__builtin__.eval(__builtin__.java:497)
    at org.python.core.__builtin__.eval(__builtin__.java:501)
    at org.python.util.PythonInterpreter.eval(PythonInterpreter.java:255)
    at org.python.jsr223.PyScriptEngine.eval(PyScriptEngine.java:57)
    at org.python.jsr223.PyScriptEngine.eval(PyScriptEngine.java:31)
    at javax.script.AbstractScriptEngine.eval(AbstractScriptEngine.java:264)
    at org.scijava.script.ScriptModule.run(ScriptModule.java:157)
    at org.scijava.module.ModuleRunner.run(ModuleRunner.java:165)
    at org.scijava.module.ModuleRunner.call(ModuleRunner.java:124)
    at org.scijava.module.ModuleRunner.call(ModuleRunner.java:63)
    at org.scijava.thread.DefaultThreadService.lambda$wrap$2(DefaultThreadService.java:225)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)

[imagejan]

The issue is really specific to jython-slim-2.7.2.jar. Removing that file and putting back jython-shaded-2.7.1.1.jar into an up-to-date Fiji installation will make the following minimal script work again:

#@ LogService log

log.info("testing")

@sebi06 can you please report this on https://github.com/jython/jython/issues ?

[imagesc-bot]

This issue has been mentioned on Image.sc Forum. There might be relevant details there:

https://forum.image.sc/t/logservice-issue-with-jython-slim-2-7-2-and-scripting-jython-1-0-0/40020/10

[ehrenfeu]

Hi @sebi06

in case you're interested you can give my jython-scijava-logging module a try. The latest version 0.5.2 has been adjusted to work around the issue described above by avoiding the messed-up calls to the info() method.

Either download it from the releases page and drop the file into Fiji's jars/ folder or simply enable the IMCF Uni Basel update site.

It uses the SciJava logging feature as a target (sink) for Python's built-in logging module. For initializing it, all you need to do is to pass on the LogService object. As an added benefit you will be able to see log messages from underlying Python (Jython) modules as well in Fiji's Console / Log window, as they are using the same mechanism.

A very simple example looks like this:

#@ LogService sjlog

import sjlogging

log = sjlogging.setup_logger(sjlog)

log.warn("warning")
log.warn("works %s like %s Python logging", "just", "real")  # <- this is Python "native" logging!

In case you want to increase the loglevel, it has convenience functions that allow you to specify the level by using a name:

sjlogging.set_loglevel("INFO")
log.info("info")

[imagejan]

@ehrenfeu wrote:

It uses the SciJava logging feature as a target (sink) for Python's built-in logging module.

How about migrating this upstream into scijava/scripting-jython, so other projects can benefit from it without having to know about the jython-scijava-logging module?

[ehrenfeu]

Hi @imagejan

I'm not sure how to do this - scijava/scripting-jython is Java code, whereas my logging wrapper is Python.

Happy to give it a try if you think it makes sense though...

[imagejan]

@ehrenfeu your project is built with Maven nevertheless, no?

I could imagine that the src/main/resources/sjlogging folder goes into src/main/resources of scripting-jython, and maybe the scripts in extra/scripts can go to src/main/resources/script_templates, so that they're listed in the Templates menu of the script editor?

How do you install your logging wrapper? Is it sufficient for import sjlogging to work if the jar file is on the classpath?

[ehrenfeu]

Yes, the project is using Maven for packaging.

There is no additional installation required, it's sufficient to have the jar file as you said. Then the code from my example above should be working.

I'll have a look and try to build the scripting-jython package locally with my modifications.

[jeff5]

I worked on this where you reported it as https://github.com/jython/jython/issues/70 but conclude it is not really a bug, or amenable to solution in Jython 2. The detailed last post may be interesting (or is that just me).