Skip to content

Commit 8df1f91

Browse files
committed
Format startup duration in human-readable units.
1 parent 29d0299 commit 8df1f91

File tree

2 files changed

+72
-6
lines changed

2 files changed

+72
-6
lines changed

core/spring-boot/src/main/java/org/springframework/boot/StartupInfoLogger.java

Lines changed: 20 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,7 @@
1616

1717
package org.springframework.boot;
1818

19+
import java.time.Duration;
1920
import java.util.concurrent.Callable;
2021

2122
import org.apache.commons.logging.Log;
@@ -87,16 +88,31 @@ private CharSequence getStartedMessage(Startup startup) {
8788
message.append(startup.action());
8889
appendApplicationName(message);
8990
message.append(" in ");
90-
message.append(startup.timeTakenToStarted().toMillis() / 1000.0);
91-
message.append(" seconds");
91+
message.append(formatDuration(startup.timeTakenToStarted().toMillis()));
9292
Long uptimeMs = startup.processUptime();
9393
if (uptimeMs != null) {
94-
double uptime = uptimeMs / 1000.0;
95-
message.append(" (process running for ").append(uptime).append(")");
94+
message.append(" (process running for ").append(formatDuration(uptimeMs)).append(")");
9695
}
9796
return message;
9897
}
9998

99+
private String formatDuration(long millis) {
100+
Duration duration = Duration.ofMillis(millis);
101+
long seconds = duration.getSeconds();
102+
if (seconds < 60) {
103+
return String.format("%.3f seconds", millis / 1000.0);
104+
}
105+
long hours = duration.toHours();
106+
int minutes = duration.toMinutesPart();
107+
int secs = duration.toSecondsPart();
108+
if (hours > 0) {
109+
return String.format("%d hour%s %d minute%s", hours, (hours != 1) ? "s" : "", minutes,
110+
(minutes != 1) ? "s" : "");
111+
}
112+
return String.format("%d minute%s %d second%s", minutes, (minutes != 1) ? "s" : "", secs,
113+
(secs != 1) ? "s" : "");
114+
}
115+
100116
private void appendAotMode(StringBuilder message) {
101117
append(message, "", () -> AotDetector.useGeneratedArtifacts() ? "AOT-processed" : null);
102118
}

core/spring-boot/src/test/java/org/springframework/boot/StartupInfoLoggerTests.java

Lines changed: 52 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -109,7 +109,7 @@ void startedFormat() {
109109
new StartupInfoLogger(getClass(), this.environment).logStarted(this.log, new TestStartup(1345L, "Started"));
110110
then(this.log).should()
111111
.info(assertArg((message) -> assertThat(message.toString()).matches("Started " + getClass().getSimpleName()
112-
+ " in \\d+\\.\\d{1,3} seconds \\(process running for 1.345\\)")));
112+
+ " in \\d+\\.\\d{1,3} seconds \\(process running for 1\\.345 seconds\\)")));
113113
}
114114

115115
@Test
@@ -130,17 +130,67 @@ void restoredFormat() {
130130
.matches("Restored " + getClass().getSimpleName() + " in \\d+\\.\\d{1,3} seconds")));
131131
}
132132

133+
@Test
134+
void startedFormatWithMinutes() {
135+
given(this.log.isInfoEnabled()).willReturn(true);
136+
new StartupInfoLogger(getClass(), this.environment).logStarted(this.log,
137+
new TestStartup(90000L, "Started", 90000L));
138+
then(this.log).should()
139+
.info(assertArg((message) -> assertThat(message.toString()).isEqualTo("Started "
140+
+ getClass().getSimpleName() + " in 1 minute 30 seconds (process running for 1 minute 30 seconds)")));
141+
}
142+
143+
@Test
144+
void startedFormatWithHours() {
145+
given(this.log.isInfoEnabled()).willReturn(true);
146+
new StartupInfoLogger(getClass(), this.environment).logStarted(this.log,
147+
new TestStartup(4500000L, "Started", 4500000L));
148+
then(this.log).should()
149+
.info(assertArg((message) -> assertThat(message.toString()).isEqualTo("Started "
150+
+ getClass().getSimpleName() + " in 1 hour 15 minutes (process running for 1 hour 15 minutes)")));
151+
}
152+
153+
@Test
154+
void startedFormatWithSingularUnits() {
155+
given(this.log.isInfoEnabled()).willReturn(true);
156+
new StartupInfoLogger(getClass(), this.environment).logStarted(this.log,
157+
new TestStartup(61000L, "Started", 61000L));
158+
then(this.log).should()
159+
.info(assertArg((message) -> assertThat(message.toString()).isEqualTo("Started "
160+
+ getClass().getSimpleName() + " in 1 minute 1 second (process running for 1 minute 1 second)")));
161+
}
162+
163+
@Test
164+
void startedFormatWithZeroSeconds() {
165+
given(this.log.isInfoEnabled()).willReturn(true);
166+
new StartupInfoLogger(getClass(), this.environment).logStarted(this.log,
167+
new TestStartup(300000L, "Started", 300000L));
168+
then(this.log).should()
169+
.info(assertArg((message) -> assertThat(message.toString()).isEqualTo("Started "
170+
+ getClass().getSimpleName() + " in 5 minutes 0 seconds (process running for 5 minutes 0 seconds)")));
171+
}
172+
133173
static class TestStartup extends Startup {
134174

135-
private final long startTime = System.currentTimeMillis();
175+
private long startTime;
136176

137177
private final @Nullable Long uptime;
138178

139179
private final String action;
140180

141181
TestStartup(@Nullable Long uptime, String action) {
182+
this(uptime, action, null);
183+
}
184+
185+
TestStartup(@Nullable Long uptime, String action, @Nullable Long timeTaken) {
142186
this.uptime = uptime;
143187
this.action = action;
188+
if (timeTaken != null) {
189+
this.startTime = System.currentTimeMillis() - timeTaken;
190+
}
191+
else {
192+
this.startTime = System.currentTimeMillis();
193+
}
144194
started();
145195
}
146196

0 commit comments

Comments
 (0)