[vscode] Spring Boot Tools slow down code complete

[degbug]

Describe the bug
when I install Spring Boot Tools in vscode, it slow down the speed of code completions.

I seen the plugin log show :

11:47:32.155 [pool-8-thread-1] INFO  o.s.i.v.c.l.u.SimpleTextDocumentService - change message work done in 1723ms

To Reproduce

Sample

https://github.com/degbug/demo

this is the log file:
boot.log.txt

[martinlippert]

Thanks for reporting this @degbug. Slowing down typing speed or completion performance is an absolute no-go here. We need to investigate. Thanks for attaching the log output, that is a great starting point.

From what I can see, it looks like the slowdown happens sometimes, and sometimes it doesn't. Did you observe any special action or sequence of activities that triggers the slowdown?

[degbug]

Thanks for reporting this @degbug. Slowing down typing speed or completion performance is an absolute no-go here. We need to investigate. Thanks for attaching the log output, that is a great starting point.

From what I can see, it looks like the slowdown happens sometimes, and sometimes it doesn't. Did you observe any special action or sequence of activities that triggers the slowdown?

@martinlippert No, I didn't observed. When I first open the project and first typing is quickly, but then it become very easy to triggers the slowdown. But I don't know what cause this.
The log file contains many error log, this may affect this?

[youngm]

I'm having a similar issue with 4.15.2 on eclipse. I didn't have time to dig into it and create an issue/reproduction. I had to revert to 4.15.1 to get my work done.

[BoykoAlex]

@degbug please try this vsix and let us know if this works better for you: https://s3.us-west-1.amazonaws.com/s3-test.spring.io/sts4/vscode-extensions/snapshots/vscode-spring-boot-1.38.0-202208052243.vsix
@youngm please try upgrading STS eclipse from the snapshot update site. Should be good to update on Monday. Curious if it works any better: https://dist.springsource.com/snapshot/TOOLS/sts4/nightly/e4.24

[degbug]

@degbug please try this vsix and let us know if this works better for you: https://s3.us-west-1.amazonaws.com/s3-test.spring.io/sts4/vscode-extensions/snapshots/vscode-spring-boot-1.38.0-202208052243.vsix @youngm please try upgrading STS eclipse from the snapshot update site. Should be good to update on Monday. Curious if it works any better: https://dist.springsource.com/snapshot/TOOLS/sts4/nightly/e4.24

@BoykoAlex I have try vscode-spring-boot-1.38.0-202208052243.vsix, It works better than before. but still work slow than disable the vscode-spring-boot extensions.

this is the log file:
boot.log6.txt

And I saw error in log:

11:19:21.762 [pool-3-thread-1] ERROR o.s.i.v.b.j.utils.SymbolCacheOnDisc - cannot write symbol cache
java.io.FileNotFoundException: /Users/degbug/.sts4/.symbolCache/degbug-auto-task-java--A71297B3246476FA87DEC5893F93A8BB.json (Too many open files)
	at java.base/java.io.FileOutputStream.open0(Native Method)
	at java.base/java.io.FileOutputStream.open(Unknown Source)
	at java.base/java.io.FileOutputStream.<init>(Unknown Source)
	at java.base/java.io.FileOutputStream.<init>(Unknown Source)
	at java.base/java.io.FileWriter.<init>(Unknown Source)
	at org.springframework.ide.vscode.boot.java.utils.SymbolCacheOnDisc.save(SymbolCacheOnDisc.java:259)
	at org.springframework.ide.vscode.boot.java.utils.SymbolCacheOnDisc.update(SymbolCacheOnDisc.java:236)
	at org.springframework.ide.vscode.boot.java.utils.SpringIndexerJava.scanFilesInternally(SpringIndexerJava.java:316)
	at org.springframework.ide.vscode.boot.java.utils.SpringIndexerJava.scanAffectedFiles(SpringIndexerJava.java:347)
	at org.springframework.ide.vscode.boot.java.utils.SpringIndexerJava.scanFiles(SpringIndexerJava.java:191)
	at org.springframework.ide.vscode.boot.java.utils.SpringIndexerJava.updateFiles(SpringIndexerJava.java:145)
	at org.springframework.ide.vscode.boot.app.SpringSymbolIndex.lambda$updateItems$28(SpringSymbolIndex.java:727)
	at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.base/java.lang.Thread.run(Unknown Source)

[BoykoAlex]

@degbug does it feel slower than 1.36 of spring boot tools extension?

[degbug]

@BoykoAlex I tried and feel it slower than 1.36.

vscode-spring-boot-1.38.0-202208052243.vsix:

1.36:

[martinlippert]

Thanks again @degbug for attaching the log output. The latest one looks okay-ish from the completion standpoint, so I am really surprised to see that version 1.38 is so much slower (thanks for the recordings, looks indeed quite terrible). More investigations on our side necessary, I guess. Will keep you updated here.

And thanks a lot for testing snapshot builds for us, this is extremely useful. Hope you find the time to test additional snapshots in the future around this issue.

[degbug]

@martinlippert This the logs:

vscode-spring-boot-1.38.0-202208052243:

boot.log1.38.txt

1.36:
boot.log1.36.txt

And I am glad to test additional snapshots in the future.

[martinlippert]

Quick update:

I tried this with the various versions. I can clearly reproduce the slowdown when using the latest release version 1.37.0, I can clearly see it running A LOT faster and more fluent with 1.36.0. The snapshot version 1.38.0-202208052243 seems to be a lot faster than 1.37.0 faster than your recording from above, but not quite at the 1.36.0 level.

The question is, why. The log indicate that the overall content-assist performance from the Spring Boot language server seems to be okay-ish and fast, so it doesn't look like the editor waits for the language server to return content-assist information.

Looks like some additional investigations are necessary here... We will continue with that...

[martinlippert]

When looking at what exactly the language server is doing, it looks to me like nothing is really blocking the code completion anymore, but too much other stuff is going on:

thread-dump-while-busy.txt

[BoykoAlex]

I've pushed d557c0d to turn off the Rewrite reconcile bits by default. Will wait for the build to go through, smoke test it and then provide a link to the build here

[BoykoAlex]

@degbug Here is the new build to try: https://dist.springsource.com/snapshot/STS4/nightly-distributions.html At the bottom of the page please download vscode-spring-boot vsix file. I hope typing will become the same as before. If this is the case wonder if you could find in Preferences -> Settings then under Extensions -> Boot-Java Config find the setting Boot-java › Rewrite: Reconcile (should be unchecked by default) check mark and try typing again just like before. Do you see much difference?

[degbug]

@degbug Here is the new build to try: https://dist.springsource.com/snapshot/STS4/nightly-distributions.html At the bottom of the page please download vscode-spring-boot vsix file. I hope typing will become the same as before. If this is the case wonder if you could find in Preferences -> Settings then under Extensions -> Boot-Java Config find the setting Boot-java › Rewrite: Reconcile (should be unchecked by default) check mark and try typing again just like before. Do you see much difference?

@BoykoAlex
I tried vscode-spring-boot-1.38.0-202208091607.vsix and feel it faster than vscode-spring-boot-1.38.0-202208052243.vsix。 And feel like 1.36.

But no matter I enable or disable the Rewrite: Reconcile option. I feel it behavior is same.

This is the log first install the vscode-spring-boot-1.38.0-202208091607.vsix
boot.log1.38.nightly_open_and_close.txt

And I notice that when I enable the Rewrite: Reconcile option, the log can not output.

When I reopen the project it appear.
this is the log after I reopen project:
boot.log1.38.nightly_close.txt

And this is the log of vscode-spring-boot-1.38.0-202208052243.vsix.
When I rollback to vscode-spring-boot-1.38.0-202208052243.vsix it become slowly.
boot.log1.38_0805.txt

[BoykoAlex]

Thanks very much for trying the build out :-) Sounded like https://s3-us-west-1.amazonaws.com/s3-test.spring.io/sts4/vscode-extensions/snapshots/vscode-spring-boot-1.38.0-202208091607.vsix worked just like 1.36 and in both cases: rewrite reconcile off and on. If this is correct I suppose we should get to start releasing STS4 with the fix we've put in.

[youngm]

FWIW, I tried out the latest nightly in eclipse and the slowness I was experiencing appears to be fixed as well.

[martinlippert]

@youngm Thanks for trying this and letting us know, very very much appreciated. The maintenance release 4.15.3 should go live tomorrow (most likely).