Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

2 nodes stucked to stream data during bootstrap of new added node with replace #10814

Closed
aleksbykov opened this issue Jun 15, 2022 · 40 comments
Closed
Assignees
Labels
Milestone

Comments

@aleksbykov
Copy link
Contributor

aleksbykov commented Jun 15, 2022

Scylla version: 5.1.dev-0.20220607.605ee74c39b2 with build-id 0cfb2d9236f29831498982e4b3e9325b787ccb4c
Scylla version: 5.1.dev-0.20220612.e87ca733f0d3 with build-id 2fcb16ce2dcf313a6d86fce8631e18e3055ab359 starting ...
Instance: i3.2xlarge
Db nodes: 3

Job: https://jenkins.scylladb.com/view/Performance/job/scylla-master/job/scylla-master-perf-regression-latency-250gb-with-nemesis/208/execution/node/112/

job performance-latency with nemesis run sequence of nemesis. One of nemesis is Terminate and replace.
The nemsis terminate the random node in cluster and add new one with replace address.
During the test node logs are have a lot of warning messages:

2022-06-15T05:36:59+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla:  [shard 6] lsa-timing - Reclamation cycle took 16000 us, trying to release 5.974 MiB preemptibly
2022-06-15T05:36:59+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla:  [shard 6] lsa-timing - Reclamation cycle took 16000 us, trying to release 5.974 MiB preemptibly
2022-06-15T05:36:59+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 6] lsa-timing - - reclamation rate = 226.561 MiB/s
2022-06-15T05:36:59+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 6] lsa-timing - - compacted segments: 1
2022-06-15T05:36:59+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 6] lsa-timing - - compacted memory: 0.070 MiB
2022-06-15T05:36:59+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 6] lsa-timing - - reclamation rate = 226.561 MiB/s
2022-06-15T05:36:59+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 6] lsa-timing - - compacted segments: 1
2022-06-15T05:36:59+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 6] lsa-timing - - compacted memory: 0.070 MiB

known issue: #10159

2 tests: test_read and test_mixed use next c-s commands running from 4 loaders:
stress_cmd_r: "cassandra-stress read no-warmup cl=QUORUM duration=600m -schema 'replication(factor=3)' -port jmx=6868 -mode cql3 native -rate 'threads=50 throttle=4000/s' -col 'size=FIXED(128) n=FIXED(8)' -pop 'dist=gauss(1..250000000,125000000,12500000)' "
stress_cmd_m: "cassandra-stress mixed no-warmup cl=QUORUM duration=600m -schema 'replication(factor=3)' -port jmx=6868 -mode cql3 native -rate 'threads=50 throttle=3500/s' -col 'size=FIXED(128) n=FIXED(8)' -pop 'dist=gauss(1..250000000,125000000,12500000)' "

Both tests: test_read and test mixed are failed by same reasons. During nemesis Terminate and replace after node 3 was terminated node1 and node2 reported a lot of next warnings:

2022-06-15T08:03:10+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla: message repeated 2 times: [  [shard 1] storage_proxy - Exception when communicating with 10.0.3.208, to read from keyspace1.standard1: abort requested]
2022-06-15T08:03:10+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla:  [shard 6] storage_proxy - Exception when communicating with 10.0.3.208, to read from keyspace1.standard1: abort requested
2022-06-15T08:03:10+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla[8266]: [shard 6] storage_proxy - Exception when communicating with 10.0.3.208, to read from keyspace1.standard1: abort requested
2022-06-15T08:03:10+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla[8266]: [shard 4] storage_proxy - Exception when communicating with 10.0.3.208, to read from keyspace1.standard1: abort requested
2022-06-15T08:03:10+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla[8266]: [shard 1] storage_proxy - Exception when communicating with 10.0.3.208, to read from keyspace1.standard1: abort requested
2022-06-15T08:03:10+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla[8266]: [shard 4] storage_proxy - Exception when communicating with 10.0.3.208, to read from keyspace1.standard1: abort requested
2022-06-15T08:03:10+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla[8266]: [shard 2] storage_proxy - Exception when communicating with 10.0.3.208, to read from keyspace1.standard1: abort requested
2022-06-15T08:03:10+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla:  [shard 4] storage_proxy - Exception when communicating with 10.0.3.208, to read from keyspace1.standard1: abort requested
2022-06-15T08:03:10+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla[8266]: [shard 3] storage_proxy - Exception when communicating with 10.0.3.208, to read from keyspace1.standard1: abort requested

But after new node4 was added and bootstrap process was started on it:

2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-4 !INFO    | scylla:  [shard 5] compaction - [Compact system.peers d8f7e0f0-ec82-11ec-8de2-93ae23a60144] Compacting [/var/lib/scylla/data/system/peers-37f71aca7dc2383ba70672528af04d4f/me-47-big-Data.db:level=0:origin=memtable,/var/lib/scylla/data/system/peers-37f71aca7dc2383ba70672528af04d4f/mc-40-big-Data.db:level=0:origin=compaction]
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-4 !INFO    | scylla:  [shard 5] compaction - [Compact system.peers d8f7e0f0-ec82-11ec-8de2-93ae23a60144] Compacting [/var/lib/scylla/data/system/peers-37f71aca7dc2383ba70672528af04d4f/me-47-big-Data.db:level=0:origin=memtable,/var/lib/scylla/data/system/peers-37f71aca7dc2383ba70672528af04d4f/mc-40-big-Data.db:level=0:origin=compaction]
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-4 !INFO    | scylla:  [shard 6] compaction - [Compact system.peers d8f7e0f0-ec82-11ec-8fd3-93aa23a60144] Compacting [/var/lib/scylla/data/system/peers-37f71aca7dc2383ba70672528af04d4f/me-20-big-Data.db:level=0:origin=memtable,/var/lib/scylla/data/system/peers-37f71aca7dc2383ba70672528af04d4f/mc-13-big-Data.db:level=0:origin=memtable]
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-4 !INFO    | scylla:  [shard 6] compaction - [Compact system.peers d8f7e0f0-ec82-11ec-8fd3-93aa23a60144] Compacting [/var/lib/scylla/data/system/peers-37f71aca7dc2383ba70672528af04d4f/me-20-big-Data.db:level=0:origin=memtable,/var/lib/scylla/data/system/peers-37f71aca7dc2383ba70672528af04d4f/mc-13-big-Data.db:level=0:origin=memtable]
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-4 !INFO    | scylla:  [shard 1] compaction - [Compact system.peers d8f80800-ec82-11ec-b7c4-93ad23a60144] Compacting [/var/lib/scylla/data/system/peers-37f71aca7dc2383ba70672528af04d4f/me-29-big-Data.db:level=0:origin=memtable,/var/lib/scylla/data/system/peers-37f71aca7dc2383ba70672528af04d4f/mc-22-big-Data.db:level=0:origin=compaction]
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-4 !INFO    | scylla:  [shard 0] storage_service - Starting to bootstrap...
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-4 !INFO    | scylla:  [shard 1] compaction - [Compact system.peers d8f80800-ec82-11ec-b7c4-93ad23a60144] Compacting [/var/lib/scylla/data/system/peers-37f71aca7dc2383ba70672528af04d4f/me-29-big-Data.db:level=0:origin=memtable,/var/lib/scylla/data/system/peers-37f71aca7dc2383ba70672528af04d4f/mc-22-big-Data.db:level=0:origin=compaction]
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-4 !INFO    | scylla:  [shard 0] storage_service - Starting to bootstrap...
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-4 !INFO    | scylla:  [shard 0] storage_service - replace[cb048d0c-1bd2-4a0f-a01e-fca83038832e]: Started replace operation, replace_nodes={{ 10.0.3.208 -> 10.0.1.25}}, sync_nodes=[10.0.1.25, 10.0.0.100, 10.0.0.13], ignore_nodes=[]
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-4 !INFO    | scylla:  [shard 0] storage_service - replace[cb048d0c-1bd2-4a0f-a01e-fca83038832e]: Started replace operation, replace_nodes={{ 10.0.3.208 -> 10.0.1.25}}, sync_nodes=[10.0.1.25, 10.0.0.100, 10.0.0.13], ignore_nodes=[]
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-4 !INFO    | scylla:  [shard 0] storage_service - replace[cb048d0c-1bd2-4a0f-a01e-fca83038832e]: Added replacing_node=10.0.1.25 to replace existing_node=10.0.3.208, coordinator=10.0.1.25
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-4 !INFO    | scylla:  [shard 0] storage_service - replace[cb048d0c-1bd2-4a0f-a01e-fca83038832e]: Added replacing_node=10.0.1.25 to replace existing_node=10.0.3.208, coordinator=10.0.1.25
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-4 !INFO    | scylla:  [shard 0] token_metadata - Added node 10.0.1.25 as pending replacing endpoint which replaces existing node 10.0.3.208
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-4 !INFO    | scylla:  [shard 0] token_metadata - Added node 10.0.1.25 as pending replacing endpoint which replaces existing node 10.0.3.208
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-4 !INFO    | scylla:  [shard 6] compaction - [Compact system.peers d8f7e0f0-ec82-11ec-8fd3-93aa23a60144] Compacted 2 sstables to [/var/lib/scylla/data/system/peers-37f71aca7dc2383ba70672528af04d4f/me-27-big-Data.db:level=0]. 31kB to 18kB (~58% of original) in 5ms = 3MB/s. ~256 total partitions merged to 1.
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-4 !INFO    | scylla:  [shard 6] compaction - [Compact system.peers d8f7e0f0-ec82-11ec-8fd3-93aa23a60144] Compacted 2 sstables to [/var/lib/scylla/data/system/peers-37f71aca7dc2383ba70672528af04d4f/me-27-big-Data.db:level=0]. 31kB to 18kB (~58% of original) in 5ms = 3MB/s. ~256 total partitions merged to 1.

But node1 and node2 are stucked to stream data. Latest messages:

022-06-15T08:12:05+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla-manager-agent[9728]: {"L":"INFO","T":"2022-06-15T08:12:05.052Z","N":"http","M":"GET /storage_service/host_id","from":"10.0.3.168:36882","status":200,"bytes":213,"duration":"1ms"}
2022-06-15T08:12:05+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla-manager-agent[9728]: {"L":"INFO","T":"2022-06-15T08:12:05.062Z","N":"http","M":"GET /storage_service/nodes/joining","from":"10.0.3.168:36882","status":200,"bytes":2,"duration":"0ms"}
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 0] storage_service - replace[cb048d0c-1bd2-4a0f-a01e-fca83038832e]: Added replacing_node=10.0.1.25 to replace existing_node=10.0.3.208, coordinator=10.0.1.25
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 0] token_metadata - Added node 10.0.1.25 as pending replacing endpoint which replaces existing node 10.0.3.208
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 0] storage_service - replace[cb048d0c-1bd2-4a0f-a01e-fca83038832e]: Added replacing_node=10.0.1.25 to replace existing_node=10.0.3.208, coordinator=10.0.1.25
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 0] token_metadata - Added node 10.0.1.25 as pending replacing endpoint which replaces existing node 10.0.3.208
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 0] storage_service - replace[cb048d0c-1bd2-4a0f-a01e-fca83038832e]: Added replacing_node=10.0.1.25 to replace existing_node=10.0.3.208, coordinator=10.0.1.25
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 0] token_metadata - Added node 10.0.1.25 as pending replacing endpoint which replaces existing node 10.0.3.208
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 0] storage_service - replace[cb048d0c-1bd2-4a0f-a01e-fca83038832e]: Added replacing_node=10.0.1.25 to replace existing_node=10.0.3.208, coordinator=10.0.1.25
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 0] token_metadata - Added node 10.0.1.25 as pending replacing endpoint which replaces existing node 10.0.3.208
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla:  [shard 6] lsa-timing - Reclamation cycle took 8000 us, trying to release 0.125 MiB non-preemptibly
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla:  [shard 6] lsa-timing - Reclamation cycle took 8000 us, trying to release 0.125 MiB non-preemptibly
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 6] lsa-timing - - reserved segments: 30
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 6] lsa-timing - - reserved segments: 30
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 6] lsa-timing - - reclamation rate = 421.871 MiB/s
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 6] lsa-timing - - reclamation rate = 421.871 MiB/s
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 6] lsa-timing - - evicted memory: 3.166 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 6] lsa-timing - - compacted segments: 48
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 6] lsa-timing - - compacted memory: 2.566 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 6] lsa-timing - - evicted memory: 3.166 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 6] lsa-timing - - compacted segments: 48
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 6] lsa-timing - - compacted memory: 2.566 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla:  [shard 5] lsa-timing - Reclamation cycle took 8000 us, trying to release 0.125 MiB non-preemptibly
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 5] lsa-timing - - reserved segments: 30
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 5] lsa-timing - - reclamation rate = 390.621 MiB/s
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 5] lsa-timing - - evicted memory: 2.938 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 5] lsa-timing - - compacted segments: 44
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 5] lsa-timing - - compacted memory: 2.374 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla:  [shard 5] lsa-timing - Reclamation cycle took 8000 us, trying to release 0.125 MiB non-preemptibly
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 5] lsa-timing - - reserved segments: 30
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 5] lsa-timing - - reclamation rate = 390.621 MiB/s
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 5] lsa-timing - - evicted memory: 2.938 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 5] lsa-timing - - compacted segments: 44
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 5] lsa-timing - - compacted memory: 2.374 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla:  [shard 1] lsa-timing - Reclamation cycle took 8000 us, trying to release 0.125 MiB non-preemptibly
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 1] lsa-timing - - reserved segments: 30
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla:  [shard 1] lsa-timing - Reclamation cycle took 8000 us, trying to release 0.125 MiB non-preemptibly
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 1] lsa-timing - - reserved segments: 30
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 1] lsa-timing - - reclamation rate = 468.746 MiB/s
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 1] lsa-timing - - reclamation rate = 468.746 MiB/s
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 1] lsa-timing - - evicted memory: 3.531 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 1] lsa-timing - - compacted segments: 52
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 1] lsa-timing - - compacted memory: 2.752 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 1] lsa-timing - - evicted memory: 3.531 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 1] lsa-timing - - compacted segments: 52
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla:  [shard 1] lsa-timing - - compacted memory: 2.752 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla[8266]: [shard 6] lsa-timing - Reclamation cycle took 8000 us, trying to release 0.125 MiB non-preemptibly
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 6] lsa-timing - - reserved segments: 30
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 6] lsa-timing - - reclamation rate = 421.871 MiB/s
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 6] lsa-timing - - evicted memory: 3.166 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 6] lsa-timing - - compacted segments: 48
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 6] lsa-timing - - compacted memory: 2.566 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla[8266]: [shard 5] lsa-timing - Reclamation cycle took 8000 us, trying to release 0.125 MiB non-preemptibly
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 5] lsa-timing - - reserved segments: 30
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 5] lsa-timing - - reclamation rate = 390.621 MiB/s
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 5] lsa-timing - - evicted memory: 2.938 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 5] lsa-timing - - compacted segments: 44
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 5] lsa-timing - - compacted memory: 2.374 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla[8266]: [shard 1] lsa-timing - Reclamation cycle took 8000 us, trying to release 0.125 MiB non-preemptibly
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 1] lsa-timing - - reserved segments: 30
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 1] lsa-timing - - reclamation rate = 468.746 MiB/s
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 1] lsa-timing - - evicted memory: 3.531 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 1] lsa-timing - - compacted segments: 52
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 1] lsa-timing - - compacted memory: 2.752 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla[8266]: [shard 6] lsa-timing - Reclamation cycle took 8000 us, trying to release 0.125 MiB non-preemptibly
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 6] lsa-timing - - reserved segments: 30
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 6] lsa-timing - - reclamation rate = 421.871 MiB/s
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 6] lsa-timing - - evicted memory: 3.166 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 6] lsa-timing - - compacted segments: 48
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 6] lsa-timing - - compacted memory: 2.566 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla[8266]: [shard 5] lsa-timing - Reclamation cycle took 8000 us, trying to release 0.125 MiB non-preemptibly
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 5] lsa-timing - - reserved segments: 30
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 5] lsa-timing - - reclamation rate = 390.621 MiB/s
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 5] lsa-timing - - evicted memory: 2.938 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 5] lsa-timing - - compacted segments: 44
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 5] lsa-timing - - compacted memory: 2.374 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !WARNING | scylla[8266]: [shard 1] lsa-timing - Reclamation cycle took 8000 us, trying to release 0.125 MiB non-preemptibly
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 1] lsa-timing - - reserved segments: 30
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 1] lsa-timing - - reclamation rate = 468.746 MiB/s
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 1] lsa-timing - - evicted memory: 3.531 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 1] lsa-timing - - compacted segments: 52
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-1 !INFO    | scylla[8266]: [shard 1] lsa-timing - - compacted memory: 2.752 MiB
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 0] storage_service - replace[cb048d0c-1bd2-4a0f-a01e-fca83038832e]: Added replacing_node=10.0.1.25 to replace existing_node=10.0.3.208, coordinator=10.0.1.25
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 0] storage_service - replace[cb048d0c-1bd2-4a0f-a01e-fca83038832e]: Added replacing_node=10.0.1.25 to replace existing_node=10.0.3.208, coordinator=10.0.1.25
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 0] token_metadata - Added node 10.0.1.25 as pending replacing endpoint which replaces existing node 10.0.3.208
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 0] token_metadata - Added node 10.0.1.25 as pending replacing endpoint which replaces existing node 10.0.3.208
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 0] storage_service - replace[cb048d0c-1bd2-4a0f-a01e-fca83038832e]: Added replacing_node=10.0.1.25 to replace existing_node=10.0.3.208, coordinator=10.0.1.25
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 0] token_metadata - Added node 10.0.1.25 as pending replacing endpoint which replaces existing node 10.0.3.208
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 0] storage_service - replace[cb048d0c-1bd2-4a0f-a01e-fca83038832e]: Added replacing_node=10.0.1.25 to replace existing_node=10.0.3.208, coordinator=10.0.1.25
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 0] token_metadata - Added node 10.0.1.25 as pending replacing endpoint which replaces existing node 10.0.3.208
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | sshd[79466]: Accepted publickey for scyllaadm from 10.0.3.5 port 40166 ssh2: RSA SHA256:1YmYWh7roz4Y3FSY7N8CetmQNlK/K5FeBPITC8KF0u8
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | sshd[79466]: Accepted publickey for scyllaadm from 10.0.3.5 port 40166 ssh2: RSA SHA256:1YmYWh7roz4Y3FSY7N8CetmQNlK/K5FeBPITC8KF0u8
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | sshd[79466]: pam_unix(sshd:session): session opened for user scyllaadm by (uid=0)
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | sshd[79466]: pam_unix(sshd:session): session opened for user scyllaadm by (uid=0)
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | systemd-logind[530]: New session 1687 of user scyllaadm.
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | systemd-logind[530]: New session 1687 of user scyllaadm.
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | systemd[1]: Started Session 1687 of user scyllaadm.
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | systemd[1]: Started Session 1687 of user scyllaadm.
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | sshd[79466]: Accepted publickey for scyllaadm from 10.0.3.5 port 40166 ssh2: RSA SHA256:1YmYWh7roz4Y3FSY7N8CetmQNlK/K5FeBPITC8KF0u8
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | sshd[79466]: pam_unix(sshd:session): session opened for user scyllaadm by (uid=0)
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | systemd-logind[530]: New session 1687 of user scyllaadm.
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | systemd[1]: Started Session 1687 of user scyllaadm.
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | sshd[79466]: Accepted publickey for scyllaadm from 10.0.3.5 port 40166 ssh2: RSA SHA256:1YmYWh7roz4Y3FSY7N8CetmQNlK/K5FeBPITC8KF0u8
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | sshd[79466]: pam_unix(sshd:session): session opened for user scyllaadm by (uid=0)
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | systemd-logind[530]: New session 1687 of user scyllaadm.
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | systemd[1]: Started Session 1687 of user scyllaadm.
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !WARNING | scylla:  [shard 2] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.125 MiB non-preemptibly
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !WARNING | scylla:  [shard 2] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.125 MiB non-preemptibly
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 2] lsa-timing - - reserved segments: 30
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 2] lsa-timing - - reserved segments: 30
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 2] lsa-timing - - reclamation rate = 281.252 MiB/s
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 2] lsa-timing - - evicted memory: 2.216 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 2] lsa-timing - - compacted segments: 29
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 2] lsa-timing - - compacted memory: 1.455 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 2] lsa-timing - - reclamation rate = 281.252 MiB/s
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 2] lsa-timing - - evicted memory: 2.216 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 2] lsa-timing - - compacted segments: 29
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 2] lsa-timing - - compacted memory: 1.455 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !WARNING | scylla:  [shard 1] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.125 MiB non-preemptibly
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 1] lsa-timing - - reserved segments: 30
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 1] lsa-timing - - reclamation rate = 312.502 MiB/s
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 1] lsa-timing - - evicted memory: 2.425 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 1] lsa-timing - - compacted segments: 34
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 1] lsa-timing - - compacted memory: 1.774 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !WARNING | scylla:  [shard 1] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.125 MiB non-preemptibly
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 1] lsa-timing - - reserved segments: 30
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 1] lsa-timing - - reclamation rate = 312.502 MiB/s
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 1] lsa-timing - - evicted memory: 2.425 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 1] lsa-timing - - compacted segments: 34
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla:  [shard 1] lsa-timing - - compacted memory: 1.774 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !WARNING | scylla[9385]: [shard 2] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.125 MiB non-preemptibly
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 2] lsa-timing - - reserved segments: 30
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 2] lsa-timing - - reclamation rate = 281.252 MiB/s
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 2] lsa-timing - - evicted memory: 2.216 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 2] lsa-timing - - compacted segments: 29
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 2] lsa-timing - - compacted memory: 1.455 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !WARNING | scylla[9385]: [shard 1] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.125 MiB non-preemptibly
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 1] lsa-timing - - reserved segments: 30
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 1] lsa-timing - - reclamation rate = 312.502 MiB/s
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 1] lsa-timing - - evicted memory: 2.425 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 1] lsa-timing - - compacted segments: 34
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 1] lsa-timing - - compacted memory: 1.774 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !WARNING | scylla[9385]: [shard 2] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.125 MiB non-preemptibly
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 2] lsa-timing - - reserved segments: 30
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 2] lsa-timing - - reclamation rate = 281.252 MiB/s
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 2] lsa-timing - - evicted memory: 2.216 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 2] lsa-timing - - compacted segments: 29
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 2] lsa-timing - - compacted memory: 1.455 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !WARNING | scylla[9385]: [shard 1] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.125 MiB non-preemptibly
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 1] lsa-timing - - reserved segments: 30
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 1] lsa-timing - - reclamation rate = 312.502 MiB/s
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 1] lsa-timing - - evicted memory: 2.425 MiB
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 1] lsa-timing - - compacted segments: 34
2022-06-15T08:12:09+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-2 !INFO    | scylla[9385]: [shard 1] lsa-timing - - compacted memory: 1.774 MiB

According to monitor, at that moment node 2 use 100% of cpu
Screenshot from 2022-06-16 00-50-48

These cause c-s command report next critical errors and failed:

2022-06-15 08:17:13.495: (CassandraStressLogEvent Severity.CRITICAL) period_type=one-time event_id=07519490-b0e0-42b4-9dd7-b9d736652c86: type=OperationOnKey regex=Operation x10 on key\(s\) \[ line_number=6976 node=Node perf-latency-nemesis-add-mana-loader-node-674f5418-1 [3.235.169.80 | 10.0.0.125] (seed: False)
java.io.IOException: Operation x10 on key(s) [4e333450313139343730]: Error executing: (ReadTimeoutException): Cassandra timeout during read query at consistency QUORUM (2 responses were required but only 1 replica responded)
2022-06-15 08:17:13.496: (CassandraStressLogEvent Severity.CRITICAL) period_type=one-time event_id=4e6da26d-8eeb-4f62-b429-f5a38df8298a: type=OperationOnKey regex=Operation x10 on key\(s\) \[ line_number=6919 node=Node perf-latency-nemesis-add-mana-loader-node-674f5418-2 [3.235.163.167 | 10.0.2.171] (seed: False)
java.io.IOException: Operation x10 on key(s) [4f4e3035503336503131]: Error executing: (ReadTimecom.datastax.driver.core.exceptions.ReadTimeoutException: Cassandra timeout during read query at consistency QUORUM (2 responses were required but only 1 replica responded)
2022-06-15 08:17:13.503: (CassandraStressLogEvent Severity.CRITICAL) period_type=one-time event_id=74418821-8633-49f7-a24c-24f4bd4cfcf5: type=OperationOnKey regex=Operation x10 on key\(s\) \[ line_number=6936 node=Node perf-latency-nemesis-add-mana-loader-node-674f5418-4 [44.197.131.82 | 10.0.2.142] (seed: False)
java.io.IOException: Operation x10 on key(s) [4b36333231304d4e3331]: Error executing: (ReadTimeoutException): Cassandra timeout during rcom.datastax.driver.core.exceptions.ReadTimeoutException: Cassandra timeout during read query at consistency QUORUM (2 responses were required but only 1 replica responded)
2022-06-15 08:17:13.508: (CassandraStressLogEvent Severity.CRITICAL) period_type=one-time event_id=07519490-b0e0-42b4-9dd7-b9d736652c86: type=OperationOnKey regex=Operation x10 on key\(s\) \[ line_number=6984 node=Node perf-latency-nemesis-add-mana-loader-node-674f5418-1 [3.235.169.80 | 10.0.0.125] (seed: False)
java.io.IOException: Operation x10 on key(s) [4e363538385038353031]: Error executing: (ReadTimeoutException): Cassandra timeout during read query at consistency QUcom.datastax.driver.core.exceptions.ReadTimeoutException: Cassandra timeout during read query at consistency QUORUM (2 responses were required but only 1 replica responded)
2022-06-15 08:17:13.517: (CassandraStressLogEvent Severity.CRITICAL) period_type=one-time event_id=4e6da26d-8eeb-4f62-b429-f5a38df8298a: type=OperationOnKey regex=Operation x10 on key\(s\) \[ line_number=6932 node=Node perf-latency-nemesis-add-mana-loader-node-674f5418-2 [3.235.163.167 | 10.0.2.171] (seed: False)
java.io.IOException: Operation x10 on key(s) [344e324f324f34323630]: Error executing: (ReadTimeoutException): Cassandra timeout during read query at consistency QUORUM (2 responses were required but only 1 replica responded)

Logs:

db-cluster | https://cloudius-jenkins-test.s3.amazonaws.com/674f5418-6d07-4c51-833d-ff90a711ef9a/20220615_083047/db-cluster-674f5418.tar.gz |
monitor-set | https://cloudius-jenkins-test.s3.amazonaws.com/674f5418-6d07-4c51-833d-ff90a711ef9a/20220615_083047/monitor-set-674f5418.tar.gz |
loader-set | https://cloudius-jenkins-test.s3.amazonaws.com/674f5418-6d07-4c51-833d-ff90a711ef9a/20220615_083047/loader-set-674f5418.tar.gz |
sct-runner | https://cloudius-jenkins-test.s3.amazonaws.com/674f5418-6d07-4c51-833d-ff90a711ef9a/20220615_083047/sct-runner-674f5418.tar.gz |

Monitoring:
http://3.216.80.233:3000/d/alternator-master/scylla-master-perf-regression-latency-250gb-with-nemesis-scylla-per-server-metrics-nemesis-master?orgId=1&from=1655279177170&to=1655281199331&var-by=instance&var-cluster=&var-dc=All&var-node=All&var-shard=All&var-sct_tags=InfoEvent&var-sct_tags=DisruptionEvent

@roydahan roydahan added master/high triage/master Looking for assignee labels Jun 15, 2022
@avikivity
Copy link
Member

@asias please investigate, let's revert the offending commit ASAP

@asias
Copy link
Contributor

asias commented Jun 16, 2022

@asias please investigate, let's revert the offending commit ASAP

will do.

@slivne slivne added type/bug and removed triage/master Looking for assignee labels Jun 16, 2022
@slivne slivne added this to the 5.1 milestone Jun 16, 2022
@asias
Copy link
Contributor

asias commented Jun 16, 2022

2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-4 !INFO    | scylla[7140]: [shard 2] repair - repair[ce8c334d-5084-4e4c-99c3-1007a1e27587]: Started to repair 1 out of 4 tables in keyspace=system_distributed, table=service_levels, table_id=b8c556bd-212d-37ad-9484-690c73a5994b, repair_reason=replace
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-4 !INFO    | scylla[7140]: [shard 6] repair - repair[ce8c334d-5084-4e4c-99c3-1007a1e27587]: Started to repair 1 out of 4 tables in keyspace=system_distributed, table=service_levels, table_id=b8c556bd-212d-37ad-9484-690c73a5994b, repair_reason=replace
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-4 !INFO    | scylla:  [shard 6] repair - repair[ce8c334d-5084-4e4c-99c3-1007a1e27587]: Started to repair 2 out of 4 tables in keyspace=system_distributed, table=view_build_status, table_id=5582b59f-8e4e-35e1-b913-3acada51eb04, repair_reason=replace
2022-06-15T08:12:07+00:00  perf-latency-nemesis-add-mana-db-node-674f5418-4 !INFO    | scylla:  [shard 6] repair - repair[ce8c334d-5084-4e4c-99c3-1007a1e27587]: Started to repair 2 out of 4 tables in keyspace=system_distributed, table=view_build_status, table_id=5582b59f-8e4e-35e1-b913-3acada51eb04, repair_reason=replace

Did we have two scylla process on the machine? In the log I saw both:

INFO  scylla[7140]: [shard 2] ....
INFO  scylla:  [shard 6] ...

What is the difference and why?

@avikivity
Copy link
Member

Maybe we have --log-to-stdout and --log-to-syslog, and everything gets duplicated.

@aleksbykov
Copy link
Contributor Author

I sure that there is single scylla running on node

@asias
Copy link
Contributor

asias commented Jun 16, 2022

I tried to load the monitor data locally but it failed as:

I used the monitor version from the tarball.

$ ./start-all.sh -v master -s ./config/scylla_servers.yml -d /home/asias/Downloads/issue.10814/monitor-set-674f5418/perf-latency-nemesis-add-mana-monitor-node-674f5418-1/20220615T083111Z-5ae55095999fc3b4

Loading prometheus data from /home/asias/Downloads/issue.10814/monitor-set-674f5418/perf-latency-nemesis-add-mana-monitor-node-674f5418-1/20220615T083111Z-5ae55095999fc3b4
Wait for alert manager container to start
Wait for Loki container to start.


Error: Loki container failed to start
For more information use: docker logs loki

@aleksbykov
Copy link
Contributor Author

Monitor is still alive if you need it

@asias
Copy link
Contributor

asias commented Jun 16, 2022

@aleksbykov this is a replace operation which uses RBNO by default, so there will be no stream session only repair.

@aleksbykov
Copy link
Contributor Author

aleksbykov commented Jun 16, 2022

@asias i saw log messages related to repair on new node (node)
But other nodes should have any log messages that they transmit data during rnbo, shouldn' they?

@asias
Copy link
Contributor

asias commented Jun 16, 2022

Looks like the cluster is already in a broken state even before replace after 07:00

Look the flat compaction / commit log io queue bandwidth.

Also, repaird started but get almost zero io bandwidth from the streaming group. Is this related to the new io scheduler?

image
image

@avikivity
Copy link
Member

Streaming queue delay is zero, looks like no demand from that queue.

@asias
Copy link
Contributor

asias commented Jun 17, 2022

@amnonh Do we have any change in the monitor dashboard? Why did it only show one shard in the floating box? In the past, it shows all the shards at the pointed timestamp.
image

@asias
Copy link
Contributor

asias commented Jun 17, 2022

node1 10.0.0.13
node2 10.0.0.100
node3 10.0.3.208
node4 10.0.1.25 (replacing node)
node4 used some cpu then cpu usage went zero. cpu usage of shard2 of node2 stayed 100% all the time.
Maybe node2 got stuck at the lsa then repair process could not make any progress.

image
image

@aleksbykov
Copy link
Contributor Author

@asias here is another run when repair get stucked:

db logs: https://cloudius-jenkins-test.s3.amazonaws.com/fb356fc1-abf7-4327-8602-305131c09805/20220617_092549/db-cluster-fb356fc1.tar.gz
Monitor: http://34.201.35.253:3000/d/detailed-master/scylla-master-perf-regression-latency-250gb-with-nemesis-latest-scylla-per-server-metrics-nemesis-master?orgId=1&from=now-12h&to=now&var-by=instance&var-cluster=&var-dc=All&var-node=All&var-shard=All&var-sct_tags=InfoEvent&var-sct_tags=DisruptionEvent

Replacing node4: has last meaningful messages:

2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 0] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: sync data for keyspace=keyspace1, status
=started
2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 0] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in k
eyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace
2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 1] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in k
eyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace
2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 3] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in k
eyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace
2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 2] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in k
eyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace
2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 4] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in k
eyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace
2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 5] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in k
eyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace
2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 6] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in k
eyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace

in this run the terminate and replace node is first nemesis which was run.So the cluster should be ok before it

@asias
Copy link
Contributor

asias commented Jun 20, 2022

@asias here is another run when repair get stucked:

db logs: https://cloudius-jenkins-test.s3.amazonaws.com/fb356fc1-abf7-4327-8602-305131c09805/20220617_092549/db-cluster-fb356fc1.tar.gz Monitor: http://34.201.35.253:3000/d/detailed-master/scylla-master-perf-regression-latency-250gb-with-nemesis-latest-scylla-per-server-metrics-nemesis-master?orgId=1&from=now-12h&to=now&var-by=instance&var-cluster=&var-dc=All&var-node=All&var-shard=All&var-sct_tags=InfoEvent&var-sct_tags=DisruptionEvent

Strange. The detailed dashboard is missing.

image

Replacing node4: has last meaningful messages:

2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 0] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: sync data for keyspace=keyspace1, status
=started
2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 0] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in k
eyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace
2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 1] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in k
eyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace
2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 3] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in k
eyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace
2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 2] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in k
eyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace
2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 4] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in k
eyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace
2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 5] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in k
eyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace
2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 6] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in k
eyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace

in this run the terminate and replace node is first nemesis which was run.So the cluster should be ok before it

@asias
Copy link
Contributor

asias commented Jun 20, 2022

db logs: https://cloudius-jenkins-test.s3.amazonaws.com/fb356fc1-abf7-4327-8602-305131c09805/20220617_092549/db-cluster-fb356fc1.tar.gz
Monitor: http://34.201.35.253:3000/d/detailed-master/scylla-master-perf-regression-latency-250gb-with-nemesis-latest-scylla-per-server-metrics-nemesis-master?orgId=1&from=now-12h&to=now&var-by=instance&var-cluster=&var-dc=All&var-node=All&var-shard=All&var-sct_tags=InfoEvent&var-sct_tags=DisruptionEvent

There was a short repair for replace ops activity. Then it went to zero.

image

Both the replacing node (node4) and existing node (node1 below) had almost zero log after the 00:47. Looks like we have a dead lock similar to what we fixed recently (logger dead lock).

node4 (replacing node)

2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 0] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in keyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace
2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 1] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in keyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace
2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 3] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in keyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace
2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 2] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in keyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace
2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 4] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in keyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace
2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 5] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in keyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace
2022-06-17T00:47:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 6] repair - repair[4e597c72-4cef-4751-b986-6a498e1ec0f7]: Started to repair 1 out of 1 tables in keyspace=keyspace1, table=standard1, table_id=35720a60-edc1-11ec-9759-e9b7bc4501c5, repair_reason=replace
2022-06-17T01:36:05+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 1] rpc - client 43.129.40.155:25586: wrong protocol magic: 474554202f204854
2022-06-17T01:36:05+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4      !ERR | scylla[7602]:  [shard 1] rpc - client 43.129.40.155:25586: server connection dropped: connection is closed
2022-06-17T01:36:15+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 4] rpc - client 43.129.40.155:28648: wrong protocol magic: 030000130e-200000
2022-06-17T01:36:15+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4      !ERR | scylla[7602]:  [shard 4] rpc - client 43.129.40.155:28648: server connection dropped: connection is closed
2022-06-17T01:36:26+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 2] rpc - client 43.129.40.155:32062: wrong protocol magic: 0001000100000000
2022-06-17T01:36:26+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4      !ERR | scylla[7602]:  [shard 2] rpc - client 43.129.40.155:32062: server connection dropped: connection is closed
2022-06-17T02:08:58+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 0] rpc - client 45.61.187.144:39718: wrong protocol magic: 474554202f204854
2022-06-17T02:08:58+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4      !ERR | scylla[7602]:  [shard 0] rpc - client 45.61.187.144:39718: server connection dropped: connection is closed
2022-06-17T04:37:06+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 2] rpc - client 107.189.8.198:58802: wrong protocol magic: 474554202f204854
2022-06-17T04:37:06+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4      !ERR | scylla[7602]:  [shard 2] rpc - client 107.189.8.198:58802: server connection dropped: connection is closed
2022-06-17T05:49:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 4] rpc - client 107.189.8.198:51426: wrong protocol magic: 474554202f204854
2022-06-17T05:49:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4      !ERR | scylla[7602]:  [shard 4] rpc - client 107.189.8.198:51426: server connection dropped: connection is closed
2022-06-17T06:31:57+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 2] rpc - client 45.61.187.144:37508: wrong protocol magic: 474554202f204854
2022-06-17T06:31:57+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4      !ERR | scylla[7602]:  [shard 2] rpc - client 45.61.187.144:37508: server connection dropped: connection is closed
2022-06-17T06:51:14+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 0] gossip - InetAddress 10.0.0.176 is now UP, status = UNKNOWN
2022-06-17T06:53:25+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4  !WARNING | scylla[7602]:  [shard 0] gossip - failure_detector_loop: Send echo to node 10.0.0.176, status = failed: seastar::rpc::timeout_error (rpc call timed out)
2022-06-17T06:53:25+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 0] gossip - failure_detector_loop: Mark node 10.0.0.176 as DOWN
2022-06-17T06:53:25+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 0] gossip - InetAddress 10.0.0.176 is now DOWN, status = UNKNOWN
2022-06-17T06:53:32+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 0] gossip - FatClient 10.0.0.176 has been silent for 30000ms, removing from gossip
2022-06-17T06:54:05+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4      !ERR | scylla[7602]:  [shard 0] rpc - client 10.0.0.176:7000: client connection dropped: read: Connection reset by peer
2022-06-17T06:54:32+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 0] gossip - 60000 ms elapsed, 10.0.0.176 gossip quarantine over
2022-06-17T07:39:01+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 3] rpc - client 171.67.71.40:36249: wrong protocol magic: 1603010075010000
2022-06-17T07:39:01+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4      !ERR | scylla[7602]:  [shard 3] rpc - client 171.67.71.40:36249: server connection dropped: connection is closed
2022-06-17T07:39:01+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 4] rpc - client 171.67.71.40:36250: wrong protocol magic: 474554202f204854
2022-06-17T07:39:01+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4      !ERR | scylla[7602]:  [shard 4] rpc - client 171.67.71.40:36250: server connection dropped: connection is closed
2022-06-17T08:16:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4     !INFO | scylla[7602]:  [shard 4] rpc - client 46.19.137.50:60918: wrong protocol magic: 474554202f204854
2022-06-17T08:16:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-4      !ERR | scylla[7602]:  [shard 4] rpc - client 46.19.137.50:60918: server connection dropped: connection is closed

node1

2022-06-17T00:45:19+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 0] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.959 MiB preemptibly
2022-06-17T00:45:19+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - reclamation rate = 500.008 MiB/s
2022-06-17T00:45:19+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - compacted segments: 5
2022-06-17T00:45:19+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - compacted memory: 0.170 MiB
2022-06-17T00:45:21+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 0] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.713 MiB preemptibly
2022-06-17T00:45:21+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - reclamation rate = 468.758 MiB/s
2022-06-17T00:45:21+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - compacted segments: 3
2022-06-17T00:45:21+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - compacted memory: 0.032 MiB
2022-06-17T00:45:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 6] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.760 MiB preemptibly
2022-06-17T00:45:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - reclamation rate = 484.383 MiB/s
2022-06-17T00:45:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - compacted segments: 4
2022-06-17T00:45:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - compacted memory: 0.050 MiB
2022-06-17T00:45:29+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] compaction - [Compact keyspace1.standard1 bb090ec0-edd6-11ec-9048-05cf8fa7abd2] Compacted 2 sstables to [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-595-big-Data.db:level=0]. 1GB to 1GB (~95% of original) in 23072ms = 52MB/s. ~1108736 total partitions merged to 1060879.
2022-06-17T00:45:29+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] compaction - [Compact keyspace1.standard1 c8ca5410-edd6-11ec-9048-05cf8fa7abd2] Compacting [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-574-big-Data.db:level=0:origin=compaction,/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-595-big-Data.db:level=0:origin=compaction]
2022-06-17T00:45:42+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] compaction - [Compact keyspace1.standard1 bbd9cc40-edd6-11ec-aaa7-05ce8fa7abd2] Compacted 2 sstables to [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-639-big-Data.db:level=0]. 2GB to 2GB (~91% of original) in 34981ms = 63MB/s. ~2114304 total partitions merged to 1941792.
2022-06-17T00:45:42+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] compaction - [Compact keyspace1.standard1 d0b43ce0-edd6-11ec-aaa7-05ce8fa7abd2] Compacting [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-639-big-Data.db:level=0:origin=compaction,/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-590-big-Data.db:level=0:origin=compaction]
2022-06-17T00:46:01+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] gossip - InetAddress 10.0.2.211 is now UP, status = UNKNOWN
2022-06-17T00:46:06+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] compaction - [Compact keyspace1.standard1 c8ca5410-edd6-11ec-9048-05cf8fa7abd2] Compacted 2 sstables to [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-602-big-Data.db:level=0]. 2GB to 2GB (~91% of original) in 37364ms = 59MB/s. ~2120064 total partitions merged to 1946518.
2022-06-17T00:46:45+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] compaction - [Compact keyspace1.standard1 d0b43ce0-edd6-11ec-aaa7-05ce8fa7abd2] Compacted 2 sstables to [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-646-big-Data.db:level=0]. 4GB to 3GB (~85% of original) in 62984ms = 59MB/s. ~3888000 total partitions merged to 3321121.
2022-06-17T00:46:45+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] compaction - [Compact keyspace1.standard1 f63fe6d0-edd6-11ec-aaa7-05ce8fa7abd2] Compacting [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-646-big-Data.db:level=0:origin=compaction,/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-541-big-Data.db:level=0:origin=compaction]
2022-06-17T00:47:50+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] storage_service - replace[5495306b-c040-4a25-a4b6-95cf8e464178]: Added replacing_node=10.0.2.211 to replace existing_node=10.0.3.113, coordinator=10.0.2.211
2022-06-17T00:47:50+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] token_metadata - Added node 10.0.2.211 as pending replacing endpoint which replaces existing node 10.0.3.113
2022-06-17T00:49:00+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] compaction - [Compact keyspace1.standard1 f63fe6d0-edd6-11ec-aaa7-05ce8fa7abd2] Compacted 2 sstables to [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-653-big-Data.db:level=0]. 8GB to 7GB (~90% of original) in 135293ms = 58MB/s. ~7772544 total partitions merged to 7025185.
2022-06-17T00:49:25+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 6] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.873 MiB preemptibly
2022-06-17T00:49:25+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - reclamation rate = 468.758 MiB/s
2022-06-17T00:49:25+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - evicted memory: 0.140 MiB
2022-06-17T00:49:25+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - compacted segments: 3
2022-06-17T00:49:25+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - compacted memory: 0.285 MiB
2022-06-17T00:49:26+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 0] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.576 MiB preemptibly
2022-06-17T00:49:26+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - reclamation rate = 437.507 MiB/s
2022-06-17T00:49:26+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - evicted memory: 0.077 MiB
2022-06-17T00:49:26+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - compacted segments: 4
2022-06-17T00:49:26+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - compacted memory: 0.360 MiB
2022-06-17T00:49:26+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 1] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.236 MiB preemptibly
2022-06-17T00:49:26+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - reclamation rate = 15.625 MiB/s
2022-06-17T00:49:26+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - evicted memory: 0.192 MiB
2022-06-17T00:49:26+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - compacted segments: 1
2022-06-17T00:49:26+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - compacted memory: 0.125 MiB
2022-06-17T00:49:27+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 1] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.861 MiB preemptibly
2022-06-17T00:49:27+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - reclamation rate = 453.132 MiB/s
2022-06-17T00:49:27+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - evicted memory: 0.222 MiB
2022-06-17T00:49:27+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 4] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.244 MiB preemptibly
2022-06-17T00:49:27+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] lsa-timing - - reclamation rate = 15.625 MiB/s
2022-06-17T00:49:27+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] lsa-timing - - compacted segments: 5
2022-06-17T00:49:27+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] lsa-timing - - compacted memory: 0.386 MiB
2022-06-17T00:49:28+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 6] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.748 MiB preemptibly
2022-06-17T00:49:28+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - reclamation rate = 468.758 MiB/s
2022-06-17T00:49:28+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - compacted segments: 2
2022-06-17T00:49:28+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - compacted memory: 0.196 MiB
2022-06-17T00:49:30+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 5] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.795 MiB preemptibly
2022-06-17T00:49:30+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - reclamation rate = 453.132 MiB/s
2022-06-17T00:49:30+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - evicted memory: 0.237 MiB
2022-06-17T00:49:31+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 6] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.748 MiB preemptibly
2022-06-17T00:49:31+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - reclamation rate = 468.757 MiB/s
2022-06-17T00:49:31+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - compacted segments: 4
2022-06-17T00:49:31+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - compacted memory: 0.264 MiB
2022-06-17T00:49:32+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 5] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.670 MiB preemptibly
2022-06-17T00:49:32+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - reclamation rate = 453.132 MiB/s
2022-06-17T00:49:32+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - compacted segments: 2
2022-06-17T00:49:32+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - compacted memory: 0.151 MiB
2022-06-17T00:49:32+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 2] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.287 MiB preemptibly
2022-06-17T00:49:32+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - reclamation rate = 15.625 MiB/s
2022-06-17T00:49:32+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - compacted segments: 4
2022-06-17T00:49:32+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - compacted memory: 0.218 MiB
2022-06-17T00:49:32+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 1] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.361 MiB preemptibly
2022-06-17T00:49:32+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - reclamation rate = 15.625 MiB/s
2022-06-17T00:49:32+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - compacted segments: 5
2022-06-17T00:49:32+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - compacted memory: 0.436 MiB
2022-06-17T00:52:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 3] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.267 MiB preemptibly
2022-06-17T00:52:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 3] lsa-timing - - reclamation rate = 15.625 MiB/s
2022-06-17T00:52:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 3] lsa-timing - - evicted memory: 0.233 MiB
2022-06-17T00:52:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 3] lsa-timing - - compacted segments: 2
2022-06-17T00:52:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 3] lsa-timing - - compacted memory: 0.093 MiB
2022-06-17T00:53:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 0] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.709 MiB preemptibly
2022-06-17T00:53:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - reclamation rate = 468.757 MiB/s
2022-06-17T00:53:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - compacted segments: 2
2022-06-17T00:53:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - compacted memory: 0.192 MiB
2022-06-17T00:53:38+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 2] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.775 MiB preemptibly
2022-06-17T00:53:38+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - reclamation rate = 453.132 MiB/s
2022-06-17T00:53:38+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - evicted memory: 0.126 MiB
2022-06-17T00:53:38+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 2] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.650 MiB preemptibly
2022-06-17T00:53:38+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - reclamation rate = 453.132 MiB/s
2022-06-17T00:53:38+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - evicted memory: 0.071 MiB
2022-06-17T00:53:38+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 2] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.775 MiB preemptibly
2022-06-17T00:53:38+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - reclamation rate = 453.132 MiB/s
2022-06-17T00:53:38+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - evicted memory: 0.037 MiB
2022-06-17T00:53:42+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 4] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.158 MiB preemptibly
2022-06-17T00:53:42+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] lsa-timing - - reclamation rate = 15.625 MiB/s
2022-06-17T00:53:42+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] lsa-timing - - compacted segments: 5
2022-06-17T00:53:42+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] lsa-timing - - compacted memory: 0.346 MiB
2022-06-17T00:53:42+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 3] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.767 MiB preemptibly
2022-06-17T00:53:42+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 3] lsa-timing - - reclamation rate = 468.758 MiB/s
2022-06-17T00:53:42+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 3] lsa-timing - - evicted memory: 0.262 MiB
2022-06-17T00:53:42+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 3] lsa-timing - - compacted segments: 2
2022-06-17T00:53:42+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 3] lsa-timing - - compacted memory: 0.095 MiB
2022-06-17T00:54:29+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] compaction - [Compact keyspace1.standard1 0afa56e0-edd8-11ec-9914-05cc8fa7abd2] Compacting [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-648-big-Data.db:level=0:origin=memtable,/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-655-big-Data.db:level=0:origin=memtable]
2022-06-17T00:54:41+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] compaction - [Compact keyspace1.standard1 11ba65b0-edd8-11ec-b2cc-05cd8fa7abd2] Compacting [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-664-big-Data.db:level=0:origin=memtable,/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-657-big-Data.db:level=0:origin=memtable]
2022-06-17T00:54:50+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] compaction - [Compact keyspace1.standard1 172d8220-edd8-11ec-b4ae-05d18fa7abd2] Compacting [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-603-big-Data.db:level=0:origin=memtable,/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-610-big-Data.db:level=0:origin=memtable]
2022-06-17T00:54:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] compaction - [Compact keyspace1.standard1 0afa56e0-edd8-11ec-9914-05cc8fa7abd2] Compacted 2 sstables to [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-662-big-Data.db:level=0]. 1GB to 1GB (~95% of original) in 22474ms = 53MB/s. ~1113088 total partitions merged to 1064497.
2022-06-17T00:54:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] compaction - [Compact keyspace1.standard1 186083e0-edd8-11ec-9914-05cc8fa7abd2] Compacting [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-641-big-Data.db:level=0:origin=compaction,/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-662-big-Data.db:level=0:origin=compaction]
2022-06-17T00:54:58+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 3] compaction - [Compact keyspace1.standard1 1be1e270-edd8-11ec-9c9f-05cb8fa7abd2] Compacting [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-654-big-Data.db:level=0:origin=memtable,/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-647-big-Data.db:level=0:origin=memtable]
2022-06-17T00:55:00+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] compaction - [Compact keyspace1.standard1 11ba65b0-edd8-11ec-b2cc-05cd8fa7abd2] Compacted 2 sstables to [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-671-big-Data.db:level=0]. 1GB to 1GB (~95% of original) in 19764ms = 61MB/s. ~1119616 total partitions merged to 1070671.
2022-06-17T00:55:14+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] compaction - [Compact keyspace1.standard1 172d8220-edd8-11ec-b4ae-05d18fa7abd2] Compacted 2 sstables to [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-617-big-Data.db:level=0]. 1GB to 1GB (~95% of original) in 24253ms = 49MB/s. ~1111040 total partitions merged to 1063055.
2022-06-17T00:55:14+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] compaction - [Compact keyspace1.standard1 25a34a60-edd8-11ec-b4ae-05d18fa7abd2] Compacting [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-596-big-Data.db:level=0:origin=compaction,/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-617-big-Data.db:level=0:origin=compaction]
2022-06-17T00:55:21+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 3] compaction - [Compact keyspace1.standard1 1be1e270-edd8-11ec-9c9f-05cb8fa7abd2] Compacted 2 sstables to [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-661-big-Data.db:level=0]. 1GB to 1GB (~95% of original) in 23394ms = 51MB/s. ~1114240 total partitions merged to 1065867.
2022-06-17T00:55:25+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] compaction - [Compact keyspace1.standard1 2c061e00-edd8-11ec-b75c-05d08fa7abd2] Compacting [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-677-big-Data.db:level=0:origin=memtable,/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-670-big-Data.db:level=0:origin=memtable]
2022-06-17T00:55:29+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] compaction - [Compact keyspace1.standard1 186083e0-edd8-11ec-9914-05cc8fa7abd2] Compacted 2 sstables to [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-669-big-Data.db:level=0]. 2GB to 2GB (~91% of original) in 37413ms = 59MB/s. ~2124032 total partitions merged to 1950168.
2022-06-17T00:55:48+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] compaction - [Compact keyspace1.standard1 2c061e00-edd8-11ec-b75c-05d08fa7abd2] Compacted 2 sstables to [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-684-big-Data.db:level=0]. 1GB to 1GB (~95% of original) in 23720ms = 51MB/s. ~1115136 total partitions merged to 1066599.
2022-06-17T00:55:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] compaction - [Compact keyspace1.standard1 25a34a60-edd8-11ec-b4ae-05d18fa7abd2] Compacted 2 sstables to [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-624-big-Data.db:level=0]. 2GB to 2GB (~91% of original) in 37891ms = 58MB/s. ~2120064 total partitions merged to 1947697.
2022-06-17T00:55:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] compaction - [Compact keyspace1.standard1 3c39e9f0-edd8-11ec-b4ae-05d18fa7abd2] Compacting [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-575-big-Data.db:level=0:origin=compaction,/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-624-big-Data.db:level=0:origin=compaction]
2022-06-17T00:56:58+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] compaction - [Compact keyspace1.standard1 3c39e9f0-edd8-11ec-b4ae-05d18fa7abd2] Compacted 2 sstables to [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-631-big-Data.db:level=0]. 4GB to 3GB (~85% of original) in 66453ms = 56MB/s. ~3888640 total partitions merged to 3323417.
2022-06-17T00:56:58+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] compaction - [Compact keyspace1.standard1 63d6c0a0-edd8-11ec-b4ae-05d18fa7abd2] Compacting [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-631-big-Data.db:level=0:origin=compaction,/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-526-big-Data.db:level=0:origin=compaction]
2022-06-17T00:57:49+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 1] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.779 MiB preemptibly
2022-06-17T00:57:49+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - reclamation rate = 468.757 MiB/s
2022-06-17T00:57:49+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - compacted segments: 4
2022-06-17T00:57:49+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - compacted memory: 0.344 MiB
2022-06-17T00:57:51+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 1] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.549 MiB preemptibly
2022-06-17T00:57:51+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - reclamation rate = 453.132 MiB/s
2022-06-17T00:57:51+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - compacted segments: 4
2022-06-17T00:57:51+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - compacted memory: 0.332 MiB
2022-06-17T00:57:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 2] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.818 MiB preemptibly
2022-06-17T00:57:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - reclamation rate = 453.132 MiB/s
2022-06-17T00:57:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - evicted memory: 0.313 MiB
2022-06-17T00:57:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - compacted segments: 1
2022-06-17T00:57:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - compacted memory: 0.032 MiB
2022-06-17T00:57:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 1] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.931 MiB preemptibly
2022-06-17T00:57:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - reclamation rate = 468.757 MiB/s
2022-06-17T00:57:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - compacted segments: 5
2022-06-17T00:57:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - compacted memory: 0.385 MiB
2022-06-17T00:57:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 2] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.818 MiB preemptibly
2022-06-17T00:57:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - reclamation rate = 453.132 MiB/s
2022-06-17T00:57:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - evicted memory: 0.274 MiB
2022-06-17T00:57:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 1] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.931 MiB preemptibly
2022-06-17T00:57:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - reclamation rate = 468.757 MiB/s
2022-06-17T00:57:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - compacted segments: 5
2022-06-17T00:57:52+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - compacted memory: 0.338 MiB
2022-06-17T00:57:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 2] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.943 MiB preemptibly
2022-06-17T00:57:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - reclamation rate = 468.757 MiB/s
2022-06-17T00:57:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - compacted segments: 3
2022-06-17T00:57:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - compacted memory: 0.183 MiB
2022-06-17T00:57:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 1] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.818 MiB preemptibly
2022-06-17T00:57:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - reclamation rate = 468.757 MiB/s
2022-06-17T00:57:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - compacted segments: 4
2022-06-17T00:57:55+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - compacted memory: 0.357 MiB
2022-06-17T00:59:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] compaction - [Compact keyspace1.standard1 63d6c0a0-edd8-11ec-b4ae-05d18fa7abd2] Compacted 2 sstables to [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-638-big-Data.db:level=0]. 8GB to 7GB (~88% of original) in 132584ms = 57MB/s. ~7634176 total partitions merged to 6768773.
2022-06-17T00:59:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] compaction - [Compact keyspace1.standard1 b2de6180-edd8-11ec-b4ae-05d18fa7abd2] Compacting [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-638-big-Data.db:level=0:origin=compaction,/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-491-big-Data.db:level=0:origin=compaction]
2022-06-17T00:59:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 1] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.125 MiB non-preemptibly
2022-06-17T00:59:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - reserved segments: 30
2022-06-17T00:59:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - reclamation rate = 468.759 MiB/s
2022-06-17T00:59:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - compacted segments: 79
2022-06-17T00:59:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - compacted memory: 6.185 MiB
2022-06-17T00:59:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 1] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.125 MiB non-preemptibly
2022-06-17T00:59:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - reserved segments: 30
2022-06-17T00:59:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - reclamation rate = 281.256 MiB/s
2022-06-17T00:59:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - compacted segments: 48
2022-06-17T00:59:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - compacted memory: 3.838 MiB
2022-06-17T01:01:18+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 1] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.631 MiB preemptibly
2022-06-17T01:01:18+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - reclamation rate = 468.759 MiB/s
2022-06-17T01:01:18+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - compacted segments: 2
2022-06-17T01:01:18+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] lsa-timing - - compacted memory: 0.164 MiB
2022-06-17T01:01:18+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 4] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.853 MiB preemptibly
2022-06-17T01:01:18+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] lsa-timing - - reclamation rate = 468.759 MiB/s
2022-06-17T01:01:18+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] lsa-timing - - compacted segments: 3
2022-06-17T01:01:18+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] lsa-timing - - compacted memory: 0.202 MiB
2022-06-17T01:01:18+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 6] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.185 MiB preemptibly
2022-06-17T01:01:18+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - reclamation rate = 15.625 MiB/s
2022-06-17T01:01:18+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - evicted memory: 0.187 MiB
2022-06-17T01:01:18+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - compacted segments: 3
2022-06-17T01:01:18+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - compacted memory: 0.251 MiB
2022-06-17T01:01:21+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 6] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.810 MiB preemptibly
2022-06-17T01:01:21+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - reclamation rate = 484.384 MiB/s
2022-06-17T01:01:21+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - compacted segments: 4
2022-06-17T01:01:21+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - compacted memory: 0.332 MiB
2022-06-17T01:01:21+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 3] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.123 MiB preemptibly
2022-06-17T01:01:21+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 3] lsa-timing - - reclamation rate = 15.625 MiB/s
2022-06-17T01:01:21+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 3] lsa-timing - - evicted memory: 0.241 MiB
2022-06-17T01:01:21+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 3] lsa-timing - - compacted segments: 3
2022-06-17T01:01:21+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 3] lsa-timing - - compacted memory: 0.119 MiB
2022-06-17T01:01:21+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 3] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.873 MiB preemptibly
2022-06-17T01:01:21+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 3] lsa-timing - - reclamation rate = 453.134 MiB/s
2022-06-17T01:01:21+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 3] lsa-timing - - evicted memory: 0.337 MiB
2022-06-17T01:01:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 5] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.635 MiB preemptibly
2022-06-17T01:01:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - reclamation rate = 468.759 MiB/s
2022-06-17T01:01:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - evicted memory: 0.131 MiB
2022-06-17T01:01:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - compacted segments: 3
2022-06-17T01:01:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - compacted memory: 0.223 MiB
2022-06-17T01:01:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 0] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.248 MiB preemptibly
2022-06-17T01:01:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - reclamation rate = 15.625 MiB/s
2022-06-17T01:01:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - evicted memory: 0.209 MiB
2022-06-17T01:01:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - compacted segments: 3
2022-06-17T01:01:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - compacted memory: 0.209 MiB
2022-06-17T01:01:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 5] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.635 MiB preemptibly
2022-06-17T01:01:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - reclamation rate = 468.759 MiB/s
2022-06-17T01:01:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - evicted memory: 0.135 MiB
2022-06-17T01:01:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - compacted segments: 3
2022-06-17T01:01:22+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - compacted memory: 0.173 MiB
2022-06-17T01:01:23+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 5] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.885 MiB preemptibly
2022-06-17T01:01:23+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - reclamation rate = 468.759 MiB/s
2022-06-17T01:01:23+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - evicted memory: 0.240 MiB
2022-06-17T01:01:23+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - compacted segments: 1
2022-06-17T01:01:23+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - compacted memory: 0.073 MiB
2022-06-17T01:01:23+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 5] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.010 MiB preemptibly
2022-06-17T01:01:23+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - reclamation rate = 15.625 MiB/s
2022-06-17T01:01:23+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - evicted memory: 0.128 MiB
2022-06-17T01:01:23+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - compacted segments: 3
2022-06-17T01:01:23+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - compacted memory: 0.231 MiB
2022-06-17T01:01:23+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 4] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.103 MiB preemptibly
2022-06-17T01:01:23+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] lsa-timing - - reclamation rate = 15.625 MiB/s
2022-06-17T01:01:23+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] lsa-timing - - evicted memory: 0.223 MiB
2022-06-17T01:01:23+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] lsa-timing - - compacted segments: 3
2022-06-17T01:01:23+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] lsa-timing - - compacted memory: 0.203 MiB
2022-06-17T01:01:23+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 2] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.693 MiB preemptibly
2022-06-17T01:01:23+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - reclamation rate = 453.134 MiB/s
2022-06-17T01:01:23+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - compacted segments: 1
2022-06-17T01:01:23+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] lsa-timing - - compacted memory: 0.070 MiB
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 6] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.060 MiB preemptibly
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - reclamation rate = 15.625 MiB/s
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - compacted segments: 4
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 6] lsa-timing - - compacted memory: 0.329 MiB
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 4] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.728 MiB preemptibly
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] lsa-timing - - reclamation rate = 46.876 MiB/s
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] lsa-timing - - compacted segments: 3
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] lsa-timing - - compacted memory: 0.221 MiB
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 3] lsa-timing - Reclamation cycle took 7999 us, trying to release 0.248 MiB preemptibly
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 3] lsa-timing - - reclamation rate = 15.625 MiB/s
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 3] lsa-timing - - compacted segments: 5
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 3] lsa-timing - - compacted memory: 0.355 MiB
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 5] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.760 MiB preemptibly
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - reclamation rate = 453.134 MiB/s
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] lsa-timing - - evicted memory: 0.172 MiB
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 0] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.748 MiB preemptibly
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - reclamation rate = 468.759 MiB/s
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - compacted segments: 3
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - compacted memory: 0.202 MiB
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 0] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.873 MiB preemptibly
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - reclamation rate = 468.759 MiB/s
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - evicted memory: 0.149 MiB
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - compacted segments: 3
2022-06-17T01:01:24+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] lsa-timing - - compacted memory: 0.129 MiB
2022-06-17T01:03:37+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] compaction - [Compact keyspace1.standard1 b2de6180-edd8-11ec-b4ae-05d18fa7abd2] Compacted 2 sstables to [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-645-big-Data.db:level=0]. 16GB to 15GB (~92% of original) in 266477ms = 58MB/s. ~14815872 total partitions merged to 13640840.
2022-06-17T01:04:20+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] compaction - [Compact keyspace1.standard1 6accb710-edd9-11ec-aaa7-05ce8fa7abd2] Compacting [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-667-big-Data.db:level=0:origin=memtable,/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-660-big-Data.db:level=0:origin=memtable]
2022-06-17T01:04:36+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] compaction - [Compact keyspace1.standard1 746e13e0-edd9-11ec-9048-05cf8fa7abd2] Compacting [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-616-big-Data.db:level=0:origin=memtable,/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-609-big-Data.db:level=0:origin=memtable]
2022-06-17T01:04:42+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 2] compaction - [Compact keyspace1.standard1 6accb710-edd9-11ec-aaa7-05ce8fa7abd2] Compacted 2 sstables to [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-674-big-Data.db:level=0]. 1GB to 1GB (~95% of original) in 22985ms = 52MB/s. ~1119616 total partitions merged to 1071061.
2022-06-17T01:04:59+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 4] lsa-timing - Reclamation cycle took 7999 us, trying to release 3.885 MiB preemptibly
2022-06-17T01:04:59+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] lsa-timing - - reclamation rate = 484.384 MiB/s
2022-06-17T01:04:59+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] lsa-timing - - compacted segments: 4
2022-06-17T01:04:59+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] lsa-timing - - compacted memory: 0.080 MiB
2022-06-17T01:05:00+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] compaction - [Compact keyspace1.standard1 746e13e0-edd9-11ec-9048-05cf8fa7abd2] Compacted 2 sstables to [/var/lib/scylla/data/keyspace1/standard1-35720a60edc111ec9759e9b7bc4501c5/me-623-big-Data.db:level=0]. 1GB to 1GB (~95% of original) in 24199ms = 50MB/s. ~1115520 total partitions merged to 1066831.
2022-06-17T01:31:02+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] rpc - client 45.61.187.144:54222: wrong protocol magic: 474554202f204854
2022-06-17T01:31:02+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1      !ERR | scylla[7789]:  [shard 0] rpc - client 45.61.187.144:54222: server connection dropped: connection is closed
2022-06-17T02:03:10+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 5] rpc - client 107.189.8.198:35838: wrong protocol magic: 474554202f204854
2022-06-17T02:03:10+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1      !ERR | scylla[7789]:  [shard 5] rpc - client 107.189.8.198:35838: server connection dropped: connection is closed
2022-06-17T02:48:33+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] rpc - client 107.189.8.198:40492: wrong protocol magic: 474554202f204854
2022-06-17T02:48:33+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1      !ERR | scylla[7789]:  [shard 4] rpc - client 107.189.8.198:40492: server connection dropped: connection is closed
2022-06-17T04:01:37+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 3] rpc - client 45.61.187.144:42248: wrong protocol magic: 474554202f204854
2022-06-17T04:01:37+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1      !ERR | scylla[7789]:  [shard 3] rpc - client 45.61.187.144:42248: server connection dropped: connection is closed
2022-06-17T06:51:11+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] gossip - InetAddress 10.0.0.176 is now UP, status = UNKNOWN
2022-06-17T06:53:00+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 0] storage_service - node_ops_cmd_check: Node 10.0.1.123 rejected node_ops_cmd=replace_prepare from node=10.0.0.176 with ops_uuid=258f344a-6fb9-4661-bfbe-454824e80be0, pending_node_ops={5495306b-c040-4a25-a4b6-95cf8e464178}, pending node ops is in progress
2022-06-17T06:53:00+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 0] storage_service - node_ops_cmd_check: Node 10.0.1.123 rejected node_ops_cmd=replace_abort from node=10.0.0.176 with ops_uuid=258f344a-6fb9-4661-bfbe-454824e80be0, pending_node_ops={5495306b-c040-4a25-a4b6-95cf8e464178}, pending node ops is in progress
2022-06-17T06:53:25+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1  !WARNING | scylla[7789]:  [shard 0] gossip - failure_detector_loop: Send echo to node 10.0.0.176, status = failed: seastar::rpc::timeout_error (rpc call timed out)
2022-06-17T06:53:25+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] gossip - failure_detector_loop: Mark node 10.0.0.176 as DOWN
2022-06-17T06:53:25+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] gossip - InetAddress 10.0.0.176 is now DOWN, status = UNKNOWN
2022-06-17T06:53:32+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] gossip - FatClient 10.0.0.176 has been silent for 30000ms, removing from gossip
2022-06-17T06:54:05+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1      !ERR | scylla[7789]:  [shard 0] rpc - client 10.0.0.176:7000: client connection dropped: read: Connection reset by peer
2022-06-17T06:54:32+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 0] gossip - 60000 ms elapsed, 10.0.0.176 gossip quarantine over
2022-06-17T08:28:43+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 1] rpc - client 46.19.137.50:41952: wrong protocol magic: 474554202f204854
2022-06-17T08:28:43+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1      !ERR | scylla[7789]:  [shard 1] rpc - client 46.19.137.50:41952: server connection dropped: connection is closed
2022-06-17T08:37:48+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1     !INFO | scylla[7789]:  [shard 4] rpc - client 107.189.8.198:52546: wrong protocol magic: 474554202f204854
2022-06-17T08:37:48+00:00 perf-latency-nemesis-ubuntu-db-node-fb356fc1-1      !ERR | scylla[7789]:  [shard 4] rpc - client 107.189.8.198:52546: server connection dropped: connection is closed

@asias
Copy link
Contributor

asias commented Jun 20, 2022

Utilization went to zero on all nodes around 01:00

image

@asias
Copy link
Contributor

asias commented Jun 20, 2022

Both aio read and aio writes went to zero too after ~01:00

image

@asias
Copy link
Contributor

asias commented Jun 20, 2022

scylla_reactor_tasks_processed did not change after ~01:00
image

@slivne
Copy link
Contributor

slivne commented Jun 22, 2022

@aleksbykov will provide a reproducer job - and we will bisect in attempt to find the problematic commit

@roydahan
Copy link

roydahan commented Jun 22, 2022

Running two "official" runs with scylla versions we have AMIs from to limit the gap:

5.1.dev-0.20220531.02608bec9d09 - ami-077042cdba3476ec5 - job #211

5.1.dev-0.20220602.adda43edc75b - ami-06e2c0680190bf550 - job #210

@aleksbykov
Copy link
Contributor Author

Issue already reproduced with ami from 2022-05-31 after 3 hours 3 minutes.
Live monitor. http://18.208.201.73:3000/d/OS-master/scylla-master-perf-regression-latency-250gb-with-nemesis-scylla-per-server-metrics-nemesis-master?orgId=1&var-by=instance&var-cluster=&var-dc=All&var-node=All&var-shard=All&var-sct_tags=InfoEvent&var-sct_tags=DisruptionEvent
Job failed, because c-s command terminated due a lot of errors there is no quorum.
Issue also reproduce for ami from 2022-06-02.
Monitoring: http://3.235.8.88:3000/d/overview-master/scylla-master-perf-regression-latency-250gb-with-nemesis-scylla-per-server-metrics-nemesis-master?orgId=1&var-by=instance&var-cluster=&var-dc=All&var-node=All&var-shard=All&var-sct_tags=InfoEvent&var-sct_tags=DisruptionEvent

Here bootstrap looks stacked for node. CLuster is still alive:

| perf-latency-nemesis-perf-v12-db-node-a4ff72ed-1      | us-east-1a | 3.91.206.238   | a4ff72ed-c0e5-4531-a277-11b9f96fe1e1 |
| perf-latency-nemesis-perf-v12-db-node-a4ff72ed-3      | us-east-1a | 3.238.52.92    | a4ff72ed-c0e5-4531-a277-11b9f96fe1e1 |
| perf-latency-nemesis-perf-v12-monitor-node-a4ff72ed-1 | us-east-1a | 3.235.8.88     | a4ff72ed-c0e5-4531-a277-11b9f96fe1e1 |
| perf-latency-nemesis-perf-v12-db-node-a4ff72ed-4      | us-east-1a | 44.201.55.174  | a4ff72ed-c0e5-4531-a277-11b9f96fe1e1 |

@aleksbykov
Copy link
Contributor Author

the officail job was passed with:
scylla version: 5.1.dev-0.20220530.78f81171ba84 with build-id 00003a841a52d03373dd428882fd622de96fa61f
ami (us-east-1): ami-043ed8d4058d17bb2
job url: https://jenkins.scylladb.com/view/master/job/scylla-master/job/scylla-master-perf-regression-latency-250gb-with-nemesis/212/

@roydahan
Copy link

Ok, so the suspected commit is one of these:

git lg 78f8117..02608be

  • 02608be - Update tools/java submodule (3 weeks ago) <Botond Dénes>
  • 660921e - Merge 'Two improvements to configure.py' from Nadav Har'El (3 weeks ago) <Botond Dénes>
    |
    | * 84e1fa0 - configure.py: make build.ninja the same every time (3 weeks ago) <Nadav Har'El>
    | * 8db9e62 - configure.py: don't delete build.ninja when rebuild is interrupted (3 weeks ago) <Nadav Har'El>
  • e85bd37 - Update seastar submodule (3 weeks ago) <Nadav Har'El>
  • 7f28378 - system_keyspace: Save coroutine's captured variable on stack (3 weeks ago)
  • 3a943b2 - sstables: validate_checksums(): add chunk index to error message (3 weeks ago) <Botond Dénes>

@roydahan
Copy link

@slivne / @avikivity do you see any immediate suspect?

@avikivity
Copy link
Member

e85bd37 is most suspect since it contains the most changes

@asias
Copy link
Contributor

asias commented Jun 24, 2022

The following two merges look suspectful from e85bd37

Merge "io: Enlighten queued_request" from Pavel E
Merge "Per-class IO bandwidth limits" from Pavel E

commit e85bd37c6e5c85f8b61484c89f7a5afe59de8836
Author: Nadav Har'El <nyh@scylladb.com>
Date:   Sun May 29 15:16:16 2022 +0300

    Update seastar submodule
    
    * seastar 96bb3a1b8...2be9677d6 (37):
      > Merge 'stream_range_as_array: always close output stream' from Benny Halevy Fixes #10592
      > net/api: add "server_socket::is_listening()"
      > src/net/proxy: remove unused variable
      > coroutine: parallel_for_each: relax contraints
      > native-stack: do not use 0 as ip address if !_dhcp
      > coroutine: fix a typo in comment
      > std-coroutine: include for LLVM-14
      > tutorial: use non-variadic version of when_all_succeed()
      > scripts: Fix build.sh to use new --c++-standard config option
      > core/thread: initialize work::pr and work::th explicitly
      > util/log-impl: remove "const" qualifier in return type
      > map_reduce: remove redundant move() in return statement
      > util: mark unused parameter with [[maybe_unused]]
      > drop unused parameters
      > build: use "20" for the default CMAKE_CXX_STANDARD
      > build: make CMAKE_CXX_STANDARD a string
      > utils: log: don't crash on allocation failure while extending log buffer
      > tests: unix_domain_test: fix thread/future confusion in client_round()
      > compat: do not use std::source_location if it is broken
      > build: use CMAKE_CXX_STANDARD instead of Seastar_CXX_DIALECT
      > Merge 'Add hello-world demo from tutorial' from Pavel
      > rpc_tester: Put client/server sides into correct sched groups
      > reactor_backend: Use _r reference, not engine() method
      > future.hh: #include std-compat.hh for SEASTAR_COROUTINES_ENABLED
      > Merge "Add more CPU-hog facilities to RPC-tester" from Pavel E
      > Merge "io: Enlighten queued_request" from Pavel E
      > Correct swapped AIO detection/setup calls
      > sharded: De-duplicate map-reduce overloads
      > file: don't trample on xfs flags when setting xfs size hint
      > Merge "Per-class IO bandwidth limits" from Pavel E
      > Merge 'sstring: fix format and optimize the performance of sstring::find().' from Jianyong Chen
      > reactor_backend: Mark reactor_backend_aio::poll() private
      > scripts/build.sh: Mind if not running on a terminal
      > test, rpc: Don't work with large buffers
      > test, futures: Don't expect ready future to resolve immediately
      > source_location compatibility: Fix an unused private field error when treat warning as errors
      > file: Remove try-catch around noexcept calls

@raphaelsc
Copy link
Member

The following two merges look suspectful from e85bd37

Merge "io: Enlighten queued_request" from Pavel E
Merge "Per-class IO bandwidth limits" from Pavel E

When investigating stuck resharding problem #10743, I realized we have a problem in the producer, which reads data from input file.

Now comes the similarity, resharding also uses streaming (maintenance) io group, so I wonder if it's hitting the same issue, as the effects are very similar to the ones described here. I suspected changes in I/O queue could be causing this.

@bhalevy
Copy link
Member

bhalevy commented Jun 26, 2022

#10814 (comment)

seastar update e85bd37 includes
scylladb/seastar@f8d7739 Merge "Per-class IO bandwidth limits" from Pavel E

which is a suspect also for #10743

@slivne
Copy link
Contributor

slivne commented Jun 26, 2022

OK - so we will create builds before this and with this and validate this is the source.

@slivne
Copy link
Contributor

slivne commented Jun 26, 2022

@bhalevy create two .deb with seastar bisect one prior to that change and one with it and lets see its the source.

@bhalevy
Copy link
Member

bhalevy commented Jun 26, 2022

@roydahan @slivne I prepared the following dev packages:

gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/with-per-class-io-bw-limiter/:
     21428  2022-06-26T16:52:32Z  gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/with-per-class-io-bw-limiter/scylla-conf_5.1.dev-0.20220626.bce987b27367-1_amd64.deb
   8127436  2022-06-26T16:54:18Z  gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/with-per-class-io-bw-limiter/scylla-jmx_5.1.dev-0.20220626.bce987b27367-1_all.deb
     14248  2022-06-26T16:52:32Z  gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/with-per-class-io-bw-limiter/scylla-kernel-conf_5.1.dev-0.20220626.bce987b27367-1_amd64.deb
   4074752  2022-06-26T16:52:33Z  gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/with-per-class-io-bw-limiter/scylla-node-exporter_5.1.dev-0.20220626.bce987b27367-1_amd64.deb
  15338784  2022-06-26T16:54:22Z  gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/with-per-class-io-bw-limiter/scylla-python3_5.1.dev-0.20220626.bce987b27367-1_amd64.deb
 194326616  2022-06-26T16:53:17Z  gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/with-per-class-io-bw-limiter/scylla-server-dbg_5.1.dev-0.20220626.bce987b27367-1_amd64.deb
  41697440  2022-06-26T16:52:48Z  gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/with-per-class-io-bw-limiter/scylla-server_5.1.dev-0.20220626.bce987b27367-1_amd64.deb
  38167076  2022-06-26T16:54:24Z  gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/with-per-class-io-bw-limiter/scylla-tools-core_5.1.dev-0.20220626.bce987b27367-1_all.deb
    160684  2022-06-26T16:54:13Z  gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/with-per-class-io-bw-limiter/scylla-tools_5.1.dev-0.20220626.bce987b27367-1_all.deb
     13216  2022-06-26T16:52:32Z  gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/with-per-class-io-bw-limiter/scylla_5.1.dev-0.20220626.bce987b27367-1_amd64.deb

gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/without-per-class-io-bw-limiter/:
     21432  2022-06-26T16:37:00Z  gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/without-per-class-io-bw-limiter/scylla-conf_5.1.dev-0.20220626.655301799cce-1_amd64.deb
   8127200  2022-06-26T16:54:43Z  gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/without-per-class-io-bw-limiter/scylla-jmx_5.1.dev-0.20220626.655301799cce-1_all.deb
     14252  2022-06-26T16:37:00Z  gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/without-per-class-io-bw-limiter/scylla-kernel-conf_5.1.dev-0.20220626.655301799cce-1_amd64.deb
   4074744  2022-06-26T16:37:01Z  gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/without-per-class-io-bw-limiter/scylla-node-exporter_5.1.dev-0.20220626.655301799cce-1_amd64.deb
  15338780  2022-06-26T16:54:50Z  gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/without-per-class-io-bw-limiter/scylla-python3_5.1.dev-0.20220626.655301799cce-1_amd64.deb
 194303032  2022-06-26T16:37:45Z  gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/without-per-class-io-bw-limiter/scylla-server-dbg_5.1.dev-0.20220626.655301799cce-1_amd64.deb
  41696072  2022-06-26T16:37:37Z  gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/without-per-class-io-bw-limiter/scylla-server_5.1.dev-0.20220626.655301799cce-1_amd64.deb
  38166932  2022-06-26T16:54:54Z  gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/without-per-class-io-bw-limiter/scylla-tools-core_5.1.dev-0.20220626.655301799cce-1_all.deb
    160688  2022-06-26T16:54:41Z  gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/without-per-class-io-bw-limiter/scylla-tools_5.1.dev-0.20220626.655301799cce-1_all.deb
     13228  2022-06-26T16:37:00Z  gs://scratch.scylladb.com/bhalevy/8ba32bde-5e01-49d4-b174-11f27c3604a8/without-per-class-io-bw-limiter/scylla_5.1.dev-0.20220626.655301799cce-1_amd64.deb

@bhalevy
Copy link
Member

bhalevy commented Jun 26, 2022

@asias
Copy link
Contributor

asias commented Jun 29, 2022

Possible root cause:

[seastar-dev] [COMMIT seastar master] Merge "Handle overflow in token bucket replenisher" from Pavel E

@fgelcer
Copy link

fgelcer commented Jul 5, 2022

seems like i'm seeing something similar, with a build from last week Scylla version 5.1.dev-0.20220702.4fd289a78ca3 with build-id c283da9c1dcf5cb79aad53e1781c6a9443dece6c

what happens in my case is that during prepare of perf with nemesis test (we run it with cl=ALL) one of the nodes stop responding, and c-s retries 10 times, until it raises write operation timeout (and SCT raises a critical event and stops)...
by the charts posted above, i see some similarity of compaction and commitlog I/O queue, but i'm not sure if this is the same issue, or not.

Screenshot from 2022-07-05 22-49-57

for now i'm keeping the monitor alive, while i'm checking for other clues, also to understand if this is the same issue, or a new one:
http://3.222.116.113:3000/d/advanced-master/advanced?orgId=1&from=1656845618990&to=1656857674804

in any case, logs can be found here:
db logs
loader logs
sct logs

test_id: 076edd96-ba0a-4829-a766-f396bce77f9b

@roydahan , FYI

@fgelcer
Copy link

fgelcer commented Jul 5, 2022

and i'm seeing the same behavior, since Scylla version 5.1.dev-0.20220625.78750c2e1a45 with build-id 93b6ca8b258edda016a94430c4b109d5affd898e

its monitor is here:
http://100.24.114.172:3000/d/advanced-master/advanced?orgId=1&from=1656214110510&to=1656217623314

and the screenshot is here:

Screenshot from 2022-07-05 22-39-03

@slivne
Copy link
Contributor

slivne commented Jul 17, 2022

@fgelcer whats the current state - can we close the issue - AFAIK this was fixed

@roydahan
Copy link

Yes, the issue no longer exist since the offending commit was reverted.

@fgelcer
Copy link

fgelcer commented Jul 18, 2022

for the first in a very long time, the latency with nemesis job finished with green status:

Screenshot from 2022-07-18 08-56-34 (copy)

Screenshot from 2022-07-18 08-56-34

@fgelcer fgelcer closed this as completed Jul 18, 2022
@fgelcer
Copy link

fgelcer commented Jul 18, 2022

just hope the culprit will contain the fix, and the issue is not exactly fixed, but it was only reverted from master

@DoronArazii DoronArazii modified the milestones: 5.1, 5.2 Nov 8, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

10 participants