Polish "Add startup time metrics"

See gh-27878
This commit is contained in:
Stephane Nicoll
2021-09-16 10:00:39 +02:00
parent 2e67963bfe
commit c62a6819fe
19 changed files with 201 additions and 185 deletions

View File

@@ -287,7 +287,7 @@ public class SpringApplication {
*/
public ConfigurableApplicationContext run(String... args) {
StopWatch stopWatch = new StopWatch();
stopWatch.start("applicationStarted");
stopWatch.start();
DefaultBootstrapContext bootstrapContext = createBootstrapContext();
ConfigurableApplicationContext context = null;
configureHeadlessProperty();
@@ -304,11 +304,12 @@ public class SpringApplication {
refreshContext(context);
afterRefresh(context, applicationArguments);
stopWatch.stop();
stopWatch.start("applicationReady");
Duration startedTime = Duration.ofMillis(stopWatch.getTotalTimeMillis());
stopWatch.start();
if (this.logStartupInfo) {
new StartupInfoLogger(this.mainApplicationClass).logStarted(getApplicationLog(), stopWatch);
new StartupInfoLogger(this.mainApplicationClass).logStarted(getApplicationLog(), startedTime);
}
listeners.started(context, Duration.ofMillis(stopWatch.getTotalTimeMillis()));
listeners.started(context, startedTime);
callRunners(context, applicationArguments);
}
catch (Throwable ex) {

View File

@@ -83,6 +83,7 @@ public interface SpringApplicationRunListener {
*/
@Deprecated
default void started(ConfigurableApplicationContext context) {
started(context, null);
}
/**
@@ -90,11 +91,11 @@ public interface SpringApplicationRunListener {
* {@link CommandLineRunner CommandLineRunners} and {@link ApplicationRunner
* ApplicationRunners} have not been called.
* @param context the application context.
* @param startupTime the time taken to start the application or {@code null} if
* @param startedTime the time taken to start the application or {@code null} if
* unknown
* @since 2.0.0
* @since 2.6.0
*/
default void started(ConfigurableApplicationContext context, Duration startupTime) {
default void started(ConfigurableApplicationContext context, Duration startedTime) {
started(context);
}
@@ -109,6 +110,7 @@ public interface SpringApplicationRunListener {
*/
@Deprecated
default void running(ConfigurableApplicationContext context) {
running(context, null);
}
/**
@@ -116,11 +118,11 @@ public interface SpringApplicationRunListener {
* been refreshed and all {@link CommandLineRunner CommandLineRunners} and
* {@link ApplicationRunner ApplicationRunners} have been called.
* @param context the application context.
* @param startupTime the time taken for the application to be ready to service
* requests or {@code null} if unknown
* @param readyTime the time taken for the application to be ready to service requests
* or {@code null} if unknown
* @since 2.6.0
*/
default void running(ConfigurableApplicationContext context, Duration startupTime) {
default void running(ConfigurableApplicationContext context, Duration readyTime) {
running(context);
}

View File

@@ -18,6 +18,7 @@ package org.springframework.boot;
import java.lang.management.ManagementFactory;
import java.net.InetAddress;
import java.time.Duration;
import java.util.concurrent.Callable;
import org.apache.commons.logging.Log;
@@ -29,7 +30,6 @@ import org.springframework.context.ApplicationContext;
import org.springframework.core.log.LogMessage;
import org.springframework.util.Assert;
import org.springframework.util.ClassUtils;
import org.springframework.util.StopWatch;
import org.springframework.util.StringUtils;
/**
@@ -56,9 +56,9 @@ class StartupInfoLogger {
applicationLog.debug(LogMessage.of(this::getRunningMessage));
}
void logStarted(Log applicationLog, StopWatch stopWatch) {
void logStarted(Log applicationLog, Duration startupTime) {
if (applicationLog.isInfoEnabled()) {
applicationLog.info(getStartedMessage(stopWatch));
applicationLog.info(getStartedMessage(startupTime));
}
}
@@ -83,12 +83,12 @@ class StartupInfoLogger {
return message;
}
private CharSequence getStartedMessage(StopWatch stopWatch) {
private CharSequence getStartedMessage(Duration startupTime) {
StringBuilder message = new StringBuilder();
message.append("Started ");
appendApplicationName(message);
message.append(" in ");
message.append(stopWatch.getTotalTimeMillis() / 1000.0);
message.append(startupTime.toMillis() / 1000.0);
message.append(" seconds");
try {
double uptime = ManagementFactory.getRuntimeMXBean().getUptime() / 1000.0;

View File

@@ -37,7 +37,7 @@ public class ApplicationReadyEvent extends SpringApplicationEvent {
private final ConfigurableApplicationContext context;
private final Duration startupTime;
private final Duration readyTime;
/**
* Create a new {@link ApplicationReadyEvent} instance.
@@ -47,6 +47,7 @@ public class ApplicationReadyEvent extends SpringApplicationEvent {
* @deprecated since 2.6.0 for removal in 2.8.0 in favor of
* {@link #ApplicationReadyEvent(SpringApplication, String[], ConfigurableApplicationContext, Duration)}
*/
@Deprecated
public ApplicationReadyEvent(SpringApplication application, String[] args, ConfigurableApplicationContext context) {
this(application, args, context, null);
}
@@ -56,13 +57,14 @@ public class ApplicationReadyEvent extends SpringApplicationEvent {
* @param application the current application
* @param args the arguments the application is running with
* @param context the context that was being created
* @param startupTime the time taken to get the application ready to service requests
* @param readyTime the time taken to get the application ready to service requests
* @since 2.6.0
*/
public ApplicationReadyEvent(SpringApplication application, String[] args, ConfigurableApplicationContext context,
Duration startupTime) {
Duration readyTime) {
super(application, args);
this.context = context;
this.startupTime = startupTime;
this.readyTime = readyTime;
}
/**
@@ -74,11 +76,12 @@ public class ApplicationReadyEvent extends SpringApplicationEvent {
}
/**
* Return the time taken for the application to be ready to service requests.
* @return the startup time
* Return the time taken for the application to be ready to service requests, or
* {@code null} if unknown.
* @return the time taken to be ready to service requests
*/
public Duration getStartupTime() {
return this.startupTime;
public Duration getReadyTime() {
return this.readyTime;
}
}

View File

@@ -36,7 +36,7 @@ public class ApplicationStartedEvent extends SpringApplicationEvent {
private final ConfigurableApplicationContext context;
private final Duration startupTime;
private final Duration startedTime;
/**
* Create a new {@link ApplicationStartedEvent} instance.
@@ -57,13 +57,14 @@ public class ApplicationStartedEvent extends SpringApplicationEvent {
* @param application the current application
* @param args the arguments the application is running with
* @param context the context that was being created
* @param startupTime the time taken to start the application
* @param startedTime the time taken to start the application
* @since 2.6.0
*/
public ApplicationStartedEvent(SpringApplication application, String[] args, ConfigurableApplicationContext context,
Duration startupTime) {
Duration startedTime) {
super(application, args);
this.context = context;
this.startupTime = startupTime;
this.startedTime = startedTime;
}
/**
@@ -75,11 +76,11 @@ public class ApplicationStartedEvent extends SpringApplicationEvent {
}
/**
* Return the time taken to start the application.
* Return the time taken to start the application, or {@code null} if unknown.
* @return the startup time
*/
public Duration getStartupTime() {
return this.startupTime;
public Duration getStartedTime() {
return this.startedTime;
}
}

View File

@@ -104,26 +104,14 @@ public class EventPublishingRunListener implements SpringApplicationRunListener,
}
@Override
@Deprecated
public void started(ConfigurableApplicationContext context) {
started(context, null);
}
@Override
public void started(ConfigurableApplicationContext context, Duration startupTime) {
context.publishEvent(new ApplicationStartedEvent(this.application, this.args, context, startupTime));
public void started(ConfigurableApplicationContext context, Duration startedTime) {
context.publishEvent(new ApplicationStartedEvent(this.application, this.args, context, startedTime));
AvailabilityChangeEvent.publish(context, LivenessState.CORRECT);
}
@Override
@Deprecated
public void running(ConfigurableApplicationContext context) {
running(context, null);
}
@Override
public void running(ConfigurableApplicationContext context, Duration startupTime) {
context.publishEvent(new ApplicationReadyEvent(this.application, this.args, context, startupTime));
public void running(ConfigurableApplicationContext context, Duration readyTime) {
context.publishEvent(new ApplicationReadyEvent(this.application, this.args, context, readyTime));
AvailabilityChangeEvent.publish(context, ReadinessState.ACCEPTING_TRAFFIC);
}

View File

@@ -88,6 +88,7 @@ import org.springframework.context.annotation.Lazy;
import org.springframework.context.event.ApplicationEventMulticaster;
import org.springframework.context.event.ContextRefreshedEvent;
import org.springframework.context.event.SimpleApplicationEventMulticaster;
import org.springframework.context.event.SmartApplicationListener;
import org.springframework.context.support.AbstractApplicationContext;
import org.springframework.context.support.StaticApplicationContext;
import org.springframework.core.Ordered;
@@ -362,36 +363,18 @@ class SpringApplicationTests {
void applicationRunningEventListener() {
SpringApplication application = new SpringApplication(ExampleConfig.class);
application.setWebApplicationType(WebApplicationType.NONE);
final AtomicReference<SpringApplication> reference = new AtomicReference<>();
class ApplicationReadyEventListener implements ApplicationListener<ApplicationReadyEvent> {
@Override
public void onApplicationEvent(ApplicationReadyEvent event) {
reference.set(event.getSpringApplication());
}
}
application.addListeners(new ApplicationReadyEventListener());
AtomicReference<ApplicationReadyEvent> reference = setupListener(application, ApplicationReadyEvent.class);
this.context = application.run("--foo=bar");
assertThat(application).isSameAs(reference.get());
assertThat(application).isSameAs(reference.get().getSpringApplication());
}
@Test
void contextRefreshedEventListener() {
SpringApplication application = new SpringApplication(ExampleConfig.class);
application.setWebApplicationType(WebApplicationType.NONE);
final AtomicReference<ApplicationContext> reference = new AtomicReference<>();
class InitializerListener implements ApplicationListener<ContextRefreshedEvent> {
@Override
public void onApplicationEvent(ContextRefreshedEvent event) {
reference.set(event.getApplicationContext());
}
}
application.setListeners(Collections.singletonList(new InitializerListener()));
AtomicReference<ContextRefreshedEvent> reference = setupListener(application, ContextRefreshedEvent.class);
this.context = application.run("--foo=bar");
assertThat(this.context).isSameAs(reference.get());
assertThat(this.context).isSameAs(reference.get().getApplicationContext());
// Custom initializers do not switch off the defaults
assertThat(getEnvironment().getProperty("foo")).isEqualTo("bar");
}
@@ -419,39 +402,21 @@ class SpringApplicationTests {
}
@Test
void applicationStartedEventHasStartupTime() {
void applicationStartedEventHasStartedTime() {
SpringApplication application = new SpringApplication(ExampleConfig.class);
application.setWebApplicationType(WebApplicationType.NONE);
final AtomicReference<ApplicationStartedEvent> reference = new AtomicReference<>();
class ApplicationStartedEventListener implements ApplicationListener<ApplicationStartedEvent> {
@Override
public void onApplicationEvent(ApplicationStartedEvent event) {
reference.set(event);
}
}
application.addListeners(new ApplicationStartedEventListener());
AtomicReference<ApplicationStartedEvent> reference = setupListener(application, ApplicationStartedEvent.class);
this.context = application.run();
assertThat(reference.get()).isNotNull().extracting(ApplicationStartedEvent::getStartupTime).isNotNull();
assertThat(reference.get()).isNotNull().extracting(ApplicationStartedEvent::getStartedTime).isNotNull();
}
@Test
void applicationReadyEventHasStartupTime() {
void applicationReadyEventHasReadyTime() {
SpringApplication application = new SpringApplication(ExampleConfig.class);
application.setWebApplicationType(WebApplicationType.NONE);
final AtomicReference<ApplicationReadyEvent> reference = new AtomicReference<>();
class ApplicationReadyEventListener implements ApplicationListener<ApplicationReadyEvent> {
@Override
public void onApplicationEvent(ApplicationReadyEvent event) {
reference.set(event);
}
}
application.addListeners(new ApplicationReadyEventListener());
AtomicReference<ApplicationReadyEvent> reference = setupListener(application, ApplicationReadyEvent.class);
this.context = application.run();
assertThat(reference.get()).isNotNull().extracting(ApplicationReadyEvent::getStartupTime).isNotNull();
assertThat(reference.get()).isNotNull().extracting(ApplicationReadyEvent::getReadyTime).isNotNull();
}
@Test
@@ -1287,6 +1252,27 @@ class SpringApplicationTests {
&& ((AvailabilityChangeEvent<?>) argument).getState().equals(state);
}
private <T extends ApplicationEvent> AtomicReference<T> setupListener(SpringApplication application,
Class<T> targetEventType) {
final AtomicReference<T> reference = new AtomicReference<>();
class TestEventListener implements SmartApplicationListener {
@Override
@SuppressWarnings("unchecked")
public void onApplicationEvent(ApplicationEvent event) {
reference.set((T) event);
}
@Override
public boolean supportsEventType(Class<? extends ApplicationEvent> eventType) {
return targetEventType.isAssignableFrom(eventType);
}
}
application.addListeners(new TestEventListener());
return reference;
}
private Condition<ConfigurableEnvironment> matchingPropertySource(final Class<?> propertySourceClass,
final String name) {

View File

@@ -18,6 +18,7 @@ package org.springframework.boot;
import java.net.InetAddress;
import java.net.UnknownHostException;
import java.time.Duration;
import org.apache.commons.logging.Log;
import org.junit.jupiter.api.Test;
@@ -59,7 +60,7 @@ class StartupInfoLoggerTests {
stopWatch.start();
given(this.log.isInfoEnabled()).willReturn(true);
stopWatch.stop();
new StartupInfoLogger(getClass()).logStarted(this.log, stopWatch);
new StartupInfoLogger(getClass()).logStarted(this.log, Duration.ofMillis(stopWatch.getTotalTimeMillis()));
ArgumentCaptor<Object> captor = ArgumentCaptor.forClass(Object.class);
verify(this.log).info(captor.capture());
assertThat(captor.getValue().toString()).matches("Started " + getClass().getSimpleName()

View File

@@ -17,7 +17,6 @@
package org.springframework.boot.admin;
import java.lang.management.ManagementFactory;
import java.time.Duration;
import javax.management.InstanceNotFoundException;
import javax.management.MBeanServer;
@@ -90,10 +89,9 @@ class SpringApplicationAdminMXBeanRegistrarTests {
ConfigurableApplicationContext context = mock(ConfigurableApplicationContext.class);
registrar.setApplicationContext(context);
registrar.onApplicationReadyEvent(new ApplicationReadyEvent(new SpringApplication(), null,
mock(ConfigurableApplicationContext.class), Duration.ZERO));
mock(ConfigurableApplicationContext.class), null));
assertThat(isApplicationReady(registrar)).isFalse();
registrar.onApplicationReadyEvent(
new ApplicationReadyEvent(new SpringApplication(), null, context, Duration.ZERO));
registrar.onApplicationReadyEvent(new ApplicationReadyEvent(new SpringApplication(), null, context, null));
assertThat(isApplicationReady(registrar)).isTrue();
}

View File

@@ -18,7 +18,6 @@ package org.springframework.boot.context;
import java.io.File;
import java.io.IOException;
import java.time.Duration;
import java.util.function.Consumer;
import org.junit.jupiter.api.AfterEach;
@@ -188,7 +187,7 @@ class ApplicationPidFileWriterTests {
ConfigurableEnvironment environment = createEnvironment(propName, propValue);
ConfigurableApplicationContext context = mock(ConfigurableApplicationContext.class);
given(context.getEnvironment()).willReturn(environment);
return new ApplicationReadyEvent(new SpringApplication(), new String[] {}, context, Duration.ZERO);
return new ApplicationReadyEvent(new SpringApplication(), new String[] {}, context, null);
}
private ConfigurableEnvironment createEnvironment(String propName, String propValue) {

View File

@@ -16,7 +16,6 @@
package org.springframework.boot.context.event;
import java.time.Duration;
import java.util.ArrayDeque;
import java.util.ArrayList;
import java.util.Collections;
@@ -73,9 +72,9 @@ class EventPublishingRunListenerTests {
this.runListener.contextLoaded(context);
checkApplicationEvents(ApplicationPreparedEvent.class);
context.refresh();
this.runListener.started(context, Duration.ZERO);
this.runListener.started(context, null);
checkApplicationEvents(ApplicationStartedEvent.class, AvailabilityChangeEvent.class);
this.runListener.running(context, Duration.ZERO);
this.runListener.running(context, null);
checkApplicationEvents(ApplicationReadyEvent.class, AvailabilityChangeEvent.class);
}