Skip to content

Commit 89b637f

Browse files
committed
added new constructor and tests
1 parent dc2874e commit 89b637f

File tree

2 files changed

+137
-10
lines changed

2 files changed

+137
-10
lines changed

sdk/common/src/main/java/io/opentelemetry/sdk/internal/ThrottlingLogger.java

Lines changed: 39 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@
88
import static java.util.concurrent.TimeUnit.MINUTES;
99

1010
import io.opentelemetry.sdk.common.Clock;
11+
import java.util.Locale;
1112
import java.util.concurrent.TimeUnit;
1213
import java.util.concurrent.atomic.AtomicBoolean;
1314
import java.util.logging.Level;
@@ -21,28 +22,52 @@
2122
* at any time.
2223
*/
2324
public class ThrottlingLogger {
24-
private static final double RATE_LIMIT = 5;
25-
private static final double THROTTLED_RATE_LIMIT = 1;
26-
private static final TimeUnit rateTimeUnit = MINUTES;
25+
private static final double DEFAULT_RATE_LIMIT = 5;
26+
private static final double DEFAULT_THROTTLED_RATE_LIMIT = 1;
27+
private static final TimeUnit DEFAULT_RATE_TIME_UNIT = MINUTES;
2728

2829
private final Logger delegate;
2930
private final AtomicBoolean throttled = new AtomicBoolean(false);
3031
private final RateLimiter fastRateLimiter;
3132
private final RateLimiter throttledRateLimiter;
3233

34+
private final double rateLimit;
35+
private final double throttledRateLimit;
36+
private final TimeUnit rateTimeUnit;
37+
3338
/** Create a new logger which will enforce a max number of messages per minute. */
3439
public ThrottlingLogger(Logger delegate) {
3540
this(delegate, Clock.getDefault());
3641
}
3742

43+
/** Alternate way to create logger that allows setting custom intervals and units. * */
44+
public ThrottlingLogger(
45+
Logger delegate, double rateLimit, double throttledRateLimit, TimeUnit rateTimeUnit) {
46+
this(delegate, Clock.getDefault(), rateLimit, throttledRateLimit, rateTimeUnit);
47+
}
48+
3849
// visible for testing
3950
ThrottlingLogger(Logger delegate, Clock clock) {
51+
this(delegate, clock, DEFAULT_RATE_LIMIT, DEFAULT_THROTTLED_RATE_LIMIT, DEFAULT_RATE_TIME_UNIT);
52+
}
53+
54+
ThrottlingLogger(
55+
Logger delegate,
56+
Clock clock,
57+
double rateLimit,
58+
double throttledRateLimit,
59+
TimeUnit rateTimeUnit) {
4060
this.delegate = delegate;
61+
this.rateLimit = rateLimit;
62+
this.throttledRateLimit = throttledRateLimit;
63+
this.rateTimeUnit = rateTimeUnit;
4164
this.fastRateLimiter =
42-
new RateLimiter(RATE_LIMIT / rateTimeUnit.toSeconds(1), RATE_LIMIT, clock);
65+
new RateLimiter(this.rateLimit / this.rateTimeUnit.toSeconds(1), this.rateLimit, clock);
4366
this.throttledRateLimiter =
4467
new RateLimiter(
45-
THROTTLED_RATE_LIMIT / rateTimeUnit.toSeconds(1), THROTTLED_RATE_LIMIT, clock);
68+
this.throttledRateLimit / this.rateTimeUnit.toSeconds(1),
69+
this.throttledRateLimit,
70+
clock);
4671
}
4772

4873
/** Log a message at the given level. */
@@ -69,9 +94,15 @@ public void log(Level level, String message, @Nullable Throwable throwable) {
6994

7095
if (throttled.compareAndSet(false, true)) {
7196
// spend the balance in the throttled one, so that it starts at zero.
72-
throttledRateLimiter.trySpend(THROTTLED_RATE_LIMIT);
73-
delegate.log(
74-
level, "Too many log messages detected. Will only log once per minute from now on.");
97+
throttledRateLimiter.trySpend(throttledRateLimit);
98+
String timeUnitString = rateTimeUnit.toString().toLowerCase(Locale.ROOT);
99+
String throttleMessage =
100+
String.format(
101+
Locale.ROOT,
102+
"Too many log messages detected. Will only log %.0f time(s) per %s from now on.",
103+
throttledRateLimit,
104+
timeUnitString.substring(0, timeUnitString.length() - 1));
105+
delegate.log(level, throttleMessage);
75106
doLog(level, message, throwable);
76107
}
77108
}

sdk/common/src/test/java/io/opentelemetry/sdk/internal/ThrottlingLoggerTest.java

Lines changed: 98 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -15,6 +15,7 @@
1515
import io.opentelemetry.sdk.common.Clock;
1616
import io.opentelemetry.sdk.testing.time.TestClock;
1717
import java.time.Duration;
18+
import java.util.concurrent.TimeUnit;
1819
import java.util.logging.Level;
1920
import java.util.logging.Logger;
2021
import org.junit.jupiter.api.Test;
@@ -76,7 +77,26 @@ void fiveInAMinuteTriggersLimiting() {
7677
assertThat(logs.getEvents()).hasSize(7);
7778
logs.assertDoesNotContain("oh no I should be suppressed!");
7879
logs.assertContains(
79-
"Too many log messages detected. Will only log once per minute from now on.");
80+
"Too many log messages detected. Will only log 1 time(s) per minute from now on.");
81+
logs.assertContains("oh no I should trigger suppression!");
82+
}
83+
84+
@Test
85+
void tenInAnHourTriggersLimiting() {
86+
Clock clock = TestClock.create();
87+
ThrottlingLogger logger = new ThrottlingLogger(realLogger, clock, 10, 2, TimeUnit.HOURS);
88+
89+
for (int i = 0; i < 10; i++) {
90+
logger.log(Level.WARNING, "oh no!");
91+
}
92+
93+
logger.log(Level.WARNING, "oh no I should trigger suppression!");
94+
logger.log(Level.WARNING, "oh no I should be suppressed!");
95+
96+
assertThat(logs.getEvents()).hasSize(12);
97+
logs.assertDoesNotContain("oh no I should be suppressed!");
98+
logs.assertContains(
99+
"Too many log messages detected. Will only log 2 time(s) per hour from now on.");
80100
logs.assertContains("oh no I should trigger suppression!");
81101
}
82102

@@ -130,7 +150,7 @@ void afterAMinuteLetOneThrough() {
130150
logs.assertDoesNotContain("oh no I should be suppressed!");
131151
logs.assertContains("oh no I should trigger suppression!");
132152
logs.assertContains(
133-
"Too many log messages detected. Will only log once per minute from now on.");
153+
"Too many log messages detected. Will only log 1 time(s) per minute from now on.");
134154

135155
clock.advance(Duration.ofMillis(60_001));
136156
logger.log(Level.WARNING, "oh no!");
@@ -145,6 +165,41 @@ void afterAMinuteLetOneThrough() {
145165
assertThat(logs.getEvents().get(8).getMessage()).isEqualTo("oh no!");
146166
}
147167

168+
@Test
169+
void afterAnHourLetTwoThrough() {
170+
TestClock clock = TestClock.create();
171+
ThrottlingLogger logger = new ThrottlingLogger(realLogger, clock, 10, 2, TimeUnit.HOURS);
172+
173+
for (int i = 0; i < 10; i++) {
174+
logger.log(Level.WARNING, "oh no!");
175+
}
176+
177+
logger.log(Level.WARNING, "oh no I should trigger suppression!");
178+
logger.log(Level.WARNING, "oh no I should be suppressed!");
179+
180+
assertThat(logs.getEvents()).hasSize(12);
181+
logs.assertDoesNotContain("oh no I should be suppressed!");
182+
logs.assertContains("oh no I should trigger suppression!");
183+
logs.assertContains(
184+
"Too many log messages detected. Will only log 2 time(s) per hour from now on.");
185+
186+
clock.advance(Duration.ofMinutes(61));
187+
logger.log(Level.WARNING, "oh no!");
188+
logger.log(Level.WARNING, "oh no!");
189+
logger.log(Level.WARNING, "oh no I should be suppressed!");
190+
assertThat(logs.getEvents()).hasSize(14);
191+
assertThat(logs.getEvents().get(13).getMessage()).isEqualTo("oh no!");
192+
193+
clock.advance(Duration.ofMinutes(61));
194+
logger.log(Level.WARNING, "oh no!");
195+
logger.log(Level.WARNING, "oh no!");
196+
logger.log(Level.WARNING, "oh no I should be suppressed!");
197+
assertThat(logs.getEvents()).hasSize(16);
198+
assertThat(logs.getEvents().get(15).getMessage()).isEqualTo("oh no!");
199+
200+
logs.assertDoesNotContain("oh no I should be suppressed!");
201+
}
202+
148203
@Test
149204
void allowOnlyOneLogPerMinuteAfterSuppression() {
150205
TestClock clock = TestClock.create();
@@ -181,4 +236,45 @@ void allowOnlyOneLogPerMinuteAfterSuppression() {
181236
assertThat(logs.getEvents()).hasSize(8);
182237
assertThat(logs.getEvents().get(7).getMessage()).isEqualTo("allowed 1");
183238
}
239+
240+
@Test
241+
void allowOnlyTwoLogPerHourAfterSuppression() {
242+
TestClock clock = TestClock.create();
243+
ThrottlingLogger logger = new ThrottlingLogger(realLogger, clock, 10, 2, TimeUnit.HOURS);
244+
245+
for (int i = 0; i < 10; i++) {
246+
logger.log(Level.WARNING, "oh no!");
247+
}
248+
249+
logger.log(Level.WARNING, "oh no I should trigger suppression!");
250+
logger.log(Level.WARNING, "oh no I should be suppressed!");
251+
252+
assertThat(logs.getEvents()).hasSize(12);
253+
254+
clock.advance(Duration.ofMinutes(10));
255+
logger.log(Level.WARNING, "suppression 1");
256+
clock.advance(Duration.ofMinutes(10));
257+
logger.log(Level.WARNING, "suppression 2");
258+
clock.advance(Duration.ofMinutes(10));
259+
clock.advance(Duration.ofSeconds(1));
260+
logger.log(Level.WARNING, "allowed 1");
261+
clock.advance(Duration.ofMinutes(10));
262+
logger.log(Level.WARNING, "suppression 3");
263+
clock.advance(Duration.ofMinutes(10));
264+
logger.log(Level.WARNING, "suppression 4");
265+
clock.advance(Duration.ofMinutes(10));
266+
clock.advance(Duration.ofSeconds(1));
267+
logger.log(Level.WARNING, "allowed 2");
268+
269+
logs.assertDoesNotContain("suppression 1");
270+
logs.assertDoesNotContain("suppression 2");
271+
logs.assertDoesNotContain("suppression 3");
272+
logs.assertDoesNotContain("suppression 4");
273+
logs.assertContains("allowed 1");
274+
logs.assertContains("allowed 2");
275+
276+
assertThat(logs.getEvents()).hasSize(14);
277+
assertThat(logs.getEvents().get(12).getMessage()).isEqualTo("allowed 1");
278+
assertThat(logs.getEvents().get(13).getMessage()).isEqualTo("allowed 2");
279+
}
184280
}

0 commit comments

Comments
 (0)