Diagnosing slow Cassandra queries
<p>I'm seeing some slow queries that I don't really understand.</p>

<p>The table looks like:</p>

<pre><code>CREATE TABLE tbl (
    key text,
    time timestamp,
    id uuid,
    data int,
    PRIMARY KEY (key, time, id)
) WITH CLUSTERING ORDER BY (time ASC, id ASC)
    AND bloom_filter_fp_chance = 0.01
    AND caching = '{"keys":"ALL", "rows_per_partition":"NONE"}'
    AND comment = ''
    AND compaction = {'class': 'org.apache.cassandra.db.compaction.SizeTieredCompactionStrategy'}
    AND compression = {'sstable_compression': 'org.apache.cassandra.io.compress.LZ4Compressor'}
    AND dclocal_read_repair_chance = 0.1
    AND default_time_to_live = 0
    AND gc_grace_seconds = 864000
    AND max_index_interval = 2048
    AND memtable_flush_period_in_ms = 0
    AND min_index_interval = 128
    AND read_repair_chance = 0.0
    AND speculative_retry = '99.0PERCENTILE';
</code></pre>

<p>The trace looks like:</p>

<pre><code> activity                                                                                                                                                       | timestamp                  | source       | source_elapsed
----------------------------------------------------------------------------------------------------------------------------------------------------------------+----------------------------+--------------+----------------
                                                                                                                                             Execute CQL3 query | 2016-09-28 16:33:51.821000 | &lt;same ip&gt; |              0
                                              Parsing SELECT * FROM tbl WHERE key = '3-069' AND time &lt;= &lt;30 minutes in the past&gt; LIMIT 1; [SharedPool-Worker-4] | 2016-09-28 16:33:51.821000 | &lt;same ip&gt; |             79
                                                                                                                      Preparing statement [SharedPool-Worker-4] | 2016-09-28 16:33:51.821000 | &lt;same ip&gt; |            186
                                                                                                  Executing single-partition query on tbl [SharedPool-Worker-5] | 2016-09-28 16:33:51.822000 | &lt;same ip&gt; |            661
                                                                                                             Acquiring sstable references [SharedPool-Worker-5] | 2016-09-28 16:33:51.822000 | &lt;same ip&gt; |            704
                                                                                                              Merging memtable tombstones [SharedPool-Worker-5] | 2016-09-28 16:33:51.822000 | &lt;same ip&gt; |            717
                                                                                                           Key cache hit for sstable 2873 [SharedPool-Worker-5] | 2016-09-28 16:33:51.822001 | &lt;same ip&gt; |            750
                                                                                              Seeking to partition beginning in data file [SharedPool-Worker-5] | 2016-09-28 16:33:51.822001 | &lt;same ip&gt; |            759
                                                                                                           Key cache hit for sstable 2872 [SharedPool-Worker-5] | 2016-09-28 16:33:51.822001 | &lt;same ip&gt; |            887
                                                                                              Seeking to partition beginning in data file [SharedPool-Worker-5] | 2016-09-28 16:33:51.822001 | &lt;same ip&gt; |            895
                                                                                                           Key cache hit for sstable 2867 [SharedPool-Worker-5] | 2016-09-28 16:33:51.822001 | &lt;same ip&gt; |            992
                                                                                              Seeking to partition beginning in data file [SharedPool-Worker-5] | 2016-09-28 16:33:51.822001 | &lt;same ip&gt; |            999
                                                                                                           Key cache hit for sstable 2854 [SharedPool-Worker-5] | 2016-09-28 16:33:51.822001 | &lt;same ip&gt; |           1115
                                                                                              Seeking to partition beginning in data file [SharedPool-Worker-5] | 2016-09-28 16:33:51.822001 | &lt;same ip&gt; |           1132
                                                                                                           Key cache hit for sstable 2841 [SharedPool-Worker-5] | 2016-09-28 16:33:51.822001 | &lt;same ip&gt; |           1243
                                                                                              Seeking to partition beginning in data file [SharedPool-Worker-5] | 2016-09-28 16:33:51.822001 | &lt;same ip&gt; |           1252
                                                                                                           Key cache hit for sstable 2828 [SharedPool-Worker-5] | 2016-09-28 16:33:51.822001 | &lt;same ip&gt; |           1340
                                                                                              Seeking to partition beginning in data file [SharedPool-Worker-5] | 2016-09-28 16:33:51.822001 | &lt;same ip&gt; |           1348
                                                                                                           Key cache hit for sstable 2771 [SharedPool-Worker-5] | 2016-09-28 16:33:51.822002 | &lt;same ip&gt; |           1463
                                                                                              Seeking to partition beginning in data file [SharedPool-Worker-5] | 2016-09-28 16:33:51.822002 | &lt;same ip&gt; |           1470
                                                                                                           Key cache hit for sstable 2562 [SharedPool-Worker-5] | 2016-09-28 16:33:51.822002 | &lt;same ip&gt; |           1577
                                                                                              Seeking to partition beginning in data file [SharedPool-Worker-5] | 2016-09-28 16:33:51.822002 | &lt;same ip&gt; |           1585
                                                                Skipped 0/8 non-slice-intersecting sstables, included 0 due to tombstones [SharedPool-Worker-5] | 2016-09-28 16:33:51.823000 | &lt;same ip&gt; |           1705
                                                                                               Merging data from memtables and 8 sstables [SharedPool-Worker-5] | 2016-09-28 16:33:51.823000 | &lt;same ip&gt; |           1715
                                                                                                        Read 2 live and 0 tombstone cells [SharedPool-Worker-5] | 2016-09-28 16:33:55.652000 | &lt;same ip&gt; |         831025
                                                                                                                                               Request complete | 2016-09-28 16:33:55.717105 | &lt;same ip&gt; |         896105
</code></pre>

<p>There are only 11 cells for this primary key, and this query returned one cell. Can anyone explain why a read of a small number of cells without any tombstones is so slow? Are there some other metrics I should be looking at? CPU and disk utilization look fine on the machine, and GC times are fairly steady and low.</p>