Created on 2017-07-04.13:38:15 by rhwood, last changed 2017-07-27.12:11:06 by tobias.
|JythonIssue2604Test.java||rhwood, 2017-07-04.14:18:31||Reproducible Test Case|
|msg11464 (view)||Author: Randall Wood (rhwood)||Date: 2017-07-04.13:38:14|
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.
|msg11465 (view)||Author: Randall Wood (rhwood)||Date: 2017-07-04.14:18:31|
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.
|msg11467 (view)||Author: James Mudd (jamesmudd)||Date: 2017-07-05.18:20:50|
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?
|msg11468 (view)||Author: Randall Wood (rhwood)||Date: 2017-07-05.23:16:40|
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.
|msg11469 (view)||Author: Randall Wood (rhwood)||Date: 2017-07-06.10:03:33|
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.
|msg11471 (view)||Author: James Mudd (jamesmudd)||Date: 2017-07-07.22:31:25|
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.
|msg11472 (view)||Author: James Mudd (jamesmudd)||Date: 2017-07-09.17:05:40|
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.
|msg11500 (view)||Author: Jim Baker (zyasoft)||Date: 2017-07-25.13:42:41|
|msg11501 (view)||Author: Jeff Allen (jeff.allen)||Date: 2017-07-26.07:28:39|
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.
|2017-07-27 12:11:06||tobias||set||nosy: + tobias|
messages: + msg11501
|2017-07-25 13:42:42||zyasoft||set||messages: + msg11500|
messages: + msg11472
|2017-07-07 22:31:25||jamesmudd||set||messages: + msg11471|
|2017-07-06 10:03:34||rhwood||set||messages: + msg11469|
|2017-07-05 23:16:40||rhwood||set||messages: + msg11468|
messages: + msg11467
messages: + msg11465
|2017-07-04 13:48:24||amak||set||nosy: + amak|