Cassandra 3.9 Идентификация узких мест трассировки CQL

#amazon-ec2 #cassandra #cql3

#amazon-ec2 #cassandra #cql3

Вопрос:

Я использую 3-узловой кластер RF3 Cassandra на AWS. Я установил время ожидания запроса на чтение на 10 мс. Я заметил, что время ожидания некоторых моих запросов истекло. Это то, что я наблюдаю в CQL при ТРАССИРОВКЕ На;

 Tracing session: 9fc1d420-9829-11e6-b04a-834837c1747b

 activity                                                                                                          | timestamp                  | source        | source_elapsed | client
------------------------------------------------------------------------------------------------------------------- ---------------------------- --------------- ---------------- -----------
                                                                                                Execute CQL3 query | 2016-10-22 10:32:02.274000 | 10.20.30.40 |              0 | 127.0.0.1
        Parsing select * from recipes where id = fcc7d8b5-46d3-4867-903c-4a5c66a1fd2e; [Native-Transport-Requests-8] | 2016-10-22 10:32:02.274000 | 10.20.30.40 |            264 | 127.0.0.1
                                                                 Preparing statement [Native-Transport-Requests-8] | 2016-10-22 10:32:02.274000 | 10.20.30.40 |            367 | 127.0.0.1
                                                        reading data from /10.20.0.1 [Native-Transport-Requests-8] | 2016-10-22 10:32:02.275000 | 10.20.30.40 |            680 | 127.0.0.1
                                         Sending READ message to /10.20.0.1 [MessagingService-Outgoing-/10.20.0.1] | 2016-10-22 10:32:02.286000 | 10.20.30.40 |          12080 | 127.0.0.1
                                  READ message received from /10.20.30.40 [MessagingService-Incoming-/10.20.30.40] | 2016-10-22 10:32:02.296000 |  10.20.0.1 |             51 | 127.0.0.1
                                                         Executing single-partition query on recipes [ReadStage-8] | 2016-10-22 10:32:02.298000 |  10.20.0.1 |           2423 | 127.0.0.1
                                                                        Acquiring sstable references [ReadStage-8] | 2016-10-22 10:32:02.298000 |  10.20.0.1 |           2481 | 127.0.0.1
                           Skipped 0/4 non-slice-intersecting sstables, included 0 due to tombstones [ReadStage-8] | 2016-10-22 10:32:02.298000 |  10.20.0.1 |           2548 | 127.0.0.1
                                                             Bloom filter allows skipping sstable 55 [ReadStage-8] | 2016-10-22 10:32:02.298000 |  10.20.0.1 |           2614 | 127.0.0.1
                                                            Bloom filter allows skipping sstable 130 [ReadStage-8] | 2016-10-22 10:32:02.298000 |  10.20.0.1 |           2655 | 127.0.0.1
                                                            Bloom filter allows skipping sstable 140 [ReadStage-8] | 2016-10-22 10:32:02.298000 |  10.20.0.1 |           2704 | 127.0.0.1
                                                            Bloom filter allows skipping sstable 141 [ReadStage-8] | 2016-10-22 10:32:02.298001 |  10.20.0.1 |           2739 | 127.0.0.1
                                                           Merged data from memtables and 4 sstables [ReadStage-8] | 2016-10-22 10:32:02.298001 |  10.20.0.1 |           2796 | 127.0.0.1
                                                                   Read 0 live and 0 tombstone cells [ReadStage-8] | 2016-10-22 10:32:02.298001 |  10.20.0.1 |           2854 | 127.0.0.1
                                                                  Enqueuing response to /10.20.30.40 [ReadStage-8] | 2016-10-22 10:32:02.299000 |  10.20.0.1 |           2910 | 127.0.0.1
                         Sending REQUEST_RESPONSE message to /10.20.30.40 [MessagingService-Outgoing-/10.20.30.40] | 2016-10-22 10:32:02.302000 |  10.20.0.1 |           6045 | 127.0.0.1
                          REQUEST_RESPONSE message received from /10.20.0.1 [MessagingService-Incoming-/10.20.0.1] | 2016-10-22 10:32:02.322000 | 10.20.30.40 |          47911 | 127.0.0.1
                                                     Processing response from /10.20.0.1 [RequestResponseStage-42] | 2016-10-22 10:32:02.322000 | 10.20.30.40 |          48056 | 127.0.0.1
                                                                                                  Request complete | 2016-10-22 10:32:02.323239 | 10.20.30.40 |          49239 | 127.0.0.1
  

При просмотре документации DataStax кажется, что столбец source_elapsed — это время, прошедшее в микросекундах до того, как событие произошло на исходном узле.

Существует большой разрыв во времени между отправкой сообщения REQUEST_RESPONSE в / 10.20.30.40 и сообщением REQUEST_RESPONSE, полученным из / 10.20.0.1.

Указывает ли это на проблему задержки в сети?

Комментарии:

1. Сколько из ваших запросов (в процентах) истекло по времени ожидания?

2. Процент составляет почти 5% (4,5454%, если быть точным)

3. Я бы рекомендовал вам отслеживать ситуацию с различными выборками и таймаутами. надеюсь, что узлы расположены в одной зоне. разница во времени также зависит от характера запроса. итак, я бы рекомендовал вам отслеживать конкретный запрос в разные временные интервалы с разными периодами ожидания.