We are using cassandra-3.0.15. Few of the read queries takes longer time(>500ms). Based on the query tracing it seems the co-ordinator node takes longer time especially while starting to process the request. What could be the reason for that? How to solve this issue?
Have attached the query trace for one of the such requests below. It can be seen that the first activity "Executing single-partition query on facility_configuration" takes around 1.4sec. The rest of the activities are pretty fast.
activity | source | source_elapsed | thread
---------------------------------------------------------------------------+----------------+----------------+-------------------------------------------
Executing single-partition query on facility_configuration | node1 | 1466289 | SharedPool-Worker-6
Acquiring sstable references | node1 | 1466298 | SharedPool-Worker-6
Key cache hit for sstable 6 | node1 | 1466314 | SharedPool-Worker-6
Skipped 0/1 non-slice-intersecting sstables, included 0 due to tombstones | node1 | 1466330 | SharedPool-Worker-6
Merging data from memtables and 1 sstables | node1 | 1466341 | SharedPool-Worker-6
Read 1 live and 0 tombstone cells | node1 | 1466450 | SharedPool-Worker-6
reading digest from /node2 | node1 | 1466466 | SharedPool-Worker-6
Sending READ message to /node2 | node1 | 1467388 | MessagingService-Outgoing-/node2
READ message received from /node1 | node2 | 1 | MessagingService-Incoming-/node1
Executing single-partition query on facility_configuration | node2 | 536 | SharedPool-Worker-3
Acquiring sstable references | node2 | 546 | SharedPool-Worker-3
Key cache hit for sstable 6 | node2 | 562 | SharedPool-Worker-3
Skipped 0/1 non-slice-intersecting sstables, included 0 due to tombstones | node2 | 575 | SharedPool-Worker-3
Merging data from memtables and 1 sstables | node2 | 586 | SharedPool-Worker-3
Read 1 live and 0 tombstone cells | node2 | 642 | SharedPool-Worker-3
Read 1 live and 0 tombstone cells | node2 | 807 | SharedPool-Worker-3
Enqueuing response to /node1 | node2 | 819 | SharedPool-Worker-3
Sending REQUEST_RESPONSE message to /node1 | node2 | 845 | MessagingService-Outgoing-/node1
REQUEST_RESPONSE message received from /node2 | node1 | 1470583 | MessagingService-Incoming-/node2
Processing response from /node2 | node1 | 1470665 | SharedPool-Worker-15
session_id | client | command | coordinator | duration | parameters | request | started_at
--------------------------------------+--------------+---------+----------------+----------+--------------------------------------------------------------------------------------------+-----------------------------+--------------------------
ddef2100-eb53-11e9-86ed-9d59234ed651 | clientNode | QUERY | node1 | 1470765 | {'consistency_level': 'QUORUM', 'page_size': '5000', 'serial_consistency_level': 'SERIAL'} | Execute CQL3 prepared query | 2019-10-10 11:48:24+0000
