Skip to content

Commit d80a4fe

Browse files
committed
Format startup duration in human-readable units.
Signed-off-by: Huang Xiao <[email protected]>
1 parent 29d0299 commit d80a4fe

File tree

2 files changed

+74
-6
lines changed

2 files changed

+74
-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: 54 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,69 @@ 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(
140+
(message) -> assertThat(message.toString()).isEqualTo("Started " + getClass().getSimpleName()
141+
+ " in 1 minute 30 seconds (process running for 1 minute 30 seconds)")));
142+
}
143+
144+
@Test
145+
void startedFormatWithHours() {
146+
given(this.log.isInfoEnabled()).willReturn(true);
147+
new StartupInfoLogger(getClass(), this.environment).logStarted(this.log,
148+
new TestStartup(4500000L, "Started", 4500000L));
149+
then(this.log).should()
150+
.info(assertArg((message) -> assertThat(message.toString()).isEqualTo("Started "
151+
+ getClass().getSimpleName() + " in 1 hour 15 minutes (process running for 1 hour 15 minutes)")));
152+
}
153+
154+
@Test
155+
void startedFormatWithSingularUnits() {
156+
given(this.log.isInfoEnabled()).willReturn(true);
157+
new StartupInfoLogger(getClass(), this.environment).logStarted(this.log,
158+
new TestStartup(61000L, "Started", 61000L));
159+
then(this.log).should()
160+
.info(assertArg((message) -> assertThat(message.toString()).isEqualTo("Started "
161+
+ getClass().getSimpleName() + " in 1 minute 1 second (process running for 1 minute 1 second)")));
162+
}
163+
164+
@Test
165+
void startedFormatWithZeroSeconds() {
166+
given(this.log.isInfoEnabled()).willReturn(true);
167+
new StartupInfoLogger(getClass(), this.environment).logStarted(this.log,
168+
new TestStartup(300000L, "Started", 300000L));
169+
then(this.log).should()
170+
.info(assertArg(
171+
(message) -> assertThat(message.toString()).isEqualTo("Started " + getClass().getSimpleName()
172+
+ " in 5 minutes 0 seconds (process running for 5 minutes 0 seconds)")));
173+
}
174+
133175
static class TestStartup extends Startup {
134176

135-
private final long startTime = System.currentTimeMillis();
177+
private long startTime;
136178

137179
private final @Nullable Long uptime;
138180

139181
private final String action;
140182

141183
TestStartup(@Nullable Long uptime, String action) {
184+
this(uptime, action, null);
185+
}
186+
187+
TestStartup(@Nullable Long uptime, String action, @Nullable Long timeTaken) {
142188
this.uptime = uptime;
143189
this.action = action;
190+
if (timeTaken != null) {
191+
this.startTime = System.currentTimeMillis() - timeTaken;
192+
}
193+
else {
194+
this.startTime = System.currentTimeMillis();
195+
}
144196
started();
145197
}
146198

0 commit comments

Comments
 (0)