遅いカサンドラの質問を診断する

Question

私は本当に理解できない遅いクエリを見ています。

テーブルは次のようになります。トレースがどのように見える

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'; 

：

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

あり、この主キーの唯一の11の細胞があり、このクエリは、一つのセルを返されました。誰もが、なぜ墓石のない少数の細胞の読取りが遅いのかを説明することはできますか？私が見なければならないいくつかの他の指標がありますか？ CPUとディスクの使用率はマシン上で正常に見え、GC時間はかなり安定して低くなっています。

Answer 1

を複数の結果を取得する必要がありますあなたが8つの異なるSSTablesに分割さパーティションを持っているようだ：

Merging data from memtables and 8 sstables [SharedPool-Worker-5] | 2016-09-28 16:33:51.823000 | <same ip> |   1715 

低速回転ディスク（たとえば7200 RPM）の場合、これは複数のディスクシークに直接変換されます。クエリはディスクサブシステムのIOPSの量によって制限されています配信することができます。

この問題を緩和するには、すべてのSSTablesをより大きなものにマージすることができます。これは確かに1つのシークだけを引き起こします。圧縮戦略の設定（STCSの微調整についてはthe documentationをチェックしてください）に応じて、nodetool compactで大きな圧縮を行うことができます。 Does nodetool compact move everything into one SSTable

コンパクションを実行したくない場合（時間がかかる、または完全に機能しない場合）、シンボリックリンクを使用してCFをSSDに移動しようとする可能性があります（ノードを停止する、データのコピー、ディレクトリのシンボリックリンク、ノードの開始）。スピンディスクよりSSDの方がIOPSが多いため、すぐにその効果を確認する必要があります。

HTH。

Answer 2

私は、同様のトレースを生成します（CCMを使用して）次のスクリプト

ccm create cas-1 --vnodes -n 1 -v 2.1.15 
ccm start 
echo "create keyspace test WITH REPLICATION={ 'class' : 'SimpleStrategy', 'replication_factor' : 1} ;" | ccm node1 cqlsh 
echo "create table test.tbl (key text,time timestamp,id uuid,data int,PRIMARY KEY (key, time, id));" | ccm node1 cqlsh 
echo "insert into test.tbl (key,time,id,data) values ('1','2000-1-1',now(),1);" | ccm node1 cqlsh 
ccm node1 nodetool flush 
echo "insert into test.tbl (key,time,id,data) values ('1','2000-2-1',now(),1);" | ccm node1 cqlsh 
ccm node1 nodetool flush 
echo "insert into test.tbl (key,time,id,data) values ('1','2000-3-1',now(),1);" | ccm node1 cqlsh 
ccm node1 nodetool flush 

echo "tracing on; select * from test.tbl where key='1' and time <= '2000-3-1' limit 1;" | ccm node1 cqlsh 
echo "tracing on; select * from test.tbl where key='1' and time <= '2000-3-1' limit 1;" | ccm node1 cqlsh 

であなたのシナリオを再現。

Now Tracing is enabled 

key | time      | id         | data 
-----+--------------------------+--------------------------------------+------ 
    1 | 1999-12-31 22:00:00+0000 | ac0791c0-85b9-11e6-9005-51c5fe8b2280 | 1 

(1 rows) 

Tracing session: ae3ebd10-85b9-11e6-9005-51c5fe8b2280 

activity                       | timestamp     | source | source_elapsed 
----------------------------------------------------------------------------------------------------+----------------------------+-----------+---------------- 
                       Execute CQL3 query | 2016-09-28 23:25:22.018000 | 127.0.0.1 |    0 
Parsing select * from test.tbl where key='1' and time <= '2000-3-1' limit 1; [SharedPool-Worker-3] | 2016-09-28 23:25:22.019000 | 127.0.0.1 |   570 
                  Preparing statement [SharedPool-Worker-3] | 2016-09-28 23:25:22.020000 | 127.0.0.1 |   1055 
             Executing single-partition query on tbl [SharedPool-Worker-1] | 2016-09-28 23:25:22.022000 | 127.0.0.1 |   4065 
               Acquiring sstable references [SharedPool-Worker-1] | 2016-09-28 23:25:22.023000 | 127.0.0.1 |   4091 
                Merging memtable tombstones [SharedPool-Worker-1] | 2016-09-28 23:25:22.024000 | 127.0.0.1 |   4132 
          Partition index with 0 entries found for sstable 3 [SharedPool-Worker-1] | 2016-09-28 23:25:22.024000 | 127.0.0.1 |   4388 
            Seeking to partition beginning in data file [SharedPool-Worker-1] | 2016-09-28 23:25:22.024000 | 127.0.0.1 |   4398 
          Partition index with 0 entries found for sstable 2 [SharedPool-Worker-1] | 2016-09-28 23:25:22.025000 | 127.0.0.1 |   4761 
            Seeking to partition beginning in data file [SharedPool-Worker-1] | 2016-09-28 23:25:22.025000 | 127.0.0.1 |   4770 
          Partition index with 0 entries found for sstable 1 [SharedPool-Worker-1] | 2016-09-28 23:25:22.025000 | 127.0.0.1 |   4991 
            Seeking to partition beginning in data file [SharedPool-Worker-1] | 2016-09-28 23:25:22.025000 | 127.0.0.1 |   5000 
    Skipped 0/3 non-slice-intersecting sstables, included 0 due to tombstones [SharedPool-Worker-1] | 2016-09-28 23:25:22.026000 | 127.0.0.1 |   5148 
            Merging data from memtables and 3 sstables [SharedPool-Worker-1] | 2016-09-28 23:25:22.026000 | 127.0.0.1 |   5159 
              Read 2 live and 0 tombstone cells [SharedPool-Worker-1] | 2016-09-28 23:25:22.027000 | 127.0.0.1 |   5365 
                        Request complete | 2016-09-28 23:25:22.023661 | 127.0.0.1 |   5661 

キー（パーティションキー）を使用すると、クエリを実行している（私のサンプルでは「1」）あなたのケースでは、「3」以上に私はすべての挿入後に洗い流すsstablesことによって、これを余儀なくされています（複数sstableファイル内のデータを持っています）。

クエリはクラスタリングキーでフィルタリングされ、 "制限1"を使用するため、パーティションキーのデータを保持するすべてのステーブルが検索される必要があります。すべての行が取得されると、順序付けられ、最初の結果が戻されます。

あなたは「リミット1」を削除する場合は、あなたは私のサンプルに戻っ

echo "select * from test.tbl where key='1' and time <= '2000-3-1';" | ccm node1 cqlsh 
Now Tracing is enabled 

key | time      | id         | data 
-----+--------------------------+--------------------------------------+------ 
    1 | 1999-12-31 22:00:00+0000 | ac0791c0-85b9-11e6-9005-51c5fe8b2280 | 1 
    1 | 2000-01-31 22:00:00+0000 | acd60550-85b9-11e6-9005-51c5fe8b2280 | 1 
    1 | 2000-02-29 22:00:00+0000 | ad8a3a20-85b9-11e6-9005-51c5fe8b2280 | 1 

(3 rows) 

Answer 3

あなたが見たいと思っている他のメトリックは、あなたが読んでいる1回の読書ごとにいくつのSSTablesがあるかを知りたいテーブルのためのものです。あなたがそれを持っていれば、他の答えが得られるものを遅くするでしょう。

このデータは、nodetool tablehistogramsで取得できます。

nodetool tablehistograms keyspace tbl 

これは、さまざまな要求に対してどのくらいの数のステーブルがヒットしているかを示します。このデータを使用している場合は、opscenterでこのデータを表示することもできます。探すTBL: SSTables per Read (percentiles)