Use Nodetool
Cassandra’s nodetool allows you to narrow problems from the cluster
down to a particular node and gives a lot of insight into the state of
the Cassandra process itself. There are dozens of useful commands (see
nodetool help for all the commands), but briefly some of the most
useful for troubleshooting:
Cluster Status
You can use nodetool status to assess status of the cluster:
$ nodetool status <optional keyspace>
Datacenter: dc1
=======================
Status=Up/Down
|/ State=Normal/Leaving/Joining/Moving
-- Address Load Tokens Owns (effective) Host ID Rack
UN 127.0.1.1 4.69 GiB 1 100.0% 35ea8c9f-b7a2-40a7-b9c5-0ee8b91fdd0e r1
UN 127.0.1.2 4.71 GiB 1 100.0% 752e278f-b7c5-4f58-974b-9328455af73f r2
UN 127.0.1.3 4.69 GiB 1 100.0% 9dc1a293-2cc0-40fa-a6fd-9e6054da04a7 r3In this case we can see that we have three nodes in one datacenter with
about 4.6GB of data each and they are all "up". The up/down status of a
node is independently determined by every node in the cluster, so you
may have to run nodetool status on multiple nodes in a cluster to see
the full view.
You can use nodetool status plus a little grep to see which nodes are
down:
$ nodetool status | grep -v '^UN'
Datacenter: dc1
===============
Status=Up/Down
|/ State=Normal/Leaving/Joining/Moving
-- Address Load Tokens Owns (effective) Host ID Rack
Datacenter: dc2
===============
Status=Up/Down
|/ State=Normal/Leaving/Joining/Moving
-- Address Load Tokens Owns (effective) Host ID Rack
DN 127.0.0.5 105.73 KiB 1 33.3% df303ac7-61de-46e9-ac79-6e630115fd75 r1In this case there are two datacenters and there is one node down in
datacenter dc2 and rack r1. This may indicate an issue on
127.0.0.5 warranting investigation.
Coordinator Query Latency
You can view latency distributions of coordinator read and write latency
to help narrow down latency issues using nodetool proxyhistograms:
$ nodetool proxyhistograms
Percentile Read Latency Write Latency Range Latency CAS Read Latency CAS Write Latency View Write Latency
(micros) (micros) (micros) (micros) (micros) (micros)
50% 454.83 219.34 0.00 0.00 0.00 0.00
75% 545.79 263.21 0.00 0.00 0.00 0.00
95% 654.95 315.85 0.00 0.00 0.00 0.00
98% 785.94 379.02 0.00 0.00 0.00 0.00
99% 3379.39 2346.80 0.00 0.00 0.00 0.00
Min 42.51 105.78 0.00 0.00 0.00 0.00
Max 25109.16 43388.63 0.00 0.00 0.00 0.00Here you can see the full latency distribution of reads, writes, range
requests (e.g. select * from keyspace.table), CAS read (compare phase
of CAS) and CAS write (set phase of compare and set). These can be
useful for narrowing down high level latency problems, for example in
this case if a client had a 20 millisecond timeout on their reads they
might experience the occasional timeout from this node but less than 1%
(since the 99% read latency is 3.3 milliseconds < 20 milliseconds).
Local Query Latency
If you know which table is having latency/error issues, you can use
nodetool tablehistograms to get a better idea of what is happening
locally on a node:
$ nodetool tablehistograms keyspace table
Percentile SSTables Write Latency Read Latency Partition Size Cell Count
(micros) (micros) (bytes)
50% 0.00 73.46 182.79 17084 103
75% 1.00 88.15 315.85 17084 103
95% 2.00 126.93 545.79 17084 103
98% 2.00 152.32 654.95 17084 103
99% 2.00 182.79 785.94 17084 103
Min 0.00 42.51 24.60 14238 87
Max 2.00 12108.97 17436.92 17084 103This shows you percentile breakdowns particularly critical metrics.
The first column contains how many sstables were read per logical read.
A very high number here indicates that you may have chosen the wrong
compaction strategy, e.g. SizeTieredCompactionStrategy typically has
many more reads per read than LeveledCompactionStrategy does for
update heavy workloads.
The second column shows you a latency breakdown of local write latency. In this case we see that while the p50 is quite good at 73 microseconds, the maximum latency is quite slow at 12 milliseconds. High write max latencies often indicate a slow commitlog volume (slow to fsync) or large writes that quickly saturate commitlog segments.
The third column shows you a latency breakdown of local read latency. We can see that local Cassandra reads are (as expected) slower than local writes, and the read speed correlates highly with the number of sstables read per read.
The fourth and fifth columns show distributions of partition size and column count per partition. These are useful for determining if the table has on average skinny or wide partitions and can help you isolate bad data patterns. For example if you have a single cell that is 2 megabytes, that is probably going to cause some heap pressure when it’s read.
Threadpool State
You can use nodetool tpstats to view the current outstanding requests
on a particular node. This is useful for trying to find out which
resource (read threads, write threads, compaction, request response
threads) the Cassandra process lacks. For example:
$ nodetool tpstats
Pool Name Active Pending Completed Blocked All time blocked
ReadStage 2 0 12 0 0
MiscStage 0 0 0 0 0
CompactionExecutor 0 0 1940 0 0
MutationStage 0 0 0 0 0
GossipStage 0 0 10293 0 0
Repair-Task 0 0 0 0 0
RequestResponseStage 0 0 16 0 0
ReadRepairStage 0 0 0 0 0
CounterMutationStage 0 0 0 0 0
MemtablePostFlush 0 0 83 0 0
ValidationExecutor 0 0 0 0 0
MemtableFlushWriter 0 0 30 0 0
ViewMutationStage 0 0 0 0 0
CacheCleanupExecutor 0 0 0 0 0
MemtableReclaimMemory 0 0 30 0 0
PendingRangeCalculator 0 0 11 0 0
SecondaryIndexManagement 0 0 0 0 0
HintsDispatcher 0 0 0 0 0
Native-Transport-Requests 0 0 192 0 0
MigrationStage 0 0 14 0 0
PerDiskMemtableFlushWriter_0 0 0 30 0 0
Sampler 0 0 0 0 0
ViewBuildExecutor 0 0 0 0 0
InternalResponseStage 0 0 0 0 0
AntiEntropyStage 0 0 0 0 0
Message type Dropped Latency waiting in queue (micros)
50% 95% 99% Max
READ 0 N/A N/A N/A N/A
RANGE_SLICE 0 0.00 0.00 0.00 0.00
_TRACE 0 N/A N/A N/A N/A
HINT 0 N/A N/A N/A N/A
MUTATION 0 N/A N/A N/A N/A
COUNTER_MUTATION 0 N/A N/A N/A N/A
BATCH_STORE 0 N/A N/A N/A N/A
BATCH_REMOVE 0 N/A N/A N/A N/A
REQUEST_RESPONSE 0 0.00 0.00 0.00 0.00
PAGED_RANGE 0 N/A N/A N/A N/A
READ_REPAIR 0 N/A N/A N/A N/AThis command shows you all kinds of interesting statistics. The first
section shows a detailed breakdown of threadpools for each Cassandra
stage, including how many threads are current executing (Active) and how
many are waiting to run (Pending). Typically if you see pending
executions in a particular threadpool that indicates a problem localized
to that type of operation. For example if the RequestResponseState
queue is backing up, that means that the coordinators are waiting on a
lot of downstream replica requests and may indicate a lack of token
awareness, or very high consistency levels being used on read requests
(for example reading at ALL ties up RF RequestResponseState threads
whereas LOCAL_ONE only uses a single thread in the ReadStage
threadpool). On the other hand if you see a lot of pending compactions
that may indicate that your compaction threads cannot keep up with the
volume of writes and you may need to tune either the compaction strategy
or the concurrent_compactors or compaction_throughput options.
The second section shows drops (errors) and latency distributions for all the major request types. Drops are cumulative since process start, but if you have any that indicate a serious problem as the default timeouts to qualify as a drop are quite high (~5-10 seconds). Dropped messages often warrants further investigation.
Compaction State
As Cassandra is a LSM datastore, Cassandra sometimes has to compact
sstables together, which can have adverse effects on performance. In
particular, compaction uses a reasonable quantity of CPU resources,
invalidates large quantities of the OS
page cache, and can put a lot
of load on your disk drives. There are great os tools <os-iostat> to
determine if this is the case, but often it’s a good idea to check if
compactions are even running using nodetool compactionstats:
$ nodetool compactionstats
pending tasks: 2
- keyspace.table: 2
id compaction type keyspace table completed total unit progress
2062b290-7f3a-11e8-9358-cd941b956e60 Compaction keyspace table 21848273 97867583 bytes 22.32%
Active compaction remaining time : 0h00m04sIn this case there is a single compaction running on the
keyspace.table table, has completed 21.8 megabytes of 97 and Cassandra
estimates (based on the configured compaction throughput) that this will
take 4 seconds. You can also pass -H to get the units in a human
readable format.
Generally each running compaction can consume a single core, but the
more you do in parallel the faster data compacts. Compaction is crucial
to ensuring good read performance so having the right balance of
concurrent compactions such that compactions complete quickly but don’t
take too many resources away from query threads is very important for
performance. If you notice compaction unable to keep up, try tuning
Cassandra’s concurrent_compactors or compaction_throughput options.
