I wanted to monitor over time the full startup time of our spring boot applications. I can see that ApplicationStartup interface in spring includes detailed information about the start time of different steps but really what I think would be nice is an overall startup time as a metric.
I really like how StartupInfoLogger contains startup time for the JVM/application and having this as a metric would allow us to send it to external metric systems via micrometer and monitor over time.
After looking at the ApplicationStartup information I am not sure there is a good rollup to show what the StartupInfoLogger shows:
[06-01-21 16:00:13.878] [main] INFO c.p.r.web.LocalApplicationRunner - Started LocalApplicationRunner in 16.605 seconds (JVM running for 17.318)
Comment From: onobc
@mbazos have you seen ApplicationStartup yet? I could see consuming this output from this endpoint to emit the metrics or alternatively creating a custom ApplicationStartup impl that emits the metrics.
Comment From: mbazos
@bono007 I originally looked at ApplicationStartup but looking at how the data is captured I think you would need to take the first event startTime and the last event endTime would that give you the full application startup time? Also I am not sure this captures JVM running time like the StartupInfoLogger
So I think it's a good idea maybe a custom ApplicationStartup that could emit metrics, but I was thinking more in the context of applications running containers where startup time can be critical metric.
I guess it's the difference between just having the overall aggregate time vs knowing all the individual details. I guess depending on the use-case people might want both but I think the overall aggregate time is maybe more valuable as it acts as a good starting point before someone would dig deeper to see why their application takes as long as it does.
Comment From: mbazos
@bono007 Also looking at the docs here https://docs.spring.io/spring-boot/docs/2.5.0/actuator-api/htmlsingle/#startup.retrieving.response-structure maybe we are just missing timeline.endTime? So then you could get the fully startup time taken and produce a metric from that?
Also I think that would cover the spring application but not the time since the JVM has been running
Comment From: onobc
bonoo007: have you seen ApplicationStartup yet?
@mbazos my bad, I see that you specified this in your original message.
maybe we are just missing timeline.endTime?
Yeh I noticed that too. I am not sure why that does not exist. Maybe Spring Boot team can give some insight into this. If there is not some technical reason, it would be a good thing to add I believe.
So then you could get the fully startup time taken and produce a metric from that?
Yes, that was my thought when I replied originally.
Also I think that would cover the spring application but not the time since the JVM has been running
There also exists the UptimeMetrics which leverages the JMX RuntimeMXBean for start and uptime (JMV perspective) that may be helpful for your case.
dig deeper to see why their application takes as long as it does.
I expect the JavaFlightRecorderApplicationStartup would be a good candidate for deeper digging.
Comment From: mbazos
Yeah I think whenever you want to dig deeper JFR is going to be the defacto tool.
To summarize this issue maybe the ask is:
* Why isn't there a timeline.endTime? and if there isn't a technical reason maybe it can be added in?
* Would be nice if either the ApplicationStartup could record micrometer metrics OR maybe UptimeMetrics should do that?
If I had some direction I wouldn't mind working on a PR just let me know.
Comment From: onobc
Hi @mbazos
I did a bit of digging and wanted to share findings:
Timeline.EndTime
The ApplicationStartup (AS) contract is very lean and only exposes a start API that returns a StartupStep. There is no concept of overall start time - new steps are just started. There is also no concept of overall end time, nor timeline. I am pretty sure all of this is by design. It would be quite a ripple to add the concept of timeline (w/ start and end times) to the ApplicationStartup contract. Another point is that AS lives in Spring Framework and not in Spring Boot.
StartupTimeline is specific to the BufferingApplicationStartup (BAS) implementation. It would be pretty straightforward to add end time to this implementation. The timeline for BAS is started by calling startRecording. We could add a stopRecording API that marked the overall end time. This endTime could then be added as a nullable field on StartupTimeline. The field would need to be nullable because the BAS is a bounded buffer of events that can be drained and retrieved randomly during the startup sequence. So when the timeline is retrieved before stopRecording has been called, the endTime field would be null. One downside to this approach would be that end time is only available in the BAS impl.
If the end goal is to simply record a metric for application start time and end time then it may be simpler to introduce a StartupTimeMetrics that did that. It feels like the AppllcationStartup may not be the best location for this based on the above findings.
I would be interested to see what the Spring Boot team suggests.
Comment From: onobc
@mbazos I think there is already something available that can be used to deduce the startup time. Take a look at SpringApplicationRunListeners. Each lifecycle step is recorded w/ its start/end time. I believe you can take the "spring.boot.application.running" step's end time and the BufferingApplicationStartup startTime to see the total startup time.
Comment From: onobc
@mbazos did you get a chance to take a look at the above suggestion?
Comment From: mbazos
Hey sorry @bono007 for the late reply. I need to dig into this. Yes I think what you are suggesting will work but I still wonder if this is something that should be handled by spring-boot core since it already is printing the total time/jvm time it just seems a lot simpler and straight forward to match the log statement with the metrics that would potentially be produced. I liked your idea of introducing StartupTimeMetrics I guess the question would be to you use SpringApplicationRunListeners to produce the StartupTimeMetrics or is it something simpler and StartupInfoLogger is used to produce StartupTimeMetrics?
Also if we were to create StartupTimeMetrics what metrics would we want?
* jvm start time
* application start time
* spring context start time
Comment From: wilkinsona
We might be able to include the startup time in the ApplicationStartedEvent. Something could then listen for that event and publish a metric.
Comment From: onobc
I have not looked too much into this, but it may interesting to see if the observability being added around the startup timeline in #27475 helps with this.
Comment From: wilkinsona
Thanks for the suggestion, @bono007. Right now, I can't see the benefit of coupling the two features. Here's a sketch of what the team had in mind when we discussed this last week: https://github.com/wilkinsona/spring-boot/tree/gh-26729. On the actuator side there would then be a listener that receives the started event and publishes the metric.
Comment From: onobc
I should have clarified (I was on my phone when I sent the link and was on the terse side). I meant to direct the question to @mbazos to ask if the observability feature in the link would help (or suffice) for what he is interested in. I do not think coupling it in for a generic solve is a good idea either.
Thanks for the link to the sketch. I was going to offer to add it in but it looks like what you have is complete on the "include startup time in the ApplicationStartedEvent" portion of the solution. Are you going to continue w/ the actuator metrics listener side ? I am happy to run w/ it if you are not.
Thanks
Comment From: mbazos
@bono007 I am having a hard time finding some extra time to work on this, so please go ahead and run with it.
Comment From: onobc
@mbazos I somehow missed your reply. I will try to submit a proposal soon.
Comment From: philwebb
Closing in favor of PR #27878