One of the nodes fails with `No space left on device` during manager-related nemeses in 24-hour Cloud longevity test

[ilya-rarov]

Issue description

• This issue is a regression.
• It is unknown if this issue is a regression.

I am not 100% certain this problem is caused by the manager, but it seems in all the occurrences it happened while one of the manager's tasks was running (maybe this is just a coincidence though).
If you think it has nothing to do with the manager please move this issue to a different repo (I guess - to scylla-enteprise)

In the problematic longevity build we created a new Cloud cluster in Staging and triggered the following nemeses on it:

1. 2023-08-04 08:17:20 - 2023-08-04 08:52:20 - disrupt_rolling_restart_cluster
2. 2023-08-04 09:23:01 - 2023-08-04 23:34:46 - disrupt_mgmt_backup

In parallel the load with the following config was running:

prepare_write_cmd:
  - "cassandra-stress write cl=QUORUM n=10485760 -schema 'replication(factor=3) compaction(strategy=SizeTieredCompactionStrategy)' -port jmx=6868 -mode cql3 native -rate threads=30 -pop seq=1..10485760 -col 'n=FIXED(10) size=FIXED(512)' -log interval=5"

stress_cmd:
  - "cassandra-stress write cl=QUORUM duration=1400m -schema 'replication(factor=3) compaction (strategy=SizeTieredCompactionStrategy)' -port jmx=6868 -mode cql3 native -rate threads=10 -pop seq=1..10485760 -col 'n=FIXED(10) size=FIXED(512)' -log interval=5"
  - "cassandra-stress read  cl=QUORUM duration=1400m -schema 'replication(factor=3) compaction (strategy=SizeTieredCompactionStrategy)' -port jmx=6868 -mode cql3 native -rate threads=10 -pop seq=1..10485760 -col 'n=FIXED(10) size=FIXED(512)' -log interval=5"

During the disrupt_mgmt_backup nemesis, the backup task was started via sctool

< t:2023-08-04 09:23:37,080 f:remote_base.py  l:520  c:RemoteLibSSH2CmdRunner p:DEBUG > Running command "/opt/scylla/scylla-cloud -c /opt/scylla/scylla-dbaas.yml cluster manager sctool --cluster-id 11232 --  backup  --location AWS_EU_WEST_1:s3:scylla-cloud-backup-11232-11016-v80c7h"...

While the task was running the storage utilization on the node scylla-cloud-operations-24h-devel-db-node-f04b5124-1 (172.18.122.20) spiked and eventually hit 100%. The node threw the error No space left on device:

2023-08-04 17:44:31.526 <2023-08-04 17:44:31.162>: (DatabaseLogEvent Severity.ERROR) period_type=one-time event_id=c1b5b322-9df8-41e9-ab26-fbb18cd9d7f1: type=NO_SPACE_ERROR regex=No space left on device line_number=7273 node=scylla-cloud-operations-24h-devel-db-node-f04b5124-1
2023-08-04T17:44:31.162 ip-172-18-122-20 !ERROR | scylla[24388]:  [shard 0] storage_service - Shutting down communications due to I/O errors until operator intervention: Disk error: std::system_error (error system:28, No space left on device)

Here are the storage utilization graphs from the monitor during the whole build (red line is for the problematic node)

Some other graphs from the monitor

Impact

One of the cluster nodes runs out of the storage space and stops responding

How frequently does it reproduce?

It reproduced a few times in a row. The other reproducers will be added in the following comments

Installation details

Kernel Version: 5.15.0-1039-aws
Scylla version (or git commit hash): 2022.2.11-20230705.27d29485de90 with build-id f467a0ad8869d61384d8bbc8f20e4fb8fd281f4b

Cloud manager version: 3.1.0

Cluster size: 6 nodes (i4i.large)

Scylla Nodes used in this run:

• scylla-cloud-operations-24h-devel-db-node-f04b5124-6 (null | 172.18.120.40) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-f04b5124-5 (null | 172.18.120.12) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-f04b5124-4 (null | 172.18.121.241) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-f04b5124-3 (null | 172.18.122.54) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-f04b5124-2 (null | 172.18.121.23) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-f04b5124-1 (null | 172.18.122.20) (shards: 2)

OS / Image: `` (aws: undefined_region)

Test: scylla-cloud-longevity-terraform-operations-24h-aws
Test id: f04b5124-5beb-4019-b3c1-3559c4726f7d
Test name: siren-tests/longevity-tests/staging/scylla-cloud-longevity-terraform-operations-24h-aws
Test config file(s):

• scylla-cloud-operations-nemeses.yaml

Logs and commands

• Restore Monitor Stack command: $ hydra investigate show-monitor f04b5124-5beb-4019-b3c1-3559c4726f7d
• Restore monitor on AWS instance using Jenkins job
• Show all stored logs command: $ hydra investigate show-logs f04b5124-5beb-4019-b3c1-3559c4726f7d

Logs:

• db-cluster-f04b5124.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/f04b5124-5beb-4019-b3c1-3559c4726f7d/20230805_001510/db-cluster-f04b5124.tar.gz
• sct-runner-events-f04b5124.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/f04b5124-5beb-4019-b3c1-3559c4726f7d/20230805_001510/sct-runner-events-f04b5124.tar.gz
• sct-f04b5124.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/f04b5124-5beb-4019-b3c1-3559c4726f7d/20230805_001510/sct-f04b5124.log.tar.gz
• loader-set-f04b5124.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/f04b5124-5beb-4019-b3c1-3559c4726f7d/20230805_001510/loader-set-f04b5124.tar.gz
• monitor-set-f04b5124.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/f04b5124-5beb-4019-b3c1-3559c4726f7d/20230805_001510/monitor-set-f04b5124.tar.gz
• siren-manager-set-f04b5124.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/f04b5124-5beb-4019-b3c1-3559c4726f7d/20230805_001510/siren-manager-set-f04b5124.tar.gz

Jenkins job URL
Argus

[ilya-rarov]

Issue description

Next repro.

The nemeses:

1. 2023-08-11 08:22:18 - 2023-08-11 14:44:27 - disrupt_cloud_replace_responsive_node
2. 2023-08-11 15:08:55 - 2023-08-11 17:08:18 - disrupt_grow_shrink_cluster
3. 2023-08-11 17:25:47 - 2023-08-12 08:08:34 - disrupt_mgmt_backup_specific_keyspaces

The load settings were the same as for the previous build.

At the beginning of the disrupt_mgmt_backup_specific_keyspaces nemesis, we started a new manager backup task for a specific keyspace - keyspace1

< t:2023-08-11 17:26:25,320 f:remote_base.py  l:520  c:RemoteLibSSH2CmdRunner p:DEBUG > Running command "/opt/scylla/scylla-cloud -c /opt/scylla/scylla-dbaas.yml cluster manager sctool --cluster-id 11370 --  backup  --keyspace keyspace1  --location AWS_EU_WEST_1:s3:scylla-cloud-backup-11370-11154-610zsa"...

While the task was running the node scylla-cloud-operations-24h-devel-db-node-cd335ce7-6 (172.23.24.135) ran out of space

2023-08-11 18:35:53.521 <2023-08-11 18:35:53.461>: (DatabaseLogEvent Severity.ERROR) period_type=one-time event_id=a0e30ea6-1d07-420d-9f94-778cb70d2a1e: type=NO_SPACE_ERROR regex=No space left on device line_number=4614 node=scylla-cloud-operations-24h-devel-db-node-cd335ce7-6
2023-08-11T18:35:53.461 ip-172-23-24-135 !ERROR | scylla[23420]:  [shard 0] storage_service - Shutting down communications due to I/O errors until operator intervention: Disk error: std::system_error (error system:28, No space left on device)

Screenshots from Grafana (yellow line):

Installation details

Kernel Version: 5.15.0-1039-aws
Scylla version (or git commit hash): 2022.2.11-20230705.27d29485de90 with build-id f467a0ad8869d61384d8bbc8f20e4fb8fd281f4b

Cloud manager version: 3.1.0

Cluster size: 6 nodes (i4i.large)

Scylla Nodes used in this run:

• scylla-cloud-operations-24h-devel-db-node-cd335ce7-8 (null | 172.23.24.87) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-cd335ce7-7 (null | 172.23.25.29) (shards: -1)
• scylla-cloud-operations-24h-devel-db-node-cd335ce7-6 (null | 172.23.24.135) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-cd335ce7-5 (null | 172.23.24.108) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-cd335ce7-4 (null | 172.23.25.192) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-cd335ce7-3 (null | 172.23.26.231) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-cd335ce7-2 (null | 172.23.25.30) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-cd335ce7-1 (null | 172.23.26.228) (shards: 2)

OS / Image: `` (aws: undefined_region)

Test: scylla-cloud-longevity-terraform-operations-24h-aws
Test id: cd335ce7-7bb4-4bdb-8777-cb25249815b6
Test name: siren-tests/longevity-tests/staging/scylla-cloud-longevity-terraform-operations-24h-aws
Test config file(s):

• scylla-cloud-operations-nemeses.yaml

Logs and commands

• Restore Monitor Stack command: $ hydra investigate show-monitor cd335ce7-7bb4-4bdb-8777-cb25249815b6
• Restore monitor on AWS instance using Jenkins job
• Show all stored logs command: $ hydra investigate show-logs cd335ce7-7bb4-4bdb-8777-cb25249815b6

Logs:

• db-cluster-cd335ce7.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/cd335ce7-7bb4-4bdb-8777-cb25249815b6/20230812_083204/db-cluster-cd335ce7.tar.gz
• sct-runner-events-cd335ce7.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/cd335ce7-7bb4-4bdb-8777-cb25249815b6/20230812_083204/sct-runner-events-cd335ce7.tar.gz
• sct-cd335ce7.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/cd335ce7-7bb4-4bdb-8777-cb25249815b6/20230812_083204/sct-cd335ce7.log.tar.gz
• loader-set-cd335ce7.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/cd335ce7-7bb4-4bdb-8777-cb25249815b6/20230812_083204/loader-set-cd335ce7.tar.gz
• monitor-set-cd335ce7.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/cd335ce7-7bb4-4bdb-8777-cb25249815b6/20230812_083204/monitor-set-cd335ce7.tar.gz
• siren-manager-set-cd335ce7.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/cd335ce7-7bb4-4bdb-8777-cb25249815b6/20230812_083204/siren-manager-set-cd335ce7.tar.gz

Jenkins job URL
Argus

[ilya-rarov]

Issue description

One more repro.

The nemeses list:

1. 2023-08-18 08:20:36 - 2023-08-18 08:56:24 - disrupt_rolling_restart_cluster
2. 2023-08-18 09:31:14 - 2023-08-19 00:32:32 - disrupt_mgmt_backup
3. 2023-08-19 01:05:45 - 2023-08-19 08:14:45 - disrupt_cloud_replace_non_responsive_node

The load settings were the same as for the previous build.

At the beginning of the nemesis disrupt_mgmt_backup we started a new backup task

< t:2023-08-18 09:31:51,270 f:remote_base.py  l:520  c:RemoteLibSSH2CmdRunner p:DEBUG > Running command "/opt/scylla/scylla-cloud -c /opt/scylla/scylla-dbaas.yml cluster manager sctool --cluster-id 11451 --  backup  --location AWS_EU_WEST_1:s3:scylla-cloud-backup-11451-11234-7ua31o"...

This task had been running longer than expected 15 hours and the nemesis failed.

< t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR > nemesis_cloud.CloudOperationMonkey: Unhandled exception in method <bound method Nemesis.disrupt_mgmt_backup of <nemesis_cloud.CloudOperationMonkey object at 0x7fd6d4523bb0>> < t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR > nemesis_cloud.CloudOperationMonkey: Unhandled exception in method <bound method Nemesis.disrupt_mgmt_backup of <nemesis_cloud.CloudOperationMonkey object at 0x7fd6d4523bb0>>
< t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR > Traceback (most recent call last):
< t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR >   File "/home/ubuntu/scylla-cluster-tests/sdcm/wait.py", line 69, in wait_for
< t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR >     res = retry(func, **kwargs)
< t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR >   File "/usr/local/lib/python3.10/site-packages/tenacity/__init__.py", line 404, in __call__
< t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR >     do = self.iter(retry_state=retry_state)
< t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR >   File "/usr/local/lib/python3.10/site-packages/tenacity/__init__.py", line 360, in iter
< t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR >     raise retry_exc.reraise()
< t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR >   File "/usr/local/lib/python3.10/site-packages/tenacity/__init__.py", line 194, in reraise
< t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR >     raise self
< t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR > tenacity.RetryError: RetryError[<Future at 0x7fd6d4177610 state=finished returned bool>]
< t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR > 
< t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR > The above exception was the direct cause of the following exception:
< t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR > 
< t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR > Traceback (most recent call last):
< t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR >   File "/home/ubuntu/scylla-cluster-tests/sdcm/mgmt/cli.py", line 399, in wait_for_status
< t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR >     return wait.wait_for(func=self.is_status_in_list, step=step, throw_exc=True,
< t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR >   File "/home/ubuntu/scylla-cluster-tests/sdcm/wait.py", line 80, in wait_for
< t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR >     raise WaitForTimeoutError(err) from ex
< t:2023-08-19 00:32:32,479 f:nemesis.py      l:4837 c:sdcm.nemesis         p:ERROR > sdcm.wait.WaitForTimeoutError: Wait for: Waiting until task: backup/36584ea2-dd92-44f1-8b78-6fe0e519161e reaches status of: ['ERROR (4/4)', 'DONE']: timeout - 54000 seconds - expired

But the task itself kept on running until it was paused during the next nemesis (disrupt_cloud_replace_non_responsive_node) before launching replace-dead operation

< t:2023-08-19 01:06:48,353 f:remote_base.py  l:520  c:RemoteLibSSH2CmdRunner p:DEBUG > Running command "/opt/scylla/scylla-cloud -c /opt/scylla/scylla-dbaas.yml cluster manager pause-all-jobs --cluster-id 11451"...

After the replace-dead succeeded the backup task was resumed

< t:2023-08-19 04:02:10,087 f:remote_base.py  l:520  c:RemoteLibSSH2CmdRunner p:DEBUG > Running command "/opt/scylla/scylla-cloud -c /opt/scylla/scylla-dbaas.yml cluster manager resume-all-jobs --cluster-id 11451"...

< t:2023-08-19 04:22:19,210 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > {"level":"debug","ts":1692418938.5278873,"caller":"manager/manager.go:100","msg":"Running Manager task is pending","clusterID":11451,"taskID":"36584ea2-dd92-44f1-8b78-6fe0e519161e","taskName":"","taskType":"backup","taskStatus":"RUNNING"}

Here is the screenshot from manager dashboard representing the life cycle of this task

After the task was resumed the node scylla-cloud-operations-24h-devel-db-node-9a05f3fd-1 (172.29.130.95) ran out of space.

2023-08-19 07:40:00.189 <2023-08-19 07:39:59.756>: (DatabaseLogEvent Severity.ERROR) period_type=one-time event_id=26dea975-1e63-4af5-9673-a28113c09d63: type=NO_SPACE_ERROR regex=No space left on device line_number=7703 node=scylla-cloud-operations-24h-devel-db-node-9a05f3fd-1
2023-08-19T07:39:59.756 ip-172-29-130-95 !ERROR | scylla[22633]:  [shard 0] storage_service - Shutting down communications due to I/O errors until operator intervention: Disk error: std::system_error (error system:28, No space left on device)

In these Grafana graphs, this node is presented with the purple line

Another node that ran out of space was scylla-cloud-operations-24h-devel-db-node-9a05f3fd-7 (172.29.129.76) - red line in the pictures above

2023-08-19T06:43:03.406 ip-172-29-129-76 !ERROR | scylla[11079]:  [shard 1] storage_service - Shutting down communications due to I/O errors until operator intervention: Disk error: std::system_error (error system:28, No space left on device)

It was a new node joined the cluster after replace-dead operation.

Installation details

Kernel Version: 5.15.0-1040-aws
Scylla version (or git commit hash): 2022.2.12-20230727.f4448d5b0265 with build-id a87bfeb65d24abf65d074a3ba2e5b9664692d716

Cloud manager version: 3.1.0

Cluster size: 6 nodes (i4i.large)

Scylla Nodes used in this run:

• scylla-cloud-operations-24h-devel-db-node-9a05f3fd-7 (null | 172.29.129.76) (shards: -1)
• scylla-cloud-operations-24h-devel-db-node-9a05f3fd-6 (null | 172.29.128.19) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-9a05f3fd-5 (null | 172.29.129.41) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-9a05f3fd-4 (null | 172.29.130.128) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-9a05f3fd-3 (null | 172.29.129.157) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-9a05f3fd-2 (null | 172.29.128.49) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-9a05f3fd-1 (null | 172.29.130.95) (shards: 2)

OS / Image: `` (aws: undefined_region)

Test: scylla-cloud-longevity-terraform-operations-24h-aws
Test id: 9a05f3fd-2e20-4a28-afe7-7823846206c5
Test name: siren-tests/longevity-tests/staging/scylla-cloud-longevity-terraform-operations-24h-aws
Test config file(s):

• scylla-cloud-operations-nemeses.yaml

Logs and commands

• Restore Monitor Stack command: $ hydra investigate show-monitor 9a05f3fd-2e20-4a28-afe7-7823846206c5
• Restore monitor on AWS instance using Jenkins job
• Show all stored logs command: $ hydra investigate show-logs 9a05f3fd-2e20-4a28-afe7-7823846206c5

Logs:

• db-cluster-9a05f3fd.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/9a05f3fd-2e20-4a28-afe7-7823846206c5/20230819_082245/db-cluster-9a05f3fd.tar.gz
• sct-runner-events-9a05f3fd.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/9a05f3fd-2e20-4a28-afe7-7823846206c5/20230819_082245/sct-runner-events-9a05f3fd.tar.gz
• sct-9a05f3fd.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/9a05f3fd-2e20-4a28-afe7-7823846206c5/20230819_082245/sct-9a05f3fd.log.tar.gz
• loader-set-9a05f3fd.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/9a05f3fd-2e20-4a28-afe7-7823846206c5/20230819_082245/loader-set-9a05f3fd.tar.gz
• monitor-set-9a05f3fd.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/9a05f3fd-2e20-4a28-afe7-7823846206c5/20230819_082245/monitor-set-9a05f3fd.tar.gz
• siren-manager-set-9a05f3fd.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/9a05f3fd-2e20-4a28-afe7-7823846206c5/20230819_082245/siren-manager-set-9a05f3fd.tar.gz

Jenkins job URL
Argus

[ilya-rarov]

Issue description

Another repro

The nemeses list:

1. 2023-08-25 08:22:12 - 2023-08-25 08:41:44 - disrupt_mgmt_repair_cli
2. 2023-08-25 09:18:53 - 2023-08-25 17:29:48 - disrupt_cloud_replace_responsive_node
3. 2023-08-25 17:46:55 - 2023-08-25 19:36:20 - disrupt_grow_shrink_cluster
4. 2023-08-25 19:49:55 - 2023-08-26 04:39:00 - disrupt_mgmt_repair_cli

The load settings were the same as for the first build.

When the nemesis disrupt_mgmt_repair_cli was triggered for the 2nd time the new repair task was created

< t:2023-08-25 19:49:55,962 f:remote_base.py  l:520  c:RemoteLibSSH2CmdRunner p:DEBUG > Running command "/opt/scylla/scylla-cloud -c /opt/scylla/scylla-dbaas.yml cluster manager sctool --cluster-id 11595 --  repair"...

While this task was running the node scylla-cloud-operations-24h-devel-db-node-95b9d688-6 (172.27.152.183) ran out of space and stopped responding

2023-08-26 04:00:39.960 <2023-08-26 04:00:39.781>: (DatabaseLogEvent Severity.ERROR) period_type=one-time event_id=8364e899-4d8f-4448-92fd-014346e3300b: type=NO_SPACE_ERROR regex=No space left on device line_number=49178 node=scylla-cloud-operations-24h-devel-db-node-95b9d688-6
2023-08-26T04:00:39.781 ip-172-27-152-183 !ERROR | scylla[21630]:  [shard 1] storage_service - Shutting down communications due to I/O errors until operator intervention: Disk error: std::system_error (error system:28, No space left on device)

In the screenshots from Grafana the storage utilization for this node is represented with a blue line


Some other graphs from the monitor

The repair task eventually failed

2023-08-26 04:39:00.425: (DisruptionEvent Severity.ERROR) period_type=end event_id=aa25f829-e86e-4518-8bac-25f94c2b9399 duration=8h49m5s: nemesis_name=MgmtRepairCli target_node=Node scylla-cloud-operations-24h-devel-db-node-95b9d688-1 [None | 172.27.154.211] (seed: True) errors=Task: repair/9f18425c-1874-448d-86c3-9553df8e5ed8 final status is: ERROR.
Task progress string: Run:		9395db84-4380-11ee-bf94-0a2270aa6e79
Status:		ERROR
Cause:		repair 122 token ranges out of 15360
Start time:	25 Aug 23 19:50:00 UTC
End time:	26 Aug 23 04:36:32 UTC
Duration:	8h46m32s
Progress:	99%/1%
Datacenters:
- AWS_EU_WEST_1
╭───────────────────────────────┬────────────────────────────────┬──────────┬──────────╮
│ Keyspace                      │                          Table │ Progress │ Duration │
├───────────────────────────────┼────────────────────────────────┼──────────┼──────────┤
│ keyspace1                     │                      standard1 │ 92%/8%   │ 8h25m54s │
├───────────────────────────────┼────────────────────────────────┼──────────┼──────────┤
│ system_auth                   │                role_attributes │ 100%     │ 2m48s    │
│ system_auth                   │                   role_members │ 100%     │ 2m36s    │
│ system_auth                   │               role_permissions │ 100%     │ 2m47s    │
│ system_auth                   │                          roles │ 100%     │ 2m23s    │
├───────────────────────────────┼────────────────────────────────┼──────────┼──────────┤
│ system_distributed_everywhere │ cdc_generation_descriptions_v2 │ 100%     │ 0s       │
├───────────────────────────────┼────────────────────────────────┼──────────┼──────────┤
│ system_distributed            │      cdc_generation_timestamps │ 100%     │ 2m21s    │
│ system_distributed            │    cdc_streams_descriptions_v2 │ 100%     │ 2m32s    │
│ system_distributed            │                 service_levels │ 100%     │ 2m16s    │
│ system_distributed            │              view_build_status │ 100%     │ 2m41s    │
╰───────────────────────────────┴────────────────────────────────┴──────────┴──────────╯
Traceback (most recent call last):
File "/home/ubuntu/scylla-cluster-tests/sdcm/nemesis.py", line 4911, in wrapper
result = method(*args[1:], **kwargs)
File "/home/ubuntu/scylla-cluster-tests/sdcm/utils/decorators.py", line 178, in wrapped
res = func(*args, **kwargs)
File "/home/ubuntu/scylla-cluster-tests/sdcm/nemesis.py", line 2807, in disrupt_mgmt_repair_cli
raise ScyllaManagerError(
sdcm.mgmt.common.ScyllaManagerError: Task: repair/9f18425c-1874-448d-86c3-9553df8e5ed8 final status is: ERROR.
Task progress string: Run:		9395db84-4380-11ee-bf94-0a2270aa6e79
Status:		ERROR
Cause:		repair 122 token ranges out of 15360
Start time:	25 Aug 23 19:50:00 UTC
End time:	26 Aug 23 04:36:32 UTC
Duration:	8h46m32s
Progress:	99%/1%
Datacenters:
- AWS_EU_WEST_1
╭───────────────────────────────┬────────────────────────────────┬──────────┬──────────╮
│ Keyspace                      │                          Table │ Progress │ Duration │
├───────────────────────────────┼────────────────────────────────┼──────────┼──────────┤
│ keyspace1                     │                      standard1 │ 92%/8%   │ 8h25m54s │
├───────────────────────────────┼────────────────────────────────┼──────────┼──────────┤
│ system_auth                   │                role_attributes │ 100%     │ 2m48s    │
│ system_auth                   │                   role_members │ 100%     │ 2m36s    │
│ system_auth                   │               role_permissions │ 100%     │ 2m47s    │
│ system_auth                   │                          roles │ 100%     │ 2m23s    │
├───────────────────────────────┼────────────────────────────────┼──────────┼──────────┤
│ system_distributed_everywhere │ cdc_generation_descriptions_v2 │ 100%     │ 0s       │
├───────────────────────────────┼────────────────────────────────┼──────────┼──────────┤
│ system_distributed            │      cdc_generation_timestamps │ 100%     │ 2m21s    │
│ system_distributed            │    cdc_streams_descriptions_v2 │ 100%     │ 2m32s    │
│ system_distributed            │                 service_levels │ 100%     │ 2m16s    │
│ system_distributed            │              view_build_status │ 100%     │ 2m41s    │
╰───────────────────────────────┴────────────────────────────────┴──────────┴──────────╯

Installation details

Kernel Version: 5.15.0-1040-aws
Scylla version (or git commit hash): 2022.2.12-20230727.f4448d5b0265 with build-id a87bfeb65d24abf65d074a3ba2e5b9664692d716

Cloud manager version: 3.2.0

Cluster size: 6 nodes (i4i.large)

Scylla Nodes used in this run:

• scylla-cloud-operations-24h-devel-db-node-95b9d688-8 (null | 172.27.152.133) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-95b9d688-7 (null | 172.27.152.145) (shards: -1)
• scylla-cloud-operations-24h-devel-db-node-95b9d688-6 (null | 172.27.152.183) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-95b9d688-5 (null | 172.27.153.34) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-95b9d688-4 (null | 172.27.152.86) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-95b9d688-3 (null | 172.27.154.160) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-95b9d688-2 (null | 172.27.153.73) (shards: 2)
• scylla-cloud-operations-24h-devel-db-node-95b9d688-1 (null | 172.27.154.211) (shards: 2)

OS / Image: `` (aws: undefined_region)

Test: scylla-cloud-longevity-terraform-operations-24h-aws
Test id: 95b9d688-ce66-4f15-ae37-576501193062
Test name: siren-tests/longevity-tests/staging/scylla-cloud-longevity-terraform-operations-24h-aws
Test config file(s):

• scylla-cloud-operations-nemeses.yaml

Logs and commands

• Restore Monitor Stack command: $ hydra investigate show-monitor 95b9d688-ce66-4f15-ae37-576501193062
• Restore monitor on AWS instance using Jenkins job
• Show all stored logs command: $ hydra investigate show-logs 95b9d688-ce66-4f15-ae37-576501193062

Logs:

• db-cluster-95b9d688.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/95b9d688-ce66-4f15-ae37-576501193062/20230826_045421/db-cluster-95b9d688.tar.gz
• sct-runner-events-95b9d688.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/95b9d688-ce66-4f15-ae37-576501193062/20230826_045421/sct-runner-events-95b9d688.tar.gz
• sct-95b9d688.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/95b9d688-ce66-4f15-ae37-576501193062/20230826_045421/sct-95b9d688.log.tar.gz
• loader-set-95b9d688.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/95b9d688-ce66-4f15-ae37-576501193062/20230826_045421/loader-set-95b9d688.tar.gz
• monitor-set-95b9d688.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/95b9d688-ce66-4f15-ae37-576501193062/20230826_045421/monitor-set-95b9d688.tar.gz
• siren-manager-set-95b9d688.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/95b9d688-ce66-4f15-ae37-576501193062/20230826_045421/siren-manager-set-95b9d688.tar.gz

Jenkins job URL
Argus

[rayakurl]

@roydahan - FYI

[Michal-Leszczynski]

I'm taking a look at that, but I would be very surprised if SM is the root cause of that, because I don't see how repair could cause node to be OOM.

[rayakurl]

I'm taking a look at that, but I would be very surprised if SM is the root cause of that, because I don't see how repair could cause node to be OOM.

Thanks @Michal-Leszczynski , feel free to move the issue for siren-enterprise if the SM is not the root cause.

[Michal-Leszczynski]

When the nemesis disrupt_mgmt_repair_cli was triggered for the 2nd time the new repair task was created

< t:2023-08-25 19:49:55,962 f:remote_base.py  l:520  c:RemoteLibSSH2CmdRunner p:DEBUG > Running command "/opt/scylla/scylla-cloud -c /opt/scylla/scylla-dbaas.yml cluster manager sctool --cluster-id 11595 --  repair"...

While this task was running the node scylla-cloud-operations-24h-devel-db-node-95b9d688-6 (172.27.152.183) ran out of space and stopped responding

This is strange, as the logs suggest that node scylla-cloud-operations-24h-devel-db-node-95b9d688-6 hasn't been taking part in any repair (except for the first run of disrupt_mgmt_repair_cli), so repair shouldn't be the cause for that.

Unfortunately, I am not familiar with used test scenarios and SM logs seems to be empty, so it would be good if I could get some information about that. Especially about repair task configuration, what other SM tasks were running etc.

[mykaul]

It's probably the same issue @ShlomiBalalis saw multiple times - repair has very very elaborate logs, and those logs fill the disk.
My question (as asked before in such bugs) - what is consuming the whole storage?

[ilya-rarov]

Especially about repair task configuration, what other SM tasks were running etc.

AFAICT, we did not apply any special configuration to the repair task.
We just ran it using the following command:

/opt/scylla/scylla-cloud -c /opt/scylla/scylla-dbaas.yml cluster manager sctool --cluster-id 11595 --  repair

I guess the configuration was default.

Regarding the other tasks. We regularly requested the status of the manager's tasks while the repair was running
Here is the first status (repair had just started)

< t:2023-08-25 19:50:05,357 f:remote_base.py  l:520  c:RemoteLibSSH2CmdRunner p:DEBUG > Running command "/opt/scylla/scylla-cloud -c /opt/scylla/scylla-dbaas.yml cluster manager sctool --cluster-id 11595 --  tasks"...
╭─────────────────────────────────────────────┬─────────────┬────────┬──────────┬─────────┬───────┬────────────────────────┬────────────────────────┬─────────┬────────────────────────╮
│ Task                                        │ Schedule    │ Window │ Timezone │ Success │ Error │ Last Success           │ Last Error             │ Status  │ Next                   │
├─────────────────────────────────────────────┼─────────────┼────────┼──────────┼─────────┼───────┼────────────────────────┼────────────────────────┼─────────┼────────────────────────┤
│ backup/ScyllaCloud-#11595                   │ 1d          │        │          │ 0       │ 3     │                        │ 25 Aug 23 17:37:45 UTC │ ERROR   │ 25 Aug 23 20:08:50 UTC │
│ healthcheck/cql                             │ @every 15s  │        │ Etc/UTC  │ 2686    │ 0     │ 25 Aug 23 19:50:04 UTC │                        │ DONE    │ 25 Aug 23 19:50:19 UTC │
│ healthcheck/rest                            │ @every 1m0s │        │ Etc/UTC  │ 698     │ 0     │ 25 Aug 23 19:49:35 UTC │                        │ DONE    │ 25 Aug 23 19:50:35 UTC │
│ healthcheck/alternator                      │ @every 15s  │        │ Etc/UTC  │ 2753    │ 0     │ 25 Aug 23 19:50:07 UTC │                        │ DONE    │ 25 Aug 23 19:50:22 UTC │
│ repair/214e70f0-f8ff-45fb-b491-6e66db80f672 │ 7d          │        │          │ 0       │ 0     │                        │                        │ NEW     │ 26 Aug 23 07:39:41 UTC │
│ repair/4be13ea9-045f-418e-a7ba-67b991f31b95 │             │        │ Etc/UTC  │ 1       │ 0     │ 25 Aug 23 08:35:09 UTC │                        │ DONE    │                        │
│ repair/9f18425c-1874-448d-86c3-9553df8e5ed8 │             │        │ Etc/UTC  │ 0       │ 0     │                        │                        │ RUNNING │                        │
╰─────────────────────────────────────────────┴─────────────┴────────┴──────────┴─────────┴───────┴────────────────────────┴────────────────────────┴─────────┴────────────────────────╯

Here is one of the last statuses - the repair had just failed

< t:2023-08-26 04:38:56,036 f:remote_base.py  l:520  c:RemoteLibSSH2CmdRunner p:DEBUG > Running command "/opt/scylla/scylla-cloud -c /opt/scylla/scylla-dbaas.yml cluster manager sctool --cluster-id 11595 --  tasks"...
╭─────────────────────────────────────────────┬─────────────┬────────┬──────────┬─────────┬───────┬────────────────────────┬────────────────────────┬─────────────┬────────────────────────╮
│ Task                                        │ Schedule    │ Window │ Timezone │ Success │ Error │ Last Success           │ Last Error             │ Status      │ Next                   │
├─────────────────────────────────────────────┼─────────────┼────────┼──────────┼─────────┼───────┼────────────────────────┼────────────────────────┼─────────────┼────────────────────────┤
│ backup/ScyllaCloud-#11595                   │ 1d          │        │          │ 0       │ 7     │                        │ 25 Aug 23 21:19:12 UTC │ ERROR       │ 26 Aug 23 20:08:50 UTC │
│ healthcheck/cql                             │ @every 15s  │        │ Etc/UTC  │ 4730    │ 0     │ 26 Aug 23 04:38:56 UTC │                        │ DONE        │ 26 Aug 23 04:39:11 UTC │
│ healthcheck/rest                            │ @every 1m0s │        │ Etc/UTC  │ 1227    │ 0     │ 26 Aug 23 04:38:36 UTC │                        │ DONE        │ 26 Aug 23 04:39:36 UTC │
│ healthcheck/alternator                      │ @every 15s  │        │ Etc/UTC  │ 4863    │ 0     │ 26 Aug 23 04:38:45 UTC │                        │ DONE        │ 26 Aug 23 04:39:00 UTC │
│ repair/214e70f0-f8ff-45fb-b491-6e66db80f672 │ 7d          │        │          │ 0       │ 0     │                        │                        │ NEW         │ 26 Aug 23 07:39:41 UTC │
│ repair/4be13ea9-045f-418e-a7ba-67b991f31b95 │             │        │ Etc/UTC  │ 1       │ 0     │ 25 Aug 23 08:35:09 UTC │                        │ DONE        │                        │
│ repair/9f18425c-1874-448d-86c3-9553df8e5ed8 │             │        │ Etc/UTC  │ 0       │ 1     │                        │ 26 Aug 23 04:36:32 UTC │ ERROR (0/3) │ 26 Aug 23 04:46:32 UTC │
╰─────────────────────────────────────────────┴─────────────┴────────┴──────────┴─────────┴───────┴────────────────────────┴────────────────────────┴─────────────┴────────────────────────╯

The list of tasks is the same - looks like there were no other running tasks during the repair.

[roydahan]

It can't be the logs because it happens only on one node and the pattern is that space is going up but also down.

@ilya-rarov please correlate the used space graph also with running compactions and possibly other advanced graphs that shows difference between this node behavior to others (e.g slower disk).

Lastly, how often does it reproduce?

[ilya-rarov]

@roydahan, I updated all the comments about the reproducers with some additional graphs. Please let me know if you think that I need to add anything else.
Looks like this problem reproduces in every build of this Cloud longevity (starting from the 4th)

[roydahan]

@ilya-rarov it doesn't help just throwing more and more information from reproducers.
We need to find an exact reproducer.
It seems like the reproducer is the backup nemesis, not repair.

In summary, we need to understand:

1. What is the raw dataset size (calculation from c-s prepare command).
2. What is the size on disk after prepare. (metric from monitor)
3. What is the size on disk before backup (metric from monitor)
4. What is the size on disk after backup (metric from monitor).

Then we should make sure that:
"data on disk before backup" + "backup temporary overhead" < "Size of disk of i4i.large"

Another easy way to test it is to increase to i4i.xlarge or 2xlarge and see till what size the "used disk" metric reach.

[rayakurl]

@ilya-rarov - As far as I remember, you run this on a larger instance type, right?

@roydahan - even if we exceed the disk size, how come only one node is getting out of space? All the nodes should be balanced if this is the case

[roydahan]

I don't know.
Maybe the manager does its operations sequentially on the nodes and not in parallel.

Another way to debug it is to keep the cluster alive and check what's taking the space on the disk.

(Start by du -sh /var/lib/scylla/* and dig into it, while comparing to another node.