search

jpype-project / jpype

JPype is cross language bridge to allow Python programs full access to Java class libraries.
http://www.jpype.org
Apache License 2.0
1.12k stars 183 forks source link

PyTest failure in Python 3.11 and above caused by calling a method that throws in a generated class #1178

Open Christopher-Chianelli opened 7 months ago

Christopher-Chianelli commented 7 months ago

Currently, to see results from PyTest failures caused by an Exception with a cause in Python 3.11 and above, I need to have this @JImplementationFor:

@JImplementationFor('java.lang.Throwable')
class _JavaException:
    @property
    def __cause__(self):
        return Exception()

To reproduce:

Python test:

def test_exception_with_cause():
    from org.example import Example
    consumer = example.getConsumer()
    consumer.accept('Error')

Java class:

package org.example

public class Example {
    private static final String className = "org.acme.GeneratedClass";
    private static final ClassLoader classLoader = new ClassLoader() {
        @Override
        public Class<?> loadClass(String name) throws ClassNotFoundException {
            if (name.equals(className)) {
                byte[] bytecode = getClassBytecode();
                return defineClass(name, bytecode, 0, bytecode.length);
            }
            return super.loadClass(name);
        }
    };

    private static byte[] getClassBytecode() {
        String className = "org.acme.GeneratedClass";
        String internalClassName = className.replace('.', '/');
        ClassWriter classWriter = new ClassWriter(ClassWriter.COMPUTE_FRAMES | ClassWriter.COMPUTE_MAXS);
        classWriter.visit(Opcodes.V17, Modifier.PUBLIC, internalClassName, null, Type.getInternalName(Object.class), new String[] { Type.getInternalName(
                Consumer.class)});

        MethodVisitor methodVisitor = classWriter.visitMethod(Modifier.PUBLIC, "<init>", Type.getMethodDescriptor(Type.VOID_TYPE), null, null);
        methodVisitor.visitCode();
        methodVisitor.visitVarInsn(Opcodes.ALOAD, 0);
        methodVisitor.visitMethodInsn(Opcodes.INVOKESPECIAL, Type.getInternalName(Object.class), "<init>", Type.getMethodDescriptor(Type.VOID_TYPE),
                false);
        methodVisitor.visitInsn(Opcodes.RETURN);
        methodVisitor.visitMaxs(0, 0);
        methodVisitor.visitEnd();

        methodVisitor = classWriter.visitMethod(Modifier.PUBLIC, "accept", Type.getMethodDescriptor(Type.VOID_TYPE, Type.getType(
                Object.class)), null, null);
        methodVisitor.visitCode();
        methodVisitor.visitVarInsn(Opcodes.ALOAD, 0);
        methodVisitor.visitVarInsn(Opcodes.ALOAD, 1);
        methodVisitor.visitTypeInsn(Opcodes.CHECKCAST, Type.getInternalName(String.class));
        methodVisitor.visitMethodInsn(Opcodes.INVOKEVIRTUAL, internalClassName, "accept",
                Type.getMethodDescriptor(Type.VOID_TYPE, Type.getType(String.class)), false);
        methodVisitor.visitInsn(Opcodes.RETURN);
        methodVisitor.visitMaxs(0, 0);
        methodVisitor.visitEnd();

        // Generates throw new RuntimeException(message)
        methodVisitor = classWriter.visitMethod(Modifier.PUBLIC, "accept", Type.getMethodDescriptor(Type.VOID_TYPE, Type.getType(String.class)), null, null);
        methodVisitor.visitCode();
        methodVisitor.visitTypeInsn(Opcodes.NEW, Type.getInternalName(RuntimeException.class));
        methodVisitor.visitInsn(Opcodes.DUP);
        methodVisitor.visitVarInsn(Opcodes.ALOAD, 1);
        methodVisitor.visitMethodInsn(Opcodes.INVOKESPECIAL, Type.getInternalName(RuntimeException.class), "<init>",
                Type.getMethodDescriptor(Type.VOID_TYPE, Type.getType(String.class)), false);
        methodVisitor.visitInsn(Opcodes.ATHROW);
        methodVisitor.visitMaxs(0, 0);
        methodVisitor.visitEnd();

        classWriter.visitEnd();

        return classWriter.toByteArray();
    }
    public static Consumer<String> getConsumer() throws Throwable {
        @SuppressWarnings("unchecked")
        Class<? extends Consumer<String>> generatedClass = (Class<? extends Consumer<String>>) classLoader.loadClass(className);
        return generatedClass.getConstructor().newInstance();
    }
}

Exception from PyTest:

INTERNALERROR> Traceback (most recent call last):
INTERNALERROR>   File ".../_pytest/main.py", line 285, in wrap_session
INTERNALERROR>     session.exitstatus = doit(config, session) or 0
INTERNALERROR>                          ^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../_pytest/main.py", line 339, in _main
INTERNALERROR>     config.hook.pytest_runtestloop(session=session)
INTERNALERROR>   File ".../pluggy/_hooks.py", line 501, in __call__
INTERNALERROR>     return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../pluggy/_manager.py", line 119, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../pluggy/_callers.py", line 138, in _multicall
INTERNALERROR>     raise exception.with_traceback(exception.__traceback__)
INTERNALERROR>   File ".../pluggy/_callers.py", line 121, in _multicall
INTERNALERROR>     teardown.throw(exception)  # type: ignore[union-attr]
INTERNALERROR>     ^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../_pytest/logging.py", line 806, in pytest_runtestloop
INTERNALERROR>     return (yield)  # Run all the tests.
INTERNALERROR>             ^^^^^
INTERNALERROR>   File ".../pluggy/_callers.py", line 102, in _multicall
INTERNALERROR>     res = hook_impl.function(*args)
INTERNALERROR>           ^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../_pytest/main.py", line 364, in pytest_runtestloop
INTERNALERROR>     item.config.hook.pytest_runtest_protocol(item=item, nextitem=nextitem)
INTERNALERROR>   File ".../pluggy/_hooks.py", line 501, in __call__
INTERNALERROR>     return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../pluggy/_manager.py", line 119, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../pluggy/_callers.py", line 138, in _multicall
INTERNALERROR>     raise exception.with_traceback(exception.__traceback__)
INTERNALERROR>   File ".../pluggy/_callers.py", line 121, in _multicall
INTERNALERROR>     teardown.throw(exception)  # type: ignore[union-attr]
INTERNALERROR>     ^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../_pytest/warnings.py", line 111, in pytest_runtest_protocol
INTERNALERROR>     return (yield)
INTERNALERROR>             ^^^^^
INTERNALERROR>   File ".../pluggy/_callers.py", line 121, in _multicall
INTERNALERROR>     teardown.throw(exception)  # type: ignore[union-attr]
INTERNALERROR>     ^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../_pytest/assertion/__init__.py", line 175, in pytest_runtest_protocol
INTERNALERROR>     return (yield)
INTERNALERROR>             ^^^^^
INTERNALERROR>   File ".../pluggy/_callers.py", line 121, in _multicall
INTERNALERROR>     teardown.throw(exception)  # type: ignore[union-attr]
INTERNALERROR>     ^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../_pytest/unittest.py", line 401, in pytest_runtest_protocol
INTERNALERROR>     res = yield
INTERNALERROR>           ^^^^^
INTERNALERROR>   File ".../pluggy/_callers.py", line 121, in _multicall
INTERNALERROR>     teardown.throw(exception)  # type: ignore[union-attr]
INTERNALERROR>     ^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../_pytest/faulthandler.py", line 85, in pytest_runtest_protocol
INTERNALERROR>     return (yield)
INTERNALERROR>             ^^^^^
INTERNALERROR>   File ".../pluggy/_callers.py", line 102, in _multicall
INTERNALERROR>     res = hook_impl.function(*args)
INTERNALERROR>           ^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../_pytest/runner.py", line 115, in pytest_runtest_protocol
INTERNALERROR>     runtestprotocol(item, nextitem=nextitem)
INTERNALERROR>   File ".../_pytest/runner.py", line 134, in runtestprotocol
INTERNALERROR>     reports.append(call_and_report(item, "call", log))
INTERNALERROR>                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../_pytest/runner.py", line 242, in call_and_report
INTERNALERROR>     report: TestReport = ihook.pytest_runtest_makereport(item=item, call=call)
INTERNALERROR>                          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../pluggy/_hooks.py", line 501, in __call__
INTERNALERROR>     return self._hookexec(self.name, self._hookimpls.copy(), kwargs, firstresult)
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../pluggy/_manager.py", line 119, in _hookexec
INTERNALERROR>     return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../pluggy/_callers.py", line 138, in _multicall
INTERNALERROR>     raise exception.with_traceback(exception.__traceback__)
INTERNALERROR>   File ".../pluggy/_callers.py", line 121, in _multicall
INTERNALERROR>     teardown.throw(exception)  # type: ignore[union-attr]
INTERNALERROR>     ^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../_pytest/tmpdir.py", line 317, in pytest_runtest_makereport
INTERNALERROR>     rep = yield
INTERNALERROR>           ^^^^^
INTERNALERROR>   File ".../pluggy/_callers.py", line 121, in _multicall
INTERNALERROR>     teardown.throw(exception)  # type: ignore[union-attr]
INTERNALERROR>     ^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../_pytest/skipping.py", line 268, in pytest_runtest_makereport
INTERNALERROR>     rep = yield
INTERNALERROR>           ^^^^^
INTERNALERROR>   File ".../pluggy/_callers.py", line 102, in _multicall
INTERNALERROR>     res = hook_impl.function(*args)
INTERNALERROR>           ^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../_pytest/runner.py", line 367, in pytest_runtest_makereport
INTERNALERROR>     return TestReport.from_item_and_call(item, call)
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../_pytest/reports.py", line 364, in from_item_and_call
INTERNALERROR>     longrepr = item.repr_failure(excinfo)
INTERNALERROR>                ^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../_pytest/python.py", line 1814, in repr_failure
INTERNALERROR>     return self._repr_failure_py(excinfo, style=style)
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../_pytest/nodes.py", line 464, in _repr_failure_py
INTERNALERROR>     return excinfo.getrepr(
INTERNALERROR>            ^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../_pytest/_code/code.py", line 699, in getrepr
INTERNALERROR>     return fmt.repr_excinfo(self)
INTERNALERROR>            ^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../_pytest/_code/code.py", line 1064, in repr_excinfo
INTERNALERROR>     reprtraceback = self.repr_traceback(excinfo_)
INTERNALERROR>                     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
INTERNALERROR>   File ".../_pytest/_code/code.py", line 993, in repr_traceback
INTERNALERROR>     entries = [
INTERNALERROR>               ^
INTERNALERROR>   File ".../_pytest/_code/code.py", line 994, in <listcomp>
INTERNALERROR>     self.repr_traceback_entry(entry, excinfo if last == entry else None)
INTERNALERROR>   File ".../_pytest/_code/code.py", line 948, in repr_traceback_entry
INTERNALERROR>     reprfileloc = ReprFileLocation(path, entry.lineno + 1, message)
INTERNALERROR>                                          ^^^^^^^^^^^^
INTERNALERROR>   File ".../_pytest/_code/code.py", line 212, in lineno
INTERNALERROR>     return self._rawentry.tb_lineno - 1
INTERNALERROR>            ~~~~~~~~~~~~~~~~~~~~~~~~~^~~
INTERNALERROR> TypeError: unsupported operand type(s) for -: 'NoneType' and 'int'
Thrameos commented 7 months ago

This should be simple to fix. The problem should be in native/common/jp_exception.cpp where we set the exception information. tb_lineno is one of the fields we set. My guess it that we didn’t have a line number in the compiled code so we left it as NULL. The PyTest code may incorrect as it is blindly assuming that the result can’t be None, which I don’t see as a requirement in the spec. I will need to investigate further and read the some PEPs.

Thrameos commented 7 months ago

I was unable to replicate the issue from your example. I get

______________________________________________ test_exception_with_cause _______________________________________________
java.lang.java.lang.IllegalStateException: java.lang.IllegalStateException: cause

The above exception was the direct cause of the following exception:

>   throw new IllegalStateException("test", new IllegalStateException("cause"));
E   Exception: Java Exception

Example.java:4: Exception

The above exception was the direct cause of the following exception:

    def test_exception_with_cause():
        jpype.startJVM(classpath='.')
        example = jpype.JClass('Example')
>       example.throwingMethod()
E       java.lang.java.lang.IllegalStateException: java.lang.IllegalStateException: test

test.py:5: java.lang.IllegalStateException
Christopher-Chianelli commented 7 months ago

At this point, I am almost certain this is a pytest bug, since this code still cause the internal error:

def test_reproducer():
    try:
        code_that_cause_exception()
    except:
        raise Exception
Christopher-Chianelli commented 7 months ago

Forgot that raise Exception is a short for raise Exception from last_raise_exception. Managed to get a minimal reproducer; it has to do with generated classes;

Reproducer is https://github.com/Christopher-Chianelli/issue-reproducer/tree/jpype-1178

Christopher-Chianelli commented 7 months ago

If the generated class has source information (i.e. classWriter.visitSource("MyFile.py", "debug"); and methodVisitor.visitLineNumber(0, line);), then the exception does not occur.

Thrameos commented 7 months ago

Unfortunately I got 

[INFO] Scanning for projects...
[ERROR] [ERROR] Some problems were encountered while processing the POMs:
[FATAL] Non-resolvable parent POM for org.optaplanner:DroolsExecutableReproducer:8.0.0-SNAPSHOT: Could not find artifact org.optaplanner:optaplanner-build-parent:pom:8.0.0-SNAPSHOT and 'parent.relativePath' points at wrong local POM @ line 7, column 11
 @
[ERROR] The build could not read 1 project -> [Help 1]
[ERROR]
[ERROR]   The project org.optaplanner:DroolsExecutableReproducer:8.0.0-SNAPSHOT (/mnt/c/Users/nelson85/Documents/devel/open/jpype/issue/pom.xml) has 1 error
[ERROR]     Non-resolvable parent POM for org.optaplanner:DroolsExecutableReproducer:8.0.0-SNAPSHOT: Could not find artifact org.optaplanner:optaplanner-build-parent:pom:8.0.0-SNAPSHOT and 'parent.relativePath' points at wrong local POM @ line 7, column 11 -> [Help 2]
[ERROR]

So I was unable to build the reproducer to verify the test. Sorry! I will try again next weekend to see if I can sort out what is going on. Unfortunately, as I don't use maven it doesn't make much sense to me.

The specific call where we mess with linenum is in native/common/jp_exception.cpp

PyObject *tb_create(
        PyObject *last_traceback,
        PyObject *dict,
        const char* filename,
        const char* funcname,
        int linenum)
{
    // Create a code for this frame. (ref count is 1)
    JPPyObject code = JPPyObject::accept((PyObject*)PyCode_NewEmpty(filename, funcname, linenum));

    // If we don't get the code object there is no point
    if (code.get() == nullptr)
        return nullptr;

    // Create a frame for the traceback.
    PyThreadState *state = PyThreadState_GET();
    PyFrameObject *pframe = PyFrame_New(state, (PyCodeObject*) code.get(), dict, NULL);
    JPPyObject frame = JPPyObject::accept((PyObject*)pframe);

    // If we don't get the frame object there is no point
    if (frame.get() == nullptr)
        return nullptr;

    // Create a traceback
#if PY_MINOR_VERSION<11
    JPPyObject lasti = JPPyObject::claim(PyLong_FromLong(pframe->f_lasti));
#else
    JPPyObject lasti = JPPyObject::claim(PyLong_FromLong(PyFrame_GetLasti(pframe)));
#endif
    JPPyObject linenuma = JPPyObject::claim(PyLong_FromLong(linenum));
    JPPyObject tuple = JPPyObject::call(PyTuple_Pack(4, Py_None, frame.get(), lasti.get(), linenuma.get()));
    JPPyObject traceback = JPPyObject::accept(PyObject_Call((PyObject*) &PyTraceBack_Type, tuple.get(), NULL));

    // We could fail in process
    if (traceback.get() == nullptr)
    {
        return nullptr;
    }

    return traceback.keep();
}

As you can see we are calling the constructor with a valid traceback linenum. If there is a problem then most likely traceback changed its signature starting in 3.11 and we would need to adjust the constructor call to account for it. I scanned the Python code base and don't see an errors in the handoff (though admittedly the code is very ugly....)

    PyObject *argsbuf[4];
    PyObject * const *fastargs;
    Py_ssize_t nargs = PyTuple_GET_SIZE(args);
    PyObject *tb_next;
    PyFrameObject *tb_frame;
    int tb_lasti;
    int tb_lineno;

    fastargs = _PyArg_UnpackKeywords(_PyTuple_CAST(args)->ob_item, nargs, kwargs, NULL, &_parser, 4, 4, 0, argsbuf);
    if (!fastargs) {
        goto exit;
    }
    tb_next = fastargs[0];
    if (!PyObject_TypeCheck(fastargs[1], &PyFrame_Type)) {
        _PyArg_BadArgument("TracebackType", "argument 'tb_frame'", (&PyFrame_Type)->tp_name, fastargs[1]);
        goto exit;
    }
    tb_frame = (PyFrameObject *)fastargs[1];
    tb_lasti = _PyLong_AsInt(fastargs[2]);
    if (tb_lasti == -1 && PyErr_Occurred()) {  <===  BAD THING HAPPENS HERE IF THERE IS ALREADY AN EXCEPTION 
        goto exit;
    }
    tb_lineno = _PyLong_AsInt(fastargs[3]);
    if (tb_lineno == -1 && PyErr_Occurred()) {
        goto exit;
    }
    return_value = tb_new_impl(type, tb_next, tb_frame, tb_lasti, tb_lineno);

As you can see form this code it may be the same error as in the PR. There is a potential the lost exception is tripping a problem in the copied traceback. But if that was the case the traceback would have failed without producing, and not one with Py_None in the linenum slot. Thus I still don't have a good explanation for what could be happening here.

Christopher-Chianelli commented 7 months ago

I think you checked out the wrong branch; the branch should be jpype-1178 not drools-classloader-reproducer (which is the default branch)

Thrameos commented 7 months ago

Ah... will try again later them.

Thrameos commented 7 months ago

I got 


(python3.12-wsl) nelson85@wl-5520983:~/devel/open/jpype/issue$ pytest
======================================================================================= test session starts ========================================================================================
platform linux -- Python 3.12.0, pytest-8.1.1, pluggy-1.4.0 -- /home/nelson85/env/python3.12-wsl/bin/python
cachedir: .pytest_cache
rootdir: /mnt/c/Users/nelson85/Documents/devel/open/jpype
configfile: setup.cfg
collected 2 items

tests/test_reproducer.py::test_throwing FAILED                                                                                                                                               [ 50%]
tests/test_reproducer.py::test_b PASSED                                                                                                                                                      [100%]

============================================================================================= FAILURES =============================================================================================
__________________________________________________________________________________________ test_throwing ___________________________________________________________________________________________

>   ???
E   Exception: Java Exception

org.acme.GeneratedClass.java:-1: Exception

The above exception was the direct cause of the following exception:

    def test_throwing():
        import jpype
        import jpype.imports
        jpype.startJVM(classpath=[
            'target/issue-reproducer-1.0.0-SNAPSHOT.jar',
            'target/dependency/asm-9.7.jar'
        ])
        from org.acme import MyClass
        consumer = MyClass.getConsumer()
>       consumer.accept('My Error')
E       java.lang.java.lang.RuntimeException: java.lang.RuntimeException: My Error

tests/test_reproducer.py:10: java.lang.RuntimeException
===================================================================================== short test summary info ======================================================================================
FAILED tests/test_reproducer.py::test_throwing - java.lang.java.lang.RuntimeException: java.lang.RuntimeException: My Error
=================================================================================== 1 failed, 1 passed in 0.49s ====================================================================================

Is this correct or incorrect?

Christopher-Chianelli commented 7 months ago

This is odd,

I don't know why it randomly worked then failed after a mvn clean install.

This is what it looks like when the internal error happens:

mvn clean install
python -m venv venv
. venv/bin/activate
pip install JPype1 pytest
pytest
===================================================================================== test session starts ======================================================================================
platform linux -- Python 3.12.2, pytest-8.1.1, pluggy-1.4.0
rootdir: .../issue-reproducer
collected 2 items                                                                                                                                                                              

tests/test_reproducer.py 
INTERNALERROR> Traceback (most recent call last):
...

Note the second test is not even run.

omercnet commented 1 month ago

any lead on a fix here? I can't reproduce this locally but fails on github actions https://github.com/omercnet/palgate-py/actions/runs/11260802234/job/31312822917?pr=2

Thrameos commented 1 month ago

I haven't touched it as I have no reproducing method. Could it be a particular version of Python 3.11. They backported some broken behavior in. It was the stuff of nightmares when I was dealing with 3.13 as what was ported in had wotk arounds only in later versions. Hence the comment... "Python 3.11 is dead to me."

Thrameos commented 1 day ago

This problem has cropped up again in my Python 3.12 testing for release. Not sure yet how to deal with it.

Thrameos commented 1 day ago

I have identified this issue. It is maddening. We are setting the line number to -1 on an integer field. Depending on the system and how it is called -1 will be changed to None. This is actually correct behavior because None means don't print a meaningless line number. But the pytest is trying to do math with it. We are once again the victim of random changes in Python code base.