Spring Boot property indexing aggressive CPU usage

[szetheli]

Eclipse is launching a java process that is consuming either 100% of 1 cpu, or 100% of all cpus depending on the circumstances.
If I leave an application.yaml file open, it'll do 100% all CPUs then quite down after a few minutes. If there's a typo in the file, it'll keep burning CPUs for as long as I can tolerate it running. It starts with Eclipse continually flashing 'Indexing Spring Boot Properties...' The eclipse heap isn't running out of memory. It hovers around 400M, but its obvious when the indexing is running because it climbs, then GCs. The indexing is constantly running even though no code is changing.

spring-boot 2.1.7.RELEASE Eclipse Version: 2019-06 (4.12.0) STS: 4.3.2.201908130627-RELEASE openjdk 11.0.4 2019-07-16 OpenJDK Runtime Environment AdoptOpenJDK (build 11.0.4+11) OpenJDK 64-Bit Server VM AdoptOpenJDK (build 11.0.4+11, mixed mode) Mac OSX Mojave

[martinlippert]

Do you have a project that could help us to reproduce the issue?

With regards to the memory usage, the problem might happen in a different process (the language server). To investigate this you could open jconsole and attach to the boot language server process to see how that behaves. Could be an interesting data point here.

[martinlippert]

Another way to investigate this could be to identify exactly which process is burning the CPU cycles, attach a profiling tool to it, and record a few profiling traces to see what is causing the high CPU usage.

[szetheli]

I think the issue had to do with having two springboot enabled projects in the same workspace that have different springboot versions (maintenance diff: 2.1.7 and 2.1.3). When I removed the nature from the project I wasn't using the issue stopped.

[martinlippert]

Which nature did you remove from that project?

[szetheli]

org.springframework.ide.eclipse.boot.validation.springbootbuilder

[kdvolder]

I cannot reproduce this problem. I have tried a few things:

• created two boot projects with different versions of boot (2.1.7 and 2.1.3). I used "New Spring starter" project to create these. I added starters 'web' and 'actuator'.
• Changed the application.properties file to .yml
• Added some contents to the yaml including something that is a syntax error.

To be precise this content:

spring:
  application:
    name: brol
mine:
  name: foo
foo:
  - abc
- def

I have the two yml files open all the time.

CPU usage remains low and I do not see the 'indexing properties' message popup for any lenght of time.

I have also enabled

• the Eciipse option to refresh workspace resources automatically using 'native hooks or polling'.
• added spring boot configuration processor to the project pom.

These two steps were a bit of shot in the dark, as I suspect somekind of a 'loop' causing repeatedly to index resources and/or running the boot validation builder. Maybe because something is causing changes in the project output folder which causes these to be called. Maybe the spring-boot configuration processor, or maybe some other maven plugin or special tool that you have installed that generates source code or byte code outside of the plain java source code compilation.

These are all wild guesses really and don't totally make sense. The 'validation' builder that you removed could not in itself cause a infinite build loop I think. Though... it could be triggered repeatedly if something else is causing a continuous/looping/repeated changes in the project's output folder.

The same is also true for the 'indexing properties' message. It seems that the indexing is triggered repeatedly, which is indicative of something causing changes in its 'inputs' which is data from the classpath, including some data from project output folder. So if something is continually triggering changes in the project output folder that would explain the message.

If you could provide some kind of sample project that causes the problem that would be very helpful. Otherwise, I am not sure what else I can try. Without a way to reproduce the problem not really much I can do except for making wild guesses and asking you to try some things.

BTW: At this point its not even really clear to me which process is spiking your CPU. Is it the spring-boot language server process? Or the Eclipse process? Or it is actually both of them?

You can observe the processes/CPU usage with jconsole or just using a unix command like 'top'. That should allow to see precisely which process is using most of the CPU (and we like to know if its a process called 'BootLanguageServerBootApp' or 'org.eclipse.equinox.launcher' or maybe something else. Please check this and tell us precisely the name of the process(es) that you see are using the bulk of the 100% CPU.

Other interesting potential sources of information:

• the eclipse error log (you can view it using "Window >> Show View >> Error Log". Seeing what kind of messages are in there could provide hints on what is going on.
• the language server logs (You can enable these via "Window >> Preferences >> Language Servers >> Spring Language Servers" Enable the checkboxes in this page to enable various logs.

Other things I'd like to know.

• are your projects maven or gradle project?
• are your projects nested (so that one project maybe 'part of the other in terms of folder structure'
• are your projects stand-alone or depending on eachother (i.e. one project consuming another as a dependency so that it relies on the data in the other project's output folder indirectly).
• are you using any special plugins that do stuff at build time like generating code or metadata in output folder(s) of the project?
• anything else that you think might make your project special?
• do you enable non-standard Eclipse workspace options (like the 'refresh resources using native hooks or polling' for example)

[szetheli]

both projects are single gradle project, independent git folders without nesting. They don't have any interdependency. RE plugins: not that I know of. This is a fresh eclipse install and new workspace that is only a few days old.
Besides the vanilla java eclipse features:

• Enhanced Decompiler (Core) and it's optional extensions
• Spring STS
• EditorConfig
• Eclipse Web Developer Tools
• Bash Editor Native hooks checkbox is disabled

The process taking 100% CPU was a java process, child process of the eclipse process.

I'll try and create a fresh sample workspace and see if I can reproduce it.

Two other datapoints: I've since disabled the sts builders and natures in both projects. There's a 'stall' in the properties helper that develops over time. I think this stall behavior is part of what got me investigating the CPU usage on my laptop. I leave the eclipse window open continually. After a day or two running the workspace, it gets progressively slower to offer autocompletes, then starts timing out the with exceptions in the eclipse log. At that point the status line says 'Sending Classpath notifications'. Eclipse will then be 50/50 chance of not closing cleanly and require a Force Quit to get it back to normal. Second datapoint is what may be a memory leak in eclipse. I can't confirm yet. This just happened yesterday. I've been monitoring eclipse, and the application memory used (not just heap, but memory reported in the OS) has been steadily growing with very light usage today (from 2GB after a fresh restart to 5GB). This was related to my laptop popping up a warning yesterday about not enough free memory. It wasn't just eclipse consuming many GBs of memory, so I can't make a strong determination here. This may just be normal class caching, etc, and I doubt its related to STS since that's all been disabled since I started tracking this issue, but thought it worth mentioning as a possible relative to the first 'stall' case.

[kdvolder]

RE plugins: not that I know of. This is a fresh eclipse install and new workspace that is only a few days old.

To clarify, I'm not just talking about eclipse plugins. I was also thinking maven plugins (or in your case the gradle equivalent). Basically, anything that does more than compile bytecodes. Maybe pre-processing some templates, or processing javascript/coffeescript/typescript, java script minifications, running webpack, etc. Or generating Java code or metadata from Java annnotations. Basically... anything that could result in some files being copied or changed in project output folders that goes beyond what the Eclipse JDT compiler does when it compiles java code.

[kdvolder]

I've since disabled the sts builders and natures in both projects. There's a 'stall' in the properties helper that develops over time. I think this stall behavior is part of what got me investigating the CPU usage on my laptop. I leave the eclipse window open continually. After a day or two running the workspace, it gets progressively slower to offer autocompletes, then starts timing out the with exceptions in the eclipse log. At that point the status line says 'Sending Classpath notifications'. Eclipse will then be 50/50 chance of not closing cleanly and require a Force Quit to get it back to normal.

This sounds to me like the language server process may have a memory leak or some other kind of resource leak that makes it loose performance over time. When you experience this next time it would be interesting to collect some information about both the Eclipse process and the language server (I think this is the 'child process' that you mentioned).

A possible explanation for what you describe could be (guessing wildly again :-)

• language server is basically out of memory and in continuous GC loop, becomes unresponsive
• eclipse sends classpath data and waits for acknowledgement which never comes

This kind of hangs both Eclipse and the LS process, one waiting for the other.

Would be interesting to see:

• jstack dump of the Eclipse process (maybe we can see if / why it is stuck?)
• jstack dump of the laguage server process (maybe we can see what it's doing something).
• use jconsole to attach the language server process. Check if it looks healthy in terms of memory.

If it looks like a memory leak in the LS process, a heapdump of the process might be useful too. (But yeah, these tend to be large and hard to share files).

[spring-projects-issues]

(comment in Pivotal Tracker added by Kris De Volder:)

Putting this ticket back into 'unstarted state' and into backlog for now. Seems like no new information is available to help debug/diagnose and as I don't have a way to reproduce it myself, there's not much that can be done.

[spring-projects-issues]

(comment in Pivotal Tracker added by Alex Boyko:)

To be re-evaluated.

[martinlippert]

@szetheli It would be super interesting to get results from the jstack to dive deeper into this performance issue and probably a bit of insight into the language server process from using jconsole (all as described by Kris in the comment above). Please let us know if you can find the time to capture that information for us. Thanks!

[hengyunabc]

I killed the BootLanguagServerBootApp process, and then the Building Error ended.

[martinlippert]

@hengyunabc if you have any more details (like a thread dump from that process that you killed) or any steps how to reproduce this, that would be awesome.

[nfrobertson]

spring-boot 2.3.1.RELEASE Eclipse Version: 2019-06 (4.16.0) STS: 4.7.1.202007271558-RELEASE Oracle JDK 1.8.0_251

I thought I was having a similar problem but after review of the SB Language Server Log it seems that STS is just aggressive at indexing spring boot properties while I have yml files (bootstrap.yml, application.yml, etc.) open. Is there a way to ease it off some? Re-indexing every second seems a bit much?

Also is there a way to adjust Eclipse so that the bottom toolbar doesn't flash the message "Indexing Spring Boot Properties..." every second while this is happening? It's a bit distracting while staring at debug console output.

snipped from SB Language Server Log. This goes on indefinitely every second... 06:29:11.988 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app 06:29:12.163 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app DONE 06:29:12.163 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexed 1919 properties. 06:29:13.218 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app 06:29:13.355 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app DONE 06:29:13.355 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexed 1919 properties. 06:29:14.395 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app 06:29:14.525 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app DONE 06:29:14.525 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexed 1919 properties. 06:29:15.570 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app 06:29:15.707 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app DONE 06:29:15.707 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexed 1919 properties. 06:29:16.866 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app 06:29:17.068 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app DONE 06:29:17.068 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexed 1919 properties. 06:29:18.060 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app 06:29:18.202 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app DONE 06:29:18.202 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexed 1919 properties. 06:29:19.258 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app 06:29:19.424 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app DONE 06:29:19.424 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexed 1919 properties. 06:29:20.486 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app 06:29:20.659 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app DONE 06:29:20.659 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexed 1919 properties. 06:29:21.676 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app 06:29:21.831 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app DONE 06:29:21.831 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexed 1919 properties. 06:29:22.926 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app 06:29:23.097 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app DONE 06:29:23.097 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexed 1919 properties. 06:29:24.091 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app 06:29:24.223 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app DONE 06:29:24.224 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexed 1919 properties. 06:29:25.268 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app 06:29:25.407 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app DONE 06:29:25.407 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexed 1919 properties. 06:29:26.501 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app 06:29:26.647 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app DONE 06:29:26.647 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexed 1919 properties. 06:29:27.764 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app 06:29:27.911 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app DONE 06:29:27.911 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexed 1919 properties. 06:29:28.974 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app 06:29:29.135 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app DONE 06:29:29.135 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexed 1919 properties. 06:29:30.200 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app 06:29:30.394 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexing Spring Boot Properties for my-sb-app DONE 06:29:30.394 [Reconciler-1] INFO o.s.ide.vscode.commons.util.Log - Indexed 1919 properties.

[martinlippert]

Thanks @nfrobertson for reporting this, it looks indeed very strange. @kdvolder do you have any idea why this might happen?

[kdvolder]

MY guess is that there must be something periodically triggering project builds in some kind of a 'cycle'. I.e. files that are changing content which triggers a build and somehow the build ends up changing the same files again in a circular loop and the indexing is somehow caught up in this loop.

This doesn't typically happen with the basic projects that I've tried so it would really help to reproduce this if you can attach a sample project that exhibits the problem.

[nfrobertson]

Ok I think I've tracked this back and it's not directly an STS issue. We have a new mostly empty spring boot app. In the Eclipse .project we kept the builders for cucumber/gherkin since we do plan to use them for unit testing. However, we currently do not have any feature or step definition files. It seems this builder cucumber.eclipse.builder.stepdefinition is causing Eclipse to rebuild constantly triggering this behavior in STS with "Indexing Spring Boot Properties" if I have a YML file open from any other project.

[martinlippert]

@nfrobertson Sounds like that would explain the behavior indeed, good catch.

@kdvolder Nevertheless we should think about and analyze whether the language server can be made a bit smarter here and avoid re-indexing things if the event arrives, but nothing has really changed.

[kdvolder]

Nevertheless we should think about and analyze whether the language server can be made a bit smarter here and avoid re-indexing things if the event arrives, but nothing has really changed.

Agreed. But it would be helpful to have something concrete to analyse. @nfrobertson any chance you can attach the 'mostly empty spring boot app' you described above, along with some instructions/steps on how to use it to trigger the problem?

[nfrobertson]

I'm not able to attach identifiable artifacts from my work but I can put the Eclipse .project here that shows how to cause this. If you create a new empty spring boot 2 project and include the cucubmer/gherkin builders/nature like below you should be able to reproduce this. The xml comments are what I used to "fix" the problem until we're ready to use them.

Eclipse .project file

<?xml version="1.0" encoding="UTF-8"?>
<projectDescription>
	<name>my-sb-app</name>
	<comment></comment>
	<projects>
	</projects>
	<buildSpec>
		<buildCommand>
			<name>org.eclipse.jdt.core.javabuilder</name>
			<arguments>
			</arguments>
		</buildCommand>
<!-- 		<buildCommand> -->
<!-- 			<name>cucumber.eclipse.builder.stepdefinition</name> -->
<!-- 			<arguments> -->
<!-- 			</arguments> -->
<!-- 		</buildCommand> -->
<!-- 		<buildCommand> -->
<!-- 			<name>cucumber.eclipse.builder.gherkin</name> -->
<!-- 			<arguments> -->
<!-- 			</arguments> -->
<!-- 		</buildCommand> -->
		<buildCommand>
			<name>org.springframework.ide.eclipse.boot.validation.springbootbuilder</name>
			<arguments>
			</arguments>
		</buildCommand>
		<buildCommand>
			<name>org.eclipse.m2e.core.maven2Builder</name>
			<arguments>
			</arguments>
		</buildCommand>
	</buildSpec>
	<natures>
<!-- 		<nature>cucumber.eclipse.nature</nature> -->
		<nature>org.eclipse.jdt.core.javanature</nature>
		<nature>org.eclipse.m2e.core.maven2Nature</nature>
	</natures>
</projectDescription>

maven pom.xml dependencies extracted:

<dependencies>
    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-web</artifactId>
    </dependency>
    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-actuator</artifactId>
    </dependency>        
    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-devtools</artifactId>
        <scope>runtime</scope>
        <optional>true</optional>
    </dependency>
    <dependency>
        <groupId>org.projectlombok</groupId>
        <artifactId>lombok</artifactId>
        <optional>true</optional>
    </dependency>
    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-test</artifactId>
        <scope>test</scope>
    </dependency>
    <dependency>
        <groupId>io.cucumber</groupId>
        <artifactId>cucumber-java</artifactId>
        <scope>test</scope>
    </dependency>
    <dependency>
        <groupId>io.cucumber</groupId>
        <artifactId>cucumber-junit</artifactId>
        <scope>test</scope>
    </dependency>        
</dependencies>

[martinlippert]

@nfrobertson I tried to reproduce this by adding the Cucumber builders to the project, but it doesn't seem to cause the constant re-indexing (as long as I don't save a file). As soon as I change a Java file and save it, the re-indexing happens. But that doesn't sound like what you described, saying that the re-indexing happened automatically all the time.

It looks like I am missing something in my project or IDE that is causing this on your end. Any idea what that could be? Maybe there are any additional cucumber configs around, settings, or files that cause the cucumber builders to kick-in and so something in the background?

[martinlippert]

And do you see the project build of the IDE also appearing constantly in the progress view, for example?

[kdvolder]

Workspace settings such as 'refresh using native hooks or polling' could also play a part in this (have been the cause of 'build loops' in the past). Not sure if it is relevant for the cucumber scenario.

[amanzag]

I'm not sure if it's related, but I have fairly large workspace, and as soon as I enable "Live Information - Automatic Process Tracking Enabled" the language server process starts burning CPU.

Attaching thread dump, although I don't see anything strange. lang_server_thread_dump.txt

[kdvolder]

I'm not sure if it's related

live process scraping is something else than property indexing. So it sounds like a different problem / cause. Problems could still be related though.

@amanzag When you say 'burning CPU' what does that mean? How much does it use, for how long?

I do see in your stackdump that something is active trying to scrape live JVM processes (which is what that option does).

We would expect some activity from this so some CPU use would be normal, it just shouldn't be excessive. (It's a polling loop and should leave enough space between checks to avoid excessive CPU use).

So how much CPU does it use? And does it die down after a while or not?

[martinlippert]

@amanzag You could also try to increase the Automatic Process Tracking Delay (in ms), so that the automatic check happens less often. In addition to that I would be highly interested in profiling data of the language server process to see what exactly is consuming the CPU. Any chance you can record such a profiling session? That would be awesome.

[amanzag]

@kdvolder It starts using between 50% and 90% of CPU all the time, it never stops. It makes the laptop run out of battery and eclipse feel sluggish, so it feels excessive to me. Note as well that it does that even when I don't have any java apps running, except for Eclipse.

@martinlippert I'll try that when I have some time.

[kdvolder]

@amanzag I'm suspecting it must have something todo with the process scraping. The evidence so far points to it (starts when you turn that on, and we also see it in the stacktrace).

The question is if this is because language server itself is somehow misbehaving (e.g calling it too frequently), or there's something going wrong in the JRE library code causing it go into some kind of a loop internally.

THe profiling data might help determine that. Also, it might be a good idea to see if changing between different JRE/JVM implementations or versions helps. And it would help also if you can share details of your system such as the OS and which exact version of the JVM is being used).

[amanzag]

So I just tried changing the tracking delay as @martinlippert suggested and, indeed, setting a higher value (e.g. 50000) lowers the CPU usage. Actually, with 50 seconds, the CPU stays at 0 all the time but it has bursts of high usage (I assume every 50 seconds).

I'm attaching a profiling session taken with VisualVM, I hope it helps.

My system specs are:

• OpenJDK 64-Bit Server VM (11.0.3+7, mixed mode)
• macOS Mojave (10.14.6) Also tried OpenJDK 14 and it's the same.

snapshot-1600339728221.nps.zip