OpenRewrite unchecked, but always Language Server Background Job(Loading Rewrite Recipes) #925

w6et · 2022-12-14T03:37:16Z

Describe the bug

Version: 4.17.0.RELEASE
when i click "package Explorer" from "java Source Window"

martinlippert · 2022-12-14T08:16:31Z

Thanks @w6et for reporting this, the language server is probably loading the OpenRewrite recipes nevertheless the preference is disabled - and therefore doesn't need to do that. We should change that.

But the activity should really happen just once and not multiple times. Do you see this progress view entry multiple times? And do they run for a very long time (or even all the time)? Or do they disappear from the progress view again?

w6et · 2022-12-14T09:06:03Z

But the activity should really happen just once and not multiple times. Do you see this progress view entry multiple times? And do they run for a very long time (or even all the time)? Or do they disappear from the progress view again?

@martinlippert yes，happen multiple times, and highly increased memory consumption together.
I'm not sure how to trigger languageServer ，I guess（looks like by Progress view）

hover on javaSourceWindow
sendClasspathNotifications
or other else,
when javaSourceWindow hang or other else，started timeout，so languageServer has been launched multiple times.

gbaso · 2022-12-14T14:10:39Z

Same here, Eclipse is unusable due to this. Constantly freezes due to dozens of (hanging) background jobs and has to be force-killed.

BoykoAlex · 2022-12-14T15:23:13Z

@w6et @gbaso I'd like to check if there are more than one language server started in these case or is it just the progress that is never terminated.
II wonder if you could try the following:

Shut down STS and vodecode and make sure that jps command executed from the terminal does not have BootLanguageServerBootApp in the list of java processes.
Start STS, work with your java code. Once you notice multiple Loading Rewrite Recipes jobs in the progress dialog run jps command again and take a note of how many BootLanguageServerBootApp are there. Wait 30 sec and run jps again, check if number of BootLanguageServerBootApp has changed.

Also, I'm curious whether you are seeing multiple Loading Rewrite Recipes jobs at startup of STS or eventually after working in STS for some time. Do you recall performing changes to maven pom or gradle build files right before seeing those rogue jobs?

martinlippert · 2022-12-14T16:15:45Z

@w6et @gbaso Can you also enable the preference to push the logs from the Spring Boot language server via: Preferences -> Language Servers -> Spring Language Servers, then activate the Spring Boot entry, then retry the IDE. From there on, the log from the language server process appears in your Console view. Maybe you can paste the content of that log output while those problems appear that you describe?

In addition to that it would also be interesting to see if the problem completely goes away if you disable the Spring Boot language server altogether from the Preferences -> Language Servers list for all the file associations.

BoykoAlex · 2022-12-14T16:34:36Z

In order not to be bugged down by rogue Loading Rewrite Recipes jobs feel free to disable: Start Language Server at startuo when Spring Boot is a dependency preference setting.

The effect of disabling it is that the Language Server would start only when java source file, boot properties/yaml being edited which equivalent to the behaviour from previous releases.

FYI: The preference setting on means that language server is started when spring-boot is on the classpath of any of the projects in the workspace and shut down when there is no spring-boot on the classpath of any of projects in the workspace. Somehow i suspect that quick language server shutdowns and start up which may result from springg-boot added and removed from the classpath in quick successions may result in the issue you describe here...

gbaso · 2022-12-14T17:21:15Z

@BoykoAlex disabling Start Language Server at startup solved the problem for now.

I'll try to dig in the logs and in jps later today.

gbaso · 2022-12-14T20:26:09Z

@martinlippert Enabling the logs immediately found an issue: startup takes almost 5 minutes, resulting in 1389 occurrences of "Validating Spring Boot version on project" between 29 maven modules. Fair to say this is not expected behaviour.

I'm currently on spring boot 2.6.5.

spring_boot_language_server.log

BoykoAlex · 2022-12-14T20:44:59Z

@gbaso We are working on reducing the number of project reconcile requests as they are too frequent. Some initial work for this but it might help already should be available tomorrow via the nightly build update site: https://dist.springsource.com/snapshot/TOOLS/sts4/nightly/e4.26

Note that unterminated jobs in the progress view originally reported in this issue by @w6et is the result of Boot LS started and shutdown in quick successions on startup. It is a different issue and we are investigating it.

gbaso · 2022-12-14T21:04:53Z

Thanks @BoykoAlex. I also had the problem of multiple LS Loading rewrite recipes. According to jps there is only one BootLanguageServerBootApp, despite multiple loading bars being shown in Eclipse.

I'm curious whether you are seeing multiple Loading Rewrite Recipes jobs at startup of STS or eventually after working in STS for some time.

They start appearing shortly after startup, but they don't seem to be triggered by the startup itself.

Do you recall performing changes to maven pom or gradle build files right before seeing those rogue jobs?

I'm doing maven module refactoring, which includes modifying poms, opening/closing projects and issuing maven updates.

w6et · 2022-12-15T05:32:05Z

According to jps there is only one BootLanguageServerBootApp, despite multiple loading bars being shown in Eclipse.

me too！only one “BootLanguageServerBootApp”（pid changed，old terminated，new created） when i‘m seeing multiple Loading Rewrite Recipes jobs

I'm curious whether you are seeing multiple Loading Rewrite Recipes jobs at startup of STS or eventually after working in STS for some time.

after working in STS for some time.I started muitiple sts.
D:\ide\sts4\SpringToolSuite4.exe --clean -data D:\works\sts41
D:\ide\sts4\SpringToolSuite4.exe --clean -data D:\works\sts42

I'm doing JavaFileName of 'Package Explorer view' to click

Do you recall performing changes to maven pom or gradle build files right before seeing those rogue jobs?

I'm not sure , The issue isn't reproduced yet.:sweat_smile:
(after enabled log、disabling start at startup if boot is a dependency、off some validation enablement, then I restarted and reverted above operations) I'm not sure what effected.
when problemed，the log seems endless(lot of Validating ).
now the log is no more refresh

amcmike3 · 2022-12-20T01:11:27Z

Unsure if I had this specific issue but I had an excessive amount of loading bars from language server background jobs showing in my progress tab and unchecking "Preferences > Language Servers > Spring Langauge Servers > Spring Boot Langauge Server > start language server at start up" like mentioned above solved my issue.

…n into frequent restarts

martinlippert · 2022-12-23T07:25:44Z

Here is a summary of things that you can do to workaround the performance issues in the 4.17.0 release:
#922 (comment)

CyberRookie · 2022-12-27T19:25:49Z

Unsure if I had this specific issue but I had an excessive amount of loading bars from language server background jobs showing in my progress tab and unchecking "Preferences > Language Servers > Spring Langauge Servers > Spring Boot Langauge Server > start language server at start up" like mentioned above solved my issue.

That solved my problem too after updating my STS to the latest Spring Boot Version and Java to SE-17 I was having that issue. Now the Eureka Server registers all my microservices.

Sanjeevan-S · 2022-12-30T18:20:35Z

Unsure if I had this specific issue but I had an excessive amount of loading bars from language server background jobs showing in my progress tab and unchecking "Preferences > Language Servers > Spring Langauge Servers > Spring Boot Langauge Server > start language server at start up" like mentioned above solved my issue.

yep that fixed the problem!

martinlippert · 2023-01-01T17:57:28Z

We will ship a fix for this issue with the upcoming 4.17.1 release.

youcangetme · 2023-05-02T20:18:59Z

OK, here are the logs @martinlippert . The language servers went crazy again :(

We jinxed it by closing this ticket...

metadata.zip

BoykoAlex · 2023-05-02T21:49:00Z

@youcangetme are there files such as .metadata\.bak_1.log bak_0.log etc? Could you please attach those as well?
Seems like the issue with starting/stopping is triggered by 2 Boot LS running at the same time... if that occurs then the infinite start/stop loop kicks off...

youcangetme · 2023-05-03T02:34:27Z

more_metadata.zip

Yep, I do distinctly recall starting a new instance by accident. It is rare for me to do that which is why I remember it.

youcangetme · 2023-05-03T15:39:00Z

I did not do a double start today but on the second start to fix a problem with a mouse the language servers entered a runaway state again.

metadata.zip

BoykoAlex · 2023-05-03T17:57:25Z

Unfortunately eclipse logs don't seem to have enough information to determine what is causing the problem. I have added logging statements in the upstream LSP4E project:
repository-0.13.1-SNAPSHOT.zip

Download the attached repository-0.13.1-SNAPSHOT.zip file. It is the zipped p2 repository to update LSP4E plugins with the changes I've made.

Download the file somewhere i.e. ~/Downloads/
In STS, Help -> Install New Software...
Find and click the Add... button in the opened dialog
Click on Archive... in the new popped up dialog
Select the downloaded repository-0.13.1-SNAPSHOT.zip file, click Add
Check-mark Language Server Support for IDE click next
Proceed with the installation, trust the publisher etc when promted.

Now restart the IDE, reproduce the issue and please send us the eclipse logs once the issue is reproduced. It is important to capture the initialization of STS/Eclipse in the logs hence I'd delete all .log and .bak_x.log files in order not to have old logs before you start reproducing the issue.

I have another idea of what that might be but lets first see the logs

We are trying to fix it for the 4.18.1 release... but if it takes longer that by the end of the week think we'd release and continue our efforts to fix this post 4.18.1.

Thanks very much for helping us to get to the bottom of this pesky issue!

youcangetme · 2023-05-03T20:50:58Z

Ok, I cleared the logs and installed the feature. I will drop a log zip when I get the problem again.

youcangetme · 2023-05-04T04:36:50Z

even_more_metadata.zip

I did not double start my instance this time.

BoykoAlex · 2023-05-04T15:23:49Z

I have added more logging and a possible fix:
repository-0.13.1-SNAPSHOT.zip

Please update again and give it another try :-)

youcangetme · 2023-05-04T20:17:41Z

I deleted the logs and installed the new patch. i will post the logs when it blows up again.

BoykoAlex · 2023-05-04T23:40:26Z

@youcangetme missed one place in the code with a possible fix. Here is the updated zip:
repository-0.13.1-SNAPSHOT.zip

Sorry about the late notice :-\

youcangetme · 2023-05-08T02:43:26Z

mega-metadata.zip

Well, this is with the new snapshot so hopefully you have usable logs.

BoykoAlex · 2023-05-08T20:26:11Z

Looks to me like the issue has two parts to it.

Part One.
The Boot LS process sometimes doesn't start normally. There is no logging info for this as logging didn't seem to start in this case at all.
For example Eclipse side logging is:

ENTRY org.eclipse.lsp4e 1 0 2023-05-07 22:39:47.517
!MESSAGE getLSWrappers(document)

!ENTRY org.eclipse.lsp4e 1 0 2023-05-07 22:39:47.517
!MESSAGE About to start LS via Wrapper `org.eclipse.languageserver.languages.springboot'. Currently started wrappers (total=0):

!ENTRY org.eclipse.lsp4e 1 0 2023-05-07 22:39:47.531
!MESSAGE Creating Wrapper for `org.eclipse.languageserver.languages.springboot' with initialPath=null project=resource

!ENTRY org.eclipse.lsp4e 1 0 2023-05-07 22:39:47.532
!MESSAGE Starting LS 'org.eclipse.languageserver.languages.springboot'

!ENTRY org.springframework.tooling.boot.ls 1 0 2023-05-07 22:39:47.700
!MESSAGE DelegatingStreamConnectionProvider - Starting Boot LS

!ENTRY org.springframework.tooling.ls.eclipse.commons 1 0 2023-05-07 22:39:47.714
!MESSAGE Started org.springframework.tooling.boot.ls LS process 2464

!ENTRY org.eclipse.lsp4e 1 0 2023-05-07 22:39:47.715
!MESSAGE LS `org.eclipse.languageserver.languages.springboot' process is started: 6188

!ENTRY org.eclipse.lsp4e 1 0 2023-05-07 22:39:47.931
!MESSAGE Initializing server-client comm for LS `org.eclipse.languageserver.languages.springboot' with pid=6188

!ENTRY org.eclipse.lsp4e 1 0 2023-05-07 22:39:47.949
!MESSAGE Sending initialize message to LS `org.eclipse.languageserver.languages.springboot' with pid=6188

!ENTRY org.eclipse.lsp4e 2 0 2023-05-07 22:39:48.795
!MESSAGE Could not get if the workspace folder capability is supported due to timeout after 1 second
!STACK 0
java.util.concurrent.TimeoutException
	at java.base/java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1960)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2095)
	at org.eclipse.lsp4e.LanguageServerWrapper.supportsWorkspaceFolderCapability(LanguageServerWrapper.java:587)
	at org.eclipse.lsp4e.LanguageServerWrapper.canOperate(LanguageServerWrapper.java:576)
	at org.eclipse.lsp4e.LanguageServerWrapper.c

There is no matching log entries on the LS side (no entries at 22:39:47 and 22:39:48):

1:18:03.765 [pool-11-thread-1] INFO  o.s.i.v.b.j.u.CompilationUnitCache - CU Cache: invalidate AST for file:///C:/Users/youca/Documents/Eclipse_Workspace_JDK17/eStore_v2/orders/src/main/java/net/subnoize/estore/orders/model/Order.java
01:18:03.790 [pool-11-thread-1] INFO  o.s.i.v.c.l.u.SimpleTextDocumentService - Closed: file:///C:/Users/youca/Documents/Eclipse_Workspace_JDK17/eStore_v2/resource/src/main/java/net/subnoize/estore/orders/OrderController.java
01:18:03.790 [pool-11-thread-1] INFO  o.s.i.v.b.j.u.CompilationUnitCache - CU Cache: invalidate AST for file:///C:/Users/youca/Documents/Eclipse_Workspace_JDK17/eStore_v2/resource/src/main/java/net/subnoize/estore/orders/OrderController.java
22:39:52.748 [main] INFO  o.s.i.v.b.a.BootLanguageServerBootApp - Starting BootLanguageServerBootApp using Java 17.0.6 with PID 1864 (C:\Data\Java\sts-4.18.0.RELEASE\plugins\org.springframework.tooling.boot.ls_1.46.0.202304251920\servers\spring-boot-language-server\BOOT-INF\classes started by youca in C:\Data\Java\sts-4.18.0.RELEASE)
22:39:52.756 [main] INFO  o.s.i.v.b.a.BootLanguageServerBootApp - No active profile set, falling back to 1 default profile: "default"
22:39:54.200 [main] INFO  o.s.i.v.boot.app.SpringSymbolIndex - project listener registered
22:39:54.989 [main] INFO  o.s.i.v.b.a.BootLanguageServerBootApp - Started BootLanguageServerBootApp in 2.635 seconds (process running for 3.151)
22:39:54.990 [main] INFO  o.s.i.v.c.l.LanguageServerRunner - java.home = C:\Data\Java\sts-4.18.0.RELEASE\plugins\org.eclipse.justj.openjdk.hotspot.jre.full.win32.x86_64_17.0.6.v20230204-1729\jre
22:39:54.991 [LanguageServerApp-lifecycle] INFO  o.s.i.v.c.l.LanguageServerRunner - Server ready to start after 3154 ms

Therefore timeouts for this:

org.eclipse.lsp4e.LanguageServerWrapper.supportsWorkspaceFolderCapability(LanguageServerWrapper.java:587)

as nothing has been received from the language server at all, however, the process seem to have started...

Part Two
Attempt to start the second language server while the first one is either stuck or being initialized or just slow. The attempt to start the second language server comes from the fact that the check whether currently started LS can work on a document from one of the projects in the workspace returns false, hence the same definition language server is being started.
The check would start returning true if server was marked as singleton.
Another instance of starting the same boot LS can be initiated from the LanguageServerWrapper#start() method if comm pipe has been closed (failed LS process start i suppose). This re-start is valid though...

I'd try to limit Boot LS t only one process/LS wrapper properly by setting singleton property in the extension point: b19c16c Should be available in the next snapshot build of STS4 for Eclipse. Will post here once available.

Also logging adjusted for lsp4e:
repository-0.13.1-SNAPSHOT.zip

BoykoAlex · 2023-05-09T00:03:02Z

@youcangetme should be ok to install snapshot of sts4 for eclipse from an nightly/snapshot update site found on this page: https://dist.springsource.com/snapshot/STS4/nightly-distributions.html
Combined with lsp4e from the comment above, please, give it another try. The change in STS4 has chances to fix the issue... but lets wait until you try it out.

youcangetme · 2023-05-09T03:00:44Z

Ok, logs reset and everything installed and updated.

BoykoAlex · 2023-05-12T14:34:59Z

@youcangetme how's it going with the new sts4 snapshot and a modified lsp4e? Have you been busy and not had time to watch this stuff or is it just working now? :-)

CyberRookie · 2023-05-12T14:37:23Z

I've been running 4.18.1 release for over a week now and no issues. Good job!

…

________________________________ From: Alex Boyko ***@***.***> Sent: Friday, May 12, 2023 10:35 AM To: spring-projects/sts4 ***@***.***> Cc: Mark Stevens ***@***.***>; Comment ***@***.***> Subject: Re: [spring-projects/sts4] OpenRewrite unchecked, but always Language Server Background Job(Loading Rewrite Recipes) (Issue #925) @youcangetme<https://github.com/youcangetme> how's it going with the new sts4 snapshot and a modified lsp4e? Have you been busy and not had time to watch this stuff or is it just working now? :-) — Reply to this email directly, view it on GitHub<#925 (comment)>, or unsubscribe<https://github.com/notifications/unsubscribe-auth/APLVTXM5IKFLDGJT4LNS7FLXFZDCBANCNFSM6AAAAAAS56MAO4>. You are receiving this because you commented.Message ID: ***@***.***>

youcangetme · 2023-05-14T14:44:53Z

Hmmmm, I have not seen the language server go nuts on any machine with the new patches installed. I am wary to pronounce it "fixed." But I am willing to say (while knocking on wood) "sure, give it prime time exposure and see."

youcangetme · 2023-05-16T03:18:54Z

I still haven't seen anything bad yet and I have been banging on it pretty darn hard.

BoykoAlex · 2023-05-16T14:23:59Z

@youcangetme could you please attach your logs (eclipse and boot ls) from these few past days? Are STS tools working though? Do you see content assists in boot properties files, spring symbols showing up after Ctrl-6, etc?

I think the singleton property for the LS extension point is the real fix to the problem... Stuff that went into LSP4E is mostly for logging... Thus if at some point you switch to just the snapshot distro of STS4 it should work just as well ideally.

youcangetme · 2023-05-18T05:48:16Z

Sorry I missed your message. I will upload the logs in the morning.

youcangetme · 2023-05-19T06:23:41Z

metadata.zip

This one seems awfully small. Sorry for the delay.

BoykoAlex · 2023-05-23T19:55:12Z

@youcangetme I have gone through the logs and it seems fixed to me - only one Boot LS at all times. Seems reasonable to mark this as fixed. The actual fix is in STS4: b19c16c

martinlippert · 2023-05-23T19:57:48Z

Thank you both @BoykoAlex and @youcangetme for your work on this, your patience, and your relentless drive to solve this. Very very much appreciated.

youcangetme · 2023-06-02T01:46:45Z

@martinlippert glad to help. Everything continues to work as expected so I am changing back to the regular distro to keep in sync with my developers.

w6et added status: waiting-for-triage type: bug labels Dec 14, 2022

martinlippert added theme: performance status: needs-investigation for: eclipse something that is specific for Eclipse for: vscode something that is specific for VSCode theme: refactoring and removed status: waiting-for-triage labels Dec 14, 2022

martinlippert added this to the 4.17.1.RELEASE milestone Dec 14, 2022

martinlippert assigned BoykoAlex Dec 14, 2022

martinlippert added a commit that referenced this issue Dec 22, 2022

GH-925: do not use LS wrapper internal API to start boot ls to not ru…

d52b374

…n into frequent restarts

martinlippert mentioned this issue Dec 23, 2022

BootLanguageServerBootApp class is taking all available cpu continuously #932

Closed

martinlippert removed the status: needs-investigation label Jan 1, 2023

martinlippert closed this as completed Jan 1, 2023

martinlippert closed this as completed May 2, 2023

BoykoAlex reopened this May 2, 2023

martinlippert modified the milestones: 4.18.1.RELEASE, 4.19.0.RELEASE May 5, 2023

BoykoAlex closed this as completed May 23, 2023

youcangetme mentioned this issue Jul 17, 2023

Spring Language Server hangs forever #1075

Closed

OpenRewrite unchecked, but always Language Server Background Job(Loading Rewrite Recipes) #925

OpenRewrite unchecked, but always Language Server Background Job(Loading Rewrite Recipes) #925

Comments

w6et commented Dec 14, 2022 • edited by martinlippert Loading

martinlippert commented Dec 14, 2022

w6et commented Dec 14, 2022

gbaso commented Dec 14, 2022

BoykoAlex commented Dec 14, 2022 • edited Loading

martinlippert commented Dec 14, 2022

BoykoAlex commented Dec 14, 2022

gbaso commented Dec 14, 2022

gbaso commented Dec 14, 2022

BoykoAlex commented Dec 14, 2022 • edited Loading

gbaso commented Dec 14, 2022

w6et commented Dec 15, 2022

amcmike3 commented Dec 20, 2022

martinlippert commented Dec 23, 2022

CyberRookie commented Dec 27, 2022

Sanjeevan-S commented Dec 30, 2022

martinlippert commented Jan 1, 2023

youcangetme commented May 2, 2023 • edited Loading

BoykoAlex commented May 2, 2023 • edited Loading

youcangetme commented May 3, 2023

youcangetme commented May 3, 2023

BoykoAlex commented May 3, 2023

youcangetme commented May 3, 2023

youcangetme commented May 4, 2023

BoykoAlex commented May 4, 2023

youcangetme commented May 4, 2023

BoykoAlex commented May 4, 2023

youcangetme commented May 8, 2023

BoykoAlex commented May 8, 2023

BoykoAlex commented May 9, 2023

youcangetme commented May 9, 2023

BoykoAlex commented May 12, 2023

CyberRookie commented May 12, 2023 via email

youcangetme commented May 14, 2023

youcangetme commented May 16, 2023

BoykoAlex commented May 16, 2023 • edited Loading

youcangetme commented May 18, 2023

youcangetme commented May 19, 2023

BoykoAlex commented May 23, 2023

martinlippert commented May 23, 2023

youcangetme commented Jun 2, 2023

w6et commented Dec 14, 2022 •

edited by martinlippert

Loading

BoykoAlex commented Dec 14, 2022 •

edited

Loading

BoykoAlex commented Dec 14, 2022 •

edited

Loading

youcangetme commented May 2, 2023 •

edited

Loading

BoykoAlex commented May 2, 2023 •

edited

Loading

BoykoAlex commented May 16, 2023 •

edited

Loading