Skip to content

[regression] Version 0.81.0 takes more than twice the compilation time than the previous version #2071

Closed
eclipse-jdtls/eclipse.jdt.ls
#1853
Closed
[regression] Version 0.81.0 takes more than twice the compilation time than the previous version#2071
eclipse-jdtls/eclipse.jdt.ls
#1853
Assignees
snjeza
Labels
bugperformanceregression
Milestone
Mid September 2021

Description

@mozhuanzuojing
mozhuanzuojing
opened on Aug 18, 2021

Version 0.81.0 takes more than twice the compilation time than the previous version

Environment
  • Operating System: Windows_NT x64 10.0.19043
  • JDK version: 16
  • Visual Studio Code version: 1.60.0-insider (system setup)
  • Java extension version: 1.81.0
  • gradle wrapper version: 7.2
Steps To Reproduce
  1. just only log file

log.zip

Preview key important logs

[Info - 上午11:48:15] 2021年8月18日上午11:48:15 Updated rom in 74591 ms
[Trace - 上午11:48:23] Received notification 'window/logMessage'.
[Info - 上午11:48:23] 2021年8月18日上午11:48:23 Starting Gradle update for nccmain
[Trace - 上午11:48:23] Received notification 'window/logMessage'.
[Info - 上午11:48:23] 2021年8月18日上午11:48:23 Updated nccmain in 82556 ms
[Trace - 上午11:48:42] Received notification 'window/logMessage'.
[Info - 上午11:48:42] 2021年8月18日上午11:48:42 Timeout while waiting for completion of job: Update project am(33)
[Trace - 上午11:48:42] Received response 'initialize - (0)' in 134202ms.
[Trace - 上午11:48:42] Sending notification 'initialized'.
[Trace - 上午11:48:42] Sending notification 'workspace/didChangeConfiguration'.
[Trace - 上午11:48:42] Received notification 'window/logMessage'.
[Info - 上午11:48:42] 2021年8月18日上午11:48:42 >> initialized

Current Result

build finish 380s

Expected Result

build 134s

Additional Informations

Activity

  1. mozhuanzuojing
    changed the title [-]Version 0.81.0 is more than twice as slow as the previous version[/-] [+]Version 0.81.0 buiding is more than twice as slow as the previous version[/+] on Aug 18, 2021
  2. mozhuanzuojing
    changed the title [-]Version 0.81.0 buiding is more than twice as slow as the previous version[/-] [+]Version 0.81.0 takes more than twice the compilation time than the previous version[/+] on Aug 18, 2021

  3. rgrunber commented on Aug 18, 2021

    @rgrunber
    rgrunber
    on Aug 18, 2021
    Member

    The only differences I'm seeing in our target between 1.2.0 (0.80.0) and 1.3.0 (0.81.0) are : buildship 3.1.5.v20210112-1646-s -> 3.1.5.v20210616-0346-s, m2e 1.17.0.20201112-0751 -> 1.18.2/latest, eclipse I20210621-1800 -> I20210810-1800

    I would probably check the individual execution times of the plugins that comprise the JDT-LS product to get a better idea of where this may be happening.

    $ cat .options
    org.eclipse.osgi/debug/bundleStartTime=true

    (java -Declipse.application=org.eclipse.jdt.ls.core.id1 -Dosgi.bundles.defaultStartLevel=4 -Declipse.product=org.eclipse.jdt.ls.core.product -Dlog.level=ALL -noverify -Xmx1G -jar org.eclipse.jdt.ls.product/target/repository/plugins/org.eclipse.equinox.launcher_*.jar -configuration org.eclipse.jdt.ls.product/target/repository/config_linux/ -debug -data /tmp/foospace --add-modules=ALL-SYSTEM --add-opens java.base/java.util=ALL-UNNAMED --add-opens java.base/java.lang=ALL-UNNAMED 2>&1 1>log.txt) &

    I can try this out also to see if I get any insights.

  4. rgrunber commented on Aug 18, 2021

    @rgrunber
    rgrunber
    on Aug 18, 2021
    Member

    I'm testing on Linux and tried with Java 11 & Java 16 as the runtime environment.

    I don't think there is a major difference for startup of just the language server (which is independent of import+building), at least for me, on Linux. I tried rebuilding JDT-LS based off of the v1.2.0 and v1.3.0 tags as well as simply using the exact server content within vscode-java 0.80.0 and 0.81.0.

    From repeatedly starting the language server 10 times at once, various times, all median start times were generally between 3000-3500ms on machine.

    Do you have a sample project available publicly somewhere so we could compare the actual build time ?

  5. mozhuanzuojing commented on Aug 19, 2021

    @mozhuanzuojing
    mozhuanzuojing
    on Aug 19, 2021
    ContributorAuthor

    @rgrunber Company projects cannot be shared. The following is an analysis from another perspective. Or we can make an appointment, we can use Sunflower software to watch remotely

    Gradle compilation is divided into two steps. The first step is to initialize first, which takes 233 seconds, and the second step officially starts to compile, which takes 240 seconds.The compilation of the previous version 0.80.0 took 150 seconds in total.

    Below is a screenshot of the cpu and jvm compiled by my local project

    Gradle Deamon JVM init and build status

    gradleDeamonBuildStart

    gradleDeamonBuildEnd

    java Language Server JVM init and build status

    javaLanguageServerBuildStart

    javaLanguageServerBuildEnd

    Simple log information records the entire compilation process, the log level is message

    • gradle-server log

    [debug] [gradle-server] Starting server.log

    • java language server log

    javaLanguageServer.log

    • java language syntax server log （ It is strange that the grammar server finally printed the shutdown log）

    javaLanguageSyntaxServer.log

  6. mozhuanzuojing commented on Aug 19, 2021

    @mozhuanzuojing
    mozhuanzuojing
    on Aug 19, 2021
    ContributorAuthor

    I suspect it is related to the current version of bug #2020 fix

    It took 233 seconds to initialize my project, which was more than two minutes. But, The sleep time waiting for the initialization task in eclipse.jdt.ls is only two minutes.

  7. rgrunber commented on Aug 19, 2021

    @rgrunber
    rgrunber
    on Aug 19, 2021
    Member

    In your javaLanguageServer.log , I can see :

    9:22:26 Initializing Language Server
...
9:24:26 Timeout while waiting for completion of job: Update project am(37)

    That definitely seems to be the 2 minute timeout from #2020. Is this also reproducible after cleaning the language server workspace ? CC'ing @snjeza for comment.

  8. snjeza commented on Aug 19, 2021

    @snjeza
    snjeza
    on Aug 19, 2021
    Collaborator

    @mozhuanzuojing Could you check https://raw.githubusercontent.com/snjeza/vscode-test/master/java-0.82.0.vsix?

  9. mozhuanzuojing commented on Aug 20, 2021

    @mozhuanzuojing
    mozhuanzuojing
    on Aug 20, 2021
    ContributorAuthor

    @snjeza @rgrunber

    Now I use java-0.82.0 version to compile my project as follows

    I think 5 minutes is the normal compilation time. Because the initialization operation and the compilation operation are executed sequentially. The two actions of initialization and compilation of version 0.80.0 are executed in parallel, but the parallel execution is wrong. So my previous compilation time was 150 seconds, now it should be about 300 seconds.

    Is my idea correct?

  10. snjeza commented on Aug 21, 2021

    @snjeza
    snjeza
    on Aug 21, 2021
    Collaborator

    @mozhuanzuojing could you, please, test https://github.com/snjeza/vscode-test/raw/master/java-0.82.1.vsix

  11. mozhuanzuojing commented on Aug 21, 2021

    @mozhuanzuojing
    mozhuanzuojing
    on Aug 21, 2021
    ContributorAuthor

    @snjeza @rgrunber

    I use java-0.82.1 version to compile my project. as follows:

    1. Clean Java Language Server Workspace

    2. First compilation. Time consuming：6min 45s
      java-0.82.1-first-build.log

    3. Second compilation. Time consuming：3min 25s
      java-0.82.1-second-build.log

    The first compilation time after clearing the workspace is still about 6 minutes, which is basically the same as the previous version. However, the second compilation was excellent, and it only took about three minutes. This should be the best result. Thank you both. If you read the log and there is no problem, I will close this issue.

  12. snjeza commented on Aug 21, 2021

    @snjeza
    snjeza
    on Aug 21, 2021
    Collaborator

    @mozhuanzuojing Could you, please, check https://github.com/snjeza/vscode-test/raw/master/java-0.82.2.vsix

  13. mozhuanzuojing commented on Aug 22, 2021

    @mozhuanzuojing
    mozhuanzuojing
    on Aug 22, 2021
    ContributorAuthor

    @snjeza

    use java-0.82.2 version to compile my project. as follows:

    1. Clean Java Language Server Workspace

    2. 【0.82.2】First compilation. Time consuming：6min 35s
      java-0.82.2-first-build.log

    3. 【0.82.2】Second compilation. Time consuming：20s
      java-0.82.2-second-build.log

    It's amazing. This result is what we want. Give you a thumbs up, I hope this fix can be released an official patch version, so I can let the team members update.

  14. snjeza commented on Aug 22, 2021

    @snjeza
    snjeza
    on Aug 22, 2021
    Collaborator

    @mozhuanzuojing You have found the regression of eclipse-jdtls/eclipse.jdt.ls#451 Thank you!
    I'm preparing a PR.

  15. snjeza
    self-assigned this
    on Aug 22, 2021
  16. snjeza
    changed the title [-]Version 0.81.0 takes more than twice the compilation time than the previous version[/-] [+][regression] Version 0.81.0 takes more than twice the compilation time than the previous version[/+] on Aug 22, 2021

  17. snjeza commented on Aug 22, 2021

    @snjeza
    snjeza
    on Aug 22, 2021
    Collaborator

    @v-yuyul @itsmaheshkariya @Moses-Everlytic @xiaomaimuchanyiyiba @rgrunber could you, please, check #2020 with https://github.com/snjeza/vscode-test/raw/master/java-0.82.2.vsix

  18. rgrunber
    added
    bug
    performance
    regression
    on Aug 23, 2021

  19. rgrunber commented on Aug 23, 2021

    @rgrunber
    rgrunber
    on Aug 23, 2021
    Member

    @v-yuyul @itsmaheshkariya @Moses-Everlytic @xiaomaimuchanyiyiba @rgrunber could you, please, check #2020 with https://github.com/snjeza/vscode-test/raw/master/java-0.82.2.vsix

    I've tried your vsix with spring-rest-client-examples and the project import completes as expected.

  20. rgrunber
    added this to the Mid September 2021 milestone on Aug 23, 2021

  21. snjeza commented on Aug 23, 2021

    @snjeza
    snjeza
    on Aug 23, 2021
    Collaborator

    I've tried your vsix with spring-rest-client-examples and the project import completes as expected.

    @rgrunber Great!. I have created the PR - eclipse-jdtls/eclipse.jdt.ls#1853
    Could you check eclipse-jdtls/eclipse.jdt.ls#451

  22. snjeza
    closed this as completedin eclipse-jdtls/eclipse.jdt.ls#1853on Aug 23, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

bugperformanceregression

Type

No type

Projects

No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions