Skip to content

Commit 5df3ab7

Browse files
committed
Fixed #82
Created a utility class for time related helper functions and moved non time logging specific code from TimerBase. Added test cases.
1 parent 426d224 commit 5df3ab7

File tree

3 files changed

+223
-25
lines changed

3 files changed

+223
-25
lines changed

src/main/java/org/culturegraph/mf/stream/pipe/TimerBase.java

Lines changed: 7 additions & 25 deletions
Original file line numberDiff line numberDiff line change
@@ -17,23 +17,21 @@
1717

1818
import org.culturegraph.mf.framework.LifeCycle;
1919
import org.culturegraph.mf.framework.Sender;
20+
import org.culturegraph.mf.util.TimeUtil;
2021
import org.slf4j.Logger;
2122
import org.slf4j.LoggerFactory;
2223

2324

2425
/**
2526
* @author Christoph Böhme
26-
*
27+
*
2728
* @param <R>
2829
* receiver type.
2930
*/
3031
public class TimerBase<R extends LifeCycle> implements Sender<R> {
3132

3233
private static final Logger LOG = LoggerFactory.getLogger(TimerBase.class);
3334

34-
private static final String[] UNIT_NAMES = { "ns", "µs", "ms", "s", "min", "h" };
35-
private static final long[] UNIT_FACTORS = { 1, 1000, 1000, 1000, 60, 60 };
36-
3735
private final String logPrefix;
3836

3937
private long count;
@@ -47,7 +45,7 @@ public final <S extends R> S setReceiver(final S receiver) {
4745
this.receiver = receiver;
4846
return receiver;
4947
}
50-
48+
5149
public R getReceiver() {
5250
return receiver;
5351
}
@@ -66,13 +64,13 @@ public final void closeStream() {
6664
final long averageDuration = cumulativeDuration / count;
6765
LOG.info(logPrefix
6866
+ String.format("Executions: %d; Cumulative duration: %s; Average duration: %s", Long.valueOf(count),
69-
scaleTime(cumulativeDuration), scaleTime(averageDuration)));
67+
TimeUtil.formatDuration(cumulativeDuration), TimeUtil.formatDuration(averageDuration)));
7068
startMeasurement();
7169
if (receiver != null) {
7270
receiver.closeStream();
7371
}
7472
stopMeasurement("Time to close stream: ");
75-
73+
7674
}
7775

7876
protected TimerBase(final String logPrefix) {
@@ -83,7 +81,7 @@ protected TimerBase(final String logPrefix) {
8381
protected final void startMeasurement() {
8482
startTime = System.nanoTime();
8583
}
86-
84+
8785
protected final void stopMeasurement(){
8886
stopMeasurement("Execution %1$d:");
8987
}
@@ -94,23 +92,7 @@ protected final void stopMeasurement(final String prefix) {
9492
count += 1;
9593
cumulativeDuration += duration;
9694

97-
LOG.info(logPrefix + String.format(prefix + " %2$s", Long.valueOf(count), scaleTime(duration)));
98-
}
99-
100-
private static String scaleTime(final long time) {
101-
long major = time;
102-
long minor;
103-
int i = -1;
104-
do {
105-
i += 1;
106-
minor = major % UNIT_FACTORS[i];
107-
major /= UNIT_FACTORS[i];
108-
} while (i == UNIT_FACTORS.length || major >= UNIT_FACTORS[i + 1]);
109-
110-
if (i == 0) {
111-
return String.format("%d%s", Long.valueOf(major), UNIT_NAMES[0]);
112-
}
113-
return String.format("%d%s %d%s", Long.valueOf(major), UNIT_NAMES[i], Long.valueOf(minor), UNIT_NAMES[i - 1]);
95+
LOG.info(logPrefix + String.format(prefix + " %2$s", Long.valueOf(count), TimeUtil.formatDuration(duration)));
11496
}
11597

11698
}
Lines changed: 59 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,59 @@
1+
/*
2+
* Copyright 2013 Deutsche Nationalbibliothek
3+
*
4+
* Licensed under the Apache License, Version 2.0 the "License";
5+
* you may not use this file except in compliance with the License.
6+
* You may obtain a copy of the License at
7+
*
8+
* http://www.apache.org/licenses/LICENSE-2.0
9+
*
10+
* Unless required by applicable law or agreed to in writing, software
11+
* distributed under the License is distributed on an "AS IS" BASIS,
12+
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13+
* See the License for the specific language governing permissions and
14+
* limitations under the License.
15+
*/
16+
package org.culturegraph.mf.util;
17+
18+
/**
19+
* Time related utility functions.
20+
*
21+
* @author Christoph Böhme
22+
*/
23+
public final class TimeUtil {
24+
25+
public static final String[] UNIT_SYMBOLS = { "ns", "µs", "ms", "s", "min", "h" };
26+
public static final long[] UNIT_FACTORS = { 1L, 1000L, 1000L, 1000L, 60L, 60L };
27+
28+
public static final long HOURS = 60L * 60L * 1000L * 1000L * 1000L;
29+
public static final long MINUTES = 60L * 1000L * 1000L * 1000L;
30+
public static final long SECONDS = 1000L * 1000L * 1000L;
31+
public static final long MILLISECONDS = 1000L * 1000L;
32+
public static final long MICROSECONDS = 1000L;
33+
public static final long NANOSECONDS = 1L;
34+
35+
private TimeUtil() {
36+
// No instances allowed
37+
}
38+
39+
public static String formatDuration(final long duration) {
40+
long major = duration;
41+
long minor = 0;
42+
int i = -1;
43+
while (i < UNIT_FACTORS.length - 1 && major >= UNIT_FACTORS[i + 1]) {
44+
long carry = 0;
45+
if (i > 0 && minor >= UNIT_FACTORS[i] / 2) {
46+
carry = 1;
47+
}
48+
i += 1;
49+
minor = major % UNIT_FACTORS[i] + carry;
50+
major /= UNIT_FACTORS[i];
51+
}
52+
53+
if (i == 0 || minor == 0) {
54+
return String.format("%d%s", Long.valueOf(major), UNIT_SYMBOLS[i]);
55+
}
56+
return String.format("%d%s %d%s", Long.valueOf(major), UNIT_SYMBOLS[i], Long.valueOf(minor), UNIT_SYMBOLS[i - 1]);
57+
}
58+
59+
}
Lines changed: 157 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,157 @@
1+
/*
2+
* Copyright 2013 Deutsche Nationalbibliothek
3+
*
4+
* Licensed under the Apache License, Version 2.0 the "License";
5+
* you may not use this file except in compliance with the License.
6+
* You may obtain a copy of the License at
7+
*
8+
* http://www.apache.org/licenses/LICENSE-2.0
9+
*
10+
* Unless required by applicable law or agreed to in writing, software
11+
* distributed under the License is distributed on an "AS IS" BASIS,
12+
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13+
* See the License for the specific language governing permissions and
14+
* limitations under the License.
15+
*/
16+
package org.culturegraph.mf.util;
17+
18+
import static org.junit.Assert.assertEquals;
19+
20+
import org.junit.Test;
21+
22+
/**
23+
* Tests for {@link TimeUtil}.
24+
*
25+
* @author Christoph Böhme
26+
*
27+
*/
28+
public final class TimeUtilTest {
29+
30+
//CHECKSTYLE OFF: MagicNumber|MultipleStringLiterals
31+
//
32+
// It does not aid the comprehensibility of the test cases
33+
// if constants were used for the (semi-randomly chosen)
34+
// numbers and their string representations.
35+
36+
@Test
37+
public void testShouldFormatNanoseconds() {
38+
final long duration = 29 * TimeUtil.NANOSECONDS;
39+
40+
final String formattedDuration = TimeUtil.formatDuration(duration);
41+
42+
assertEquals("29ns", formattedDuration);
43+
}
44+
45+
@Test
46+
public void testShouldFormatMicroseconds() {
47+
final long duration = 28 * TimeUtil.MICROSECONDS;
48+
49+
final String formattedDuration = TimeUtil.formatDuration(duration);
50+
51+
assertEquals("28µs", formattedDuration);
52+
}
53+
54+
@Test
55+
public void testShouldFormatSeconds() {
56+
final long duration = 10 * TimeUtil.SECONDS;
57+
58+
final String formattedDuration = TimeUtil.formatDuration(duration);
59+
60+
assertEquals("10s", formattedDuration);
61+
}
62+
63+
@Test
64+
public void testShouldFormatMinutes() {
65+
final long duration = 58 * TimeUtil.MINUTES;
66+
67+
final String formattedDuration = TimeUtil.formatDuration(duration);
68+
69+
assertEquals("58min", formattedDuration);
70+
}
71+
72+
@Test
73+
public void testShouldFormatMicrosecondsPlusNanoseconds() {
74+
final long duration = 28 * TimeUtil.MICROSECONDS + 9 * TimeUtil.NANOSECONDS;
75+
76+
final String formattedDuration = TimeUtil.formatDuration(duration);
77+
78+
assertEquals("28µs 9ns", formattedDuration);
79+
}
80+
81+
@Test
82+
public void testShouldFormatSecondsPlusMilliseconds() {
83+
final long duration = 10 * TimeUtil.SECONDS + 8 * TimeUtil.MILLISECONDS;
84+
85+
final String formattedDuration = TimeUtil.formatDuration(duration);
86+
87+
assertEquals("10s 8ms", formattedDuration);
88+
}
89+
90+
@Test
91+
public void testShouldRoundDownIfRemainderLessThanHalf() {
92+
final long duration = 23 * TimeUtil.MINUTES + 1 * TimeUtil.SECONDS + 499 * TimeUtil.MILLISECONDS;
93+
94+
final String formattedDuration = TimeUtil.formatDuration(duration);
95+
96+
assertEquals("23min 1s", formattedDuration);
97+
}
98+
99+
@Test
100+
public void testShouldRoundDownIfNanosecondsLessThanHalf() {
101+
final long duration = 23 * TimeUtil.MILLISECONDS + 1 * TimeUtil.MICROSECONDS + 499 * TimeUtil.NANOSECONDS;
102+
103+
final String formattedDuration = TimeUtil.formatDuration(duration);
104+
105+
assertEquals("23ms 1µs", formattedDuration);
106+
}
107+
108+
@Test
109+
public void testShouldIgnoreSmallerQualifiersWhenRounding() {
110+
final long duration = 23 * TimeUtil.MINUTES + 1 * TimeUtil.SECONDS + 501 * TimeUtil.MICROSECONDS;
111+
112+
final String formattedDuration = TimeUtil.formatDuration(duration);
113+
114+
assertEquals("23min 1s", formattedDuration);
115+
}
116+
117+
@Test
118+
public void testShouldRoundUpIfRemainderGreaterThanHalf() {
119+
final long duration = 42 * TimeUtil.MINUTES + 1 * TimeUtil.SECONDS + 501 * TimeUtil.MILLISECONDS;
120+
121+
final String formattedDuration = TimeUtil.formatDuration(duration);
122+
123+
assertEquals("42min 2s", formattedDuration);
124+
}
125+
126+
@Test
127+
public void testShouldRoundDownIfNanosecondsGreaterThanHalf() {
128+
final long duration = 42 * TimeUtil.MILLISECONDS + 1 * TimeUtil.MICROSECONDS + 501 * TimeUtil.NANOSECONDS;
129+
130+
final String formattedDuration = TimeUtil.formatDuration(duration);
131+
132+
assertEquals("42ms 2µs", formattedDuration);
133+
}
134+
135+
@Test
136+
public void testShouldRoundUpIfRemainderIsMidway() {
137+
final long duration = 42 * TimeUtil.MINUTES + 1 * TimeUtil.SECONDS + 500 * TimeUtil.MILLISECONDS;
138+
139+
final String formattedDuration = TimeUtil.formatDuration(duration);
140+
141+
assertEquals("42min 2s", formattedDuration);
142+
}
143+
144+
/**
145+
* Test for issue #82: TimerBase throws ArrayIndexOutOfBoundsException
146+
* if the measured duration is longer than one hour.
147+
*/
148+
@Test
149+
public void testShouldNotFailIfDurationNeedsLargestQuantifier() {
150+
final long duration = 1 * TimeUtil.HOURS + 1 * TimeUtil.MINUTES;
151+
152+
final String formattedDuration = TimeUtil.formatDuration(duration);
153+
154+
assertEquals("1h 1min", formattedDuration);
155+
}
156+
157+
}

0 commit comments

Comments
 (0)