Convert Python stack trace to Java stack trace

[drj11]

If the Python code raises an Exception then this GATE plugin handles this by noting that it couldn't read JSON from the Python process and closing the pipeline.

In some sense this works, in that processing is halted, but it's not very clean and the plugin couldn't be more intelligent about catching the Exception (on the Python side) and reporting it via a particular JSON message.

Here's an example from a (accidentally misconfigured) rumourVeracity Python code:

Using Theano backend.
Traceback (most recent call last):
  File "/home/ac1xdrj/prj/models/rumourVeracity/veracity_gate.py", line 4, in <module>
    from innerAttentionModel import InnerAttentionModel
  File "/home/ac1xdrj/prj/models/rumourVeracity/innerAttentionModel.py", line 5, in <module>
    from keras import backend as K
  File "/home/ac1xdrj/prj/models/rumourVeracity/venv/local/lib/python2.7/site-packages/keras/__init__.py", line 3, in <module>
    from . import utils
  File "/home/ac1xdrj/prj/models/rumourVeracity/venv/local/lib/python2.7/site-packages/keras/utils/__init__.py", line 6, in <module>
    from . import conv_utils
  File "/home/ac1xdrj/prj/models/rumourVeracity/venv/local/lib/python2.7/site-packages/keras/utils/conv_utils.py", line 9, in <module>
    from .. import backend as K
  File "/home/ac1xdrj/prj/models/rumourVeracity/venv/local/lib/python2.7/site-packages/keras/backend/__init__.py", line 86, in <module>
    from .theano_backend import *
  File "/home/ac1xdrj/prj/models/rumourVeracity/venv/local/lib/python2.7/site-packages/keras/backend/theano_backend.py", line 7, in <module>
    import theano
ImportError: No module named theano
Unable to read JSON from python process, closing pipeline
com.fasterxml.jackson.databind.JsonMappingException: No content to map due to end-of-input
 at [Source: java.io.BufferedReader@69946c29; line: 1, column: 1]
	at com.fasterxml.jackson.databind.JsonMappingException.from(JsonMappingException.java:164)
	at com.fasterxml.jackson.databind.ObjectMapper._initForReading(ObjectMapper.java:3036)
	at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:2978)
	at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:2128)
	at gate.python.PythonPR.execute(PythonPR.java:158)
	at gate.util.Benchmark.executeWithBenchmarking(Benchmark.java:291)
	at gate.creole.SerialController.runComponent(SerialController.java:225)
	at gate.creole.SerialController.executeImpl(SerialController.java:157)
	at gate.creole.AbstractController.execute(AbstractController.java:78)
	at gate.util.Benchmark.executeWithBenchmarking(Benchmark.java:291)
	at gate.gui.SerialControllerEditor$RunAction$1.run(SerialControllerEditor.java:1759)
	at java.lang.Thread.run(Thread.java:748)
gate.creole.ExecutionException: Unable to read JSON from python process - perhaps process printed to stdout? (use stderr instead)
	at gate.python.PythonPR.execute(PythonPR.java:165)
	at gate.util.Benchmark.executeWithBenchmarking(Benchmark.java:291)
	at gate.creole.SerialController.runComponent(SerialController.java:225)
	at gate.creole.SerialController.executeImpl(SerialController.java:157)
	at gate.creole.AbstractController.execute(AbstractController.java:78)
	at gate.util.Benchmark.executeWithBenchmarking(Benchmark.java:291)
	at gate.gui.SerialControllerEditor$RunAction$1.run(SerialControllerEditor.java:1759)
	at java.lang.Thread.run(Thread.java:748)
Caused by: com.fasterxml.jackson.databind.JsonMappingException: No content to map due to end-of-input
 at [Source: java.io.BufferedReader@69946c29; line: 1, column: 1]
	at com.fasterxml.jackson.databind.JsonMappingException.from(JsonMappingException.java:164)
	at com.fasterxml.jackson.databind.ObjectMapper._initForReading(ObjectMapper.java:3036)
	at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:2978)
	at com.fasterxml.jackson.databind.ObjectMapper.readValue(ObjectMapper.java:2128)
	at gate.python.PythonPR.execute(PythonPR.java:158)
	... 7 more
Using Theano backend.
Traceback (most recent call last):
  File "/home/ac1xdrj/prj/models/rumourVeracity/veracity_gate.py", line 4, in <module>
    from innerAttentionModel import InnerAttentionModel
  File "/home/ac1xdrj/prj/models/rumourVeracity/innerAttentionModel.py", line 5, in <module>
    from keras import backend as K
  File "/home/ac1xdrj/prj/models/rumourVeracity/venv/local/lib/python2.7/site-packages/keras/__init__.py", line 3, in <module>
    from . import utils
  File "/home/ac1xdrj/prj/models/rumourVeracity/venv/local/lib/python2.7/site-packages/keras/utils/__init__.py", line 6, in <module>
    from . import conv_utils
  File "/home/ac1xdrj/prj/models/rumourVeracity/venv/local/lib/python2.7/site-packages/keras/utils/conv_utils.py", line 9, in <module>
    from .. import backend as K
  File "/home/ac1xdrj/prj/models/rumourVeracity/venv/local/lib/python2.7/site-packages/keras/backend/__init__.py", line 86, in <module>
    from .theano_backend import *
  File "/home/ac1xdrj/prj/models/rumourVeracity/venv/local/lib/python2.7/site-packages/keras/backend/theano_backend.py", line 7, in <module>
    import theano
ImportError: No module named theano

[drj11]

To be fair the current behaviour is acceptable, no-one is harmed and all the tracebacks and output are there (twice, in some cases!), it's more of a "this would be neater if..."

[ianroberts]

If the tracebacks can be captured nicely on the Python side then we can even fake the python traceback into the Java one (see Throwable.setStackTrace) so it comes out as e.g.

gate.creole.ExecutionException: Exception in Python code: ImportError: No module named theano
        at python(/home/ac1xdrj/prj/models/rumourVeracity/venv/local/lib/python2.7/site-packages/keras/backend/theano_backend.py:7)
        <a load more stack frames>
        at python(/home/ac1xdrj/prj/models/rumourVeracity/innerAttentionModel.py:5)
        at python(/home/ac1xdrj/prj/models/rumourVeracity/veracity_gate.py:4)
        at gate.python.PythonPR.execute(PythonPR.java:165)
	at gate.util.Benchmark.executeWithBenchmarking(Benchmark.java:291)

[johann-petrak]

This should work properly in the 2.0-SNAPSHOT version, but faking the python traceback into the Java one is not implemented yet.

[johann-petrak]

@ianroberts do you have code to convert a python stackframe to a java traceback as in the example you give?

[johann-petrak]

I think I am happy with just getting the original python stacktrace as message of a single Exception on the Java side for now.
If somebody feels strongly about the conversion into a Java stack trace, please open another issue to discuss the details there.

[greenwoodma]

I agree that it would be nice to do this as a stack trace so that those of us who are more Java experts than Python can see something that at a glance we can understand. Although I also agree that it's not hugely important.

There is an example of setting the stack trace when looking at none Java files as part of the Jape code. Specifically see here https://github.com/GateNLP/gateplugin-ANNIE/blob/fea2e875a5aedb1b8f602f65d9902a9d5078c6ae/src/main/java/gate/jape/SourceInfo.java#L92

[greenwoodma]

Could we repoen the issue, but mark as an enhancement so that if someone has the time they could come back and improve this later? If the issue is closed it just disappears from view and will get forgotten.

[johann-petrak]

TBH I am not sure how much this would be helping: the conversion may make it harder to find the actual Python stacktrace among some big Java stacktrace because then both would look very similar. On the other hand a nicely formatted python stacktrace could be made to stand out.

I would still be interested if the example from @ianroberts above is the output of testing code or just manually written fake output? If we can make it look like that, maybe with "at PYTHON" screaming at us, it could be an option.

[ianroberts]

I would still be interested if the example from @ianroberts above is the output of testing code or just manually written fake output?

It's manually faked up but based on what is done by the JAPE SourceInfo that Mark linked to above.

[johann-petrak]

I have updated the way how Python exceptions get shown on the Java side. At the moment, the python process writes a traceback to stderr which should always get copied to the java side (as stdout like all other stderr from python).
In addition, the python process sends back the exception message and an info string which is the formatted traceback from python which gets then printed as part of the Java exception (this goes to the error logger, i.e. stderr in the GUI)
The reason why it could be useful to always copy the traceback from the python process output is that sending back the traceback or stack trace is something that involves the JSON communication where we could also have a problem. In such a case we would not get useful information on the java side.

Either way, getting the Python traceback that way is easily readable and has the advantage that it stands out from the Java stacktrace, so it is actually easier to figure out where to look for the Python error than it would be if the Python traceback looks exactly like the Java traceback. I am now even more in favour of not converting.
Any other reasons why the conversion would be an advantage?

[greenwoodma]

Well my original reason still stands; Java developers will be able to read the Java stacktrace much easier (at a glance really) to follow the flow into the python code than they will the Python traceback which may be something they have never seen before. I know I'm probably in the minority with my lack of python experience, but making life easier for Java developers in general can't be a bad thing.

At the end of the day it would be a nice feature to have (which is why I suggested leaving the issue open with an enhancement label) but not a blocker for release.