CODEWITHSUNDEEP
cassandracassandra-3.0
Luciano
Luciano

Reputation: 43

Cassandra High client read request latency compared to local read latency

We have a 20 nodes Cassandra cluster running a lot of read requests (~900k/sec at peak). Our dataset is fairly small, so everything is served directly from memory (OS Page Cache). Our datamodel is quite simple (just a key/value) and all of our reads are performed with consistency level one (RF 3).

We use the Java Datastax driver with TokenAwarePolicy, so all of our reads should go directly to one node that has the requested data.

These are some metrics extracted from one of the nodes regarding client read request latency and local read latency.

org_apache_cassandra_metrics_ClientRequest_50thPercentile{scope="Read",name="Latency",} 105.778
org_apache_cassandra_metrics_ClientRequest_95thPercentile{scope="Read",name="Latency",} 1131.752
org_apache_cassandra_metrics_ClientRequest_99thPercentile{scope="Read",name="Latency",} 3379.391
org_apache_cassandra_metrics_ClientRequest_999thPercentile{scope="Read",name="Latency",} 25109.16

org_apache_cassandra_metrics_Keyspace_50thPercentile{keyspace=“<keyspace>”,name="ReadLatency",} 61.214
org_apache_cassandra_metrics_Keyspace_95thPercentile{keyspace="<keyspace>",name="ReadLatency",} 126.934
org_apache_cassandra_metrics_Keyspace_99thPercentile{keyspace="<keyspace>",name="ReadLatency",} 182.785
org_apache_cassandra_metrics_Keyspace_999thPercentile{keyspace="<keyspace>",name="ReadLatency",} 454.826

org_apache_cassandra_metrics_Table_50thPercentile{keyspace="<keyspace>",scope="<table>",name="CoordinatorReadLatency",} 105.778
org_apache_cassandra_metrics_Table_95thPercentile{keyspace="<keyspace>",scope="<table>",name="CoordinatorReadLatency",} 1131.752
org_apache_cassandra_metrics_Table_99thPercentile{keyspace="<keyspace>",scope="<table>",name="CoordinatorReadLatency",} 3379.391
org_apache_cassandra_metrics_Table_999thPercentile{keyspace="<keyspace>",scope="<table>",name="CoordinatorReadLatency",} 25109.16

Another important detail is that most of our queries (~70%) don't return anything, i.e., they are for records not found. So, bloom filters play an important role here and they seem to be fine:

Bloom filter false positives: 27574
Bloom filter false ratio: 0.00000
Bloom filter space used: 
Bloom filter off heap memory used: 6760992

As it can be seen, the reads in each one of the nodes are really fast, the 99.9% is less than 0.5 ms. However, the client request latency is way higher, going above 4ms on the 99%. If I'm reading with CL ONE and using TokenAwarePolicy, shouldn't both values be similar to each other, since no coordination is required? Am I missing something? Is there anything else I could check to see what's going on?

Thanks in advance.

Upvotes: 2

Views: 3257

Answers (3)

Luciano
Luciano

Reputation: 43

thanks for your reply and sorry about the delay in getting back to you.

One thing I’ve found out is that our clusters had: dynamic_snitch_badness_threshold=0 in the config files. Changing that to the default value (0.1) helped a lot in terms of the client request latency.

The GC seems to be stable, even under high load. The pauses are constant (~10ms / sec) and I haven’t seen spikes (not even full gcs). We’re using CMS with a bigger Xmn (2.5GB).

Read repairs happen all the time (we have it set to 10% chance), so when the system is handling 800k rec/sec, we have ~80k read repairs/sec happening in background.

It also seems that we’re asking too much for the 20 machines cluster. From the client point of view, latency is quite stable until 800k qps, after that it starts to spike a little bit, but still under a manageable threshold.

Thanks for all the tips, the dynamic snitch thing was really helpful!

Upvotes: 0

hiwkby
hiwkby

Reputation: 11

Even if using TokenAwarePolicy, the driver can't work with the policy when the driver doesn't know which partition key is.

If you are using simple statements, no routing information is provided. So you need additional information to the driver by calling setRoutingKey.

The DataStax Java Driver's manual is a good friend. http://docs.datastax.com/en/developer/java-driver/3.1/manual/load_balancing/#requirements

If TokenAware is perfectly working, CoordinatorReadLatency value is mostly same value with ReadLatency. You should check it too.

http://cassandra.apache.org/doc/latest/operating/metrics.html?highlight=coordinatorreadlatency

Upvotes: 1

Mick Semb Wever
Mick Semb Wever

Reputation: 21

@luciano

there are various reasons why the coordinator and the replica can report different 99th percentiles for read latencies, even with token awareness configured in the client.

these can be anything that manifests in between the coordinator code to the replica's storage engine code in the read path.

examples can be:

  • read repairs (not directly related to a particular request, as is asynchronous to the read the triggered it, but can cause issues),
  • host timeouts (and/or speculative retries),
  • token awareness failure (dynamic snitch simply not keeping up),
  • GC pauses,

look for metrics anomalies per host, overlaps with GC, and even try to capture traces for some of the slower requests and investigate if they're doing everything you expect from C* (eg token awareness).

well-tuned and spec'd clusters may also witness the dynamic snitch simply not being able to keep up and do its intended job. in such situations disabling the dynamic snitch can fix the high latencies for top-end read percentiles. see https://issues.apache.org/jira/browse/CASSANDRA-6908

be careful though, measure and confirm hypotheses, as mis-applied solutions easily have negative effects!

Upvotes: 2

Related Questions