Add buffering ApplicationStartup variant

As of spring-projects/spring-framework#24878, Spring Framework provides
an `ApplicationStartup` infrastructure that applications can use to
collect and track events during the application startup phase.

This commit adds a new `BufferingApplicationStartup` implementation that
buffer `StartupStep`s and tracks their execution time. Once buffered,
these steps can be pushed to an external metrics system or drained
through a web endpoint, to a file...

Closes gh-22603

spring-boot-project/spring-boot/src/main/java/org/springframework/boot/context/metrics/buffering/BufferedStartupStep.java

@@ -0,0 +1,173 @@
+/*
+ * Copyright 2002-2020 the original author or authors.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      https://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package org.springframework.boot.context.metrics.buffering;
+
+import java.util.Iterator;
+import java.util.function.Consumer;
+import java.util.function.Supplier;
+
+import org.springframework.core.metrics.StartupStep;
+
+/**
+ * {@link StartupStep} implementation to be buffered by
+ * {@link BufferingApplicationStartup}. Its processing time is recorded using
+ * {@link System#nanoTime()}.
+ *
+ * @author Brian Clozel
+ */
+class BufferedStartupStep implements StartupStep {
+
+	private final String name;
+
+	private final long id;
+
+	private final Long parentId;
+
+	private long startTime;
+
+	private long endTime;
+
+	private final DefaultTags tags;
+
+	private final Consumer<BufferedStartupStep> recorder;
+
+	BufferedStartupStep(long id, String name, Long parentId, Consumer<BufferedStartupStep> recorder) {
+		this.id = id;
+		this.parentId = parentId;
+		this.tags = new DefaultTags();
+		this.name = name;
+		this.recorder = recorder;
+	}
+
+	@Override
+	public String getName() {
+		return this.name;
+	}
+
+	@Override
+	public long getId() {
+		return this.id;
+	}
+
+	@Override
+	public Long getParentId() {
+		return this.parentId;
+	}
+
+	@Override
+	public Tags getTags() {
+		return this.tags;
+	}
+
+	@Override
+	public StartupStep tag(String key, String value) {
+		if (this.endTime != 0L) {
+			throw new IllegalStateException("StartupStep has already ended.");
+		}
+		this.tags.add(key, value);
+		return this;
+	}
+
+	@Override
+	public StartupStep tag(String key, Supplier<String> value) {
+		return this.tag(key, value.get());
+	}
+
+	@Override
+	public void end() {
+		this.recorder.accept(this);
+	}
+
+	long getStartTime() {
+		return this.startTime;
+	}
+
+	void recordStartTime(long startTime) {
+		this.startTime = startTime;
+	}
+
+	long getEndTime() {
+		return this.endTime;
+	}
+
+	void recordEndTime(long endTime) {
+		this.endTime = endTime;
+	}
+
+	static class DefaultTags implements Tags {
+
+		private Tag[] tags = new Tag[0];
+
+		void add(String key, String value) {
+			Tag[] newTags = new Tag[this.tags.length + 1];
+			System.arraycopy(this.tags, 0, newTags, 0, this.tags.length);
+			newTags[newTags.length - 1] = new DefaultTag(key, value);
+			this.tags = newTags;
+		}
+
+		@Override
+		public Iterator<Tag> iterator() {
+			return new TagsIterator();
+		}
+
+		private class TagsIterator implements Iterator<Tag> {
+
+			private int idx = 0;
+
+			@Override
+			public boolean hasNext() {
+				return this.idx < DefaultTags.this.tags.length;
+			}
+
+			@Override
+			public Tag next() {
+				return DefaultTags.this.tags[this.idx++];
+			}
+
+			@Override
+			public void remove() {
+				throw new UnsupportedOperationException("tags are append only");
+			}
+
+		}
+
+	}
+
+	static class DefaultTag implements Tag {
+
+		private final String key;
+
+		private final String value;
+
+		DefaultTag(String key, String value) {
+			this.key = key;
+			this.value = value;
+		}
+
+		@Override
+		public String getKey() {
+			return this.key;
+		}
+
+		@Override
+		public String getValue() {
+			return this.value;
+		}
+
+	}
+
+}

spring-boot-project/spring-boot/src/main/java/org/springframework/boot/context/metrics/buffering/BufferingApplicationStartup.java

@@ -0,0 +1,145 @@
+/*
+ * Copyright 2002-2020 the original author or authors.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      https://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package org.springframework.boot.context.metrics.buffering;
+
+import java.time.Instant;
+import java.util.ArrayDeque;
+import java.util.ArrayList;
+import java.util.Deque;
+import java.util.List;
+import java.util.concurrent.BlockingQueue;
+import java.util.concurrent.LinkedBlockingQueue;
+import java.util.function.Predicate;
+
+import org.springframework.core.metrics.ApplicationStartup;
+import org.springframework.core.metrics.StartupStep;
+import org.springframework.util.Assert;
+
+/**
+ * {@link ApplicationStartup} implementation that buffers {@link StartupStep steps} and
+ * records their timestamp as well as their processing time.
+ * <p>
+ * Once recording has been {@link #startRecording() started}, steps are buffered up until
+ * the configured {@link #BufferingApplicationStartup(int) capacity}; after that, new
+ * steps are not recorded.
+ * <p>
+ * There are several ways to keep the buffer size low:
+ * <ul>
+ * <li>configuring {@link #addFilter(Predicate) filters} to only record steps that are
+ * relevant to us.
+ * <li>{@link #drainBufferedTimeline() draining} the buffered steps.
+ * </ul>
+ *
+ * @author Brian Clozel
+ * @since 2.4.0
+ */
+public class BufferingApplicationStartup implements ApplicationStartup {
+
+	private Instant recordingStartTime;
+
+	private long recordingStartNanos;
+
+	private long currentSequenceId = 0;
+
+	private final Deque<Long> currentSteps;
+
+	private final BlockingQueue<BufferedStartupStep> recordedSteps;
+
+	private Predicate<StartupStep> stepFilters = (step) -> true;
+
+	/**
+	 * Create a new buffered {@link ApplicationStartup} with a limited capacity and starts
+	 * the recording of steps.
+	 * @param capacity the configured capacity; once reached, new steps are not recorded.
+	 */
+	public BufferingApplicationStartup(int capacity) {
+		this.currentSteps = new ArrayDeque<>();
+		this.currentSteps.offerFirst(this.currentSequenceId);
+		this.recordedSteps = new LinkedBlockingQueue<>(capacity);
+		startRecording();
+	}
+
+	/**
+	 * Start the recording of steps and mark the beginning of the {@link StartupTimeline}.
+	 * The class constructor already implicitly calls this, but it is possible to reset it
+	 * as long as steps have not been recorded already.
+	 * @throws IllegalStateException if called and {@link StartupStep} have been recorded
+	 * already.
+	 */
+	public void startRecording() {
+		Assert.state(this.recordedSteps.isEmpty(), "Cannot restart recording once steps have been buffered.");
+		this.recordingStartTime = Instant.now();
+		this.recordingStartNanos = getCurrentTime();
+	}
+
+	/**
+	 * Add a predicate filter to the list of existing ones.
+	 * <p>
+	 * A {@link StartupStep step} that doesn't match all filters will not be recorded.
+	 * @param filter the predicate filter to add.
+	 */
+	public void addFilter(Predicate<StartupStep> filter) {
+		this.stepFilters = this.stepFilters.and(filter);
+	}
+
+	/**
+	 * Return the {@link StartupTimeline timeline} as a snapshot of currently buffered
+	 * steps.
+	 * <p>
+	 * This will not remove steps from the buffer, see {@link #drainBufferedTimeline()}
+	 * for its counterpart.
+	 * @return a snapshot of currently buffered steps.
+	 */
+	public StartupTimeline getBufferedTimeline() {
+		return new StartupTimeline(this.recordingStartTime, this.recordingStartNanos, this.recordedSteps);
+	}
+
+	/**
+	 * Return the {@link StartupTimeline timeline} by pulling steps from the buffer.
+	 * <p>
+	 * This removes steps from the buffer, see {@link #getBufferedTimeline()} for its
+	 * read-only counterpart.
+	 * @return buffered steps drained from the buffer.
+	 */
+	public StartupTimeline drainBufferedTimeline() {
+		List<BufferedStartupStep> steps = new ArrayList<>(this.recordedSteps.size());
+		this.recordedSteps.drainTo(steps);
+		return new StartupTimeline(this.recordingStartTime, this.recordingStartNanos, steps);
+	}
+
+	@Override
+	public StartupStep start(String name) {
+		BufferedStartupStep step = new BufferedStartupStep(++this.currentSequenceId, name,
+				this.currentSteps.peekFirst(), this::record);
+		step.recordStartTime(getCurrentTime());
+		this.currentSteps.offerFirst(this.currentSequenceId);
+		return step;
+	}
+
+	private void record(BufferedStartupStep step) {
+		step.recordEndTime(getCurrentTime());
+		if (this.stepFilters.test(step)) {
+			this.recordedSteps.offer(step);
+		}
+		this.currentSteps.removeFirst();
+	}
+
+	private long getCurrentTime() {
+		return System.nanoTime();
+	}
+
+}

spring-boot-project/spring-boot/src/main/java/org/springframework/boot/context/metrics/buffering/StartupTimeline.java

@@ -0,0 +1,120 @@
+/*
+ * Copyright 2002-2020 the original author or authors.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      https://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package org.springframework.boot.context.metrics.buffering;
+
+import java.time.Duration;
+import java.time.Instant;
+import java.util.Collection;
+import java.util.List;
+import java.util.stream.Collectors;
+
+import org.springframework.core.metrics.StartupStep;
+
+/**
+ * Represent the timeline of {@link StartupStep steps} recorded by
+ * {@link BufferingApplicationStartup}. Each {@link TimelineEvent} has a start and end
+ * time as well as a duration measured with nanosecond precision.
+ *
+ * @author Brian Clozel
+ * @since 2.4.0
+ */
+public class StartupTimeline {
+
+	private final Instant startTime;
+
+	private final List<TimelineEvent> events;
+
+	StartupTimeline(Instant startTime, long startNanoTime, Collection<BufferedStartupStep> events) {
+		this.startTime = startTime;
+		this.events = events.stream().map((event) -> new TimelineEvent(event, startTime, startNanoTime))
+				.collect(Collectors.toList());
+	}
+
+	/**
+	 * Return the start time of this timeline.
+	 * @return the start time
+	 */
+	public Instant getStartTime() {
+		return this.startTime;
+	}
+
+	/**
+	 * Return the recorded events.
+	 * @return the events
+	 */
+	public List<TimelineEvent> getEvents() {
+		return this.events;
+	}
+
+	/**
+	 * Event on the current {@link StartupTimeline}. Each event has a start/end time, a
+	 * precise duration and the complete {@link StartupStep} information associated with
+	 * it.
+	 */
+	public static class TimelineEvent {
+
+		private final StartupStep startupStep;
+
+		private final Instant startTime;
+
+		private final Instant endTime;
+
+		private final Duration duration;
+
+		TimelineEvent(BufferedStartupStep startupStep, Instant startupDate, long startupNanoTime) {
+			this.startupStep = startupStep;
+			this.startTime = startupDate.plus(Duration.ofNanos(startupStep.getStartTime() - startupNanoTime));
+			this.endTime = startupDate.plus(Duration.ofNanos(startupStep.getEndTime() - startupNanoTime));
+			this.duration = Duration.ofNanos(startupStep.getEndTime() - startupStep.getStartTime());
+		}
+
+		/**
+		 * Return the start time of this event.
+		 * @return the start time
+		 */
+		public Instant getStartTime() {
+			return this.startTime;
+		}
+
+		/**
+		 * Return the end time of this event.
+		 * @return the end time
+		 */
+		public Instant getEndTime() {
+			return this.endTime;
+		}
+
+		/**
+		 * Return the duration of this event, i.e. the processing time of the associated
+		 * {@link StartupStep} with nanoseconds precision.
+		 * @return the event duration
+		 */
+		public Duration getDuration() {
+			return this.duration;
+		}
+
+		/**
+		 * Return the {@link StartupStep} information for this event.
+		 * @return the step information.
+		 */
+		public StartupStep getStartupStep() {
+			return this.startupStep;
+		}
+
+	}
+
+}

spring-boot-project/spring-boot/src/main/java/org/springframework/boot/context/metrics/buffering/package-info.java

@@ -0,0 +1,21 @@
+/*
+ * Copyright 2012-2020 the original author or authors.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      https://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+/**
+ * {@link org.springframework.core.metrics.ApplicationStartup} implementation for
+ * buffering steps and measuring their processing time.
+ */
+package org.springframework.boot.context.metrics.buffering;

spring-boot-project/spring-boot/src/test/java/org/springframework/boot/context/metrics/buffering/BufferingApplicationStartupTests.java

@@ -0,0 +1,103 @@
+/*
+ * Copyright 2012-2020 the original author or authors.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      https://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package org.springframework.boot.context.metrics.buffering;
+
+import org.junit.jupiter.api.Test;
+
+import org.springframework.core.metrics.StartupStep;
+
+import static org.assertj.core.api.Assertions.assertThat;
+import static org.assertj.core.api.Assertions.assertThatThrownBy;
+
+/**
+ * Tests for {@link BufferingApplicationStartup}.
+ *
+ * @author Brian Clozel
+ */
+class BufferingApplicationStartupTests {
+
+	@Test
+	void shouldNotRecordEventsWhenOverCapacity() {
+		BufferingApplicationStartup applicationStartup = new BufferingApplicationStartup(2);
+		applicationStartup.start("first").end();
+		applicationStartup.start("second").end();
+		applicationStartup.start("third").end();
+		assertThat(applicationStartup.getBufferedTimeline().getEvents()).hasSize(2);
+	}
+
+	@Test
+	void shouldNotRecordEventsWhenFiltered() {
+		BufferingApplicationStartup applicationStartup = new BufferingApplicationStartup(5);
+		applicationStartup.addFilter((step) -> step.getName().startsWith("spring"));
+		applicationStartup.start("spring.first").end();
+		StartupStep filtered = applicationStartup.start("filtered.second");
+		applicationStartup.start("spring.third").end();
+		filtered.end();
+		assertThat(applicationStartup.getBufferedTimeline().getEvents()).hasSize(2);
+		StartupTimeline.TimelineEvent firstEvent = applicationStartup.getBufferedTimeline().getEvents().get(0);
+		assertThat(firstEvent.getStartupStep().getId()).isEqualTo(1);
+		assertThat(firstEvent.getStartupStep().getParentId()).isEqualTo(0);
+		StartupTimeline.TimelineEvent secondEvent = applicationStartup.getBufferedTimeline().getEvents().get(1);
+		assertThat(secondEvent.getStartupStep().getId()).isEqualTo(3);
+		assertThat(secondEvent.getStartupStep().getParentId()).isEqualTo(2);
+	}
+
+	@Test
+	void bufferShouldNotBeEmptyWhenGettingSnapshot() {
+		BufferingApplicationStartup applicationStartup = new BufferingApplicationStartup(2);
+		applicationStartup.start("first").end();
+		applicationStartup.start("second").end();
+		assertThat(applicationStartup.getBufferedTimeline().getEvents()).hasSize(2);
+		assertThat(applicationStartup.getBufferedTimeline().getEvents()).hasSize(2);
+	}
+
+	@Test
+	void bufferShouldBeEmptyWhenDraining() {
+		BufferingApplicationStartup applicationStartup = new BufferingApplicationStartup(2);
+		applicationStartup.start("first").end();
+		applicationStartup.start("second").end();
+		assertThat(applicationStartup.drainBufferedTimeline().getEvents()).hasSize(2);
+		assertThat(applicationStartup.getBufferedTimeline().getEvents()).isEmpty();
+	}
+
+	@Test
+	void startRecordingShouldFailIfEventsWereRecorded() {
+		BufferingApplicationStartup applicationStartup = new BufferingApplicationStartup(2);
+		applicationStartup.start("first").end();
+		assertThatThrownBy(applicationStartup::startRecording).isInstanceOf(IllegalStateException.class)
+				.hasMessage("Cannot restart recording once steps have been buffered.");
+	}
+
+	@Test
+	void taggingShouldFailWhenEventAlreadyRecorded() {
+		BufferingApplicationStartup applicationStartup = new BufferingApplicationStartup(2);
+		StartupStep step = applicationStartup.start("first");
+		step.end();
+		assertThatThrownBy(() -> step.tag("name", "value")).isInstanceOf(IllegalStateException.class)
+				.hasMessage("StartupStep has already ended.");
+	}
+
+	@Test
+	void taggingShouldFailWhenRemovingEntry() {
+		BufferingApplicationStartup applicationStartup = new BufferingApplicationStartup(2);
+		StartupStep step = applicationStartup.start("first");
+		step.tag("name", "value");
+		assertThatThrownBy(() -> step.getTags().iterator().remove()).isInstanceOf(UnsupportedOperationException.class)
+				.hasMessage("tags are append only");
+	}
+
+}