Skip to content

Commit 4c43d6c

Browse files
authored
[Test] Ensure test pass with explicit counter and timer (elastic#74666)
ApiKeyServiceTests#testApiKeyAuthCacheWillLogWarningOnPossibleThrashing is a new tested added as part of elastic#74388. But it fails intermittently on CI. The likely reason is that either the counter or the timer is not the expected value when the code runs. This PR explicitly configures both the counter and timer needed for triggering the warning message so that the warning message should always fire as expected. Resolves: elastic#74586
1 parent 4a4ce85 commit 4c43d6c

File tree

2 files changed

+31
-7
lines changed

2 files changed

+31
-7
lines changed

x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/ApiKeyService.java

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1149,6 +1149,11 @@ LongAdder getEvictionCounter() {
11491149
return evictionCounter;
11501150
}
11511151

1152+
// package private for test
1153+
AtomicLong getLastEvictionCheckedAt() {
1154+
return lastEvictionCheckedAt;
1155+
}
1156+
11521157
/**
11531158
* Returns realm name for the authenticated user.
11541159
* If the user is authenticated by realm type {@value API_KEY_REALM_TYPE}

x-pack/plugin/security/src/test/java/org/elasticsearch/xpack/security/authc/ApiKeyServiceTests.java

Lines changed: 26 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -123,6 +123,7 @@
123123
import static org.hamcrest.Matchers.equalTo;
124124
import static org.hamcrest.Matchers.instanceOf;
125125
import static org.hamcrest.Matchers.is;
126+
import static org.hamcrest.Matchers.lessThanOrEqualTo;
126127
import static org.hamcrest.Matchers.not;
127128
import static org.hamcrest.Matchers.notNullValue;
128129
import static org.hamcrest.Matchers.nullValue;
@@ -778,39 +779,57 @@ public void testApiKeyCacheWillNotTraceLogOnEvictionDueToCacheTtl() throws Illeg
778779
}
779780
}
780781

781-
@AwaitsFix(bugUrl = "https://github.com/elastic/elasticsearch/issues/74586")
782782
public void testApiKeyAuthCacheWillLogWarningOnPossibleThrashing() throws Exception {
783783
ApiKeyService service = createApiKeyService(
784-
Settings.builder().put("xpack.security.authc.api_key.cache.max_keys", 1).build());
784+
Settings.builder().put("xpack.security.authc.api_key.cache.max_keys", 2).build());
785785
final Cache<String, ListenableFuture<CachedApiKeyHashResult>> apiKeyAuthCache = service.getApiKeyAuthCache();
786786

787787
// Fill the cache
788-
final String apiKeyId = randomAlphaOfLength(22);
789-
apiKeyAuthCache.put(apiKeyId, new ListenableFuture<>());
788+
apiKeyAuthCache.put(randomAlphaOfLength(20), new ListenableFuture<>());
789+
apiKeyAuthCache.put(randomAlphaOfLength(21), new ListenableFuture<>());
790790
final Logger logger = LogManager.getLogger(ApiKeyService.class);
791-
Loggers.setLevel(logger, Level.WARN);
791+
Loggers.setLevel(logger, Level.TRACE);
792792
final MockLogAppender appender = new MockLogAppender();
793793
Loggers.addAppender(logger, appender);
794794
appender.start();
795795

796796
try {
797797
// Prepare the warning logging to trigger
798798
service.getEvictionCounter().add(4500);
799+
final long thrashingCheckIntervalInSeconds = 300L;
800+
final long secondsToNanoSeconds = 1_000_000_000L;
801+
// Calculate the last thrashing check time to ensure that the elapsed time is longer than the
802+
// thrashing checking interval (300 seconds). Also add another 10 seconds to counter any
803+
// test flakiness.
804+
final long lastCheckedAt = System.nanoTime() - (thrashingCheckIntervalInSeconds + 10L) * secondsToNanoSeconds;
805+
service.getLastEvictionCheckedAt().set(lastCheckedAt);
799806
// Ensure the counter is updated
800807
assertBusy(() -> assertThat(service.getEvictionCounter().longValue() >= 4500, is(true)));
808+
appender.addExpectation(new MockLogAppender.SeenEventExpectation(
809+
"evict", ApiKeyService.class.getName(), Level.TRACE,
810+
"API key with ID [*] was evicted from the authentication cache*"
811+
));
801812
appender.addExpectation(new MockLogAppender.SeenEventExpectation(
802813
"thrashing", ApiKeyService.class.getName(), Level.WARN,
803814
"Possible thrashing for API key authentication cache,*"
804815
));
805-
apiKeyAuthCache.put(randomAlphaOfLength(23), new ListenableFuture<>());
816+
apiKeyAuthCache.put(randomAlphaOfLength(22), new ListenableFuture<>());
806817
appender.assertAllExpectationsMatched();
807818

819+
// Counter and timer should be reset
820+
assertThat(service.getLastEvictionCheckedAt().get(), lessThanOrEqualTo(System.nanoTime()));
821+
assertBusy(() -> assertThat(service.getEvictionCounter().longValue(), equalTo(0L)));
822+
808823
// Will not log warning again for the next eviction because of throttling
824+
appender.addExpectation(new MockLogAppender.SeenEventExpectation(
825+
"evict-again", ApiKeyService.class.getName(), Level.TRACE,
826+
"API key with ID [*] was evicted from the authentication cache*"
827+
));
809828
appender.addExpectation(new MockLogAppender.UnseenEventExpectation(
810829
"throttling", ApiKeyService.class.getName(), Level.WARN,
811830
"Possible thrashing for API key authentication cache,*"
812831
));
813-
apiKeyAuthCache.put(randomAlphaOfLength(24), new ListenableFuture<>());
832+
apiKeyAuthCache.put(randomAlphaOfLength(23), new ListenableFuture<>());
814833
appender.assertAllExpectationsMatched();
815834
} finally {
816835
appender.stop();

0 commit comments

Comments
 (0)