Completion cache resets after file recompilation resulting in slow code completion #847

Yanpas · 2018-11-14T11:43:40Z

I have large enough project (about 8000 java files). Code completion works fast if you do not edit a file, but if you do some edits you will wait for any kind of suggestion for several seconds. Typing code becomes a headache.

STR:

Open large project and one java file
Try to edit some lines of code : cut and paste, request autocompletion. It should be fast
Open any ten files in the same project, don't touch them, just open
Repeat step 2, performance will get terribly slow.

Screencast:

fbricon · 2018-11-14T13:12:53Z

Can you tell if it's a regression or not? What's your project topology? Maven/Gradle? Number of modules? files per modules? number of dependencies?

Yanpas · 2018-11-14T13:33:43Z

I can't tell whether it's a regression, since I'm using it for about one month.
Project uses Eclipse's .classpth. There are several maven and gradle projects in working tree, but maven and gradle support is disabled.

Project consists of 220 jar dependencies (<classpathentry kind="lib" in .classpath) and 80 source entries

grepped all sources and calculated number of srcs

cat .classpath | grep 'kind="src"' | awk '{print $3}' | sed -rne 's_path="(.+)".+_\1_p' > flds
cat flds | while read fl; do echo -n "$fl ";  { find $fl -name '*.java' | wc -l ; }; done

Most projects consist of about 10 source files, 10 projects about 100 files and one of more than thousand.

Yanpas · 2018-11-14T13:36:12Z

PC specs:
Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz
32 gigs of RAM

java language server eats 4.9 gigs of RAM

java user settings:

{
   "java.completion.guessMethodArguments": true,
    "java.completion.overwrite": false,
    "java.decompiler.fernflower": {
        "udv": true,
        "ind": "    "
    },
    "java.errors.incompleteClasspath.severity": "ignore",
    "java.format.settings.profile": "GoogleStyle",
    "java.format.settings.url": "/home/yan/.config/eclipse-java-style.xml",
    "java.import.gradle.enabled": false,
    "java.jdt.ls.vmargs": "-noverify -Xmx5G -XX:+UseG1GC -XX:+UseStringDeduplication -XX:+CompactStrings",
    "java.signatureHelp.enabled": true
}

java workspace settings:

{
    "java.import.maven.enabled": false,
}

fbricon · 2018-11-14T13:44:45Z

How's the performance in Eclipse?

fbricon · 2018-11-14T13:49:37Z

Can you enable"java.trace.server":"verbose", then get the logs from the output view after :

code-completion without editing
code-completion while editing

fbricon · 2018-11-14T13:51:53Z

do you have things like automatic save enabled?
can you try after disabling auto build ("java.autobuild.enabled": false)

fbricon · 2018-11-14T13:54:54Z

Project consists of 220 jar dependencies (<classpathentry kind="lib" in .classpath) and 80 source entries

is that in just 1 project .classpath?

Yanpas · 2018-11-14T14:09:42Z

How's the performance in Eclipse?

Eclipse editing works fluent and instant, no matter how I edit. But the project was loading much longer (1-2 minutes I guess)

Yanpas · 2018-11-14T14:16:19Z

Project consists of 220 jar dependencies (<classpathentry kind="lib" in .classpath) and 80 source entries

is that in just 1 project .classpath?

yes

Yanpas · 2018-11-14T14:22:59Z

I've noticed that when I reloaded vscode window and relauched server it became much faster (2-3 times). Still slower than eclipse and feels lagging. But initially it consumes 2.5 gigs of ram. After 1-2 days of usage it uses max available RAM (5 gigs).

Yanpas · 2018-11-14T14:45:33Z

do you have things like automatic save enabled?

"files.autoSave": "off",

can you try after disabling auto build ("java.autobuild.enabled": false)

tried, didn't noticed any difference

Yanpas · 2018-11-14T15:00:22Z

code-completion without editing

https://gist.github.com/Yanpas/6b174057dcc440991a2613b046436ee4

code-completion while editing

https://gist.github.com/Yanpas/229a5f22bae6f274661d4b36b96b9697

Yanpas · 2018-11-14T15:18:50Z

Nonverbose log when I made some edits, entered Array and pressed code completion:

[Trace - 18:17:53] Sending notification 'textDocument/didChange'.
[Trace - 18:17:53] Sending request 'textDocument/completion - (797)'.
[Trace - 18:17:53] Received response 'textDocument/completion - (797)' in 147ms.
[Trace - 18:17:53] Sending request 'completionItem/resolve - (798)'.
[Trace - 18:17:53] Sending request 'workspace/executeCommand - (799)'.
[Trace - 18:17:53] Sending request 'textDocument/codeAction - (800)'.
[Trace - 18:17:53] Sending notification 'textDocument/didChange'.
[Trace - 18:17:53] Received response 'completionItem/resolve - (798)' in 101ms.
[Trace - 18:17:53] Sending request 'completionItem/resolve - (801)'.
[Trace - 18:17:53] Received response 'completionItem/resolve - (801)' in 2ms.
[Trace - 18:17:53] Sending notification 'textDocument/didChange'.
[Trace - 18:17:54] Sending request 'completionItem/resolve - (802)'.
[Trace - 18:17:54] Received response 'completionItem/resolve - (802)' in 3ms.
[Trace - 18:17:54] Sending notification 'textDocument/didChange'.
[Trace - 18:17:54] Sending request 'workspace/executeCommand - (803)'.
[Trace - 18:17:54] Sending request 'textDocument/codeAction - (804)'.
[Trace - 18:17:54] Sending notification '$/cancelRequest'.
[Trace - 18:17:54] Received response 'textDocument/codeAction - (800)' in 604ms. Request failed: The request (id: 800, method: 'textDocument/codeAction') has been cancelled (-32800).
[Trace - 18:17:54] Sending request 'textDocument/documentSymbol - (805)'.
[Trace - 18:17:54] Received notification 'language/progressReport'.
[Trace - 18:17:54] Received notification 'language/progressReport'.
[Trace - 18:17:55] Sending request 'completionItem/resolve - (806)'.
[Trace - 18:17:55] Received response 'completionItem/resolve - (806)' in 2ms.
[Trace - 18:17:55] Received notification 'language/progressReport'.
[Trace - 18:17:55] Received notification 'language/progressReport'.
[Trace - 18:17:55] Received notification 'textDocument/publishDiagnostics'.
[Trace - 18:17:55] Sending notification 'textDocument/didChange'.
[Trace - 18:17:55] Received notification 'textDocument/publishDiagnostics'.
[Trace - 18:17:55] Received notification 'textDocument/publishDiagnostics'.
[Trace - 18:17:55] Sending request 'workspace/executeCommand - (807)'.
[Trace - 18:17:55] Sending notification '$/cancelRequest'.
[Trace - 18:17:55] Sending request 'textDocument/documentSymbol - (808)'.
[Trace - 18:17:56] Sending request 'textDocument/codeAction - (809)'.
[Trace - 18:17:56] Sending notification '$/cancelRequest'.
[Trace - 18:17:56] Sending notification 'textDocument/didChange'.
[Trace - 18:17:56] Sending request 'textDocument/completion - (810)'.
[Trace - 18:17:56] Received notification 'textDocument/publishDiagnostics'.
[Trace - 18:17:56] Received notification 'language/progressReport'.
[Trace - 18:17:56] Received response 'textDocument/documentSymbol - (805)' in 1825ms. Request failed: The request (id: 805, method: 'textDocument/documentSymbol') has been cancelled (-32800).
[Trace - 18:17:56] Received response 'textDocument/codeAction - (804)' in 1925ms. Request failed: The request (id: 804, method: 'textDocument/codeAction') has been cancelled (-32800).
[Trace - 18:17:56] Sending request 'workspace/executeCommand - (811)'.
[Trace - 18:17:56] Sending request 'textDocument/codeAction - (812)'.
[Trace - 18:17:56] Sending notification '$/cancelRequest'.
[Trace - 18:17:56] Sending notification '$/cancelRequest'.
[Trace - 18:17:56] Sending request 'textDocument/completion - (813)'.
[Trace - 18:17:56] Sending notification '$/cancelRequest'.
[Trace - 18:17:56] Sending request 'textDocument/documentSymbol - (814)'.
[Trace - 18:17:56] Received notification 'language/progressReport'.
[Trace - 18:17:57] Received notification 'language/progressReport'.
[Trace - 18:17:57] Received notification 'language/progressReport'.
[Trace - 18:17:57] Received notification 'language/progressReport'.
[Trace - 18:17:57] Received notification 'textDocument/publishDiagnostics'.
[Trace - 18:17:57] Received notification 'textDocument/publishDiagnostics'.
[Trace - 18:17:57] Received notification 'textDocument/publishDiagnostics'.
[Trace - 18:17:58] Sending request 'textDocument/codeAction - (815)'.
[Trace - 18:17:58] Sending notification '$/cancelRequest'.
[Trace - 18:17:58] Received notification 'textDocument/publishDiagnostics'.
[Trace - 18:17:58] Received notification 'language/progressReport'.
[Trace - 18:17:58] Received response 'workspace/executeCommand - (799)' in 4611ms.
[Trace - 18:17:58] Received response 'workspace/executeCommand - (803)' in 4008ms.
[Trace - 18:17:58] Received response 'textDocument/codeAction - (809)' in 2439ms.
[Trace - 18:17:58] Received response 'workspace/executeCommand - (807)' in 2657ms.
[Trace - 18:17:58] Received response 'textDocument/documentSymbol - (808)' in 2557ms.
[Trace - 18:17:58] Received response 'textDocument/completion - (810)' in 2297ms.
[Trace - 18:17:58] Received response 'workspace/executeCommand - (811)' in 2054ms.
[Trace - 18:17:58] Received response 'textDocument/codeAction - (812)' in 2054ms.
[Trace - 18:17:58] Received response 'textDocument/completion - (813)' in 2058ms.
[Trace - 18:17:58] Received response 'textDocument/codeAction - (815)' in 469ms.
[Trace - 18:17:58] Received response 'textDocument/documentSymbol - (814)' in 1985ms.
[Trace - 18:17:58] Sending request 'completionItem/resolve - (816)'.
[Trace - 18:17:58] Received response 'completionItem/resolve - (816)' in 2ms.

fbricon · 2018-11-14T15:52:54Z

can you disable all java extensions but the red hat one?

Yanpas · 2018-11-14T16:31:35Z

Still the same. about 4 seconds it takes to execute textDocument/documentSymbol

Yanpas · 2019-04-08T13:28:47Z

Finally I've pointed out the reason of lags. No matter how much edits you do to the current file and how often do you save it.

Open large project and one java file
Try to edit some lines of code : cut and paste, request autocompletion. It should be fast
Open any ten files in the same project, don't touch them, just open
Repeat step 2, performance will get terribly slow. (I see Validate documents progress bar on each edit, but seems it's progress bar is unrelated to performance)

fbricon · 2019-04-08T13:43:01Z

Thanks for the heads up, that's very useful information. @snjeza is currently looking at some performance improvements that might help here (or not)

Yanpas · 2019-04-09T17:22:48Z

It also looks like closing files gets good performance back. I've made two profiling samples: 1 (one file opened) and M (about 12 files opened):

tmp.zip

snjeza · 2019-04-09T17:59:43Z

@Yanpas could you test https://raw.githubusercontent.com/snjeza/vscode-test/master/java-0.43.1.vsix ?

Yanpas · 2019-04-09T18:09:28Z

@snjeza yeah, much better, I think it resolves this issue.

fbricon · 2019-04-09T18:10:58Z

@snjeza which changes are in your custom build? all of the pending PRs?

snjeza · 2019-04-09T18:24:15Z

@snjeza which changes are in your custom build? all of the pending PRs?

@fbricon I have created a new PR.

fbricon added bug performance content-assist labels Nov 14, 2018

snjeza self-assigned this Apr 8, 2019

snjeza mentioned this issue Apr 9, 2019

Optimize validation #989

Merged

fbricon added this to the Mid April 2019 milestone Apr 9, 2019

fbricon closed this as completed in #989 Apr 9, 2019

fbricon mentioned this issue Apr 16, 2019

Language service status is always '`100% Starting Java Language Server - Importing Maven Projects' redhat-developer/vscode-java#670

Closed

Yanpas mentioned this issue Apr 20, 2019

Completion is buggy #1003

Closed

fbricon mentioned this issue Oct 21, 2019

Is the delay on diagnostics results intentional? #1198

Open

snjeza mentioned this issue Dec 8, 2021

Diagnostics from changes to build configuration not reflected in open source files #1964

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Completion cache resets after file recompilation resulting in slow code completion #847

Completion cache resets after file recompilation resulting in slow code completion #847

Yanpas commented Nov 14, 2018 •

edited

Loading

fbricon commented Nov 14, 2018

Yanpas commented Nov 14, 2018

Yanpas commented Nov 14, 2018 •

edited

Loading

fbricon commented Nov 14, 2018

fbricon commented Nov 14, 2018

fbricon commented Nov 14, 2018

fbricon commented Nov 14, 2018

Yanpas commented Nov 14, 2018 •

edited

Loading

Yanpas commented Nov 14, 2018

Yanpas commented Nov 14, 2018

Yanpas commented Nov 14, 2018 •

edited

Loading

Yanpas commented Nov 14, 2018

Yanpas commented Nov 14, 2018

fbricon commented Nov 14, 2018

Yanpas commented Nov 14, 2018

Yanpas commented Apr 8, 2019 •

edited

Loading

fbricon commented Apr 8, 2019

Yanpas commented Apr 9, 2019

snjeza commented Apr 9, 2019

Yanpas commented Apr 9, 2019

fbricon commented Apr 9, 2019

snjeza commented Apr 9, 2019

Completion cache resets after file recompilation resulting in slow code completion #847

Completion cache resets after file recompilation resulting in slow code completion #847

Comments

Yanpas commented Nov 14, 2018 • edited Loading

fbricon commented Nov 14, 2018

Yanpas commented Nov 14, 2018

Yanpas commented Nov 14, 2018 • edited Loading

fbricon commented Nov 14, 2018

fbricon commented Nov 14, 2018

fbricon commented Nov 14, 2018

fbricon commented Nov 14, 2018

Yanpas commented Nov 14, 2018 • edited Loading

Yanpas commented Nov 14, 2018

Yanpas commented Nov 14, 2018

Yanpas commented Nov 14, 2018 • edited Loading

Yanpas commented Nov 14, 2018

Yanpas commented Nov 14, 2018

fbricon commented Nov 14, 2018

Yanpas commented Nov 14, 2018

Yanpas commented Apr 8, 2019 • edited Loading

fbricon commented Apr 8, 2019

Yanpas commented Apr 9, 2019

snjeza commented Apr 9, 2019

Yanpas commented Apr 9, 2019

fbricon commented Apr 9, 2019

snjeza commented Apr 9, 2019

Yanpas commented Nov 14, 2018 •

edited

Loading

Yanpas commented Nov 14, 2018 •

edited

Loading

Yanpas commented Nov 14, 2018 •

edited

Loading

Yanpas commented Nov 14, 2018 •

edited

Loading

Yanpas commented Apr 8, 2019 •

edited

Loading