Hi Cassandra Users,
I'm relatively new to Cassandra and first I have to say I'm really
impressed by the technology.
Good design and a lot of stuff to understand the underlying (the Oreilly
book help a lot as well as thelastpickle blog post).
I have an muli-datacenter c* cluster (US, Europe, Singapore) with eight
node on each (two seeds on each region), two racks on Eu, Singapore, 3
on US. Everything deployed in AWS.
We have a keyspace configured with network topology and two replicas on
every region like this: {'class': 'NetworkTopologyStrategy',
'ap-southeast-1': '2', 'eu-west-1': '2', 'us-east-1': '2'}
Investigating some performance issue I noticed strange things in my
experiment:
What we expect is very slow latency 3/5ms max for this specific select
query. So we want every read to be local the each datacenter.
We configure DCAwareRoundRobinPolicy(local_dc=DC) in python, and the
same in Go gocql.TokenAwareHostPolicy(gocql.DCAwareRoundRobinPolicy("DC"))
Testing a bit with two short program (I can provide them) in go and
python I notice very strange result. Basically I do the same query over
and over with a very limited dataset of id.
The first result were surprising cause the very first query were always
more than 250ms and after with stressing c* (playing with sleep between
query) I can achieve a good ratio of query at 3/4 ms (what I expected).
My guess was that long query were somewhat executed not locally (or at
least imply multi datacenter queries) and short one no.
Activating tracing in my program (like enalbing trace in cqlsh) kindla
confirm my suspicion.
(I will provide trace in attachment).
My question is why sometime C* try to read not localy? how we can
disable it? what is the criteria for this?
(btw I'm very not fan of this multi region design for theses very
specific kind of issues...)
Also side question: why C* is so slow at connection? it's like it's
trying to reach every nodes in each DC? (we only provide locals seeds
however). Sometimes it take more than 20s...
Any help appreciated.
Best,
--
Raphael Mazelier
1659724153007200197 [Info] before query
Aug 05 2022 06:29:13.229 [INFO] main.go:18 - Tracing session
81281b0014ec11ed8fd10f5c2d1a52b5 (coordinator: 10.66.111.13, duration: 0s):
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.008: reading
digest from /10.66.201.210 (source: 10.66.111.13, elapsed: 116)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.008: Executing
single-partition query on roles (source: 10.66.111.13, elapsed: 117)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.008: Acquiring
sstable references (source: 10.66.111.13, elapsed: 148)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.008: reading
digest from /10.66.200.74 (source: 10.66.111.13, elapsed: 154)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.008: reading
digest from /10.0.197.122 (source: 10.66.111.13, elapsed: 163)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.008: Skipped
0/2 non-slice-intersecting sstables, included 0 due to tombstones (source:
10.66.111.13, elapsed: 165)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.008: reading
digest from /10.0.197.246 (source: 10.66.111.13, elapsed: 175)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.008: Sending
READ message to /10.66.201.210 (source: 10.66.111.13, elapsed: 179)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.008: Key cache
hit for sstable 2 (source: 10.66.111.13, elapsed: 181)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.008001:
Sending READ message to /10.66.200.74 (source: 10.66.111.13, elapsed: 187)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.008001:
Sending READ message to /10.0.197.122 (source: 10.66.111.13, elapsed: 194)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.008001: Key
cache hit for sstable 5 (source: 10.66.111.13, elapsed: 197)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.008001:
Sending READ message to /10.0.197.246 (source: 10.66.111.13, elapsed: 200)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Merged
data from memtables and 2 sstables (source: 10.66.111.13, elapsed: 234)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: READ
message received from /10.66.111.13 (source: 10.66.201.210, elapsed: 7)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: READ
message received from /10.66.111.13 (source: 10.66.200.74, elapsed: 7)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Read 1
live rows and 0 tombstone cells (source: 10.66.111.13, elapsed: 249)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Executing
single-partition query on roles (source: 10.66.201.210, elapsed: 100)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Executing
single-partition query on roles (source: 10.66.200.74, elapsed: 81)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009:
speculating read retry on /10.0.111.65 (source: 10.66.111.13, elapsed: 332)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Acquiring
sstable references (source: 10.66.201.210, elapsed: 139)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Acquiring
sstable references (source: 10.66.200.74, elapsed: 112)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Sending
READ message to /10.0.111.65 (source: 10.66.111.13, elapsed: 376)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Skipped
0/1 non-slice-intersecting sstables, included 0 due to tombstones (source:
10.66.201.210, elapsed: 151)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Skipped
0/1 non-slice-intersecting sstables, included 0 due to tombstones (source:
10.66.200.74, elapsed: 124)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Key cache
hit for sstable 7 (source: 10.66.201.210, elapsed: 162)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Key cache
hit for sstable 7 (source: 10.66.200.74, elapsed: 133)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Merged
data from memtables and 1 sstables (source: 10.66.201.210, elapsed: 193)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Merged
data from memtables and 1 sstables (source: 10.66.200.74, elapsed: 167)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Read 1
live rows and 0 tombstone cells (source: 10.66.201.210, elapsed: 208)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Read 1
live rows and 0 tombstone cells (source: 10.66.200.74, elapsed: 180)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Read 1
live rows and 0 tombstone cells (source: 10.66.201.210, elapsed: 218)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Read 1
live rows and 0 tombstone cells (source: 10.66.200.74, elapsed: 207)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Enqueuing
response to /10.66.111.13 (source: 10.66.201.210, elapsed: 222)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Enqueuing
response to /10.66.111.13 (source: 10.66.200.74, elapsed: 213)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Sending
REQUEST_RESPONSE message to /10.66.111.13 (source: 10.66.201.210, elapsed: 252)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.009: Sending
REQUEST_RESPONSE message to /10.66.111.13 (source: 10.66.200.74, elapsed: 246)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.01:
REQUEST_RESPONSE message received from /10.66.201.210 (source: 10.66.111.13,
elapsed: 1255)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.01: Processing
response from /10.66.201.210 (source: 10.66.111.13, elapsed: 1285)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.01:
REQUEST_RESPONSE message received from /10.66.200.74 (source: 10.66.111.13,
elapsed: 1412)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.01: Processing
response from /10.66.200.74 (source: 10.66.111.13, elapsed: 1444)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.057: READ
message received from /10.66.111.13 (source: 10.0.197.122, elapsed: 6)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.057: Executing
single-partition query on roles (source: 10.0.197.122, elapsed: 55)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.057: Acquiring
sstable references (source: 10.0.197.122, elapsed: 82)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.057: Skipped
0/2 non-slice-intersecting sstables, included 0 due to tombstones (source:
10.0.197.122, elapsed: 99)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.057: Key cache
hit for sstable 2 (source: 10.0.197.122, elapsed: 115)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.057: Key cache
hit for sstable 1 (source: 10.0.197.122, elapsed: 135)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.057: Merged
data from memtables and 2 sstables (source: 10.0.197.122, elapsed: 167)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.057: Read 1
live rows and 0 tombstone cells (source: 10.0.197.122, elapsed: 183)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.057: Read 1
live rows and 0 tombstone cells (source: 10.0.197.122, elapsed: 190)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.057: Enqueuing
response to /10.66.111.13 (source: 10.0.197.122, elapsed: 194)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.057001:
Sending REQUEST_RESPONSE message to /10.66.111.13 (source: 10.0.197.122,
elapsed: 225)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.072: READ
message received from /10.66.111.13 (source: 10.0.197.246, elapsed: 11)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.072: Executing
single-partition query on roles (source: 10.0.197.246, elapsed: 90)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.072: Acquiring
sstable references (source: 10.0.197.246, elapsed: 123)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.072: Skipped
0/1 non-slice-intersecting sstables, included 0 due to tombstones (source:
10.0.197.246, elapsed: 135)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.072: Key cache
hit for sstable 8 (source: 10.0.197.246, elapsed: 145)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.072: Merged
data from memtables and 1 sstables (source: 10.0.197.246, elapsed: 173)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.072: Read 1
live rows and 0 tombstone cells (source: 10.0.197.246, elapsed: 189)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.072: Read 1
live rows and 0 tombstone cells (source: 10.0.197.246, elapsed: 196)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.072: Enqueuing
response to /10.66.111.13 (source: 10.0.197.246, elapsed: 201)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.072: Sending
REQUEST_RESPONSE message to /10.66.111.13 (source: 10.0.197.246, elapsed: 234)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.093: READ
message received from /10.66.111.13 (source: 10.0.111.65, elapsed: 30)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.093: Executing
single-partition query on roles (source: 10.0.111.65, elapsed: 91)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.093: Acquiring
sstable references (source: 10.0.111.65, elapsed: 139)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.093: Skipped
0/1 non-slice-intersecting sstables, included 0 due to tombstones (source:
10.0.111.65, elapsed: 155)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.093: Key cache
hit for sstable 9 (source: 10.0.111.65, elapsed: 197)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.093: Merged
data from memtables and 1 sstables (source: 10.0.111.65, elapsed: 235)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.093: Read 1
live rows and 0 tombstone cells (source: 10.0.111.65, elapsed: 252)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.093: Read 1
live rows and 0 tombstone cells (source: 10.0.111.65, elapsed: 260)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.093: Enqueuing
response to /10.66.111.13 (source: 10.0.111.65, elapsed: 265)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.093: Sending
REQUEST_RESPONSE message to /10.66.111.13 (source: 10.0.111.65, elapsed: 300)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.094:
REQUEST_RESPONSE message received from /10.0.197.122 (source: 10.66.111.13,
elapsed: 85313)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.094:
Processing response from /10.0.197.122 (source: 10.66.111.13, elapsed: 85386)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.115:
REQUEST_RESPONSE message received from /10.0.197.246 (source: 10.66.111.13,
elapsed: 106910)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.115:
Processing response from /10.0.197.246 (source: 10.66.111.13, elapsed: 106963)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.115: reading
digest from /10.66.201.210 (source: 10.66.111.13, elapsed: 107084)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.115: Executing
single-partition query on roles (source: 10.66.111.13, elapsed: 107096)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.115: Acquiring
sstable references (source: 10.66.111.13, elapsed: 107112)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.115: Skipped
0/2 non-slice-intersecting sstables, included 0 due to tombstones (source:
10.66.111.13, elapsed: 107124)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.115: reading
digest from /10.66.200.74 (source: 10.66.111.13, elapsed: 107128)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.115: Key cache
hit for sstable 2 (source: 10.66.111.13, elapsed: 107138)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.115: reading
digest from /10.0.111.65 (source: 10.66.111.13, elapsed: 107144)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.115: Key cache
hit for sstable 5 (source: 10.66.111.13, elapsed: 107156)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.115001:
Sending READ message to /10.66.200.74 (source: 10.66.111.13, elapsed: 107161)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.115001:
reading digest from /10.0.197.122 (source: 10.66.111.13, elapsed: 107169)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.115001:
Sending READ message to /10.66.201.210 (source: 10.66.111.13, elapsed: 107168)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.115001: Merged
data from memtables and 2 sstables (source: 10.66.111.13, elapsed: 107184)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.115001:
Sending READ message to /10.0.111.65 (source: 10.66.111.13, elapsed: 107192)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.115001:
Sending READ message to /10.0.197.122 (source: 10.66.111.13, elapsed: 107201)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.115001: Read 1
live rows and 0 tombstone cells (source: 10.66.111.13, elapsed: 107202)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116:
speculating read retry on /10.0.197.246 (source: 10.66.111.13, elapsed: 107309)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: READ
message received from /10.66.111.13 (source: 10.66.201.210, elapsed: 9)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: READ
message received from /10.66.111.13 (source: 10.66.200.74, elapsed: 6)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: Sending
READ message to /10.0.197.246 (source: 10.66.111.13, elapsed: 107356)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: Executing
single-partition query on roles (source: 10.66.201.210, elapsed: 64)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: Executing
single-partition query on roles (source: 10.66.200.74, elapsed: 98)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116:
REQUEST_RESPONSE message received from /10.66.201.210 (source: 10.66.111.13,
elapsed: 108218)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: Acquiring
sstable references (source: 10.66.201.210, elapsed: 98)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: Acquiring
sstable references (source: 10.66.200.74, elapsed: 126)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: Skipped
0/1 non-slice-intersecting sstables, included 0 due to tombstones (source:
10.66.201.210, elapsed: 109)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: Skipped
0/1 non-slice-intersecting sstables, included 0 due to tombstones (source:
10.66.200.74, elapsed: 142)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: Key cache
hit for sstable 7 (source: 10.66.201.210, elapsed: 117)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: Key cache
hit for sstable 7 (source: 10.66.200.74, elapsed: 155)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: Merged
data from memtables and 1 sstables (source: 10.66.201.210, elapsed: 149)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: Merged
data from memtables and 1 sstables (source: 10.66.200.74, elapsed: 182)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: Read 1
live rows and 0 tombstone cells (source: 10.66.201.210, elapsed: 166)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: Read 1
live rows and 0 tombstone cells (source: 10.66.200.74, elapsed: 197)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: Read 1
live rows and 0 tombstone cells (source: 10.66.201.210, elapsed: 174)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: Read 1
live rows and 0 tombstone cells (source: 10.66.200.74, elapsed: 207)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: Enqueuing
response to /10.66.111.13 (source: 10.66.201.210, elapsed: 178)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: Enqueuing
response to /10.66.111.13 (source: 10.66.200.74, elapsed: 214)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: Sending
REQUEST_RESPONSE message to /10.66.111.13 (source: 10.66.201.210, elapsed: 219)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.116: Sending
REQUEST_RESPONSE message to /10.66.111.13 (source: 10.66.200.74, elapsed: 252)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.117:
Processing response from /10.66.201.210 (source: 10.66.111.13, elapsed: 108255)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.117:
REQUEST_RESPONSE message received from /10.66.200.74 (source: 10.66.111.13,
elapsed: 108366)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.117:
Processing response from /10.66.200.74 (source: 10.66.111.13, elapsed: 108384)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.15:
REQUEST_RESPONSE message received from /10.0.111.65 (source: 10.66.111.13,
elapsed: 142063)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.15: Processing
response from /10.0.111.65 (source: 10.66.111.13, elapsed: 142148)
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.15: Initiating
read-repair (source: 10.66.111.13, elapsed: 142178)
1659724153232091281 [Info] KO query result: took 224.871065ms
Aug 05 2022 06:29:13.231 [INFO] main.go:18 - 2022/08/05 18:29:13.163: READ
message received from /10.66.111.13 (source: 10.0.111.65, elapsed: 22)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.163: Executing
single-partition query on roles (source: 10.0.111.65, elapsed: 77)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.163: Acquiring
sstable references (source: 10.0.111.65, elapsed: 113)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.163: Skipped
0/1 non-slice-intersecting sstables, included 0 due to tombstones (source:
10.0.111.65, elapsed: 132)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.163: Key cache
hit for sstable 9 (source: 10.0.111.65, elapsed: 146)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.163: Merged
data from memtables and 1 sstables (source: 10.0.111.65, elapsed: 180)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.163: Read 1
live rows and 0 tombstone cells (source: 10.0.111.65, elapsed: 196)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.163: Read 1
live rows and 0 tombstone cells (source: 10.0.111.65, elapsed: 203)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.192: READ
message received from /10.66.111.13 (source: 10.0.197.122, elapsed: 4)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.192: Executing
single-partition query on roles (source: 10.0.197.122, elapsed: 55)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.192: Acquiring
sstable references (source: 10.0.197.122, elapsed: 81)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.192: Skipped
0/2 non-slice-intersecting sstables, included 0 due to tombstones (source:
10.0.197.122, elapsed: 96)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.192: Key cache
hit for sstable 2 (source: 10.0.197.122, elapsed: 118)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.218:
REQUEST_RESPONSE message received from /10.0.111.65 (source: 10.66.111.13,
elapsed: 209442)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.218:
Processing response from /10.0.111.65 (source: 10.66.111.13, elapsed: 209497)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.227:
REQUEST_RESPONSE message received from /10.0.197.122 (source: 10.66.111.13,
elapsed: 218919)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.227:
Processing response from /10.0.197.122 (source: 10.66.111.13, elapsed: 219005)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.227:
Read-repair DC_LOCAL (source: 10.66.111.13, elapsed: 219125)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.227: reading
data from /10.66.201.210 (source: 10.66.111.13, elapsed: 219139)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.227: Executing
single-partition query on user_db (source: 10.66.111.13, elapsed: 219161)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.227: Acquiring
sstable references (source: 10.66.111.13, elapsed: 219166)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.227: Merging
memtable contents (source: 10.66.111.13, elapsed: 219173)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.227: Sending
READ message to /10.66.201.210 (source: 10.66.111.13, elapsed: 219180)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.227: Key cache
hit for sstable 59072 (source: 10.66.111.13, elapsed: 219183)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.227: Key cache
hit for sstable 59060 (source: 10.66.111.13, elapsed: 219198)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.228: Read 1
live rows and 2 tombstone cells (source: 10.66.111.13, elapsed: 219241)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.228: READ
message received from /10.66.111.13 (source: 10.66.201.210, elapsed: 6)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.228: Executing
single-partition query on user_db (source: 10.66.201.210, elapsed: 62)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.228: Acquiring
sstable references (source: 10.66.201.210, elapsed: 100)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.228: Merging
memtable contents (source: 10.66.201.210, elapsed: 108)
Aug 05 2022 06:29:13.232 [INFO] main.go:18 - 2022/08/05 18:29:13.228: Bloom
filter allows skipping sstable 59232 (source: 10.66.201.210, elapsed: 117)
Datacenter: ap-southeast-1
==========================
Status=Up/Down
|/ State=Normal/Leaving/Joining/Moving
-- Address Load Tokens Owns (effective) Host ID
Rack
UN 10.80.197.48 76.32 GiB 256 25.7%
4d1a1159-fc5d-431c-a420-8bff72ef2484 ap-southeast-1b
UN 10.80.111.193 75.48 GiB 256 25.9%
0a69d219-f42f-4de9-9c8d-7efc06355e59 ap-southeast-1a
UN 10.80.197.197 75.65 GiB 256 25.1%
bb87ff84-4b68-46d9-87a3-e1e8d0d6fe07 ap-southeast-1b
UN 10.80.197.103 76.44 GiB 256 26.3%
ba8f4192-cfcd-411c-a40a-b1b790834d14 ap-southeast-1b
UN 10.80.197.121 70.16 GiB 256 22.9%
ae116bf3-7f82-451e-9734-747f1ab58d5f ap-southeast-1b
UN 10.80.111.234 74.78 GiB 256 24.2%
e0974eb1-7b9b-487c-bcbe-8e16f50d6508 ap-southeast-1a
UN 10.80.111.189 79.08 GiB 256 25.2%
345d5e63-3f7e-4c6b-9ab9-09c5fca7eb59 ap-southeast-1a
UN 10.80.111.126 78.64 GiB 256 24.8%
64e01eaf-8200-4e06-aa69-6efce2d57d0e ap-southeast-1a
Datacenter: eu-west-1
=====================
Status=Up/Down
|/ State=Normal/Leaving/Joining/Moving
-- Address Load Tokens Owns (effective) Host ID
Rack
UN 10.0.111.145 79.99 GiB 256 26.2%
1aadc267-e9cc-4a8c-bb7f-a4ebf828f7f2 eu-west-1a
UN 10.0.111.17 76.11 GiB 256 25.7%
42d01053-1bbe-4fef-aed8-8f3bc201fab5 eu-west-1a
UN 10.0.111.65 71.36 GiB 256 23.3%
f4a7b146-80a1-408e-a31a-893e3465a271 eu-west-1a
UN 10.0.197.246 68.73 GiB 256 24.2%
31905c62-dd32-4acc-b247-90899f8069ca eu-west-1b
UN 10.0.197.88 74.66 GiB 256 23.9%
8b42330a-e209-4e43-9174-e7b8c23eaa80 eu-west-1b
UN 10.0.197.122 75.26 GiB 256 25.5%
1336edb6-5dec-4826-b263-4263b7ff24d3 eu-west-1b
UN 10.0.197.74 75.88 GiB 256 26.4%
75819f26-673a-4853-98c4-efebca4444c6 eu-west-1b
UN 10.0.111.31 73.62 GiB 256 24.8%
8f0b2f7a-5c07-4936-9ebf-acb4333b067f eu-west-1a
Datacenter: us-east-1
=====================
Status=Up/Down
|/ State=Normal/Leaving/Joining/Moving
-- Address Load Tokens Owns (effective) Host ID
Rack
UN 10.66.201.210 71.6 GiB 256 22.8%
7f369bcf-12c1-4d3a-aae2-53fe06bbff06 us-east-1c
UN 10.66.111.5 72.38 GiB 256 23.4%
0148c92a-482a-4b5d-98df-d1ac88b40ffe us-east-1a
UN 10.66.200.74 71.4 GiB 256 23.7%
ec84e8b6-fc78-44df-9f18-aeb937858a69 us-east-1d
UN 10.66.201.139 69.2 GiB 256 22.7%
0bfa85b6-9def-4c86-9ede-08af6542847d us-east-1c
UN 10.66.201.43 66.57 GiB 256 20.9%
0ba00e53-b02e-4423-94ce-3a5974098d16 us-east-1c
UN 10.66.200.40 72.49 GiB 256 21.4%
3f95a54f-d9a1-42e6-acdb-3661dfe858f7 us-east-1d
UN 10.66.200.191 61.62 GiB 256 19.8%
d4d846c0-be1e-4cc0-8a54-70caab497699 us-east-1d
UN 10.66.111.13 70.97 GiB 256 23.4%
0839e0af-5b21-4efe-aa21-27f67f0f5d07 us-east-1a
UN 10.66.111.205 70.32 GiB 256 21.8%
9bf4075f-1563-4c7f-b812-89a31a95dc57 us-east-1a Aug 05 2022 06:29:11.031 [INFO] main.go:18 - 2022/08/05 18:29:11.028: Acquiring
sstable references (source: 10.66.111.205, elapsed: 162)
Aug 05 2022 06:29:11.031 [INFO] main.go:18 - 2022/08/05 18:29:11.028: Merging
memtable contents (source: 10.66.111.205, elapsed: 172)
Aug 05 2022 06:29:11.031 [INFO] main.go:18 - 2022/08/05 18:29:11.028: Bloom
filter allows skipping sstable 59507 (source: 10.66.111.205, elapsed: 183)
Aug 05 2022 06:29:11.031 [INFO] main.go:18 - 2022/08/05 18:29:11.028: Key cache
hit for sstable 59501 (source: 10.66.111.205, elapsed: 199)
Aug 05 2022 06:29:11.031 [INFO] main.go:18 - 2022/08/05 18:29:11.028: Read 1
live rows and 1 tombstone cells (source: 10.66.111.205, elapsed: 236)
Aug 05 2022 06:29:11.044 [INFO] main.go:18 - Tracing session
7ffc1e2014ec11ed8fd10f5c2d1a52b5 (coordinator: 10.66.111.13, duration: 0s):
1659724151046051232 [Info] OK query result: & took 4.616752ms
Aug 05 2022 06:29:11.046 [INFO] main.go:18 - 2022/08/05 18:29:11.043: Executing
single-partition query on user_db (source: 10.66.111.13, elapsed: 75)
Aug 05 2022 06:29:11.046 [INFO] main.go:18 - 2022/08/05 18:29:11.043: Acquiring
sstable references (source: 10.66.111.13, elapsed: 103)
Aug 05 2022 06:29:11.046 [INFO] main.go:18 - 2022/08/05 18:29:11.043: Merging
memtable contents (source: 10.66.111.13, elapsed: 111)
Aug 05 2022 06:29:11.046 [INFO] main.go:18 - 2022/08/05 18:29:11.043: Key cache
hit for sstable 59072 (source: 10.66.111.13, elapsed: 124)
Aug 05 2022 06:29:11.046 [INFO] main.go:18 - 2022/08/05 18:29:11.043: Key cache
hit for sstable 59060 (source: 10.66.111.13, elapsed: 145)
Aug 05 2022 06:29:11.046 [INFO] main.go:18 - 2022/08/05 18:29:11.043: Read 1
live rows and 2 tombstone cells (source: 10.66.111.13, elapsed: 201)
1659724151056167883 [Info] before query
Aug 05 2022 06:29:11.059 [INFO] main.go:18 - Tracing session
7ffe681014ec11ed8fd10f5c2d1a52b5 (coordinator: 10.66.111.13, duration: 198µs):
1659724151060795620 [Info] OK query result: took 4.622199ms
Aug 05 2022 06:29:11.060 [INFO] main.go:18 - 2022/08/05 18:29:11.057: Executing
single-partition query on user_db (source: 10.66.111.13, elapsed: 88)
Aug 05 2022 06:29:11.060 [INFO] main.go:18 - 2022/08/05 18:29:11.057: Acquiring
sstable references (source: 10.66.111.13, elapsed: 103)
Aug 05 2022 06:29:11.060 [INFO] main.go:18 - 2022/08/05 18:29:11.057: Merging
memtable contents (source: 10.66.111.13, elapsed: 113)
Aug 05 2022 06:29:11.060 [INFO] main.go:18 - 2022/08/05 18:29:11.057: Bloom
filter allows skipping sstable 59065 (source: 10.66.111.13, elapsed: 124)
Aug 05 2022 06:29:11.060 [INFO] main.go:18 - 2022/08/05 18:29:11.057: Key cache
hit for sstable 58252 (source: 10.66.111.13, elapsed: 133)
Aug 05 2022 06:29:11.060 [INFO] main.go:18 - 2022/08/05 18:29:11.057: Read 1
live rows and 2 tombstone cells (source: 10.66.111.13, elapsed: 171)
1659724151070892984 [Info] before query
Aug 05 2022 06:29:11.074 [INFO] main.go:18 - Tracing session
8000b20014ec11eda66655e765dc5305 (coordinator: 10.66.111.205, duration: 0s):
Aug 05 2022 06:29:11.075 [INFO] main.go:18 - 2022/08/05 18:29:11.072: Executing
single-partition query on user_db (source: 10.66.111.205, elapsed: 95)
Aug 05 2022 06:29:11.075 [INFO] main.go:18 - 2022/08/05 18:29:11.072: Acquiring
sstable references (source: 10.66.111.205, elapsed: 116)
Aug 05 2022 06:29:11.075 [INFO] main.go:18 - 2022/08/05 18:29:11.072: Merging
memtable contents (source: 10.66.111.205, elapsed: 122)
1659724151075492912 [Info] OK query result: took 4.588015ms
Aug 05 2022 06:29:11.075 [INFO] main.go:18 - 2022/08/05 18:29:11.072: Bloom
filter allows skipping sstable 59507 (source: 10.66.111.205, elapsed: 130)
Aug 05 2022 06:29:11.075 [INFO] main.go:18 - 2022/08/05 18:29:11.072: Key cache
hit for sstable 59501 (source: 10.66.111.205, elapsed: 144)
Aug 05 2022 06:29:11.075 [INFO] main.go:18 - 2022/08/05 18:29:11.072: Read 1
live rows and 1 tombstone cells (source: 10.66.111.205, elapsed: 178)
1659724151085599833 [Info] before query
Aug 05 2022 06:29:11.089 [INFO] main.go:18 - Tracing session
8002fbf014ec11ed8fd10f5c2d1a52b5 (coordinator: 10.66.111.13, duration: 250µs):
Aug 05 2022 06:29:11.090 [INFO] main.go:18 - 2022/08/05 18:29:11.087: Executing
single-partition query on user_db (source: 10.66.111.13, elapsed: 111)
Aug 05 2022 06:29:11.090 [INFO] main.go:18 - 2022/08/05 18:29:11.087: Acquiring
sstable references (source: 10.66.111.13, elapsed: 139)
1659724151090291862 [Info] OK query result: took 4.685499ms
