Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Spring Boot Validations Builder hung seemingly forever #1103

Closed
davidmichaelkarr opened this issue Aug 24, 2023 · 22 comments
Closed

Spring Boot Validations Builder hung seemingly forever #1103

davidmichaelkarr opened this issue Aug 24, 2023 · 22 comments

Comments

@davidmichaelkarr
Copy link

I posted the following on SO a little while ago: https://stackoverflow.com/questions/76972725/my-eclipse-with-springboot-has-been-running-spring-boot-validations-builder-on . I'm having trouble updating the post to add the "spring-tools-4" tag, or a screenshot.

Rephrasing the post, my Eclipse (2023-06) has been hung on "Spring Boot Validations Builder" for a couple of hours now. The progress bar hasn't moved at all. I attempted to cancel it a long time ago, and all it did was add "(Cancel Requested)", but it's still been running for a long time since I did that.

Earlier today, I found that the Spring Boot Language Server bg job was hanging for long periods. I ended up simply killing the SBLS javaw job, which seemed to make the bg job go away for a while, but it always returned. I then tried rebooting (Windows 11), and now I'm stuck in this SBVB loop.

@martinlippert
Copy link
Member

My assumption is that this is related to #1068. But it is somewhat hard to tell whether this is really the same issue without further details here.

We could verify this by capturing a thread dump of the BootLanguageServerApp process that is running side-by-side with your IDE while the validation is not making any progress anymore and attach that here. That might at least reveal whether this is the same issue or a different one. But the changes are very high that this is related.

In the meantime, please disable the Reconciling of Java Sources on the Preferences -> Spring -> Open Rewrite, that should help to avoid this issue. It also disables the validations that would otherwise show up in your source code, but the next version of the tools will bring back this feature then for you.

@slavap
Copy link

slavap commented Aug 25, 2023

@martinlippert

In the meantime, please disable the Reconciling of Java Sources on the Preferences -> Spring -> Open Rewrite, that should help to avoid this issue.

I have the same problem with always "executing" Spring Boot Language Server - and disable Reconciling does not help at all.

@davidmichaelkarr
Copy link
Author

I had already disabled that flag today after this started happening, and I've since restarted Eclipse. It made no difference.

However, I have managed to get past this, in an unfortunate way. This hanging has always been happening on the same project, so I restarted Eclipse and quickly closed the project before it could get stuck again. Problem solved, at least until I have to look at this project again, which is likely, considering it's one of the projects my team maintains. Frankly, I think it's likely this is some problem with Groovy. That service has a handful of Groovy tests (which do nothing that a plain Java test could do). One of our devs is tasked with replacing the Groovy tests with Java tests, so perhaps I'll be able to open that project again soon, except for the fact that he is likely going to be asking me for help with that.

Despite the fact that closing the project fixed the SBVB hang, the "Spring Boot Language Server" bg job is still running continuously. I don't know if that will ever complete.

A version that fixes all of this couldn't come soon enough.

@davidmichaelkarr
Copy link
Author

And if it matters, the SBLS bg job is still running, 8 hours later. I don't believe it will stop unless I manually kill the process, and then it will likely just restart. It's not clear to me what the impact is of it running.

@tommai78101
Copy link

tommai78101 commented Aug 25, 2023

I have the same issue. Attached are some log messages with some error exceptions. Would this help? The logs would eventually stay stuck when the Spring Boot Language Server kept running non-stop in the background.

10:07:15.213 [main] INFO  o.s.i.v.b.a.BootLanguageServerBootApp - Starting BootLanguageServerBootApp using Java 17.0.7 with PID 28592 (C:\Users\user\.p2\pool\plugins\org.springframework.tooling.boot.ls_1.48.0.202308011907\servers\spring-boot-language-server\BOOT-INF\classes started by user in C:\WINDOWS\System32)
10:07:15.220 [main] INFO  o.s.i.v.b.a.BootLanguageServerBootApp - No active profile set, falling back to 1 default profile: "default"
10:07:18.259 [main] INFO  o.s.i.v.boot.app.SpringSymbolIndex - project listener registered
10:07:18.860 [main] INFO  o.s.i.v.b.a.BootLanguageServerBootApp - Started BootLanguageServerBootApp in 4.727 seconds (process running for 6.546)
10:07:18.863 [main] INFO  o.s.i.v.c.l.LanguageServerRunner - java.home = C:\devtools\temurin-jdk-17
10:07:18.867 [LanguageServerApp-lifecycle] INFO  o.s.i.v.c.l.LanguageServerRunner - Server ready to start after 6552 ms
10:07:18.867 [LanguageServerApp-lifecycle] INFO  o.s.i.v.c.l.LanguageServerRunner - Starting LS as client
10:07:18.867 [LanguageServerApp-lifecycle] INFO  o.s.i.v.c.l.LanguageServerRunner - Connected to parent using stdio
10:07:19.077 [pool-12-thread-1] INFO  o.s.i.v.c.l.u.SimpleLanguageServer - Initializing
10:07:19.121 [pool-12-thread-1] INFO  o.s.i.v.c.l.u.CompletionServerCapabilityRegistration - hasDynamicCompletionRegistration = false
10:07:19.123 [pool-12-thread-1] INFO  o.s.i.v.c.l.u.CompletionServerCapabilityRegistration - Registering Completion Capability Statically
10:07:19.123 [pool-12-thread-1] INFO  o.s.i.v.c.l.u.SimpleLanguageServer - Returning server capabilities to client
10:07:19.214 [Simple-Language-Server main thread] INFO  o.s.i.v.b.j.h.BootJavaProjectReconcilerScheduler - Starting project reconciler for Java sources
10:07:19.219 [pool-12-thread-1] INFO  o.s.i.v.c.l.u.SimpleTextDocumentService - change arrived: 1
10:07:19.220 [Simple-Language-Server main thread] INFO  o.s.i.v.b.a.BootVersionValidationConfig - Started Boot Version reconciler
10:07:19.223 [Simple-Language-Server main thread] INFO  o.s.i.v.b.jdt.ls.JdtLsProjectCache - INIT CLASSPATH LISTENER enableClasspath=true
10:07:19.225 [Simple-Language-Server main thread] INFO  o.s.i.v.b.jdt.ls.JdtLsProjectCache - Enable classpath listener enabled = true current enablement = false
10:07:19.225 [Simple-Language-Server main thread] INFO  o.s.i.v.b.jdt.ls.JdtLsProjectCache - Adding classpath listener enabled=true
10:07:19.225 [Simple-Language-Server main thread] INFO  o.s.i.v.b.jdt.ls.JdtLsProjectCache - Project Observer is supported
10:07:19.249 [pool-12-thread-1] INFO  o.s.i.v.b.j.u.CompilationUnitCache - Invalidate AST for MyFile.java
10:07:19.258 [pool-4-thread-1] INFO  o.s.i.v.b.j.u.CompilationUnitCache - CU Cache: work item submitted for doc MyFile.java
10:07:19.261 [pool-12-thread-1] INFO  o.s.i.v.boot.app.SpringSymbolIndex - update settings of spring indexer - start
10:07:19.262 [pool-12-thread-1] INFO  o.s.i.v.boot.app.SpringSymbolIndex - update settings of spring indexer - done
10:07:19.269 [pool-12-thread-1] INFO  o.s.i.v.b.j.BootJavaLanguageServerComponents - update live process tracker settings - start
10:07:19.269 [pool-12-thread-1] INFO  o.s.i.v.b.j.BootJavaLanguageServerComponents - update live process tracker settings - done
10:07:19.269 [ForkJoinPool.commonPool-worker-1] INFO  o.s.i.v.b.j.r.RewriteRecipeRepository - Loading Rewrite Recipes...
10:07:19.272 [pool-12-thread-1] INFO  o.s.i.v.b.j.l.v.SpringProcessConnectorRemote - updating settings for remote processses to track - start
10:07:19.272 [pool-12-thread-1] INFO  o.s.i.v.b.j.l.v.SpringProcessConnectorRemote - updating settings for remote processses to track - done
10:07:19.398 [Simple-Language-Server main thread] INFO  o.s.i.v.c.l.u.SimpleLanguageServer - Initialization completed after 7083 ms
10:07:21.410 [pool-12-thread-1] INFO  o.s.i.v.boot.app.SpringSymbolIndex - update settings of spring indexer - start
10:07:21.411 [pool-12-thread-1] INFO  o.s.i.v.boot.app.SpringSymbolIndex - update settings of spring indexer - done
10:07:21.417 [pool-12-thread-1] INFO  o.s.i.v.b.j.BootJavaLanguageServerComponents - update live process tracker settings - start
10:07:21.417 [pool-12-thread-1] INFO  o.s.i.v.b.j.BootJavaLanguageServerComponents - update live process tracker settings - done
10:07:21.418 [pool-12-thread-1] INFO  o.s.i.v.b.j.l.v.SpringProcessConnectorRemote - updating settings for remote processses to track - start
10:07:21.418 [pool-12-thread-1] INFO  o.s.i.v.b.j.l.v.SpringProcessConnectorRemote - updating settings for remote processses to track - done
10:07:23.731 [Simple-Language-Server main thread] INFO  o.s.i.v.boot.app.SpringSymbolIndex - project created event: ProjectA
10:07:23.844 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files for symbols for project: ProjectA - no. of files: 144
10:07:23.848 [Simple-Language-Server main thread] INFO  o.s.i.v.boot.app.SpringSymbolIndex - project created event: ProjectA
10:07:23.898 [pool-4-thread-2] INFO  o.s.i.v.b.j.u.CompilationUnitCache - CU Cache: work item submitted for doc MyFile.java
10:07:23.924 [ForkJoinPool.commonPool-worker-2] INFO  o.s.i.v.b.j.u.CompilationUnitCache - Started parsing CU for MyFile.java
10:07:23.936 [ForkJoinPool.commonPool-worker-2] INFO  o.s.i.v.b.j.u.CompilationUnitCache - Creating name env for project 'ProjectA'
10:07:24.585 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files, AST parse, pass 1 for files: 144
10:07:32.640 [pool-12-thread-1] INFO  o.s.i.v.boot.app.SpringSymbolIndex - Update document [file changed]: MyFile.java
10:07:42.082 [pool-12-thread-1] INFO  o.s.i.v.b.j.u.CompilationUnitCache - Removing and cleaning up name env for project ProjectA
10:07:42.143 [ForkJoinPool.commonPool-worker-2] ERROR o.s.i.v.boot.java.utils.CUResolver - {}
java.lang.reflect.InvocationTargetException: null
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at org.springframework.ide.vscode.boot.java.utils.CUResolver.resolve(CUResolver.java:273)
	at org.springframework.ide.vscode.boot.java.utils.CompilationUnitCache.parse2(CompilationUnitCache.java:283)
	at org.springframework.ide.vscode.boot.java.utils.CompilationUnitCache.lambda$requestCU$3(CompilationUnitCache.java:245)
	at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1768)
	at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.exec(CompletableFuture.java:1760)
	at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:373)
	at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1182)
	at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1655)
	at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1622)
	at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:165)
Caused by: java.lang.NullPointerException: Cannot invoke "java.util.zip.ZipFile.entries()" because "this.zipFile" is null
	at org.eclipse.jdt.internal.compiler.batch.ClasspathJar.getModulesDeclaringPackage(ClasspathJar.java:244)
	at org.eclipse.jdt.internal.compiler.batch.ClasspathLocation.isPackage(ClasspathLocation.java:184)
	at org.eclipse.jdt.internal.compiler.batch.ClasspathJar.findClass(ClasspathJar.java:119)
	at org.eclipse.jdt.internal.compiler.batch.FileSystem.internalFindClass(FileSystem.java:512)
	at org.eclipse.jdt.internal.compiler.batch.FileSystem.findClass(FileSystem.java:435)
	at org.eclipse.jdt.internal.compiler.batch.FileSystem.findType(FileSystem.java:532)
	at org.eclipse.jdt.internal.compiler.lookup.LookupEnvironment.lambda$0(LookupEnvironment.java:240)
	at org.eclipse.jdt.internal.compiler.lookup.LookupEnvironment.askForTypeFromModules(LookupEnvironment.java:375)
	at org.eclipse.jdt.internal.compiler.lookup.LookupEnvironment.askForType(LookupEnvironment.java:239)
	at org.eclipse.jdt.internal.compiler.lookup.UnresolvedReferenceBinding.resolve(UnresolvedReferenceBinding.java:116)
	at org.eclipse.jdt.internal.compiler.lookup.BinaryTypeBinding.resolveType(BinaryTypeBinding.java:251)
	at org.eclipse.jdt.internal.compiler.lookup.PackageBinding.getTypeOrPackage(PackageBinding.java:252)
	at org.eclipse.jdt.internal.compiler.lookup.CompilationUnitScope.findImport(CompilationUnitScope.java:578)
	at org.eclipse.jdt.internal.compiler.lookup.CompilationUnitScope.findSingleImport(CompilationUnitScope.java:650)
	at org.eclipse.jdt.internal.compiler.lookup.CompilationUnitScope.faultInImports(CompilationUnitScope.java:479)
	at org.eclipse.jdt.internal.compiler.lookup.CompilationUnitScope.faultInTypes(CompilationUnitScope.java:552)
	at org.eclipse.jdt.core.dom.CompilationUnitResolver.resolve(CompilationUnitResolver.java:1311)
	... 14 common frames omitted
10:07:42.534 [ForkJoinPool.commonPool-worker-2] ERROR o.s.i.v.boot.java.utils.CUResolver - {}
java.lang.reflect.InvocationTargetException: null
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at org.springframework.ide.vscode.boot.java.utils.CUResolver.convert(CUResolver.java:322)
	at org.springframework.ide.vscode.boot.java.utils.CompilationUnitCache.parse2(CompilationUnitCache.java:290)
	at org.springframework.ide.vscode.boot.java.utils.CompilationUnitCache.lambda$requestCU$3(CompilationUnitCache.java:245)
	at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1768)
	at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.exec(CompletableFuture.java:1760)
	at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:373)
	at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1182)
	at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1655)
	at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1622)
	at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:165)
Caused by: java.lang.NullPointerException: Cannot read field "scope" because "compilationUnitDeclaration" is null
	at org.eclipse.jdt.core.dom.CompilationUnitResolver.convert(CompilationUnitResolver.java:334)
	at org.eclipse.jdt.core.dom.CompilationUnitResolver.convert(CompilationUnitResolver.java:299)
	... 14 common frames omitted
10:07:42.535 [ForkJoinPool.commonPool-worker-2] INFO  o.s.i.v.b.j.u.CompilationUnitCache - Parsed successfully CU for MyFile.java
10:07:47.100 [pool-4-thread-2] INFO  o.s.i.v.b.j.u.CompilationUnitCache - CU Cache: work item submitted for doc MyFile.java
10:07:50.429 [ForkJoinPool.commonPool-worker-1] INFO  o.s.i.v.b.j.r.RewriteRecipeRepository - Done loading Rewrite Recipes
10:07:50.433 [ForkJoinPool.commonPool-worker-1] INFO  o.s.i.v.b.a.BootLanguageServerInitializer - Triggering reconcile on all open documents
10:07:50.444 [ForkJoinPool.commonPool-worker-1] INFO  o.s.i.v.b.j.h.BootJavaProjectReconcilerScheduler - Started project reconciler for Java sources
10:07:50.951 [Reconciler-1] INFO  o.s.i.v.b.j.u.CompilationUnitCache - CU Cache: work item submitted for doc MyFile.java
10:07:50.951 [Reconciler-1] INFO  o.s.i.v.b.j.r.JdtReconciler - reconciling (JDT): MyFile.java done in 2ms
10:07:51.533 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files done, number of symbols created: 2055
10:07:51.746 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files for symbols for project: ProjectA took ms: 27902
10:07:51.750 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files for symbols for project: ProjectA - no. of files: 0
10:07:51.766 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files used cached data: ProjectA - no. of cached symbols retrieved: 0
10:07:51.768 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files for symbols for project: ProjectA took ms: 20
10:07:51.803 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files for symbols for project: ats - no. of files: 68
10:07:52.011 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files, AST parse, pass 1 for files: 68
10:07:55.739 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files done, number of symbols created: 351
10:07:55.799 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files for symbols for project: ats took ms: 3996
10:07:55.801 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files for symbols for project: ats - no. of files: 0
10:07:55.805 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files used cached data: ats - no. of cached symbols retrieved: 0
10:07:55.806 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files for symbols for project: ats took ms: 7
10:07:55.896 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files for symbols for project: ProjectA - no. of files: 639
10:07:56.291 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files, AST parse, pass 1 for files: 639
10:08:01.156 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files done, number of symbols created: 523
10:08:01.415 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files for symbols for project: ProjectA took ms: 5519
10:08:01.416 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files for symbols for project: ProjectA - no. of files: 0
10:08:01.420 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files used cached data: ProjectA - no. of cached symbols retrieved: 0
10:08:01.420 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files for symbols for project: ProjectA took ms: 5
10:08:01.435 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files for symbols for project: ProjectA - no. of files: 16
10:08:01.553 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files used cached data: ProjectA - no. of cached symbols retrieved: 43
10:08:01.553 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files restored cached dependency data: 0 - no. of cached dependencies: {}
10:08:01.553 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files for symbols for project: ProjectA took ms: 118
10:08:01.554 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files for symbols for project: ProjectA - no. of files: 0
10:08:01.557 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files used cached data: ProjectA - no. of cached symbols retrieved: 0
10:08:01.558 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files for symbols for project: ProjectA took ms: 5
10:08:01.604 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files for symbols for project: ProjectA - no. of files: 135
10:08:01.788 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files used cached data: ProjectA - no. of cached symbols retrieved: 725
10:08:01.789 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files restored cached dependency data: 0 - no. of cached dependencies: {}
10:08:01.792 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files for symbols for project: ProjectA took ms: 188
10:08:01.793 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files for symbols for project: ProjectA - no. of files: 0
10:08:01.797 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files used cached data: ProjectA - no. of cached symbols retrieved: 0
10:08:01.797 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files for symbols for project: ProjectA took ms: 5
10:08:01.823 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files for symbols for project: ProjectA - no. of files: 59
10:08:01.955 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files used cached data: ProjectA - no. of cached symbols retrieved: 142
10:08:01.955 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files restored cached dependency data: 0 - no. of cached dependencies: {}
10:08:01.956 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files for symbols for project: ProjectA took ms: 133
10:08:01.957 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files for symbols for project: ProjectA - no. of files: 0
10:08:01.960 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files used cached data: ProjectA - no. of cached symbols retrieved: 0
10:08:01.960 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files for symbols for project: ProjectA took ms: 4
10:08:01.987 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files for symbols for project: ProjectA - no. of files: 28
10:08:02.116 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files used cached data: ProjectA - no. of cached symbols retrieved: 118
10:08:02.116 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files restored cached dependency data: 0 - no. of cached dependencies: {}
10:08:02.116 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files for symbols for project: ProjectA took ms: 128
10:08:02.117 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files for symbols for project: ProjectA - no. of files: 0
10:08:02.121 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files used cached data: ProjectA - no. of cached symbols retrieved: 0
10:08:02.121 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files for symbols for project: ProjectA took ms: 5
10:08:02.526 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files for symbols for project: ProjectA - no. of files: 4139
10:08:03.948 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files, AST parse, pass 1 for files: 4139
10:08:15.867 [pool-12-thread-1] INFO  o.s.i.v.boot.app.SpringSymbolIndex - Update document [file changed]: MyFile.java
10:09:05.990 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files done, number of symbols created: 19
10:09:06.782 [pool-5-thread-1] INFO  o.s.i.v.b.j.utils.SpringIndexerJava - scan java files for symbols for project: ProjectA took ms: 64256
10:09:06.783 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files for symbols for project: ProjectA - no. of files: 0
10:09:06.784 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files used cached data: ProjectA - no. of cached symbols retrieved: 0
10:09:06.784 [pool-5-thread-1] INFO  o.s.i.v.b.j.u.SpringFactoriesIndexer - scan factories files for symbols for project: ProjectA took ms: 2

I also have the "Reconciling of Java Sources" disabled, but I noticed in the log messages, it is still attempting to reconcile the Java sources and ignoring this option.

image

@slavap
Copy link

slavap commented Aug 26, 2023

@martinlippert
Yes, checkboxes are not working probably, I have:
image

And despite of that still see in console:

18:18:00.616 [ForkJoinPool.commonPool-worker-1] INFO  o.s.i.v.b.a.BootLanguageServerInitializer - Triggering reconcile on all open documents
18:18:00.619 [ForkJoinPool.commonPool-worker-1] INFO  o.s.i.v.b.j.h.BootJavaProjectReconcilerScheduler - Started project reconciler for Java sources

@BoykoAlex
Copy link
Contributor

BoykoAlex commented Aug 27, 2023

There must be log statements for each reconciled project with time it took. Do you see these log statements while OR reconciling is off?

@BoykoAlex
Copy link
Contributor

And if it matters, the SBLS bg job is still running, 8 hours later. I don't believe it will stop unless I manually kill the process, and then it will likely just restart. It's not clear to me what the impact is of it running.

@davidmichaelkarr The background job is unlikely a job... it is just a rogue progress monitor, hence it is not something severe but is annoying and deserves to be fixed.

@martinlippert
Copy link
Member

While looking at this again, I think my initial thought that this might be related to the slow performance of the Java source file reconciling seems to be wrong and misleading. The screenshot on the related SO issue (https://stackoverflow.com/questions/76972725/my-eclipse-with-spring-boot-has-been-running-spring-boot-validations-builder-o) shows the Spring Boot Validations Builder in the progress view in addition to the generic language server progress bar, so I think we need to look more into the details here of what exactly happens while those progress bars don't finish.

Can you capture a thread dump of both the IDE process (SpringToolSuite4) as well as the language server process (BootLanguageServerApp) while this happens?

And @davidmichaelkarr, you mentioned that this happens for a specific project. Can you share that project with us? Or can you create a sample (or stripped down version of that) project and share that with us, if it reproduces the issue?

@davidmichaelkarr
Copy link
Author

I won't be able to share that project, and I have no idea what aspect of it is contributing to this problem.

I will reopen the project and verify I can get this behavior again, and get those thread dumps. I have some other things I have to get done today, so it might not be until tomorrow.

@davidmichaelkarr
Copy link
Author

@BoykoAlex , I don't know whether it's a "job" or a "rogue progress monitor", but it is more than just annoying. When it is doing that, it blocks me from doing anything else. Once I kill the external process, it proceeds with the next thing I asked it to do.

@BoykoAlex
Copy link
Contributor

@davidmichaelkarr what the external process you are killing? Is it the BootLanguageServer process?

@davidmichaelkarr
Copy link
Author

Yes.

@BoykoAlex
Copy link
Contributor

Well... yes, in this case we'd need a thread dump for the BootLanguageServer process before you kill it next time... It might reveal us what got stuck...

@davidmichaelkarr
Copy link
Author

eclipse.txt
blsba.txt

@BoykoAlex
Copy link
Contributor

When OR reconciling is off it simply doesn't go through OR AST visitors... However "empty" reconciling still occurs thus for each java file empty lis of diagnostics is sent... Looks like it is stuck sending this empty list of diagnostics :-\ Not sure why this occurs... how many java files are in your project? Do you notice project being built over and over again?

@BoykoAlex
Copy link
Contributor

@davidmichaelkarr Any chance you can perhaps grab the newest snapshot version of STS and give it a try? The reconciling has been re-worked from the ground up in the soon to be released version and it might serve you much better...
(See: https://dist.springsource.com/snapshot/STS4/nightly-distributions.html to grab proper distribution or update site)

@davidmichaelkarr
Copy link
Author

@BoykoAlex , I have dozens of projects open. The LS notification doesn't say which projects it's working on. I am not currently seeing any build loops. Note that the last run of the BLS appeared to complete without my killing it, but I think it likely ran for many hours before stopping.

Setting up my typical workspace with a different STS version will take some time, but I can proceed with that when I'm not doing priority work. I'll want to do it in a separate installation.

@BoykoAlex
Copy link
Contributor

BoykoAlex commented Aug 30, 2023

@davidmichaelkarr thanks for the thread dumps. I'm able to reproduce it and working towards fixing this. I think the reason for messages stuck is something consumes the previously received message and is not doing this in async fashion thus it received and attempting to send something on the same thread which is problematic... It seems like I might have a prototype fix for this but it is yet to be confirmed. Will keep you posted.

@BoykoAlex
Copy link
Contributor

Very likely i have a fix for this issue. Will test more tomorrow and if everything looks as great as it does now will push it in

@BoykoAlex
Copy link
Contributor

Seems like this 1377be2 fixes it. I'd try the new snapshot build that is running now.

See https://dist.springsource.com/snapshot/STS4/nightly-distributions.html and watch for the distro from Aug 30 or try eclipse language servers nightly update site from the page.

@martinlippert martinlippert added this to the 4.20.0.RELEASE milestone Aug 30, 2023
@BoykoAlex
Copy link
Contributor

Also pushed this to cover possibly more such scenarios c5ae048 where we'd send a message on the same thread as the received notification message. Also ensured ids are unique for progress tasks to avoid rogue progress bars.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

5 participants