Frequent failures in multi-datacenter bootstrap: `the topology coordinator rejected request to join the cluster: request canceled because some required nodes are dead`

[rzetelskik]

With ScyllaDB Operator, we are observing very high frequency of failed bootstraps of multi-datacenter clusters with the following error message. In the following example this is coming from node europe-west4-a-0 (c1af46c6-4f5a-4265-916e-10058fef1d0d, 10.43.0.15).

2025-08-07T16:03:20.308728619Z INFO  2025-08-07 16:03:20,308 [shard 0:main] init - join cluster
2025-08-07T16:03:20.308752839Z INFO  2025-08-07 16:03:20,308 [shard 0:strm] storage_service - entering STARTING mode
2025-08-07T16:03:20.332395948Z INFO  2025-08-07 16:03:20,332 [shard 0:strm] storage_service - Found group 0 with ID 48bf3021-73a6-11f0-afbf-4cd9f5c8bdd5, with leader of ID 95f6ce46-7a2d-4654-820d-f174e1aff199 and IP 10.35.64.63
2025-08-07T16:03:20.339846987Z INFO  2025-08-07 16:03:20,339 [shard 0:strm] storage_service - Will join existing cluster in raft topology operations mode
2025-08-07T16:03:20.339862577Z INFO  2025-08-07 16:03:20,339 [shard 0:strm] storage_service - Loading persisted peers into the gossiper
2025-08-07T16:03:20.339874507Z INFO  2025-08-07 16:03:20,339 [shard 0:strm] storage_service - initial_contact_nodes={10.35.64.63, 10.27.225.14}, loaded_endpoints=[], loaded_peer_features=0
2025-08-07T16:03:20.339942477Z INFO  2025-08-07 16:03:20,339 [shard 0:strm] storage_service - Performing gossip shadow round
2025-08-07T16:03:20.339949187Z INFO  2025-08-07 16:03:20,339 [shard 0:strm] gossip - Gossip shadow round started with nodes={10.35.64.63, 10.27.225.14}
2025-08-07T16:03:20.355357267Z INFO  2025-08-07 16:03:20,355 [shard 0:strm] gossip - Gossip shadow round finished with nodes_talked={10.27.225.14, 10.35.64.63}
...
2025-08-07T16:03:20.357548926Z INFO  2025-08-07 16:03:20,357 [shard 0:strm] gossip - failure_detector_loop: Started main loop
2025-08-07T16:03:20.357575616Z INFO  2025-08-07 16:03:20,357 [shard 0:strm] raft_group0 - setup_group0: joining group 0...
2025-08-07T16:03:20.357632916Z INFO  2025-08-07 16:03:20,357 [shard 0:strm] raft_group0 - server c1af46c6-4f5a-4265-916e-10058fef1d0d found no local group 0. Discovering...
2025-08-07T16:03:20.365309406Z INFO  2025-08-07 16:03:20,365 [shard 0:strm] raft_group0 - server c1af46c6-4f5a-4265-916e-10058fef1d0d found group 0 with group id 48bf3021-73a6-11f0-afbf-4cd9f5c8bdd5, leader 95f6ce46-7a2d-4654-820d-f174e1aff199
2025-08-07T16:03:20.365323576Z INFO  2025-08-07 16:03:20,365 [shard 0:strm] raft_topology - join: sending the join request to 10.35.64.63
2025-08-07T16:03:20.412128844Z INFO  2025-08-07 16:03:20,412 [shard 0:strm] raft_topology - join: request to join placed, waiting for the response from the topology coordinator
2025-08-07T16:03:20.415015544Z INFO  2025-08-07 16:03:20,414 [shard 0:strm] raft_group0 - Server c1af46c6-4f5a-4265-916e-10058fef1d0d is starting group 0 with id 48bf3021-73a6-11f0-afbf-4cd9f5c8bdd5
2025-08-07T16:03:20.416326514Z INFO  2025-08-07 16:03:20,416 [shard 0:strm] raft_group0 - Detected snapshot with index=0, id=1e2ac6f8-906a-4338-981c-5dc1858ba13a, triggering new snapshot
2025-08-07T16:03:20.416340464Z WARN  2025-08-07 16:03:20,416 [shard 0:strm] raft_group0 - Could not create new snapshot, there are no entries applied
...
2025-08-07T16:03:22.433275447Z ERROR 2025-08-07 16:03:22,433 [shard 0:main] init - Startup failed: std::runtime_error (the topology coordinator rejected request to join the cluster: request canceled because some required nodes are dead)
2025-08-07T16:03:22.495580624Z 2025-08-07 16:03:22,495 WARN exited: scylla (exit status 1; not expected)
2025-08-07T16:03:22.495598024Z 2025-08-07 16:03:22,495 WARN exited: scylla (exit status 1; not expected)

The process then restarts and unsuccessfully tries to join the cluster again, but hangs.

2025-08-07T16:03:24.879468091Z INFO  2025-08-07 16:03:24,879 [shard 0:main] init - join cluster
2025-08-07T16:03:24.879471920Z INFO  2025-08-07 16:03:24,879 [shard 0:strm] storage_service - entering STARTING mode
...
(no further related logs)

Meanwhile, the logs from europe-west1-a-0 (95f6ce46-7a2d-4654-820d-f174e1aff199, 10.35.64.63):

2025-08-07T16:03:20.369190138Z INFO  2025-08-07 16:03:20,369 [shard 0: gms] raft_topology - received request to join from host_id: c1af46c6-4f5a-4265-916e-10058fef1d0d
...
2025-08-07T16:03:20.408394557Z INFO  2025-08-07 16:03:20,408 [shard 0: gms] raft_topology - placed join request for c1af46c6-4f5a-4265-916e-10058fef1d0d
...
2025-08-07T16:03:21.407623878Z INFO  2025-08-07 16:03:21,407 [shard 0: gms] gossip - InetAddress c1af46c6-4f5a-4265-916e-10058fef1d0d/10.43.0.15 is now UP, status = UNKNOWN
2025-08-07T16:03:21.427971408Z INFO  2025-08-07 16:03:21,427 [shard 0: gms] gossip - Removed endpoint c1af46c6-4f5a-4265-916e-10058fef1d0d
2025-08-07T16:03:21.428001868Z INFO  2025-08-07 16:03:21,427 [shard 0: gms] gossip - InetAddress c1af46c6-4f5a-4265-916e-10058fef1d0d/c1af46c6-4f5a-4265-916e-10058fef1d0d is now DOWN, status = UNKNOWN
2025-08-07T16:03:21.428050228Z INFO  2025-08-07 16:03:21,427 [shard 0: gms] gossip - Finished to force remove node c1af46c6-4f5a-4265-916e-10058fef1d0d

We've occasionally observed this in 2025.1.2 (least frequently) and 2025.1.5, but it became much more prevalent in 2025.2.1, with roughly 80-90% of multi-datacenter clusters created in our tests failing on bootstrap with this error.

I'd like to figure out the cause behind this scenario and so I'll appreciate any help in debugging this.
Is this expected that the node can't join the cluster having encountered this error?
Is there something we can do to prevent this?

In case more verbose logs are required to debug this, please let me know which services should have the log level raised.

---

Logs and supplementary info (nodetool status, gossipinfo where applicable) can be found here:
europe-west1-a-0: https://gcsweb.scylla-operator.scylladb.com/gcs/scylla-operator-prow/logs/ci-scylla-operator-latest-e2e-gke-multi-datacenter-parallel/1953480005082157056/artifacts/e2e/workers/europe-west1/namespaces/e2e-test-scylladbcluster-nqjbc-c9nsb-2qnap/pods/basic-vswwm-europe-west1-europe-west1-a-0/
europe-west-1-b-0: https://gcsweb.scylla-operator.scylladb.com/gcs/scylla-operator-prow/logs/ci-scylla-operator-latest-e2e-gke-multi-datacenter-parallel/1953480005082157056/artifacts/e2e/workers/europe-west1/namespaces/e2e-test-scylladbcluster-nqjbc-c9nsb-2qnap/pods/basic-vswwm-europe-west1-europe-west1-b-0/
europe-west-1-c-0: https://gcsweb.scylla-operator.scylladb.com/gcs/scylla-operator-prow/logs/ci-scylla-operator-latest-e2e-gke-multi-datacenter-parallel/1953480005082157056/artifacts/e2e/workers/europe-west1/namespaces/e2e-test-scylladbcluster-nqjbc-c9nsb-2qnap/pods/basic-vswwm-europe-west1-europe-west1-c-0/

europe-west-3-a-0: https://gcsweb.scylla-operator.scylladb.com/gcs/scylla-operator-prow/logs/ci-scylla-operator-latest-e2e-gke-multi-datacenter-parallel/1953480005082157056/artifacts/e2e/workers/europe-west3/namespaces/e2e-test-scylladbcluster-nqjbc-c9nsb-2a92t/pods/basic-vswwm-europe-west3-europe-west3-a-0/
europe-west-3-b-0: https://gcsweb.scylla-operator.scylladb.com/gcs/scylla-operator-prow/logs/ci-scylla-operator-latest-e2e-gke-multi-datacenter-parallel/1953480005082157056/artifacts/e2e/workers/europe-west3/namespaces/e2e-test-scylladbcluster-nqjbc-c9nsb-2a92t/pods/basic-vswwm-europe-west3-europe-west3-b-0/
europe-west-3-c-0: https://gcsweb.scylla-operator.scylladb.com/gcs/scylla-operator-prow/logs/ci-scylla-operator-latest-e2e-gke-multi-datacenter-parallel/1953480005082157056/artifacts/e2e/workers/europe-west3/namespaces/e2e-test-scylladbcluster-nqjbc-c9nsb-2a92t/pods/basic-vswwm-europe-west3-europe-west3-c-0/

europe-west4-a-0: https://gcsweb.scylla-operator.scylladb.com/gcs/scylla-operator-prow/logs/ci-scylla-operator-latest-e2e-gke-multi-datacenter-parallel/1953480005082157056/artifacts/e2e/workers/europe-west4/namespaces/e2e-test-scylladbcluster-nqjbc-c9nsb-33q49/pods/basic-vswwm-europe-west4-europe-west4-a-0/

[czeslavo]

Update from the Operator team side: we're still experiencing the same issue with ScyllaDB 2025.3.0 in the Operator E2E tests (see scylladb/scylla-operator#2923). Could you please help us with debugging this? It's blocking us from supporting ScyllaDB >=2025.2.0.

[mykaul]

@emdroid - please assign for someone to take a look.

[mykaul]

@emdroid - please assign for someone to take a look.

@emdroid ?!

[emdroid]

@gleb-cloudius Could you have a look at this one? What's interesting is that it seems to be increasing frequency with 2025.2 (compared to 2025.1) where the gossiper host id changes were introduced - so it might or might not be connected to these.

For what I can see is that the topology coordinator thinks that some nodes are down (in which case it will not allow topology changes indeed), but the question is why (and if the nodes are really down).

[gleb-cloudius]

Looking at the logs I see that the topology coordinator sees node a59bda6b-1141-4e96-ae7e-983d99917f69 as dead during bootstrap operation:

2025-08-07T16:03:20.402027094Z WARN  2025-08-07 16:03:20,401 [shard 0: gms] raft_topology - topology coordinator: cancel request queue because no request can proceed. Dead nodes: {a59bda6b-1141-4e96-ae7e-983d99917f69}
2025-08-07T16:03:21.401835480Z INFO  2025-08-07 16:03:21,401 [shard 0: gms] raft_topology - updating topology state: cancel all topology requests
2025-08-07T16:03:21.407121871Z INFO  2025-08-07 16:03:21,407 [shard 0: gms] gossip - Removed endpoint c1af46c6-4f5a-4265-916e-10058fef1d0d
2025-08-07T16:03:21.407138391Z INFO  2025-08-07 16:03:21,407 [shard 0: gms] gossip - Finished to force remove node c1af46c6-4f5a-4265-916e-10058fef1d0d
2025-08-07T16:03:21.407452451Z INFO  2025-08-07 16:03:21,407 [shard 0: gms] gossip - Node c1af46c6-4f5a-4265-916e-10058fef1d0d is not in endpoint_state_map anymore
2025-08-07T16:03:21.511890125Z INFO  2025-08-07 16:03:21,511 [shard 0: gms] group0_voter_handler - Node a59bda6b-1141-4e96-ae7e-983d99917f69 is not alive and non-voter, skipping
2025-08-07T16:03:40.174735684Z INFO  2025-08-07 16:03:40,174 [shard 0:main] raft_group_registry - marking Raft server a59bda6b-1141-4e96-ae7e-983d99917f69 as alive for raft groups
2025-08-07T16:03:41.936611173Z INFO  2025-08-07 16:03:41,936 [shard 0: gms] gossip - Node a59bda6b-1141-4e96-ae7e-983d99917f69 has restarted, now UP, status = NORMAL
2025-08-07T16:03:44.252580508Z WARN  2025-08-07 16:03:44,252 [shard 0: gms] gossip - Fail to send EchoMessage to a59bda6b-1141-4e96-ae7e-983d99917f69/10.35.64.100: seastar::rpc::closed_error (connection is closed)
2025-08-07T16:03:44.944915175Z INFO  2025-08-07 16:03:44,944 [shard 0: gms] gossip - InetAddress a59bda6b-1141-4e96-ae7e-983d99917f69/10.35.64.100 is now UP, status = NORMAL

So, as you can see the leader mark a59bda6b-1141-4e96-ae7e-983d99917f69 alive after the operation is already cancelled. It also claims that the node restarted Node a59bda6b-1141-4e96-ae7e-983d99917f69 has restarted. Looking at the a59bda6b-1141-4e96-ae7e-983d99917f69 logs it indeed restarted shortly before:

basic-vswwm-europe-west1-europe-west1-c-0/scylla.current:2025-08-07T16:02:07.631789648Z INFO  2025-08-07 16:02:07,631 [shard 0:main] init - Scylla version 2025.2.1-0.20250716.7bb43d812e1c with build-id fa241ccfab41c76a524dd8d44d1106db0c6b6dca starting ...
basic-vswwm-europe-west1-europe-west1-c-0/scylla.current:2025-08-07T16:02:23.747492631Z INFO  2025-08-07 16:02:23,747 [shard 0:main] init - Scylla version 2025.2.1-0.20250716.7bb43d812e1c initialization completed.

Looking at all the nodes starting time, it looks like the entire cluster was rolling restarted before joining a new node actually. Why?

basic-vswwm-europe-west3-europe-west3-c-0/scylla.current:2025-08-07T15:56:06.391279972Z INFO  2025-08-07 15:56:06,391 [shard 0:main] init - Scylla version 2025.2.1-0.20250716.7bb43d812e1c with build-id fa241ccfab41c76a524dd8d44d1106db0c6b6dca starting ...
basic-vswwm-europe-west3-europe-west3-c-0/scylla.current:2025-08-07T15:56:06.546654933Z INFO  2025-08-07 15:56:06,546 [shard 0:main] init - Setting local host id to 2905cf1e-dcdc-4ba6-9f53-c69cc5227437
basic-vswwm-europe-west3-europe-west3-c-0/scylla.current:2025-08-07T15:56:12.329922282Z INFO  2025-08-07 15:56:12,329 [shard 0:main] init - Scylla version 2025.2.1-0.20250716.7bb43d812e1c initialization completed.
basic-vswwm-europe-west3-europe-west3-b-0/scylla.current:2025-08-07T15:54:55.893092761Z INFO  2025-08-07 15:54:55,892 [shard 0:main] init - Scylla version 2025.2.1-0.20250716.7bb43d812e1c with build-id fa241ccfab41c76a524dd8d44d1106db0c6b6dca starting ...
basic-vswwm-europe-west3-europe-west3-b-0/scylla.current:2025-08-07T15:54:56.046296708Z INFO  2025-08-07 15:54:56,046 [shard 0:main] init - Setting local host id to 3c5ecd4c-7ee2-4973-bd1f-1bffe735acb3
basic-vswwm-europe-west3-europe-west3-b-0/scylla.current:2025-08-07T15:55:00.611679574Z INFO  2025-08-07 15:55:00,608 [shard 0:main] init - Scylla version 2025.2.1-0.20250716.7bb43d812e1c initialization completed.
basic-vswwm-europe-west3-europe-west3-a-0/scylla.current:2025-08-07T15:53:50.898398591Z INFO  2025-08-07 15:53:50,898 [shard 0:main] init - Scylla version 2025.2.1-0.20250716.7bb43d812e1c with build-id fa241ccfab41c76a524dd8d44d1106db0c6b6dca starting ...
basic-vswwm-europe-west3-europe-west3-a-0/scylla.current:2025-08-07T15:53:51.045297990Z INFO  2025-08-07 15:53:51,045 [shard 0:main] init - Setting local host id to b01aba0d-3726-4581-b7cb-cdf74c7e0bdb
basic-vswwm-europe-west3-europe-west3-a-0/scylla.current:2025-08-07T15:53:55.294815221Z INFO  2025-08-07 15:53:55,294 [shard 0:main] init - Scylla version 2025.2.1-0.20250716.7bb43d812e1c initialization completed.
basic-vswwm-europe-west1-europe-west1-c-0/scylla.current:2025-08-07T16:02:07.631789648Z INFO  2025-08-07 16:02:07,631 [shard 0:main] init - Scylla version 2025.2.1-0.20250716.7bb43d812e1c with build-id fa241ccfab41c76a524dd8d44d1106db0c6b6dca starting ...
basic-vswwm-europe-west1-europe-west1-c-0/scylla.current:2025-08-07T16:02:23.747492631Z INFO  2025-08-07 16:02:23,747 [shard 0:main] init - Scylla version 2025.2.1-0.20250716.7bb43d812e1c initialization completed.
basic-vswwm-europe-west1-europe-west1-b-0/scylla.current:2025-08-07T15:59:47.209007636Z INFO  2025-08-07 15:59:47,208 [shard 0:main] init - Scylla version 2025.2.1-0.20250716.7bb43d812e1c with build-id fa241ccfab41c76a524dd8d44d1106db0c6b6dca starting ...
basic-vswwm-europe-west1-europe-west1-b-0/scylla.current:2025-08-07T16:00:03.340763963Z INFO  2025-08-07 16:00:03,340 [shard 0:main] init - Scylla version 2025.2.1-0.20250716.7bb43d812e1c initialization completed.
basic-vswwm-europe-west1-europe-west1-a-0/scylla.current:2025-08-07T15:57:34.738639240Z INFO  2025-08-07 15:57:34,738 [shard 0:main] init - Scylla version 2025.2.1-0.20250716.7bb43d812e1c with build-id fa241ccfab41c76a524dd8d44d1106db0c6b6dca starting ...
basic-vswwm-europe-west1-europe-west1-a-0/scylla.current:2025-08-07T15:57:45.921482123Z INFO  2025-08-07 15:57:45,921 [shard 0:main] init - Scylla version 2025.2.1-0.20250716.7bb43d812e1c initialization completed.

The only strange thing I see is that more than a minute passed between the restart and the topology coordinator marking the node as alive, which is strange, and even then it failed to connect to the node straight away (as gossip - Fail to send EchoMessage indicates), but why operator even tries to boot a new node without checking cluster status? As far as I see node a59bda6b-1141-4e96-ae7e-983d99917f69 is considered to be down by all nodes in the cluster when the bootstrap starts:

basic-vswwm-europe-west3-europe-west3-c-0/scylla.current:2025-08-07T16:01:25.427871898Z INFO  2025-08-07 16:01:25,427 [shard 0: gms] gossip - InetAddress a59bda6b-1141-4e96-ae7e-983d99917f69 is now DOWN, status = shutdown
basic-vswwm-europe-west3-europe-west3-b-0/scylla.current:2025-08-07T16:01:25.427945478Z INFO  2025-08-07 16:01:25,427 [shard 0: gms] gossip - InetAddress a59bda6b-1141-4e96-ae7e-983d99917f69 is now DOWN, status = shutdown
basic-vswwm-europe-west3-europe-west3-a-0/scylla.current:2025-08-07T16:01:25.427916908Z INFO  2025-08-07 16:01:25,427 [shard 0: gms] gossip - InetAddress a59bda6b-1141-4e96-ae7e-983d99917f69 is now DOWN, status = shutdown
basic-vswwm-europe-west1-europe-west1-b-0/scylla.current:2025-08-07T16:01:53.336156110Z INFO  2025-08-07 16:01:53,335 [shard 0:strm] gossip - InetAddress a59bda6b-1141-4e96-ae7e-983d99917f69 is now DOWN, status = NORMAL
basic-vswwm-europe-west1-europe-west1-a-0/scylla.current:2025-08-07T16:01:25.424233158Z INFO  2025-08-07 16:01:25,424 [shard 0: gms] gossip - InetAddress a59bda6b-1141-4e96-ae7e-983d99917f69 is now DOWN, status = shutdown
basic-vswwm-europe-west3-europe-west3-c-0/scylla.current:2025-08-07T16:03:43.057804187Z INFO  2025-08-07 16:03:43,057 [shard 0: gms] gossip - InetAddress a59bda6b-1141-4e96-ae7e-983d99917f69/10.35.64.100 is now UP, status = NORMAL
basic-vswwm-europe-west3-europe-west3-b-0/scylla.current:2025-08-07T16:03:46.868165631Z INFO  2025-08-07 16:03:46,868 [shard 0: gms] gossip - InetAddress a59bda6b-1141-4e96-ae7e-983d99917f69/10.35.64.100 is now UP, status = NORMAL
basic-vswwm-europe-west3-europe-west3-a-0/scylla.current:2025-08-07T16:03:44.944915175Z INFO  2025-08-07 16:03:44,944 [shard 0: gms] gossip - InetAddress a59bda6b-1141-4e96-ae7e-983d99917f69/10.35.64.100 is now UP, status = NORMAL
basic-vswwm-europe-west1-europe-west1-b-0/scylla.current:2025-08-07T16:04:05.168378025Z INFO  2025-08-07 16:04:05,168 [shard 0: gms] gossip - InetAddress a59bda6b-1141-4e96-ae7e-983d99917f69/10.35.64.100 is now UP, status = NORMAL
basic-vswwm-europe-west1-europe-west1-a-0/scylla.current:2025-08-07T16:03:40.595348236Z INFO  2025-08-07 16:03:40,595 [shard 0: gms] gossip - InetAddress a59bda6b-1141-4e96-ae7e-983d99917f69/10.35.64.100 is now UP, status = NORMAL

The new node is started at 16:03:18 when all other nodes think it is down. The only bug I can see is in the operator itself.

[rzetelskik]

Thanks for looking into it @gleb-cloudius, this is very useful.

Looking at all the nodes starting time, it looks like the entire cluster was rolling restarted before joining a new node actually. Why?

Only europe-west1 was. After all nodes in europe-west3 went up, europe-west1 was updated so that its seeds include a DNS address pointing to nodes in europe-west3. This caused a rollout. So you're right, europe-west1-c-0 (a59bda6b-1141-4e96-ae7e-983d99917f69) restarted, which I've missed before as the Pod was recreated and so the logs from the previous run were gone.

Is there anything inherently incorrect about performing a rolling restart at this point? Assuming the operator (correctly) waits for all nodes to be UN again before making any topology changes?

As far as I see node a59bda6b-1141-4e96-ae7e-983d99917f69 is considered to be down by all nodes in the cluster when the bootstrap starts

All but itself. We consider a node ready when it considers itself as UN and it has native transport enabled. Topology changes can only happen when we consider all existing nodes ready. So this is correct from the operator perspective. Whether that's actually good enough for topology changes is a very long running discussion: #8275, scylladb/scylla-operator#1077, scylladb/scylla-operator#1108...

Looking at the logs of the api-status-probe container (here is how it checks the status), it looks like europe-west1-c-0 (a59bda6b-1141-4e96-ae7e-983d99917f69) reported itself UN at all times after it finished initialising after the restart.

grep -m 1 'Node="10\.35\.64\.100" Status="U" State="N"' artifacts/e2e/workers/europe-west1/namespaces/e2e-test-scylladbcluster-nqjbc-c9nsb-2qnap/pods/basic-vswwm-europe-west1-europe-west1-c-0/scylladb-api-status-probe.current
2025-08-07T16:02:22.695716950Z I0807 16:02:22.695632       1 scylladbapistatus/prober.go:95] "readyz probe: node state" Node="10.35.64.100" Status="U" State="N"

grep -m 1 'Node="10\.35\.64\.100" NativeTransportEnabled=true' artifacts/e2e/workers/europe-west1/namespaces/e2e-test-scylladbcluster-nqjbc-c9nsb-2qnap/pods/basic-vswwm-europe-west1-europe-west1-c-0/scylladb-api-status-probe.current
2025-08-07T16:02:32.396097107Z I0807 16:02:32.396049       1 scylladbapistatus/prober.go:105] "readyz probe: node state" Node="10.35.64.100" NativeTransportEnabled=true

grep 'Node="10\.35\.64\.100" Status="U" State="N"' artifacts/e2e/workers/europe-west1/namespaces/e2e-test-scylladbcluster-nqjbc-c9nsb-2qnap/pods/basic-vswwm-europe-west1-europe-west1-c-0/scylladb-api-status-probe.current | wc -m
46207

grep 'Node="10\.35\.64\.100" Status="D"' artifacts/e2e/workers/europe-west1/namespaces/e2e-test-scylladbcluster-nqjbc-c9nsb-2qnap/pods/basic-vswwm-europe-west1-europe-west1-c-0/scylladb-api-status-probe.current | wc -m
0

So if all the other nodes see the node as down after the restart, is it expected that it considers itself UN all this time? Should it also have native transport enabled?

[gleb-cloudius]

Thanks for looking into it @gleb-cloudius, this is very useful.

Looking at all the nodes starting time, it looks like the entire cluster was rolling restarted before joining a new node actually. Why?

Only europe-west1 was. After all nodes in europe-west3 went up, europe-west1 was updated so that its seeds include a DNS address pointing to nodes in europe-west3. This caused a rollout. So you're right, europe-west1-c-0 (a59bda6b-1141-4e96-ae7e-983d99917f69) restarted, which I've missed before as the Pod was recreated and so the logs from the previous run were gone.

Not that it matters much but logs show that west3 was restarted as well.

Is there anything inherently incorrect about performing a rolling restart at this point? Assuming the operator (correctly) waits for all nodes to be UN again before making any topology changes?

If done correctly there is anything incorrect. But to do rolling restart correctly you need to check that all nodes see the restarted node as alive before proceeding.

As far as I see node a59bda6b-1141-4e96-ae7e-983d99917f69 is considered to be down by all nodes in the cluster when the bootstrap starts

All but itself. We consider a node ready when it considers itself as UN and it has native transport enabled. Topology changes can only happen when we consider all existing nodes ready. So this is correct from the operator perspective. Whether that's actually good enough for topology changes is a very long running discussion: #8275, scylladb/scylla-operator#1077, scylladb/scylla-operator#1108...

No, this is not correct from the operator perspective unrelated to topology changes. You may have failed cql queries if you rolling restart a next node without waiting for previous one to be seen as UP by all nodes in the cluster. I do not know who you have those long running discussion with but you should stop and fix the operator (I recognize the first one where I participated and IIRC said exactly that).

We tried to improve the situation in 28c0a27, but as the patch puts is:

    This is still a best effort thing: if some nodes are unreachable or
    gossiper propagation takes too much time the boot process continues
    anyway.

And we actually see that this is what is happening in this cluster:

./basic-vswwm-europe-west1-europe-west1-c-0/scylla.current:2025-08-07T16:02:23.739635171Z WARN  2025-08-07 16:02:23,739 [shard 0:strm] gossip - Failed to notify node 2905cf1e-dcdc-4ba6-9f53-c69cc5227437 that I am UP: seastar::rpc::timeout_error (rpc call timed out)
./basic-vswwm-europe-west1-europe-west1-c-0/scylla.current:2025-08-07T16:02:23.739660331Z WARN  2025-08-07 16:02:23,739 [shard 0:strm] gossip - Failed to notify node 3c5ecd4c-7ee2-4973-bd1f-1bffe735acb3 that I am UP: seastar::rpc::timeout_error (rpc call timed out)
./basic-vswwm-europe-west1-europe-west1-c-0/scylla.current:2025-08-07T16:02:23.739665321Z WARN  2025-08-07 16:02:23,739 [shard 0:strm] gossip - Failed to notify node 582b2456-1d6b-4c35-b4e6-13907f8f29e9 that I am UP: seastar::rpc::timeout_error (rpc call timed out)
./basic-vswwm-europe-west1-europe-west1-c-0/scylla.current:2025-08-07T16:02:23.739669211Z WARN  2025-08-07 16:02:23,739 [shard 0:strm] gossip - Failed to notify node 95f6ce46-7a2d-4654-820d-f174e1aff199 that I am UP: seastar::rpc::timeout_error (rpc call timed out)
./basic-vswwm-europe-west1-europe-west1-c-0/scylla.current:2025-08-07T16:02:23.739672841Z WARN  2025-08-07 16:02:23,739 [shard 0:strm] gossip - Failed to notify node b01aba0d-3726-4581-b7cb-cdf74c7e0bdb that I am UP: seastar::rpc::timeout_error (rpc call timed out)
./basic-vswwm-europe-west1-europe-west1-b-0/scylla.current:2025-08-07T16:00:03.333532292Z WARN  2025-08-07 16:00:03,333 [shard 0:strm] gossip - Failed to notify node 2905cf1e-dcdc-4ba6-9f53-c69cc5227437 that I am UP: seastar::rpc::timeout_error (rpc call timed out)
./basic-vswwm-europe-west1-europe-west1-b-0/scylla.current:2025-08-07T16:00:03.333554412Z WARN  2025-08-07 16:00:03,333 [shard 0:strm] gossip - Failed to notify node a59bda6b-1141-4e96-ae7e-983d99917f69 that I am UP: seastar::rpc::timeout_error (rpc call timed out)
./basic-vswwm-europe-west1-europe-west1-b-0/scylla.current:2025-08-07T16:00:03.333559243Z WARN  2025-08-07 16:00:03,333 [shard 0:strm] gossip - Failed to notify node 3c5ecd4c-7ee2-4973-bd1f-1bffe735acb3 that I am UP: seastar::rpc::timeout_error (rpc call timed out)
./basic-vswwm-europe-west1-europe-west1-b-0/scylla.current:2025-08-07T16:00:03.333563003Z WARN  2025-08-07 16:00:03,333 [shard 0:strm] gossip - Failed to notify node 95f6ce46-7a2d-4654-820d-f174e1aff199 that I am UP: seastar::rpc::timeout_error (rpc call timed out)
./basic-vswwm-europe-west1-europe-west1-b-0/scylla.current:2025-08-07T16:00:03.333566772Z WARN  2025-08-07 16:00:03,333 [shard 0:strm] gossip - Failed to notify node b01aba0d-3726-4581-b7cb-cdf74c7e0bdb that I am UP: seastar::rpc::timeout_error (rpc call timed out)
./basic-vswwm-europe-west1-europe-west1-a-0/scylla.current:2025-08-07T15:57:45.914451453Z WARN  2025-08-07 15:57:45,914 [shard 0:strm] gossip - Failed to notify node 2905cf1e-dcdc-4ba6-9f53-c69cc5227437 that I am UP: seastar::rpc::timeout_error (rpc call timed out)
./basic-vswwm-europe-west1-europe-west1-a-0/scylla.current:2025-08-07T15:57:45.914471723Z WARN  2025-08-07 15:57:45,914 [shard 0:strm] gossip - Failed to notify node a59bda6b-1141-4e96-ae7e-983d99917f69 that I am UP: seastar::rpc::timeout_error (rpc call timed out)
./basic-vswwm-europe-west1-europe-west1-a-0/scylla.current:2025-08-07T15:57:45.914477383Z WARN  2025-08-07 15:57:45,914 [shard 0:strm] gossip - Failed to notify node 3c5ecd4c-7ee2-4973-bd1f-1bffe735acb3 that I am UP: seastar::rpc::timeout_error (rpc call timed out)
./basic-vswwm-europe-west1-europe-west1-a-0/scylla.current:2025-08-07T15:57:45.914482293Z WARN  2025-08-07 15:57:45,914 [shard 0:strm] gossip - Failed to notify node 582b2456-1d6b-4c35-b4e6-13907f8f29e9 that I am UP: seastar::rpc::timeout_error (rpc call timed out)
./basic-vswwm-europe-west1-europe-west1-a-0/scylla.current:2025-08-07T15:57:45.914538753Z WARN  2025-08-07 15:57:45,914 [shard 0:strm] gossip - Failed to notify node b01aba0d-3726-4581-b7cb-cdf74c7e0bdb that I am UP: seastar::rpc::timeout_error (rpc call

[rzetelskik]

I went through the entire discussion in #8275 and found that it led to a supposed solution agreed between the operator and core, where #16763 would be implemented. The description of the issue was unclear to me as it was mixing up the requirements for declaring readiness to serve requests and readiness for topology changes. I discussed this with @gleb-cloudius and it seems that the issue was meant to address the limitations on K8s' side by hacking the status check into Scylla. Regardless of how the implementation is split between Scylla and orchestration, the invariant for both bootstrap and rolling restart operations is that all nodes in the cluster see all other nodes as UP/ALIVE. We need Operator to perform this.

There were also comments in #8275 mentioning some concerns about the status check being insufficient, as a node may go down after the check, in which case bootstrap will fail. @gleb-cloudius confirmed this is expected and the same thing may happen after the bootstrap has already started.

Created a tracker on the Operator side: scylladb/scylla-operator#2947.

[gleb-cloudius]

by hacking the status check into Scylla

We never agreed to do that. I proposed to put it into a management agent if needed, not into scylla itself.