Skip to content

Commit 53f16d9

Browse files
BouncheckBouncheck
committed
Stabilize AdvancedShardAwarenessIT
On recent Scylla versions this test started failing periodically. It looks like with newer Scylla the driver somehow hits a scenario where it successfully initializes a good portion of the connections, then all connection attempts to one of the nodes get rejected. It is accompanied by multiple erros like this: ``` 19:38:41.582 [s0-admin-1] WARN c.d.o.d.i.core.pool.ChannelPool - [s0|/127.0.2.2:19042] Error while opening new channel com.datastax.oss.driver.api.core.DriverTimeoutException: [s0|id: 0xfc42b7c7, L:/127.0.0.1:11854 - R:/127.0.2.2:19042] Protocol initialization request, step 1 (OPTIONS): timed out after 5000 ms at com.datastax.oss.driver.internal.core.channel.ChannelHandlerRequest.onTimeout(ChannelHandlerRequest.java:110) at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98) at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:160) at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173) at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166) at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:569) at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:998) at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.base/java.lang.Thread.run(Thread.java:829) ``` Increasing delays between reconnections or even increasing the test timeout (largest value tried was 40 seconds) does not help with this situation. The node logs do not show anything raising suspicion. Not even a WARN. This change lowers the number of nodes to 1 (previously 2) and the number of expected channels per session to 33 (previously 66) in resource heavy test methods. Number of sessions remains at 4. The reconnection delays in `should_not_struggle_to_fill_pools` will now start at around 300ms and should not rise above 3200ms. This is the smallest tested set of changes that seems to resolve the issue. The test remains meaningful since `should_struggle_to_fill_pools` still displays considerably worse performance without adv. shard awareness.
1 parent 18752f6 commit 53f16d9

File tree

1 file changed

+23
-39
lines changed

1 file changed

+23
-39
lines changed

‎integration-tests/src/test/java/com/datastax/oss/driver/core/pool/AdvancedShardAwarenessIT.java‎

Lines changed: 23 additions & 39 deletions
Original file line numberDiff line numberDiff line change
@@ -51,7 +51,7 @@ public class AdvancedShardAwarenessIT {
5151

5252
@ClassRule
5353
public static final CustomCcmRule CCM_RULE =
54-
CustomCcmRule.builder().withNodes(2).withJvmArgs("--smp=3").build();
54+
CustomCcmRule.builder().withNodes(1).withJvmArgs("--smp=3").build();
5555

5656
public static ch.qos.logback.classic.Logger channelPoolLogger =
5757
(ch.qos.logback.classic.Logger) LoggerFactory.getLogger(ChannelPool.class);
@@ -100,33 +100,22 @@ public void stopCapturingLogs() {
100100
public void should_initialize_all_channels(boolean reuseAddress) {
101101
int expectedChannelsPerNode = 6; // Divisible by smp
102102
String node1 = CCM_RULE.getCcmBridge().getNodeIpAddress(1);
103-
String node2 = CCM_RULE.getCcmBridge().getNodeIpAddress(2);
104103
Pattern reconnectionPattern1 =
105104
Pattern.compile(".*" + Pattern.quote(node1) + ".*Scheduling next reconnection in.*");
106-
Pattern reconnectionPattern2 =
107-
Pattern.compile(".*" + Pattern.quote(node2) + ".*Scheduling next reconnection in.*");
108-
Set<Pattern> forbiddenOccurences =
109-
ImmutableSet.of(shardMismatchPattern, reconnectionPattern1, reconnectionPattern2);
105+
Set<Pattern> forbiddenOccurences = ImmutableSet.of(shardMismatchPattern, reconnectionPattern1);
110106
Map<Pattern, Integer> expectedOccurences =
111107
ImmutableMap.of(
112108
Pattern.compile(
113-
".*"
114-
+ Pattern.quote(node1)
115-
+ ":19042.*Reconnection attempt complete, 6/6 channels.*"),
116-
1,
117-
Pattern.compile(
118-
".*"
119-
+ Pattern.quote(node2)
120-
+ ":19042.*Reconnection attempt complete, 6/6 channels.*"),
121-
1);
109+
".*"
110+
+ Pattern.quote(node1)
111+
+ ":19042.*Reconnection attempt complete, 6/6 channels.*"),
112+
1);
122113
DriverConfigLoader loader =
123114
SessionUtils.configLoaderBuilder()
124115
.withBoolean(DefaultDriverOption.SOCKET_REUSE_ADDRESS, reuseAddress)
125116
.withBoolean(DefaultDriverOption.CONNECTION_ADVANCED_SHARD_AWARENESS_ENABLED, true)
126117
.withInt(DefaultDriverOption.ADVANCED_SHARD_AWARENESS_PORT_LOW, 10000)
127118
.withInt(DefaultDriverOption.ADVANCED_SHARD_AWARENESS_PORT_HIGH, 60000)
128-
// Due to rounding up the connections per shard this will result in 6 connections per
129-
// node
130119
.withInt(DefaultDriverOption.CONNECTION_POOL_LOCAL_SIZE, expectedChannelsPerNode)
131120
.build();
132121
try (CqlSession session =
@@ -149,13 +138,13 @@ public void should_initialize_all_channels(boolean reuseAddress) {
149138

150139
@Test
151140
public void should_see_mismatched_shard() {
152-
int expectedChannelsPerNode = 66; // Divisible by smp
141+
int expectedChannelsPerNode = 33; // Divisible by smp
153142
DriverConfigLoader loader =
154143
SessionUtils.configLoaderBuilder()
155144
.withBoolean(DefaultDriverOption.CONNECTION_ADVANCED_SHARD_AWARENESS_ENABLED, true)
156145
.withInt(DefaultDriverOption.ADVANCED_SHARD_AWARENESS_PORT_LOW, 10000)
157146
.withInt(DefaultDriverOption.ADVANCED_SHARD_AWARENESS_PORT_HIGH, 60000)
158-
.withInt(DefaultDriverOption.CONNECTION_POOL_LOCAL_SIZE, 66)
147+
.withInt(DefaultDriverOption.CONNECTION_POOL_LOCAL_SIZE, expectedChannelsPerNode)
159148
.build();
160149
try (CqlSession session =
161150
CqlSession.builder()
@@ -176,13 +165,13 @@ public void should_see_mismatched_shard() {
176165
// There is no need to run this as a test, but it serves as a comparison
177166
@SuppressWarnings("unused")
178167
public void should_struggle_to_fill_pools() {
179-
int expectedChannelsPerNode = 66; // Divisible by smp
168+
int expectedChannelsPerNode = 33; // Divisible by smp
180169
DriverConfigLoader loader =
181170
SessionUtils.configLoaderBuilder()
182171
.withBoolean(DefaultDriverOption.CONNECTION_ADVANCED_SHARD_AWARENESS_ENABLED, false)
183-
.withInt(DefaultDriverOption.CONNECTION_POOL_LOCAL_SIZE, 66)
184-
.withDuration(DefaultDriverOption.RECONNECTION_BASE_DELAY, Duration.ofMillis(200))
185-
.withDuration(DefaultDriverOption.RECONNECTION_MAX_DELAY, Duration.ofMillis(4000))
172+
.withInt(DefaultDriverOption.CONNECTION_POOL_LOCAL_SIZE, expectedChannelsPerNode)
173+
.withDuration(DefaultDriverOption.RECONNECTION_BASE_DELAY, Duration.ofMillis(300))
174+
.withDuration(DefaultDriverOption.RECONNECTION_MAX_DELAY, Duration.ofMillis(3200))
186175
.build();
187176
CqlSessionBuilder builder =
188177
CqlSession.builder()
@@ -210,13 +199,13 @@ public void should_struggle_to_fill_pools() {
210199

211200
@Test
212201
public void should_not_struggle_to_fill_pools() {
213-
int expectedChannelsPerNode = 66;
202+
int expectedChannelsPerNode = 33;
214203
DriverConfigLoader loader =
215204
SessionUtils.configLoaderBuilder()
216205
.withBoolean(DefaultDriverOption.CONNECTION_ADVANCED_SHARD_AWARENESS_ENABLED, true)
217206
.withInt(DefaultDriverOption.CONNECTION_POOL_LOCAL_SIZE, expectedChannelsPerNode)
218-
.withDuration(DefaultDriverOption.RECONNECTION_BASE_DELAY, Duration.ofMillis(10))
219-
.withDuration(DefaultDriverOption.RECONNECTION_MAX_DELAY, Duration.ofMillis(20))
207+
.withDuration(DefaultDriverOption.RECONNECTION_BASE_DELAY, Duration.ofMillis(300))
208+
.withDuration(DefaultDriverOption.RECONNECTION_MAX_DELAY, Duration.ofMillis(3200))
220209
.build();
221210
CqlSessionBuilder builder =
222211
CqlSession.builder()
@@ -239,29 +228,24 @@ public void should_not_struggle_to_fill_pools() {
239228
.until(() -> areAllPoolsFullyInitialized(allSessions, expectedChannelsPerNode));
240229
int tolerance = 2; // Sometimes socket ends up already in use
241230
String node1 = CCM_RULE.getCcmBridge().getNodeIpAddress(1);
242-
String node2 = CCM_RULE.getCcmBridge().getNodeIpAddress(2);
243231
Pattern reconnectionPattern1 =
244232
Pattern.compile(".*" + Pattern.quote(node1) + ".*Scheduling next reconnection in.*");
245-
Pattern reconnectionPattern2 =
246-
Pattern.compile(".*" + Pattern.quote(node2) + ".*Scheduling next reconnection in.*");
247233
Map<Pattern, Integer> expectedOccurences =
248234
ImmutableMap.of(
249235
Pattern.compile(
250-
".*"
251-
+ Pattern.quote(node1)
252-
+ ":19042.*Reconnection attempt complete, 66/66 channels.*"),
253-
1 * sessions,
254-
Pattern.compile(
255-
".*"
256-
+ Pattern.quote(node2)
257-
+ ":19042.*Reconnection attempt complete, 66/66 channels.*"),
258-
1 * sessions);
236+
".*"
237+
+ Pattern.quote(node1)
238+
+ ":19042.*Reconnection attempt complete, "
239+
+ expectedChannelsPerNode
240+
+ "/"
241+
+ expectedChannelsPerNode
242+
+ " channels.*"),
243+
sessions);
259244
List<ILoggingEvent> logsCopy = ImmutableList.copyOf(appender.list);
260245
expectedOccurences.forEach(
261246
(pattern, times) -> assertMatchesAtLeast(pattern, times, logsCopy));
262247
assertNoLogMatches(shardMismatchPattern, logsCopy);
263248
assertMatchesAtMost(reconnectionPattern1, tolerance, logsCopy);
264-
assertMatchesAtMost(reconnectionPattern2, tolerance, logsCopy);
265249
}
266250
}
267251

0 commit comments

Comments
 (0)