Issue2604

I have a process that uses Jython to check that files are being checked into a SCM using the correct line ends (its a Java test that uses Jython, embedded using JSR 223, to run 29057 tests. Each test is the following Jython script (written on the fly in Java where PATH is the file to check and changes every time):

import os
failing = False
if "\r\n" in open(os.path.normpath(PATH), "rb").read():
    failing = True

This has the following runtimes (in seconds) on the same computer with no other changes than Jython version:

Jython 2.7.0: 89.442 (~1.5 minutes)
Jython 2.7.1: 10,788.489 (~3 hours or ~120 times as long as 2.7.0)

Am working on an isolated reproducible Java class; will attach when ready.

Reproducible Test Case. Run (on a POSIX system; I don't know the syntax for Windows) as:

javac -classpath hamcrest-core-1.3.jar:jython-standalone-2.7.1.jar:junit-4.12.jar:. JythonIssue2604Test.java
java -classpath hamcrest-core-1.3.jar:jython-standalone-2.7.1.jar:junit-4.12.jar:. JythonIssue2604Test

Requires:
JUnit 4.12 (http://repo1.maven.org/maven2/junit/junit/4.12/junit-4.12.jar)
Hamcrest Core 1.3 (http://repo1.maven.org/maven2/org/hamcrest/hamcrest-core/1.3/hamcrest-core-1.3.jar)

Jython Standalone. Run with version 2.7.0 and 2.7.1 to see the difference in behavior.

I have tested this using the uploaded test case and can't see a large difference between 2.7.0 and 2.7.1. Here are my results:

james@james-desktop ~/Desktop/Jython-2604 $ java -classpath hamcrest-core-1.3.jar:jython-standalone-2.7.0.jar:junit-4.12.jar:. JythonIssue2604Test
JUnit version 4.12
.
Time: 1.059

OK (1 test)

james@james-desktop ~/Desktop/Jython-2604 $ java -classpath hamcrest-core-1.3.jar:jython-standalone-2.7.1.jar:junit-4.12.jar:. JythonIssue2604Test
JUnit version 4.12
.
Time: 1.055

OK (1 test)

Recompiled between the tests. I have run each lots of times and see variation around +-0.1 sec on both versions. Should I expect to see 2.7.1 being a lot slower?

Maybe you could provide some more details, what OS and what JVM?

With only one file tested, most of the time is the initialization of Jython, and any difference is hidden by that. With the 29057 iterations of that four line script in a single JVM, the effect is visible.

If you download the sources.jar for jython-standalone-2.7.1, unzip it, and run the test from the root of that unzipped JAR, that the results are:
Tests run: 3648,  Failures: 46
Time: 10.366 (Jython 2.7.0)
Time: 943.857 (Jython 2.7.1)

Sorry I wasn't clear on the need to run this against a large directory structure to see the effect.

I am seeing this on macOS 10.12.5 with java 1.8.0_102.

Travis CI (Ubuntu 12.04.5 LTS with java 1.8.0_121) and AppVeyor (Windows Server 2012 R2 with java 1.8.0_121) are both killing my CI builds in the original use case (29057 files) with Jython 2.7.1 because the builds are running over an hour.

Ok I have definitely reproduced this and it is bad! On Linux Mint 18.1, openjdk version "1.8.0_131"

Slightly different file set but run over: Tests run: 4546,  Failures: 50
2.7.0 = 5.61 secs
2.7.1 = 688.406 secs

So in my test 2.7.1 is also ~120 times slower.

Haven't identified where the performance changed but will hopefully get time to have a look at that.

After a little work with git bisect I know the cause of this problem, however I am unsure of the correct solution.

This problem was introduced in commit c7a3eba where a change is made to "Isolate each JSR ScriptEngine with separate PySystemState" to fix #2154.

Simply reverting this commit appears to resolve this problem and causes no problems in the regrtests, however I don't know if this is a good idea. I'm still not completely sure why this change results in such a large performance issue here.

I have a pull request (https://github.com/jythontools/jython/pull/82) to revert this commit for discussion,  would be good if Jim could have a look at this.

James Mudd, thanks for identifying the performance regression as due
to the fix for #2514.

Resolving this problem is one of a number of JSR 223 fixes that should
be addressed. Unfortunately there is no single answer on what to do
here because in some cases users need the sys module to be isolated;
and in other cases, that costs too much in terms of performance. Some
details from my email on June 13 to jython-dev:

> I took a detailed look at
> http://bugs.jython.org/issue2513. Unfortunately there is no easy fix
> for this problem as stated, because org.python.jsr223.ScriptEngine,
> via org.python.util.PythonInterepreter, relies on
> org.python.core.PySystemState (= sys in Python), which effectively
> collects together global state for Python, either directly, such as
> sys.stdout, or indirectly, via sys.modules and any globals within
> those modules. The mechanism that ScriptEngine uses to put locals on
> a thread local will not work here, because this is maintained by a
> separate entity in Python, the frame object (= PyFrame in Jython);
> there is no such support for sys.stdout, etc, to be looked up from
> the thread.

JavaScript has similar issues, and the Nashorn implementation
addresses this by extending the JSR223 API to enable better
configuration of the relevant tradeoffs. So again quoting from my email:

> There is a possible solution, but it's not feasible at this point in
> the release cycle and needs to be deferred to later. Instead of
> always attempting to reuse PySystemState, Jython's JSR223 should
> instead support a model where new PySystemState objects can be
> attached to a ScriptEngine. I believe this is similar to what
> Nashorn supports with its --global-per-engine property (also
> configurable some other ways, see the notes). Regardless of exact
> similarity, this is how we would have to do it:

> ScriptEngine engine = factory.getScriptEngine(new String[] { "--global-per-engine" });

> (https://wiki.openjdk.java.net/display/Nashorn/Nashorn+jsr223+engine+notes)

I've been thinking about the relationships amongst thread state, interpreter state and sys module. It wasn't motivated by this problem, and I'm just trying to understand why it is the way it is in CPython first. It's a bit of Jython that a. has to be slightly different from CPython (no GIL), and b. we keep having to tweak.

I've concluded that, in any Python implementation, we need an instance of sys per interpreter -- or rather, an instance of "module administration" per interpreter. So our response to #2154 is surely correct. Is it just that module administration is terribly expensive? I probably made that a bit worse in my FS-encoding fixes, but I've been suspicious of the import subsystem since the first time I single-stepped through it.