https://kotlinlang.org
Join Slack
Not kotlin (sorry) but can anyone provide some hints on how to debug a slow startup of a Spring Boot...
# spring
d
Not kotlin (sorry) but can anyone provide some hints on how to debug a slow startup of a Spring Boot app in Intellij? The problem in my case is that it takes cca 30s even before the Spring logo appears. I've tried setting 
debug=true
, but it doesn't help because it only affects the Spring itself.
OTOH if I use Spring devtools I can see a devtools related message just after starting the app from IDEA (followed by 30s silence). So perhaps there is a connection to Spring after all?
h
Are you on Windows? It might just be the Windows Defender unpacking and scanning all the JARs…
d
No, on MacOS. Whatever it is, is there any way to investigate?
h
I'd start by making a threaddump during the silence period. If that has nothing either, you can go deeper (I don't know what the equivalent of 
strace
on MacOS is though).
a
Add 
debug: true
(or 
debug=true
to the top of you application.yaml (or application.properties) file and re-start. Watch to what line things hand on...
SpringBoot will dump a lot of information to the console logs.
d
Try using a profiler when you start the application. That’ll tell you what’s taking time.
d
@ashmelev As I wrote I already tried 
debug=true
. Didn't help.
@Daniel Pitts I've tried that but the profiler shows events only from the moment the app is being started. For some strange reason, I see 30s silence even before the app starts starting, i.e. before the "Starting ..." log event appears.
d
Might be time the JVM itself is taking to start up then.
How are you running the app?
d
From Intellij.
Actually, this is the beginning of my logs:
Copy code
17:21:34.198 [main] INFO org.springframework.test.context.support.AnnotationConfigContextLoaderUtils -- Could not detect default configuration classes for test class [xxx]: CucumberTestContext does not declare any static, non-private, non-final, nested classes annotated with @Configuration.
17:21:34.288 [main] INFO org.springframework.boot.test.context.SpringBootTestContextBootstrapper -- Found @SpringBootConfiguration xxx for test class xxx
17:21:34.533 [main] INFO org.springframework.boot.devtools.restart.RestartApplicationListener -- Restart disabled due to context in which it is running
17:22:01,058 |-INFO in ch.qos.logback.core.joran.util.ConfigurationWatchListUtil@53630682 - Adding [jar:file:/Users/xxx/.m2/repository/org/springframework/boot/spring-boot/3.2.5/spring-boot-3.2.5.jar!/org/springframework/boot/logging/logback/defaults.xml] to configuration watch list.
This is followed by a bunch of log events from logback init and immediately after that Spring starts starting. But apparently Spring devtools is doing something right at the beginning (see the first 3 log events). Then follows the mysterious 30s silence.
d
What does your run configuration look like?
d
It's vanilla Intellij (i.e. generated and untouched since then)
d
Is it a maven or gradle project, or something else?
d
maven
d
Is IntelliJ running a maven build before the application starts?
d
Who knows 🙂 But the this happens everytime, irrespective of the code changes
d
Next time you run it, look at the "Build" tab to see if any activity is happening.
d
Yes, there's just an up-to-date check which passes (in under 1s)
d
Is it a SpringBoot application? Can you set a break-point before the runApplication?
d
Yes, it's SpringBoot but I doubt a break point would have any effect since (as I said) the silence happens before the app is even starting. So it's probably not the usual "Spring Boot starts slowly".
d
The runApplication is what actually starts the app
d
ah, okay you are right!
d
Try running with profiling:
The IntelliJ Profiler will tell you a lot about what is happening.
d
As I said before the output of the profiler was not helpful but then I was starting the app in a test context so a test framework might have interfered. I see the issue happening even with running the app standalone. Let me give the profiling data a second try, though.
I think the profiler data are quite strange. It reports 8s while the SpringBoot log clearly says that the app was running for 35s. Where are the missing 27s? 🙂
d
It reports CPU time, so it might not include IO time.
If you expand that row, it might provide additional insights.
d
Ok, do you see anything suspicious here?
d
Not really. Is there any other threads to look at?
Is this a project you could share? I wouldn't mind taking a quick look at it later today when I have time.
d
Unfortunately not 😞 Thanks a lot, anyway. If you have any idea where to look at please share it.
Actually, your comment about IO vs CPU time got me to investigate project root dir and there was a forgotten 250MB dir. So I dropped it but it didn't change anything.
d
There might be a way to change the profiler output to be wall-clock time rather than CPU time.
image.png
👍 1
d
Hmm, can you see anything here?
d
That wide bit at the start looks like its waiting on IO some operation being ready, but it looks like it is also in its own thread, so its hards to say if that's causing a delay.
b
This is probably not the solution, but I had as similar problem before. It was caused by the jvm taking a long time to resolve the ip address for localhost. I solved it by adding my Mac hostname to 
/etc/hosts
, and suddenly everything was fast again. Something similar is mentioned here: https://stackoverflow.com/questions/39636792/jvm-takes-a-long-time-to-resolve-ip-address-for-localhost
d
Ah, that wouldn’t surprise me.
10 Views
Open in Slack
PreviousNext
Powered by

kotlinlang

A modern programming language that makes developers happier.

Powered by