Skip to content

Commit a2b3ddf

Browse files
CTMBNaraCTMBNara
committed
Replace static sampling with configurable.
1 parent d63d03e commit a2b3ddf

5 files changed

Lines changed: 45 additions & 124 deletions

File tree

‎src/main/java/org/prebid/server/auction/requestfactory/Ortb2RequestFactory.java‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -558,7 +558,7 @@ private Future<Account> wrapFailure(Throwable exception, String accountId, HttpR
558558
if (exception instanceof UnauthorizedAccountException) {
559559
return Future.failedFuture(exception);
560560
} else if (exception instanceof PreBidException) {
561-
unknownAccountLogger.warn(accountErrorMessage(exception.getMessage(), httpRequest), 100);
561+
unknownAccountLogger.warn(accountErrorMessage(exception.getMessage(), httpRequest), logSamplingRate);
562562
} else {
563563
metrics.updateAccountRequestRejectedByFailedFetch(accountId);
564564
logger.warn("Error occurred while fetching account: {}", exception.getMessage());

‎src/main/java/org/prebid/server/handler/openrtb2/AmpHandler.java‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -370,14 +370,14 @@ private void handleResult(AsyncResult<RawResponseContext> responseResult,
370370
conditionalLogger.info(
371371
"%s, Referer: %s"
372372
.formatted(message, routingContext.request().headers().get(HttpUtil.REFERER_HEADER)),
373-
100);
373+
logSamplingRate);
374374

375375
status = HttpResponseStatus.BAD_REQUEST;
376376
body = message;
377377
} else if (exception instanceof UnauthorizedAccountException) {
378378
metricRequestStatus = MetricName.badinput;
379379
final String message = exception.getMessage();
380-
conditionalLogger.info(message, 100);
380+
conditionalLogger.info(message, logSamplingRate);
381381

382382
errorMessages = Collections.singletonList(message);
383383

‎src/main/java/org/prebid/server/log/ConditionalLogger.java‎

Lines changed: 27 additions & 78 deletions
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,6 @@
88
import java.util.concurrent.ConcurrentMap;
99
import java.util.concurrent.ThreadLocalRandom;
1010
import java.util.concurrent.TimeUnit;
11-
import java.util.concurrent.atomic.AtomicInteger;
1211
import java.util.function.Consumer;
1312

1413
public class ConditionalLogger {
@@ -19,125 +18,75 @@ public class ConditionalLogger {
1918
private final String key;
2019
private final Logger logger;
2120

22-
private final ConcurrentMap<String, AtomicInteger> messageToCount;
23-
private final ConcurrentMap<String, Long> messageToWait;
21+
private final ConcurrentMap<String, Instant> messageToWait;
2422

2523
public ConditionalLogger(String key, Logger logger) {
2624
this.key = key; // can be null
2725
this.logger = Objects.requireNonNull(logger);
2826

29-
messageToCount = Caffeine.newBuilder()
30-
.maximumSize(CACHE_MAXIMUM_SIZE)
31-
.expireAfterWrite(EXPIRE_CACHE_DURATION, TimeUnit.HOURS)
32-
.<String, AtomicInteger>build()
33-
.asMap();
34-
3527
messageToWait = Caffeine.newBuilder()
3628
.maximumSize(CACHE_MAXIMUM_SIZE)
3729
.expireAfterWrite(EXPIRE_CACHE_DURATION, TimeUnit.HOURS)
38-
.<String, Long>build()
30+
.<String, Instant>build()
3931
.asMap();
4032
}
4133

4234
public ConditionalLogger(Logger logger) {
4335
this(null, logger);
4436
}
4537

46-
public void infoWithKey(String key, String message, int limit) {
47-
log(key, limit, logger -> logger.info(message));
38+
public void debug(String message, long duration, TimeUnit unit) {
39+
log(message, duration, unit, logger::debug);
4840
}
4941

50-
public void info(String message, int limit) {
51-
log(message, limit, logger -> logger.info(message));
42+
public void debug(String message, double samplingRate) {
43+
log(message, samplingRate, logger::debug);
5244
}
5345

5446
public void info(String message, long duration, TimeUnit unit) {
55-
log(message, duration, unit, logger -> logger.info(message));
47+
log(message, duration, unit, logger::info);
5648
}
5749

5850
public void info(String message, double samplingRate) {
59-
if (samplingRate >= 1.0d || ThreadLocalRandom.current().nextDouble() < samplingRate) {
60-
logger.warn(message);
61-
}
51+
log(message, samplingRate, logger::info);
6252
}
6353

64-
public void errorWithKey(String key, String message, int limit) {
65-
log(key, limit, logger -> logger.error(message));
54+
public void warn(String message, long duration, TimeUnit unit) {
55+
log(message, duration, unit, logger::warn);
6656
}
6757

68-
public void error(String message, int limit) {
69-
log(message, limit, logger -> logger.error(message));
58+
public void warn(String message, double samplingRate) {
59+
log(message, samplingRate, logger::warn);
7060
}
7161

7262
public void error(String message, long duration, TimeUnit unit) {
73-
log(message, duration, unit, logger -> logger.error(message));
63+
log(message, duration, unit, logger::error);
7464
}
7565

7666
public void error(String message, double samplingRate) {
77-
if (samplingRate >= 1.0d || ThreadLocalRandom.current().nextDouble() < samplingRate) {
78-
logger.error(message);
79-
}
80-
}
81-
82-
public void debug(String message, int limit) {
83-
log(message, limit, logger -> logger.debug(message));
84-
}
85-
86-
public void debug(String message, long duration, TimeUnit unit) {
87-
log(message, duration, unit, logger -> logger.debug(message));
67+
log(message, samplingRate, logger::error);
8868
}
8969

90-
public void debug(String message, double samplingRate) {
70+
private static void log(String message, double samplingRate, Consumer<String> logger) {
9171
if (samplingRate >= 1.0d || ThreadLocalRandom.current().nextDouble() < samplingRate) {
92-
logger.debug(message);
72+
logger.accept(message);
9373
}
9474
}
9575

96-
public void warn(String message, int limit) {
97-
log(message, limit, logger -> logger.warn(message));
98-
}
99-
100-
public void warn(String message, long duration, TimeUnit unit) {
101-
log(message, duration, unit, logger -> logger.warn(message));
102-
}
103-
104-
public void warn(String message, double samplingRate) {
105-
if (samplingRate >= 1.0d || ThreadLocalRandom.current().nextDouble() < samplingRate) {
106-
logger.warn(message);
107-
}
108-
}
109-
110-
/**
111-
* Calls {@link Consumer} if the given limit for specified key is not exceeded.
112-
*/
113-
private void log(String key, int limit, Consumer<Logger> consumer) {
114-
final String resolvedKey = ObjectUtils.defaultIfNull(this.key, key);
115-
final AtomicInteger count = messageToCount.computeIfAbsent(resolvedKey, ignored -> new AtomicInteger());
116-
if (count.incrementAndGet() >= limit) {
117-
count.set(0);
118-
consumer.accept(logger);
119-
}
120-
}
76+
private void log(String message, long duration, TimeUnit unit, Consumer<String> logger) {
77+
final String key = ObjectUtils.defaultIfNull(this.key, message);
78+
final Instant currentTime = Instant.now();
79+
final Instant endTime = messageToWait.computeIfAbsent(
80+
key, ignored -> calculateEndTime(currentTime, duration, unit));
12181

122-
/**
123-
* Calls {@link Consumer} if the given time for specified key is not exceeded.
124-
*/
125-
private void log(String key, long duration, TimeUnit unit, Consumer<Logger> consumer) {
126-
final long currentTime = Instant.now().toEpochMilli();
127-
final String resolvedKey = ObjectUtils.defaultIfNull(this.key, key);
128-
final long endTime = messageToWait.computeIfAbsent(resolvedKey, ignored -> calculateEndTime(duration, unit));
129-
130-
if (currentTime >= endTime) {
131-
messageToWait.replace(resolvedKey, endTime, calculateEndTime(duration, unit));
132-
consumer.accept(logger);
82+
// we skip 1st ever log event for the key
83+
if (currentTime.isAfter(endTime) || currentTime.equals(endTime)) {
84+
messageToWait.replace(key, endTime, calculateEndTime(currentTime, duration, unit));
85+
logger.accept(message);
13386
}
13487
}
13588

136-
/**
137-
* Returns time in millis as current time incremented by specified duration.
138-
*/
139-
private static long calculateEndTime(long duration, TimeUnit unit) {
140-
final long durationInMillis = unit.toMillis(duration);
141-
return Instant.now().plusMillis(durationInMillis).toEpochMilli();
89+
private static Instant calculateEndTime(Instant currentTime, long duration, TimeUnit unit) {
90+
return currentTime.plusMillis(unit.toMillis(duration));
14291
}
14392
}

‎src/main/java/org/prebid/server/privacy/gdpr/TcfDefinerService.java‎

Lines changed: 7 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -386,25 +386,25 @@ private TCString decodeTcString(String consentString, RequestLogInfo requestLogI
386386
}
387387
}
388388

389-
private static void logWarn(String consent, String message, RequestLogInfo requestLogInfo) {
389+
private void logWarn(String consent, String message, RequestLogInfo requestLogInfo) {
390390
if (requestLogInfo == null || requestLogInfo.getRequestType() == null) {
391391
final String exceptionMessage = "Parsing consent string:\"%s\" failed for undefined type with exception %s"
392392
.formatted(consent, message);
393-
undefinedCorruptConsentLogger.info(exceptionMessage, 100);
393+
undefinedCorruptConsentLogger.info(exceptionMessage, samplingRate);
394394
return;
395395
}
396396

397397
switch (requestLogInfo.getRequestType()) {
398398
case amp -> ampCorruptConsentLogger.info(
399-
logMessage(consent, MetricName.amp.toString(), requestLogInfo, message), 100);
399+
logMessage(consent, MetricName.amp.toString(), requestLogInfo, message), samplingRate);
400400
case openrtb2app -> appCorruptConsentLogger.info(
401-
logMessage(consent, MetricName.openrtb2app.toString(), requestLogInfo, message), 100);
401+
logMessage(consent, MetricName.openrtb2app.toString(), requestLogInfo, message), samplingRate);
402402
case openrtb2dooh -> doohCorruptConsentLogger.info(
403-
logMessage(consent, MetricName.openrtb2dooh.toString(), requestLogInfo, message), 100);
403+
logMessage(consent, MetricName.openrtb2dooh.toString(), requestLogInfo, message), samplingRate);
404404
case openrtb2web -> siteCorruptConsentLogger.info(
405-
logMessage(consent, MetricName.openrtb2web.toString(), requestLogInfo, message), 100);
405+
logMessage(consent, MetricName.openrtb2web.toString(), requestLogInfo, message), samplingRate);
406406
default -> undefinedCorruptConsentLogger.info(
407-
logMessage(consent, "video or sync or setuid", requestLogInfo, message), 100);
407+
logMessage(consent, "video or sync or setuid", requestLogInfo, message), samplingRate);
408408
}
409409
}
410410

‎src/test/java/org/prebid/server/log/ConditionalLoggerTest.java‎

Lines changed: 8 additions & 36 deletions
Original file line numberDiff line numberDiff line change
@@ -8,22 +8,21 @@
88
import org.junit.jupiter.api.BeforeEach;
99
import org.junit.jupiter.api.Test;
1010
import org.junit.jupiter.api.extension.ExtendWith;
11-
import org.mockito.Mock;
11+
import org.mockito.Spy;
1212
import org.mockito.junit.jupiter.MockitoExtension;
1313

1414
import java.util.concurrent.TimeUnit;
1515

1616
import static org.mockito.ArgumentMatchers.argThat;
1717
import static org.mockito.Mockito.times;
1818
import static org.mockito.Mockito.verify;
19-
import static org.mockito.Mockito.verifyNoMoreInteractions;
2019

2120
@ExtendWith(MockitoExtension.class)
2221
@ExtendWith(VertxExtension.class)
2322
public class ConditionalLoggerTest {
2423

25-
@Mock
26-
private Logger logger;
24+
@Spy
25+
private Logger logger = LoggerFactory.getLogger(ConditionalLoggerTest.class);
2726

2827
private Vertx vertx;
2928

@@ -41,45 +40,18 @@ public void tearDown(VertxTestContext context) {
4140
}
4241

4342
@Test
44-
public void infoWithKeyShouldCallLoggerWithExpectedCount() {
43+
public void infoShouldCallLoggerForEachLog() {
4544
// when
46-
for (int i = 0; i < 10; i++) {
47-
conditionalLogger.infoWithKey("key", "Log Message1", 2);
48-
conditionalLogger.infoWithKey("key", "Log Message2", 2);
49-
}
50-
51-
// then
52-
verify(logger, times(10)).info("Log Message2");
53-
verifyNoMoreInteractions(logger);
54-
}
55-
56-
@Test
57-
public void infoShouldCallLoggerWithExpectedCount() {
58-
// when
59-
for (int i = 0; i < 10; i++) {
60-
conditionalLogger.info("Log Message", 2);
61-
}
62-
63-
// then
64-
verify(logger, times(5)).info("Log Message");
65-
}
66-
67-
@Test
68-
public void infoShouldCallLoggerBySpecifiedKeyWithExpectedCount() {
69-
// given
70-
conditionalLogger = new ConditionalLogger("key1", logger);
71-
72-
// when
73-
for (int i = 0; i < 10; i++) {
74-
conditionalLogger.info("Log Message" + i, 2);
45+
for (int i = 0; i < 5; i++) {
46+
conditionalLogger.info("Log Message" + i, 0, TimeUnit.MILLISECONDS);
7547
}
7648

7749
// then
7850
verify(logger, times(5)).info(argThat(o -> o.toString().startsWith("Log Message")));
7951
}
8052

8153
@Test
82-
public void infoShouldCallLoggerWithExpectedTimeout() {
54+
public void infoShouldSkipLogsForDuration() {
8355
// when
8456
for (int i = 0; i < 5; i++) {
8557
conditionalLogger.info("Log Message", 200, TimeUnit.MILLISECONDS);
@@ -91,7 +63,7 @@ public void infoShouldCallLoggerWithExpectedTimeout() {
9163
}
9264

9365
@Test
94-
public void infoShouldCallLoggerBySpecifiedKeyWithExpectedTimeout() {
66+
public void infoShouldSkipLogsForKeyForDuration() {
9567
// given
9668
conditionalLogger = new ConditionalLogger("key1", logger);
9769

0 commit comments

Comments
 (0)