Collect metrics during application context startup

[bclozel]

Debugging issues about slow application startup times or even figuring out the sequence of events during the application context startup can be challenging.

This issue is about providing a low-cost, safe and metadata-rich strategy to collect metrics during the application context startup. This should be opt-in only and have little to no cost when disabled.

Collected data and metrics should help to:

• have a better understanding of the application context startup process
• identify problematic infrastructure components (like beans taking a lot of time or resources during @PostConstruct processing, creating beans that should have been guarded with conditions, etc).

[twicksell]

+1 to this. We'd love to get some insight into this timing. Further, we'd really like to see this type of data recorded to something like Micrometer, or at least a hook point so that we can capture these timings and record them ourselves.

[mdeinum]

Not sure if this is the right issue (or maybe should open a new issue). Now that the flight recorder is part of OpenJDK 11 (and backported to a recent 8 version) would it make sense to introduce these kind of events into the Spring (and maybe other Spring projects later)?

[bclozel]

@mdeinum this is the right issue. Right now we're thinking about providing an extension point for registering an implementation that would receive those events and could delegate to JFR, a library (like Micrometer) or anything custom.

This would be a good start in Framework and we could provide such implementations in Spring Boot. What do you think?

[bclozel]

I've been working on this a bit and I'll try to summarize the current state of affairs here.

Feature description

This feature is about adding a metrics-like abstraction to the Spring application context and instrumenting various infrastructure components in Spring Framework.

We'd like to achieve the following:

• give a better picture of what happens with a Spring application context (which beans are created, lifecycle phases)
• provide tooling to the Spring team; with all the work going on about GraalVM native image, startup time improvement, this should help defining priorities
• help the Spring community with pathological applications (unusually long startup times) or unexpected behavior

Non-goals:

• this feature is not about replacing other metrics systems like micrometer
• this should be limited to the application context lifecycle and should not be used for runtime behavior metrics, like web requests. Once the context is started, other systems should take the lead.

ContextEvent API

By default, the Spring application context will use a "no-op" implementation that won't record metrics events.

Applications can configure a ContextEventFactory on the context directly with org.springframework.context.ConfigurableApplicationContext#setContextEventFactory.

This ContextEventFactory can then be used to create events, add metadata to these events and record them.
Here's an example of instrumentation for the Spring application context (here, scanning base packages):

@Override
public void scan(String... basePackages) {
  Assert.notEmpty(basePackages, "At least one base package must be specified");
  // create a metrics event using the configured factory
  // implementations can start recording time duration for this event
  ContextEvent scanPackagesEvent = this.getContextEventFactory().create("spring.context.base-packages.scan");
  // add metadata as Tag instances (key/value String pairs)
  scanPackagesEvent.getTags().add("packages", () -> Arrays.toString(basePackages));
  this.scanner.scan(basePackages);
  // once recorded, the event should be immutable and its execution time recorded
  scanPackagesEvent.record();
}

The current state of this change does not ship any implementation (besides the "no-op" version) in Spring Framework directly.

Spring Boot integration

I've tested this infrastructure with a couple of implementations in Spring Boot - also taking the opportunity to instrument the lifecycle of Spring Boot applications (specific events, startup phase before the context creation, web server setup, etc).

A first draft implementation is measuring execution time and buffering the events, then exposing them as a startup timeline. Once exported, we can use this data to represent the startup sequence with something like this (here, a quick proof of concept with a JavaScript library):

Another implementation delegates events directly to Java Flight Recorder:

Next steps

1. Check that the Spring community would be interested in this, and whether we should expand/change the scope of this feature
2. Collect feedback from the Spring team and community about the infrastructure itself (interfaces, concept names)
3. Prepare a complete vision of this feature in Spring Boot: from configuration, to event collection and exporting data

If we make good progress on these 3 points, we can consider moving this issue to a 5.3 milestone.

[smaldini]

Awesome we are watching that feature closely as we have an internal implementation capturing similar metrics.
Couple points:

• Will we be able to wire the ContextEventFactory factory via spring.factories ?
• Will this provide an In Memory store out of the box we can use at the end of startup to replay and forward metrics ?Sending during startup can skew the data by adding delays but also might not be possible until we have the infrastructure in place, e.g. a kafka client or similar.

[mdeinum]

Really like this and could help identify bottlenecks in the startup/init of an application. Do you have a feature branch that we could checkout/play with?

[bclozel]

@smaldini Thanks for the feedback! This would be a good opportunity to ensure that this feature fits your use case.

• Right now I've implemented the Spring Boot support using spring.factories: it's pretty easy to set up and it's so early in the process that anything else is not really possible. When Spring Boot application start, the application context is not even instantiated so we would be creating the ContextEventFactory first, recording startup events and configuring that factory in the application context as soon as it's instantiated.

• I'm currently using a very simple implementation that buffers events; I'm not sure where to take it from there - should we try and expose those events on an actuator endpoint? Let developers drain the events queue and push them to a distributed event system? When should that buffer be cleared, as we probably don't want to let that sit in memory for the while lifetime of the application? Many of those questions will have to be answered on the Spring Boot side of things.

@mdeinum I'm going to get feedback from the Framework team on the main elements (concept names, packaging interfaces). As soon as we're clear, I think we should push this to SNAPSHOTs and iterate on the actual instrumentation of the application context. I've run this with several sample applications but I did not cover the whole feature spectrum and I'm probably missing things here. Your feedback here will be super important.

[bclozel]

I've just pushed a first version of this, with the basic infrastructure. Note that as of this commit, JDK8u262 is required to build Spring Framework (to get the Java Flight Recorder implementation provided here) - of course, Spring Framework 5.x does not require this version at runtime since this JFR implementation is opt-in only.

We'll continue working on this feature in Spring Boot to provide an easy setup and data export facilities.

Feel free to start experimenting and submit feedback here or in a new issue. We've got some time to iterate on this new API until the RC phase.