2015-11-11 2 views
2

Я портирую код в своем приложении от Rhino до Nashorn (в основном, чтобы не отставать от современной моды, а не от недостатка функциональности в Rhino), и я получаю очень плохую производительность с Nashorn.Nashorn в 3 раза медленнее Rhino, как оптимизировать?

Мое приложение имеет набор файлов LESS, скомпилированных во время выполнения (контент является динамическим и не может быть предварительно скомпилирован). Это делается один раз при запуске и каждый раз, когда изменения обнаруживаются во время выполнения.

Rhino дает довольно стабильную производительность около 4-5 секунд (сценарий JS загружается с максимальной оптимизацией Rhino).

Nashorn дает некоторые абсолютно странные результаты - около 15-17 секунд, но после 10-й итерации и около 10 минут времени производительность становится довольно хорошей - около 3 секунд. Но из-за начальной медленности мое приложение с Nashorn начинается в общем примерно на 30 секунд дольше, чем с Rhino (есть и другие файлы LESS, скомпилированные).

Так что вопрос:

Что я могу сделать для обеспечения Nashorn выполнять самую высокую оптимизацию сценария сразу, а не после того, как 10-20th итерации?


Ниже тайминги из файла журнала

2015-11-11 09:29:16,419 compile(less, styles.less) = 15179ms 
-------------------------------------------------------------- 
    15.179  % compile (styles.less) 
-------------------------------------------------------------- 
    13.940 91.8% less-rhino-ji.js lessFileToCss(styles.less) 
    1.227 8.0% YUICompressor minify(styles.less) 

2015-11-11 09:30:12,900 compile(less, styles.less) = 13274ms 
-------------------------------------------------------------- 
    13.274  % compile (styles.less) 
-------------------------------------------------------------- 
    11.605 87.4% less-rhino-ji.js lessFileToCss(styles.less) 
    1.664 12.5% YUICompressor minify(styles.less) 

2015-11-11 09:30:43,705 compile(less, styles.less) = 6906ms 
-------------------------------------------------------------- 
    6.906  % compile (styles.less) 
-------------------------------------------------------------- 
    5.695 82.4% less-rhino-ji.js lessFileToCss(styles.less) 
    1.205 17.4% YUICompressor minify(styles.less) 

2015-11-11 09:31:09,194 compile(less, styles.less) = 6041ms 
-------------------------------------------------------------- 
    6.041  % compile (styles.less) 
-------------------------------------------------------------- 
    4.622 76.5% less-rhino-ji.js lessFileToCss(styles.less) 
    1.412 23.3% YUICompressor minify(styles.less) 

2015-11-11 09:31:49,558 compile(less, styles.less) = 7619ms 
-------------------------------------------------------------- 
    7.619  % compile (styles.less) 
-------------------------------------------------------------- 
    3.056 40.1% less-rhino-ji.js lessFileToCss(styles.less) 
    4.555 59.7% YUICompressor minify(styles.less) 

2015-11-11 09:36:25,586 compile(less, styles.less) = 5226ms 
-------------------------------------------------------------- 
    5.226  % compile (styles.less) 
-------------------------------------------------------------- 
    4.104 78.5% less-rhino-ji.js lessFileToCss(styles.less) 
    1.116 21.3% YUICompressor minify(styles.less) 

2015-11-11 09:36:40,745 compile(less, styles.less) = 3839ms 
-------------------------------------------------------------- 
    3.839  % compile (styles.less) 
-------------------------------------------------------------- 
    2.664 69.3% less-rhino-ji.js lessFileToCss(styles.less) 
    1.169 30.4% YUICompressor minify(styles.less) 

2015-11-11 09:37:02,876 compile(less, styles.less) = 3074ms 
-------------------------------------------------------------- 
    3.074  % compile (styles.less) 
-------------------------------------------------------------- 
    1.948 63.3% less-rhino-ji.js lessFileToCss(styles.less) 
    1.120 36.4% YUICompressor minify(styles.less) 

2015-11-11 09:37:29,140 compile(less, styles.less) = 4773ms 
-------------------------------------------------------------- 
    4.773  % compile (styles.less) 
-------------------------------------------------------------- 
    3.682 77.1% less-rhino-ji.js lessFileToCss(styles.less) 
    1.085 22.7% YUICompressor minify(styles.less) 

2015-11-11 09:37:51,768 compile(less, styles.less) = 2761ms 
-------------------------------------------------------------- 
    2.761  % compile (styles.less) 
-------------------------------------------------------------- 
    1.661 60.1% less-rhino-ji.js lessFileToCss(styles.less) 
    1.094 39.6% YUICompressor minify(styles.less) 

2015-11-11 09:38:19,053 compile(less, styles.less) = 2743ms 
-------------------------------------------------------------- 
    2.743  % compile (styles.less) 
-------------------------------------------------------------- 
    1.639 59.7% less-rhino-ji.js lessFileToCss(styles.less) 
    1.098 40.0% YUICompressor minify(styles.less) 

Update: По рекомендации от Olipro я начал процесс со следующими аргументами:

java -XX:+UnlockDiagnosticVMOptions -XX:+PrintCompilation ... 

Результат является не совсем понятно - имена класса es, генерируемые Nashorn, похожи на jdk.nashorn.internal.scripts.Script$Recompilation$438$121292A$\^eval\_::L:3187$toCSS, однако только по имени метода я вижу, что во время самой длинной компиляции файла CSS (4.4 секунды) в этом тестовом прогоне метод toCSS() был перекомпилирован 5 раз и кажется, что 2 фоновых потока составляли разные версии одного и того же метода параллельно (немного странно для меня) - скорее всего, это действительно основная причина плохой производительности.

Тем не менее - ни намек, как улучшить производительность при запуске :(

строки из журнала (1st column = мс от начала Jvm):

11100 5677 jdk.nas...tion$438$121292A$\^eval\_::L:3187$toCSS (103 bytes) 
11119 5682 jdk.nas...tion$446$150019A$\^eval\_::L:4147$toCSS (137 bytes) 
11377 5677 jdk.nas...tion$438$121292A$\^eval\_::L:3187$toCSS (103 bytes) made not entrant 
11507 5677 jdk.nas...tion$438$121292A$\^eval\_::L:3187$toCSS (103 bytes) made zombie 
11932 5798 jdk.nas...tion$438$121292A$\^eval\_::L:3187$toCSS (103 bytes) 
13381 5798 jdk.nas...tion$438$121292A$\^eval\_::L:3187$toCSS (103 bytes) made not entrant 
14272 5798 jdk.nas...tion$438$121292A$\^eval\_::L:3187$toCSS (103 bytes) made zombie 
14778 5682 jdk.nas...tion$446$150019A$\^eval\_::L:4147$toCSS (137 bytes) made not entrant 
14860 6049 jdk.nas...tion$438$121292A$\^eval\_::L:3187$toCSS (103 bytes) 
14890 6056 jdk.nas...tion$446$150019A$\^eval\_::L:4147$toCSS (137 bytes) 
15019 5682 jdk.nas...tion$446$150019A$\^eval\_::L:4147$toCSS (137 bytes) made zombie 
15223 6162 jdk.nas...tion$457$121460$\^eval\_::L:3187$toCSS$isEmpty (31 bytes) 

ответ

0

Это звучит, как вы жертва J в Java Как правило, Java не будет JIT-кода до тех пор, пока он не будет профилировать его, и это звучит точно так, как в этой ситуации.

Теперь : опции, которые вы можете передать при запуске JRE, скомпилируйте все сразу с -Xcomp или после меньшего количества прогонов с -XX:CompileThreshold, но оба они обычно не рекомендуются.

Если все экземпляры JVM действуют как не что иное, как прославленный компилятор, вы можете разумно убежать с попыткой -Xcomp, но если ваша программа будет долговечной, пусть это будет. В любом случае, конечно, я рекомендую пройти -server

+0

Я попытался использовать '-Xcomp' - конечный результат значительно хуже.Общее время запуска увеличилось с 1:40 минут до 15:30. Итак, не уверен, что происходит в JVM за кулисами, но '-Xcomp' ничего не оптимизирует в моем случае. –

+0

Правильно, '-Xcomp' приводит к тому, что JVM компилирует * все * в собственный машинный код и поэтому не рекомендуется. Я бы предложил просмотреть варианты здесь: https://docs.oracle.com/javase/8/docs/technotes/tools/windows/java.html#BABDDFII и включить регистрацию активности компиляции, чтобы вы могли получить представление о том, как Java ускоряет процесс. – Olipro