backup timeout when uploading to s3 (end up with failure `Indexing snapshot files failed on host`)

[fruch]

Installation details

Kernel Version: 5.13.0-1031-aws
Scylla version (or git commit hash): 5.1.dev-20220706.a0ffbf3291b7 with build-id 3490fa9f14da510e97a1d0f53f693cac13a70494
Cluster size: 6 nodes (i3.4xlarge)
Manager Version: 3.0.0-0.20220523.5501e5d7f53

Scylla Nodes used in this run:

• longevity-tls-50gb-3d-master-db-node-fb8b36a7-9 (63.35.163.81 | 10.0.3.187) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-fb8b36a7-8 (52.31.41.157 | 10.0.0.95) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-fb8b36a7-7 (34.244.145.19 | 10.0.0.195) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-fb8b36a7-6 (34.241.120.110 | 10.0.0.111) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-fb8b36a7-5 (34.244.16.3 | 10.0.1.141) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-fb8b36a7-4 (34.253.116.115 | 10.0.0.12) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-fb8b36a7-3 (3.251.71.251 | 10.0.1.19) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-fb8b36a7-2 (52.16.243.180 | 10.0.2.34) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-fb8b36a7-10 (34.243.184.173 | 10.0.0.66) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-fb8b36a7-1 (63.33.208.165 | 10.0.1.209) (shards: 14)

OS / Image: ami-07d73e5ea1fc772eb (aws: eu-west-1)

Test: longevity-50gb-3days
Test id: fb8b36a7-c818-4b0b-8ae3-f3ee2cafa53a
Test name: scylla-master/longevity/longevity-50gb-3days
Test config file(s):

• longevity-50GB-3days-authorization-and-tls-ssl.yaml

Issue description

backup was working o.k. for ~2.5 hours:

< t:2022-07-10 19:46:55,290 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > sctool output: Run:               68480f6c-0074-11ed-8c00-0ada645d1fc3
< t:2022-07-10 19:46:55,290 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > Status:           RUNNING (uploading data)
< t:2022-07-10 19:46:55,290 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > Start time:       10 Jul 22 17:19:08 UTC
< t:2022-07-10 19:46:55,290 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > Duration: 2h27m46s
< t:2022-07-10 19:46:55,290 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > Progress: 99%/0%
< t:2022-07-10 19:46:55,290 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > Snapshot Tag:     sm_20220710171912UTC
< t:2022-07-10 19:46:55,290 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > Datacenters:
< t:2022-07-10 19:46:55,290 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG >   - eu-west
< t:2022-07-10 19:46:55,290 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG >
< t:2022-07-10 19:46:55,290 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > ╭────────────┬──────────┬─────────┬─────────┬──────────────┬──────────╮
< t:2022-07-10 19:46:55,290 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > │ Host       │ Progress │    Size │ Success │ Deduplicated │   Failed │
< t:2022-07-10 19:46:55,290 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > ├────────────┼──────────┼─────────┼─────────┼──────────────┼──────────┤
< t:2022-07-10 19:46:55,290 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > │ 10.0.0.111 │     100% │ 21.992G │ 21.992G │            0 │        0 │
< t:2022-07-10 19:46:55,290 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > │ 10.0.0.12  │     100% │ 21.511G │ 21.511G │            0 │        0 │
< t:2022-07-10 19:46:55,290 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > │ 10.0.0.195 │   99%/0% │ 22.922G │ 22.753G │            0 │ 172.830M │
< t:2022-07-10 19:46:55,290 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > │ 10.0.0.95  │      99% │ 29.205G │ 29.205G │            0 │        0 │
< t:2022-07-10 19:46:55,290 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > │ 10.0.1.141 │     100% │ 18.556G │ 18.556G │            0 │        0 │
< t:2022-07-10 19:46:55,290 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > │ 10.0.1.209 │     100% │ 22.173G │ 22.173G │            0 │        0 │
< t:2022-07-10 19:46:55,290 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > ╰────────────┴──────────┴─────────┴─────────┴──────────────┴──────────╯

and then failed with the following:

< t:2022-07-10 19:47:05,215 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Run:            68480f6c-0074-11ed-8c00-0ada645d1fc3
< t:2022-07-10 19:47:05,215 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Status:         ERROR (uploading data)
< t:2022-07-10 19:47:05,220 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Cause:          upload
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG >  10.0.0.195: keyspace1.standard1: upload snapshot: copy "data:keyspace1/standard1-45183ad0002111edb97479c04c879a65/snapshots/sm_20220710171912UTC" to "s3:manager-backup-tests-us-east-1/backup/sst/cluster/f2972720-cb85-4ab3-b5fb-d72d4d195d38/dc/eu-west/node/a846b4ec-4eeb-43ad-b7
89-df7dabfa66a6/keyspace/keyspace1/table/standard1/45183ad0002111edb97479c04c879a65": job error (1657446887): s3 upload: 400 Bad Request: <?xml version="1.0" encoding="UTF-8"?>
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > <Error><Code>RequestTimeout</Code><Message>Your socket connection to the server was not read from or written to within the timeout period. Idle connections will be closed.</Message><RequestId>D88KJC301DEEVFEQ</RequestId><HostId>HX3vytjgqgJDYE4AlPQpFrhOEs0WDpnSbYeK2m2gxdxNnUCeNQmcJCzvLq4wTA0NXcI0CAQy7XI=</HostId></Error>; standard1-45183ad0002111edb97479c04c879a65/snapshots/sm_20220710171912UTC/me-13418-big-Data.db s3 upload: 400 Bad Request: <?xml version="
1.0" encoding="UTF-8"?>
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > <Error><Code>RequestTimeout</Code><Message>Your socket connection to the server was not read from or written to within the timeout period. Idle connections will be closed.</Message><RequestId>D88KJC301DEEVFEQ</RequestId><HostId>HX3vytjgqgJDYE4AlPQpFrhOEs0WDpnSbYeK2m2gxdxNnUCeNQmcJCzvLq4wTA0NXcI0CAQy7XI=</HostId></Error>; standard1-45183ad0002111edb97479c04c879a65/snapshots/sm_20220710171912UTC/me-13418-big-Data.db s3 upload: 400 Bad Request: <?xml version="1.0" encoding="UTF-8"?>
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > <Error><Code>RequestTimeout</Code><Message>Your socket connection to the server was not read from or written to within the timeout period. Idle connections will be closed.</Message><RequestId>D88KJC301DEEVFEQ</RequestId><HostId>HX3vytjgqgJDYE4AlPQpFrhOEs0WDpnSbYeK2m2gxdxNnUCeNQmcJCzvLq4wTA0NXcI0CAQy7XI=</HostId></Error>
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Start time:     10 Jul 22 17:19:08 UTC
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > End time:       10 Jul 22 19:46:55 UTC
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Duration:       2h27m46s
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Progress:       99%/0%
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Snapshot Tag:   sm_20220710171912UTC
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Datacenters:
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG >   - eu-west
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Errors:
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG >   - standard1-45183ad0002111edb97479c04c879a65/snapshots/sm_20220710171912UTC/me-13418-big-Data.db s3 upload: 400 Bad Request: <?xml version="1.0" encoding="UTF-8"?>
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > <Error><Code>RequestTimeout</Code><Message>Your socket connection to the server was not read from or written to within the timeout period. Idle connections will be closed.</Message><RequestId>D88KJC301DEEVFEQ</RequestId><HostId>HX3vytjgqgJDYE4AlPQpFrhOEs0WDpnSbYeK2m2gxdxNnUCeNQmcJCzvLq4wTA0NXcI0CAQy7XI=</HostId></Error>; standard1-45183ad0002111edb97479c04c879a65/snapshots/sm_20220710171912UTC/me-13418-big-Data.db s3 upload: 400 Bad Request: <?xml version="1.0" encoding="UTF-8"?>
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > <Error><Code>RequestTimeout</Code><Message>Your socket connection to the server was not read from or written to within the timeout period. Idle connections will be closed.</Message><RequestId>D88KJC301DEEVFEQ</RequestId><HostId>HX3vytjgqgJDYE4AlPQpFrhOEs0WDpnSbYeK2m2gxdxNnUCeNQmcJCzvLq4wTA0NXcI0CAQy7XI=</HostId></Error>
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG >
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > ╭────────────┬──────────┬─────────┬─────────┬──────────────┬──────────╮
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > │ Host       │ Progress │    Size │ Success │ Deduplicated │   Failed │
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > ├────────────┼──────────┼─────────┼─────────┼──────────────┼──────────┤
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > │ 10.0.0.111 │     100% │ 21.992G │ 21.992G │            0 │        0 │
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > │ 10.0.0.12  │     100% │ 21.511G │ 21.511G │            0 │        0 │
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > │ 10.0.0.195 │   99%/0% │ 22.922G │ 22.753G │            0 │ 172.830M │
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > │ 10.0.0.95  │     100% │ 29.205G │ 29.205G │            0 │        0 │
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > │ 10.0.1.141 │     100% │ 18.556G │ 18.556G │            0 │        0 │
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > │ 10.0.1.209 │     100% │ 22.173G │ 22.173G │            0 │        0 │
< t:2022-07-10 19:47:05,221 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > ╰────────────┴──────────┴─────────┴─────────┴──────────────┴──────────╯

the tasks retries:

< t:2022-07-10 19:57:00,007 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Run:            72d4a86c-008a-11ed-8c01-0ada645d1fc3
< t:2022-07-10 19:57:00,007 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Status:         RUNNING (indexing files)
< t:2022-07-10 19:57:00,007 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Start time:     10 Jul 22 19:56:55 UTC
< t:2022-07-10 19:57:00,007 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Duration:       4s
< t:2022-07-10 19:57:00,007 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Progress:       -
< t:2022-07-10 19:57:00,007 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Snapshot Tag:   sm_20220710171912UTC
< t:2022-07-10 19:57:00,007 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Datacenters:
< t:2022-07-10 19:57:00,007 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG >   - eu-west
< t:2022-07-10 19:57:00,007 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG >

and fails straight away:

< t:2022-07-10 19:57:10,339 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Run:            72d4a86c-008a-11ed-8c01-0ada645d1fc3
< t:2022-07-10 19:57:10,340 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Status:         ERROR (indexing files)
< t:2022-07-10 19:57:10,340 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Cause:          index
< t:2022-07-10 19:57:10,340 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG >  10.0.1.209: could not find any files
< t:2022-07-10 19:57:10,340 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG >  10.0.0.12: could not find any files
< t:2022-07-10 19:57:10,340 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG >  10.0.0.111: could not find any files
< t:2022-07-10 19:57:10,340 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG >  10.0.0.95: could not find any files
< t:2022-07-10 19:57:10,340 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG >  10.0.1.141: could not find any files
< t:2022-07-10 19:57:10,340 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Start time:     10 Jul 22 19:56:55 UTC
< t:2022-07-10 19:57:10,340 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > End time:       10 Jul 22 19:57:00 UTC
< t:2022-07-10 19:57:10,340 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Duration:       5s
< t:2022-07-10 19:57:10,340 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Progress:       -
< t:2022-07-10 19:57:10,340 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Snapshot Tag:   sm_20220710171912UTC
< t:2022-07-10 19:57:10,340 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Datacenters:
< t:2022-07-10 19:57:10,340 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG >   - eu-west

3020695:< t:2022-07-10 19:57:00,932 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Jul 10 19:57:00 longevity-tls-50gb-3d-master-monitor-node-fb8b36a7-1 scylla-manager[166
48]: {"L":"ERROR","T":"2022-07-10T19:57:00.927Z","N":"backup.index","M":"Indexing snapshot files failed see exact errors above","duration":"1.146242062s","_trace_id":"3Ug8flv9SBS_vuto
hyT1YA","S":"github.com/scylladb/go-log.Logger.log\n\tgithub.com/scylladb/go-log@v0.0.7/logger.go:101\ngithub.com/scylladb/go-log.Logger.Error\n\tgithub.com/scylladb/go-log@v0.0.7/log
ger.go:84\ngithub.com/scylladb/scylla-manager/v3/pkg/service/backup.(*worker).Index.func1\n\tgithub.com/scylladb/scylla-manager/v3/pkg/service/backup/worker_index.go:24\ngithub.com/sc
ylladb/scylla-manager/v3/pkg/service/backup.(*worker).Index\n\tgithub.com/scylladb/scylla-manager/v3/pkg/service/backup/worker_index.go:30\ngithub.com/scylladb/scylla-manager/v3/pkg/s
ervice/backup.(*Service).Backup.func5\n\tgithub.com/scylladb/scylla-manager/v3/pkg/service/backup/service.go:755\ngithub.com/scylladb/scylla-manager/v3/pkg/service/backup.(*Service).B
ackup.func11\n\tgithub.com/scylladb/scylla-manager/v3/pkg/service/backup/service.go:808\ngithub.com/scylladb/scylla-manager/v3/pkg/service/backup.(*Service).Backup\n\tgithub.com/scyll
adb/scylla-manager/v3/pkg/service/backup/service.go:812\ngithub.com/scylladb/scylla-manager/v3/pkg/service/backup.Runner.Run\n\tgithub.com/scylladb/scylla-manager/v3/pkg/service/backu
p/runner.go:26\ngithub.com/scylladb/scylla-manager/v3/pkg/service/scheduler.PolicyRunner.Run\n\tgithub.com/scylladb/scylla-manager/v3/pkg/service/scheduler/policy.go:32\ngithub.com/sc
ylladb/scylla-manager/v3/pkg/service/scheduler.(*Service).run\n\tgithub.com/scylladb/scylla-manager/v3/pkg/service/scheduler/service.go:432\ngithub.com/scylladb/scylla-manager/v3/pkg/
scheduler.(*Scheduler).asyncRun.func1\n\tgithub.com/scylladb/scylla-manager/v3/pkg/scheduler/scheduler.go:412"}
3020696:< t:2022-07-10 19:57:00,944 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Jul 10 19:57:00 longevity-tls-50gb-3d-master-monitor-node-fb8b36a7-1 scylla-manager[166
48]: {"L":"INFO","T":"2022-07-10T19:57:00.943Z","N":"scheduler.f2972720","M":"Run ended with ERROR","task":"backup/0c14e13b-7f7e-4298-83a5-adf564aacc29","status":"ERROR","cause":"inde
x: 10.0.1.209: could not find any files; 10.0.0.12: could not find any files; 10.0.0.111: could not find any files; 10.0.0.95: could not find any files; 10.0.1.141: could not find any
 files","duration":"5.901123544s","_trace_id":"3Ug8flv9SBS_vutohyT1YA"}

Logs:

• Restore Monitor Stack command: $ hydra investigate show-monitor fb8b36a7-c818-4b0b-8ae3-f3ee2cafa53a

• Restore monitor on AWS instance using Jenkins job

• Show all stored logs command: $ hydra investigate show-logs fb8b36a7-c818-4b0b-8ae3-f3ee2cafa53a

• db-cluster-fb8b36a7.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/fb8b36a7-c818-4b0b-8ae3-f3ee2cafa53a/20220713_081619/db-cluster-fb8b36a7.tar.gz

• monitor-set-fb8b36a7.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/fb8b36a7-c818-4b0b-8ae3-f3ee2cafa53a/20220713_081619/monitor-set-fb8b36a7.tar.gz

• loader-set-fb8b36a7.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/fb8b36a7-c818-4b0b-8ae3-f3ee2cafa53a/20220713_081619/loader-set-fb8b36a7.tar.gz

• normal-fb8b36a7.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/fb8b36a7-c818-4b0b-8ae3-f3ee2cafa53a/20220713_081619/normal-fb8b36a7.log.tar.gz

• summary-fb8b36a7.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/fb8b36a7-c818-4b0b-8ae3-f3ee2cafa53a/20220713_081619/summary-fb8b36a7.log.tar.gz

• events-fb8b36a7.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/fb8b36a7-c818-4b0b-8ae3-f3ee2cafa53a/20220713_081619/events-fb8b36a7.log.tar.gz

• output-fb8b36a7.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/fb8b36a7-c818-4b0b-8ae3-f3ee2cafa53a/20220713_081619/output-fb8b36a7.log.tar.gz

• debug-fb8b36a7.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/fb8b36a7-c818-4b0b-8ae3-f3ee2cafa53a/20220713_081619/debug-fb8b36a7.log.tar.gz

• sct-fb8b36a7.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/fb8b36a7-c818-4b0b-8ae3-f3ee2cafa53a/20220713_081619/sct-fb8b36a7.log.tar.gz

• error-fb8b36a7.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/fb8b36a7-c818-4b0b-8ae3-f3ee2cafa53a/20220713_081619/error-fb8b36a7.log.tar.gz

• critical-fb8b36a7.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/fb8b36a7-c818-4b0b-8ae3-f3ee2cafa53a/20220713_081619/critical-fb8b36a7.log.tar.gz

• raw_events-fb8b36a7.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/fb8b36a7-c818-4b0b-8ae3-f3ee2cafa53a/20220713_081619/raw_events-fb8b36a7.log.tar.gz

• warning-fb8b36a7.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/fb8b36a7-c818-4b0b-8ae3-f3ee2cafa53a/20220713_081619/warning-fb8b36a7.log.tar.gz

• email_data-fb8b36a7.json.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/fb8b36a7-c818-4b0b-8ae3-f3ee2cafa53a/20220713_081619/email_data-fb8b36a7.json.tar.gz

• argus-fb8b36a7.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/fb8b36a7-c818-4b0b-8ae3-f3ee2cafa53a/20220713_081619/argus-fb8b36a7.log.tar.gz

• left_processes-fb8b36a7.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/fb8b36a7-c818-4b0b-8ae3-f3ee2cafa53a/20220713_081619/left_processes-fb8b36a7.log.tar.gz

Jenkins job URL

[fruch]

happens again a few times:

timeout on uploading some of the snapshot from node-1, but the retries failing on getting the indexs

< t:2022-07-16 01:29:47,380 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Run:            bfbd6f4a-04a6-11ed-a7a3-0a1c0579966b
< t:2022-07-16 01:29:47,380 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Status:         ERROR (indexing files)
< t:2022-07-16 01:29:47,380 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Cause:          index
< t:2022-07-16 01:29:47,380 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG >  10.0.2.140: could not find any files
< t:2022-07-16 01:29:47,380 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG >  10.0.1.13: could not find any files
< t:2022-07-16 01:29:47,380 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG >  10.0.1.123: could not find any files
< t:2022-07-16 01:29:47,381 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG >  10.0.3.40: could not find any files
< t:2022-07-16 01:29:47,381 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG >  10.0.1.101: could not find any files
< t:2022-07-16 01:29:47,381 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Start time:     16 Jul 22 01:29:34 UTC
< t:2022-07-16 01:29:47,381 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > End time:       16 Jul 22 01:29:39 UTC
< t:2022-07-16 01:29:47,381 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Duration:       5s
< t:2022-07-16 01:29:47,381 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Progress:       -
< t:2022-07-16 01:29:47,381 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Snapshot Tag:   sm_20220715220558UTC
< t:2022-07-16 01:29:47,381 f:base.py         l:228  c:RemoteLibSSH2CmdRunner p:DEBUG > Datacenters:

Installation details

Kernel Version: 5.15.0-1015-aws
Scylla version (or git commit hash): 5.1.dev-20220714.98aa3ec99b9b with build-id e27b38549f89da2f016567fc243c8404a6460ebc
Cluster size: 6 nodes (i3.4xlarge)

Scylla Nodes used in this run:

• longevity-tls-50gb-3d-master-db-node-8dce4a7e-9 (34.244.142.219 | 10.0.1.13) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-8dce4a7e-8 (34.252.229.242 | 10.0.3.40) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-8dce4a7e-7 (3.250.124.209 | 10.0.1.101) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-8dce4a7e-6 (34.244.161.163 | 10.0.0.77) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-8dce4a7e-5 (54.75.84.148 | 10.0.2.140) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-8dce4a7e-4 (34.244.80.175 | 10.0.1.123) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-8dce4a7e-3 (3.250.10.77 | 10.0.3.184) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-8dce4a7e-2 (34.243.250.187 | 10.0.3.232) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-8dce4a7e-1 (34.246.186.17 | 10.0.1.31) (shards: 14)

OS / Image: ami-08cbc2649e53039f8 (aws: eu-west-1)

Test: longevity-50gb-3days
Test id: 8dce4a7e-e326-4373-bd48-e772fbfbe457
Test name: scylla-master/longevity/longevity-50gb-3days
Test config file(s):

• longevity-50GB-3days-authorization-and-tls-ssl.yaml

• Restore Monitor Stack command: $ hydra investigate show-monitor 8dce4a7e-e326-4373-bd48-e772fbfbe457

• Restore monitor on AWS instance using Jenkins job

• Show all stored logs command: $ hydra investigate show-logs 8dce4a7e-e326-4373-bd48-e772fbfbe457

Logs:

No logs captured during this run.

Jenkins job URL

[fruch]

@mmatczuk wrote on slack:

This is “common” case when Scylla is overloaded, if that fails we pretty much can do nothing because all the retries timeouts and such are in place

That's might explain the initial timeout that fails the task, but retry fails from a whole different reason, looking for files which aren't there anymore (since they uploaded already, I think...), which has nothing todo with load on the node.

[ShlomiBalalis]

Occurred with 2.6.3 as well (cloud run):

Installation details

Kernel Version: 5.13.0-1031-aws
Scylla version (or git commit hash): 2021.1.12-20220620.e23889f17 with build-id 00bd36a6a55a00508aad03c6e9a11932a6c3b1a6
Cluster size: 6 nodes (i3.large)

Scylla Nodes used in this run:
No resources left at the end of the run

OS / Image: ami-0763124bdca4e1fe3 (aws: eu-west-1)

Test: scylla-cloud-operations-24h-aws
Test id: 93acda10-4dca-4275-8d16-05e7eec8ba8d
Test name: siren-tests/longevity-tests/scylla-cloud-operations-24h-aws
Test config file(s):

• scylla_cloud_defaults.yaml

Issue description

one of the backups failed consistantly (as in, in all of the 3 retries, too):

< t:2022-07-17 00:43:57,931 f:base.py         l:142  c:RemoteCmdRunner      p:DEBUG > Command "/opt/scylla/scylla-cloud -c /opt/scylla/scylla-dbaas.yml cluster manager sctool --cluster-id 20406 --    task progress backup/576ed931-139f-498d-89d8-d3d7b7587308" finished with status 0
< t:2022-07-17 00:43:57,931 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > sctool output: Arguments: -K 'keyspace1' -L AWS_EU_WEST_1:s3:scylla-cloud-backup-20406-20509-sq954o
< t:2022-07-17 00:43:57,931 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > Status:           ERROR (indexing files)
< t:2022-07-17 00:43:57,931 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > Cause:            index
< t:2022-07-17 00:43:57,931 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG >  172.19.228.197: could not find any files
< t:2022-07-17 00:43:57,931 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG >  172.19.228.235: could not find any files
< t:2022-07-17 00:43:57,931 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG >  172.19.230.164: could not find any files
< t:2022-07-17 00:43:57,931 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG >  172.19.229.59: could not find any files
< t:2022-07-17 00:43:57,931 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > Start time:       17 Jul 22 00:43:28 UTC
< t:2022-07-17 00:43:57,931 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > End time: 17 Jul 22 00:43:37 UTC
< t:2022-07-17 00:43:57,931 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > Duration: 9s
< t:2022-07-17 00:43:57,931 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > Progress: -
< t:2022-07-17 00:43:57,931 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > Snapshot Tag:     sm_20220716151801UTC
< t:2022-07-17 00:43:57,931 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > Datacenters:      
< t:2022-07-17 00:43:57,931 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG >   - AWS_EU_WEST_1

A different backup that ran later in the longevity passed with no issue:

< t:2022-07-17 12:04:36,361 f:base.py         l:142  c:RemoteCmdRunner      p:DEBUG > Command "/opt/scylla/scylla-cloud -c /opt/scylla/scylla-dbaas.yml cluster manager sctool --cluster-id 20406 --    task progress backup/f7ee6211-4322-424b-b3c7-7696c727cbda" finished with status 0
< t:2022-07-17 12:04:36,361 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > sctool output: Arguments: -L AWS_EU_WEST_1:s3:scylla-cloud-backup-20406-20509-sq954o
< t:2022-07-17 12:04:36,361 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > Status:           DONE
< t:2022-07-17 12:04:36,361 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > Start time:       17 Jul 22 12:04:16 UTC
< t:2022-07-17 12:04:36,361 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > End time: 17 Jul 22 12:04:35 UTC
< t:2022-07-17 12:04:36,361 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > Duration: 19s
< t:2022-07-17 12:04:36,361 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > Progress: 100%
< t:2022-07-17 12:04:36,361 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > Snapshot Tag:     sm_20220717013739UTC
< t:2022-07-17 12:04:36,361 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > Datacenters:      
< t:2022-07-17 12:04:36,361 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG >   - AWS_EU_WEST_1
< t:2022-07-17 12:04:36,361 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > 
< t:2022-07-17 12:04:36,361 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > ╭────────────────┬──────────┬──────────┬──────────┬──────────────┬────────╮
< t:2022-07-17 12:04:36,361 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > │ Host           │ Progress │     Size │  Success │ Deduplicated │ Failed │
< t:2022-07-17 12:04:36,361 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > ├────────────────┼──────────┼──────────┼──────────┼──────────────┼────────┤
< t:2022-07-17 12:04:36,361 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > │ 172.19.228.197 │     100% │ 44.87GiB │ 44.87GiB │       340MiB │     0B │
< t:2022-07-17 12:04:36,361 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > │ 172.19.228.235 │     100% │ 56.02GiB │ 56.02GiB │       508MiB │     0B │
< t:2022-07-17 12:04:36,361 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > │ 172.19.229.177 │     100% │ 56.60GiB │ 56.60GiB │       366MiB │     0B │
< t:2022-07-17 12:04:36,361 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > │ 172.19.229.59  │     100% │ 47.12GiB │ 47.12GiB │     46.63GiB │     0B │
< t:2022-07-17 12:04:36,361 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > │ 172.19.230.164 │     100% │ 52.66GiB │ 52.66GiB │        62MiB │     0B │
< t:2022-07-17 12:04:36,361 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > │ 172.19.230.93  │     100% │ 41.35GiB │ 41.35GiB │       299MiB │     0B │
< t:2022-07-17 12:04:36,361 f:cli.py          l:1064 c:sdcm.mgmt.cli        p:DEBUG > ╰────────────────┴──────────┴──────────┴──────────┴──────────────┴────────╯

• Restore Monitor Stack command: $ hydra investigate show-monitor 93acda10-4dca-4275-8d16-05e7eec8ba8d
• Restore monitor on AWS instance using Jenkins job
• Show all stored logs command: $ hydra investigate show-logs 93acda10-4dca-4275-8d16-05e7eec8ba8d

Logs:

• db-cluster-93acda10.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/93acda10-4dca-4275-8d16-05e7eec8ba8d/20220717_122429/db-cluster-93acda10.tar.gz
• monitor-set-93acda10.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/93acda10-4dca-4275-8d16-05e7eec8ba8d/20220717_122429/monitor-set-93acda10.tar.gz
• siren-manager-set-93acda10.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/93acda10-4dca-4275-8d16-05e7eec8ba8d/20220717_122429/siren-manager-set-93acda10.tar.gz
• loader-set-93acda10.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/93acda10-4dca-4275-8d16-05e7eec8ba8d/20220717_122429/loader-set-93acda10.tar.gz
• sct-runner-93acda10.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/93acda10-4dca-4275-8d16-05e7eec8ba8d/20220717_122429/sct-runner-93acda10.tar.gz

Jenkins job URL

[juliayakovlev]

Reproduced with 5.1.dev-20220719.274691f45e3d

Installation details

Kernel Version: 5.15.0-1015-aws
Scylla version (or git commit hash): 5.1.dev-20220719.274691f45e3d with build-id 8bedc6db4fe1f245a70c67d2d2135b056a361a78
Cluster size: 6 nodes (i3.4xlarge)

Scylla Nodes used in this run:

• longevity-tls-50gb-3d-master-db-node-18f65c02-9 (52.50.223.37 | 10.0.2.20) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-18f65c02-8 (34.250.158.91 | 10.0.3.100) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-18f65c02-7 (3.250.24.106 | 10.0.1.161) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-18f65c02-6 (54.170.138.198 | 10.0.2.190) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-18f65c02-5 (34.245.58.121 | 10.0.3.23) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-18f65c02-4 (52.17.191.16 | 10.0.0.236) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-18f65c02-3 (34.244.86.218 | 10.0.3.238) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-18f65c02-2 (54.171.127.68 | 10.0.3.106) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-18f65c02-15 (34.247.183.150 | 10.0.0.35) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-18f65c02-14 (176.34.148.131 | 10.0.2.137) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-18f65c02-13 (54.75.58.7 | 10.0.1.26) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-18f65c02-12 (52.17.235.246 | 10.0.3.173) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-18f65c02-11 (54.75.98.54 | 10.0.1.206) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-18f65c02-10 (3.250.42.138 | 10.0.3.105) (shards: 14)
• longevity-tls-50gb-3d-master-db-node-18f65c02-1 (54.154.115.110 | 10.0.1.82) (shards: 14)

OS / Image: ami-02742dcbeb0063751 (aws: eu-west-1)

Test: longevity-50gb-3days
Test id: 18f65c02-9d8e-4183-a79f-659995a96759
Test name: scylla-master/longevity/longevity-50gb-3days
Test config file(s):

• longevity-50GB-3days-authorization-and-tls-ssl.yaml

Issue description

>>>>>>>
Your description here...
<<<<<<<

• Restore Monitor Stack command: $ hydra investigate show-monitor 18f65c02-9d8e-4183-a79f-659995a96759
• Restore monitor on AWS instance using Jenkins job
• Show all stored logs command: $ hydra investigate show-logs 18f65c02-9d8e-4183-a79f-659995a96759

Logs:

• db-cluster-18f65c02.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/18f65c02-9d8e-4183-a79f-659995a96759/20220724_194120/db-cluster-18f65c02.tar.gz
• monitor-set-18f65c02.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/18f65c02-9d8e-4183-a79f-659995a96759/20220724_194120/monitor-set-18f65c02.tar.gz
• loader-set-18f65c02.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/18f65c02-9d8e-4183-a79f-659995a96759/20220724_194120/loader-set-18f65c02.tar.gz
• normal-18f65c02.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/18f65c02-9d8e-4183-a79f-659995a96759/20220724_194120/normal-18f65c02.log.tar.gz
• summary-18f65c02.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/18f65c02-9d8e-4183-a79f-659995a96759/20220724_194120/summary-18f65c02.log.tar.gz
• events-18f65c02.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/18f65c02-9d8e-4183-a79f-659995a96759/20220724_194120/events-18f65c02.log.tar.gz
• output-18f65c02.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/18f65c02-9d8e-4183-a79f-659995a96759/20220724_194120/output-18f65c02.log.tar.gz
• debug-18f65c02.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/18f65c02-9d8e-4183-a79f-659995a96759/20220724_194120/debug-18f65c02.log.tar.gz
• sct-18f65c02.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/18f65c02-9d8e-4183-a79f-659995a96759/20220724_194120/sct-18f65c02.log.tar.gz
• error-18f65c02.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/18f65c02-9d8e-4183-a79f-659995a96759/20220724_194120/error-18f65c02.log.tar.gz
• critical-18f65c02.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/18f65c02-9d8e-4183-a79f-659995a96759/20220724_194120/critical-18f65c02.log.tar.gz
• raw_events-18f65c02.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/18f65c02-9d8e-4183-a79f-659995a96759/20220724_194120/raw_events-18f65c02.log.tar.gz
• warning-18f65c02.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/18f65c02-9d8e-4183-a79f-659995a96759/20220724_194120/warning-18f65c02.log.tar.gz
• email_data-18f65c02.json.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/18f65c02-9d8e-4183-a79f-659995a96759/20220724_194120/email_data-18f65c02.json.tar.gz
• argus-18f65c02.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/18f65c02-9d8e-4183-a79f-659995a96759/20220724_194120/argus-18f65c02.log.tar.gz
• left_processes-18f65c02.log.tar.gz - https://cloudius-jenkins-test.s3.amazonaws.com/18f65c02-9d8e-4183-a79f-659995a96759/20220724_194120/left_processes-18f65c02.log.tar.gz

Jenkins job URL