From 6da9141d3ccfb21aead3b19474f8855724e0ca85 Mon Sep 17 00:00:00 2001 From: Dmitry Konstantinov Date: Wed, 21 Aug 2024 15:54:58 -0400 Subject: [PATCH] Fix latency reported by ideal consistency level monitoring patch by Dmitry Konstantinov; reviewed by Ariel Weisberg for CASSANDRA-19651 --- CHANGES.txt | 1 + .../service/AbstractWriteResponseHandler.java | 19 ++++-- .../service/WriteResponseHandlerTest.java | 59 ++++++++++++++++++- 3 files changed, 71 insertions(+), 8 deletions(-) diff --git a/CHANGES.txt b/CHANGES.txt index b2424f106f..07aa493a7a 100644 --- a/CHANGES.txt +++ b/CHANGES.txt @@ -1,4 +1,5 @@ 4.0.14 + * Fix latency reported by ideal consistency level monitoring (CASSANDRA-19651) * Use default commitlog settings in test YAMLs (CASSANDRA-19830) * Do not spam log with SSLExceptions (CASSANDRA-18839) * Fix schema.cql created by a snapshot after dropping more than one column (CASSANDRA-19747) diff --git a/src/java/org/apache/cassandra/service/AbstractWriteResponseHandler.java b/src/java/org/apache/cassandra/service/AbstractWriteResponseHandler.java index 7128277883..0ef944c247 100644 --- a/src/java/org/apache/cassandra/service/AbstractWriteResponseHandler.java +++ b/src/java/org/apache/cassandra/service/AbstractWriteResponseHandler.java @@ -171,7 +171,7 @@ public abstract class AbstractWriteResponseHandler implements RequestCallback } } - public final void expired() + protected final void logFailureOrTimeoutToIdealCLDelegate() { //Tracking ideal CL was not configured if (idealCLDelegate == null) @@ -191,6 +191,11 @@ public abstract class AbstractWriteResponseHandler implements RequestCallback } } + public final void expired() + { + logFailureOrTimeoutToIdealCLDelegate(); + } + /** * @return the minimum number of endpoints that must respond. */ @@ -241,9 +246,13 @@ public abstract class AbstractWriteResponseHandler implements RequestCallback { //The ideal CL should only count as a strike if the requested CL was achieved. //If the requested CL is not achieved it's fine for the ideal CL to also not be achieved. - if (idealCLDelegate != null) + if (idealCLDelegate != null && blockFor() + failures <= candidateReplicaCount()) { idealCLDelegate.requestedCLAchieved = true; + if (idealCLDelegate == this) + { + replicaPlan.keyspace().metric.idealCLWriteLatency.addNano(System.nanoTime() - queryStartNanoTime); + } } condition.signalAll(); @@ -262,6 +271,8 @@ public abstract class AbstractWriteResponseHandler implements RequestCallback failureReasonByEndpoint.put(from, failureReason); + logFailureOrTimeoutToIdealCLDelegate(); + if (blockFor() + n > candidateReplicaCount()) signal(); } @@ -288,10 +299,6 @@ public abstract class AbstractWriteResponseHandler implements RequestCallback { replicaPlan.keyspace().metric.writeFailedIdealCL.inc(); } - else - { - replicaPlan.keyspace().metric.idealCLWriteLatency.addNano(System.nanoTime() - queryStartNanoTime); - } } } diff --git a/test/unit/org/apache/cassandra/service/WriteResponseHandlerTest.java b/test/unit/org/apache/cassandra/service/WriteResponseHandlerTest.java index 5d8d19107a..f1bdbef485 100644 --- a/test/unit/org/apache/cassandra/service/WriteResponseHandlerTest.java +++ b/test/unit/org/apache/cassandra/service/WriteResponseHandlerTest.java @@ -26,6 +26,7 @@ import java.util.concurrent.TimeUnit; import com.google.common.base.Predicates; import org.apache.cassandra.dht.Murmur3Partitioner; +import org.apache.cassandra.exceptions.RequestFailureReason; import org.apache.cassandra.locator.EndpointsForToken; import org.apache.cassandra.locator.ReplicaPlans; import org.junit.Before; @@ -150,17 +151,23 @@ public class WriteResponseHandlerTest //dc1 awr.onResponse(createDummyMessage(0)); awr.onResponse(createDummyMessage(1)); + + // there are not enough responses for ideal EACH_QUORUM yet + assertEquals(startingCount, ks.metric.idealCLWriteLatency.latency.getCount()); + //dc2 awr.onResponse(createDummyMessage(4)); awr.onResponse(createDummyMessage(5)); + // there are enough responses for ideal EACH_QUORUM, we should not wait for all responses + assertTrue( TimeUnit.DAYS.toMicros(1) < ks.metric.idealCLWriteLatency.totalLatency.getCount()); + assertEquals(startingCount + 1, ks.metric.idealCLWriteLatency.latency.getCount()); + //Don't need the others awr.expired(); awr.expired(); assertEquals(0, ks.metric.writeFailedIdealCL.getCount()); - assertTrue( TimeUnit.DAYS.toMicros(1) < ks.metric.idealCLWriteLatency.totalLatency.getCount()); - assertEquals(startingCount + 1, ks.metric.idealCLWriteLatency.latency.getCount()); } /** @@ -232,6 +239,30 @@ public class WriteResponseHandlerTest assertEquals(0, ks.metric.idealCLWriteLatency.totalLatency.getCount()); } + @Test + public void failedIdealCLIncrementsStatForExplicitOnFailure() + { + AbstractWriteResponseHandler awr = createWriteResponseHandler(ConsistencyLevel.LOCAL_QUORUM, ConsistencyLevel.EACH_QUORUM); + + long startingCountForWriteFailedIdealCL = ks.metric.writeFailedIdealCL.getCount(); + long startingCountForIdealCLWriteLatency = ks.metric.idealCLWriteLatency.totalLatency.getCount(); + + + //Succeed in local DC + awr.onResponse(createDummyMessage(0)); + awr.onResponse(createDummyMessage(1)); + awr.onResponse(createDummyMessage(2)); + + + //Fail in remote DC + awr.onFailure(targets.get(3).endpoint(), RequestFailureReason.TIMEOUT); + awr.onFailure(targets.get(4).endpoint(), RequestFailureReason.TIMEOUT); + awr.onResponse(createDummyMessage(5)); + + assertEquals(startingCountForWriteFailedIdealCL + 1, ks.metric.writeFailedIdealCL.getCount()); + assertEquals(startingCountForIdealCLWriteLatency, ks.metric.idealCLWriteLatency.totalLatency.getCount()); + } + /** * Validate that failing to achieve ideal CL doesn't increase the failure counter when not meeting CL * @throws Throwable @@ -257,6 +288,30 @@ public class WriteResponseHandlerTest assertEquals(startingCount, ks.metric.writeFailedIdealCL.getCount()); } + @Test + public void failedIdealCLDoesNotIncrementsStatOnExplicitQueryFailure() + { + AbstractWriteResponseHandler awr = createWriteResponseHandler(ConsistencyLevel.LOCAL_QUORUM, ConsistencyLevel.EACH_QUORUM); + + long startingCountForWriteFailedIdealCL = ks.metric.writeFailedIdealCL.getCount(); + long startingCountForIdealCLWriteLatency = ks.metric.idealCLWriteLatency.totalLatency.getCount(); + + + //Fail in local DC + awr.onFailure(targets.get(0).endpoint(), RequestFailureReason.TIMEOUT); + awr.onFailure(targets.get(1).endpoint(), RequestFailureReason.TIMEOUT); + awr.onResponse(createDummyMessage(2)); + + + //Fail in remote DC + awr.onFailure(targets.get(3).endpoint(), RequestFailureReason.TIMEOUT); + awr.onFailure(targets.get(4).endpoint(), RequestFailureReason.TIMEOUT); + awr.onResponse(createDummyMessage(5)); + + assertEquals(startingCountForWriteFailedIdealCL, ks.metric.writeFailedIdealCL.getCount()); + assertEquals(startingCountForIdealCLWriteLatency, ks.metric.idealCLWriteLatency.totalLatency.getCount()); + } + private static AbstractWriteResponseHandler createWriteResponseHandler(ConsistencyLevel cl, ConsistencyLevel ideal) {