Re: [HELP] Cassandra 4.1.1 Repeated Bootstrapping Failure

[Bowen Song via user]

Hi Scott,


Thank you for pointing this out. I found it too, but I deemed it to be 
irrelevant because the following reasons:


 * it was fixed in 4.1.1, as you have correctly pointed out; and
 * the error message is slightly different, "writevAddresses" vs
   "writeAddress"; and
 * it actually got stuck for 15 minutes without any logs related to the
   streaming, but in my case everything worked fine up until it
   suddenly times out.

Therefore I did not mention it in the email.


Regards,

Bowen


On 11/09/2023 22:24, C. Scott Andreas wrote:

Bowen, thanks for reaching out.

My mind immediately jumped to a ticket which has very similar 
pathology: "CASSANDRA-18110 
: Streaming 
progress virtual table lock contention can trigger TCP_USER_TIMEOUT 
and fail streaming" -- but I see this was fixed in 4.1.1.


On Sep 11, 2023, at 2:09 PM, Bowen Song via user 
 wrote:



  *Description*

When adding a new node to an existing cluster, the new node 
bootstrapping fails with the 
"io.netty.channel.unix.Errors$NativeIoException: writeAddress(..) 
failed: Connection timed out" error from the streaming source node. 
Resuming the bootstrap with "nodetool bootstrap resume" works, but 
the resumed bootstrap can fail too. We often need to run "nodetool 
bootstrap resume" a couple of times to complete the bootstrapping on 
a joining node.



  Steps that produced the error

(I'm hesitant to say "step to reproduce", because I failed to 
reproduce the error on a testing cluster)
Install Cassandra 4.1.1 on new servers, using two of the existing 
nodes as seed nodes, start the new node and let it join the cluster. 
Watch the logs.



  Environment

All nodes, existing or new, have the same software versions as below.

Cassandra: version 4.1.1
Java: OpenJDK 11
OS: Debian 11

Existing nodes each has 1TB SSD, 64GB memory and 6 cores CPU, and 
num_tokens is set to 4
New nodes each has 2TB SSD, 128GB memory and 16 cores CPU, and 
num_tokens is set to 8


Cassandra is in a single DC, single rack setup with about 130 nodes, 
and all non-system keyspaces have RF=3


Relevant config options:

stream_throughput_outbound: 15MiB/s
  streaming_connections_per_host: 2
  auto_bootstrap: not set, default to true
  internode_tcp_user_timeout: not set, default to 30 seconds
  internode_streaming_tcp_user_timeout: not set, default to 5 minutes
  streaming_keep_alive_period: not set, default to 5 minutes
  streaming_state_expires: not set, default to 3 days
  streaming_state_size: not set, default to 40MiB
  streaming_stats_enabled: not set, default to true
  uuid_sstable_identifiers_enabled: true (turned on after
upgraded to 4.1 last year)


  What we have tried

*Tried*: checking the hardware and network
*Result*: everything appears to be fine

*Tried*: Google searching for the error message 
"io.netty.channel.unix.Errors$NativeIoException: writeAddress(..) 
failed: Connection timed out"
*Result*: only one matching result was found, and it points to 
CASSANDRA-16143 
. That 
certainly doesn't apply in our case, as it was fixed in 4.0, and I 
also don't believe our data centre grade SSDs are that slow.


*Tried*: reducing the stream_throughput_outbound from 30 to 15 MiB/s
*Result*: did not help, no sign of any improvement

*Tried*: analyse the logs from the joining node and the streaming 
source nodes
*Result*: the error says the write connection timed out on the 
sending end, but a few seconds before that, both sending and 
receiving ends of the connection were still communicating with each 
other. I couldn't make sense of it.


*Tried*: bootstrapping a different node of the same spec
*Result*: same error reproduced

*Tried*: attempting to reproduce the error on a testing cluster
*Result*: unable to reproduce this error on a smaller testing cluster 
with less nodes, less powerful hardware, same Cassandar, Java and OS 
version, same config, same schema, less data and same mixed number of 
vnodes.


*Tried*: keep retrying with "nodetool bootstrap resume"
*Result*: this works and unblocked us from adding new nodes to the 
cluster, but this obviously is not how it should be done.



  What do I expect from posting this

I'm suspecting that this is a bug in Cassandra, but lack the evidence 
to support that, and lacks the expertise in debugging Cassandra (or 
any other Java application).
It would be much appreciated if anyone could offer me some help on 
this, or point me to a direction that may lead to the solution.



  Relevant logs

Note: IP address, keyspace and table names are reducted. The IP 
address ending in 111 is the joining node, and the IP address ending 
in 182 was one of the streaming source node.


The logs from the joining node (IP: xxx.xxx.xxx.111):

DEBUG [Stream-Deserializer-/xxx.xxx.xxx.182:7000-e0e09450]
2023-09-09 15:59:13,555 

Re: [HELP] Cassandra 4.1.1 Repeated Bootstrapping Failure

[C. Scott Andreas]

Bowen, thanks for reaching out.My mind immediately jumped to a ticket which has very similar 
pathology: "CASSANDRA-18110: Streaming progress virtual table lock contention can trigger 
TCP_USER_TIMEOUT and fail streaming" -- but I see this was fixed in 4.1.1.On Sep 11, 2023, 
at 2:09 PM, Bowen Song via user  wrote:DescriptionWhen adding 
a new node to an existing cluster, the new node
 bootstrapping fails with the
 "io.netty.channel.unix.Errors$NativeIoException: writeAddress(..)
 failed: Connection timed out" error from the streaming source
 node. Resuming the bootstrap with "nodetool bootstrap resume"
 works, but the resumed bootstrap can fail too. We often need to
 run "nodetool bootstrap resume" a couple of times to complete
 the bootstrapping on a joining node.Steps that produced the error(I'm hesitant to 
say "step to reproduce", because I failed to
 reproduce the error on a testing cluster) Install Cassandra 4.1.1 on new 
servers, using two of the existing
 nodes as seed nodes, start the new node and let it join the
 cluster. Watch the logs. EnvironmentAll nodes, existing or new, have the 
same software versions as
 below.Cassandra: version 4.1.1 Java: OpenJDK 11 OS: Debian 11Existing 
nodes each has 1TB SSD, 64GB memory and 6 cores CPU, and
 num_tokens is set to 4 New nodes each has 2TB SSD, 128GB memory and 16 
cores CPU, and
 num_tokens is set to 8  Cassandra is in a single DC, single rack setup 
with about 130
 nodes, and all non-system keyspaces have RF=3  Relevant config options:  
stream_throughput_outbound: 15MiB/s   streaming_connections_per_host: 2   
auto_bootstrap: not set, default to true   internode_tcp_user_timeout: not set, 
default to 30 seconds   internode_streaming_tcp_user_timeout: not set, default 
to 5
 minutes   streaming_keep_alive_period: not set, default to 5 minutes   
streaming_state_expires: not set, default to 3 days   streaming_state_size: not 
set, default to 40MiB   streaming_stats_enabled: not set, default to true   
uuid_sstable_identifiers_enabled: true (turned on after
 upgraded to 4.1 last year)What we have triedTried: checking the 
hardware and network Result: everything appears to be fine  Tried: Google 
searching for the error message
 "io.netty.channel.unix.Errors$NativeIoException: writeAddress(..)
 failed: Connection timed out" Result: only one matching result was found, 
and it points
 to CASSANDRA-16143.
 That certainly doesn't apply in our case, as it was fixed in 4.0,
 and I also don't believe our data centre grade SSDs are that slow.  Tried: 
reducing the stream_throughput_outbound from 30 to
 15 MiB/s Result: did not help, no sign of any improvement  Tried: analyse 
the logs from the joining node and the
 streaming source nodes Result: the error says the write connection timed 
out on
 the sending end, but a few seconds before that, both sending and
 receiving ends of the connection were still communicating with
 each other. I couldn't make sense of it.  Tried: bootstrapping a different 
node of the same spec Result: same error reproduced  Tried: attempting to 
reproduce the error on a testing
 cluster Result: unable to reproduce this error on a smaller testing
 cluster with less nodes, less powerful hardware, same Cassandar,
 Java and OS version, same config, same schema, less data and same
 mixed number of vnodes.  Tried: keep retrying with "nodetool bootstrap 
resume" Result: this works and unblocked us from adding new nodes
 to the cluster, but this obviously is not how it should be done. What do I 
expect from posting thisI'm suspecting that this is a bug in Cassandra, but 
lack the
 evidence to support that, and lacks the expertise in debugging
 Cassandra (or any other Java application). It would be much appreciated if 
anyone could offer me some help on
 this, or point me to a direction that may lead to the solution. Relevant 
logsNote: IP address, keyspace and table names are reducted. The IP
 address ending in 111 is the joining node, and the IP address
 ending in 182 was one of the streaming source node.The logs from the 
joining node (IP: xxx.xxx.xxx.111):DEBUG
 [Stream-Deserializer-/xxx.xxx.xxx.182:7000-e0e09450]
 2023-09-09 15:59:13,555 StreamDeserializingTask.java:74 -
 [Stream #69de5e80-4f21-11ee-abc5-1de0bb481b0e channel:
 e0e09450] Received Prepare SYNACK ( 440 files} INFO  
[Stream-Deserializer-/xxx.xxx.xxx.182:7000-e0e09450]
 2023-09-09 15:59:13,556 StreamResultFuture.java:187 - [Stream
 #69de5e80-4f21-11ee-abc5-1de0bb481b0e ID#0] Prepare completed.
 Receiving 440 files(38.941GiB), sending 0 files(0.000KiB) DEBUG 
[Stream-Deserializer-/xxx.xxx.xxx.182:7000-e0e09450]
 2023-09-09 15:59:13,556 StreamCoordinator.java:148 -
 Connecting next session 69de5e80-4f21-11ee-abc5-1de0bb481b0e
 with 

[HELP] Cassandra 4.1.1 Repeated Bootstrapping Failure

[Bowen Song via user]

 *Description*

When adding a new node to an existing cluster, the new node 
bootstrapping fails with the 
"io.netty.channel.unix.Errors$NativeIoException: writeAddress(..) 
failed: Connection timed out" error from the streaming source node. 
Resuming the bootstrap with "nodetool bootstrap resume" works, but the 
resumed bootstrap can fail too. We often need to run "nodetool bootstrap 
resume" a couple of times to complete the bootstrapping on a joining node.



 Steps that produced the error

(I'm hesitant to say "step to reproduce", because I failed to reproduce 
the error on a testing cluster)
Install Cassandra 4.1.1 on new servers, using two of the existing nodes 
as seed nodes, start the new node and let it join the cluster. Watch the 
logs.



 Environment

All nodes, existing or new, have the same software versions as below.

   Cassandra: version 4.1.1
   Java: OpenJDK 11
   OS: Debian 11

Existing nodes each has 1TB SSD, 64GB memory and 6 cores CPU, and 
num_tokens is set to 4
New nodes each has 2TB SSD, 128GB memory and 16 cores CPU, and 
num_tokens is set to 8


Cassandra is in a single DC, single rack setup with about 130 nodes, and 
all non-system keyspaces have RF=3


Relevant config options:

  stream_throughput_outbound: 15MiB/s
  streaming_connections_per_host: 2
  auto_bootstrap: not set, default to true
  internode_tcp_user_timeout: not set, default to 30 seconds
  internode_streaming_tcp_user_timeout: not set, default to 5 minutes
  streaming_keep_alive_period: not set, default to 5 minutes
  streaming_state_expires: not set, default to 3 days
  streaming_state_size: not set, default to 40MiB
  streaming_stats_enabled: not set, default to true
  uuid_sstable_identifiers_enabled: true (turned on after upgraded
   to 4.1 last year)


 What we have tried

*Tried*: checking the hardware and network
*Result*: everything appears to be fine

*Tried*: Google searching for the error message 
"io.netty.channel.unix.Errors$NativeIoException: writeAddress(..) 
failed: Connection timed out"
*Result*: only one matching result was found, and it points to 
CASSANDRA-16143 . 
That certainly doesn't apply in our case, as it was fixed in 4.0, and I 
also don't believe our data centre grade SSDs are that slow.


*Tried*: reducing the stream_throughput_outbound from 30 to 15 MiB/s
*Result*: did not help, no sign of any improvement

*Tried*: analyse the logs from the joining node and the streaming source 
nodes
*Result*: the error says the write connection timed out on the sending 
end, but a few seconds before that, both sending and receiving ends of 
the connection were still communicating with each other. I couldn't make 
sense of it.


*Tried*: bootstrapping a different node of the same spec
*Result*: same error reproduced

*Tried*: attempting to reproduce the error on a testing cluster
*Result*: unable to reproduce this error on a smaller testing cluster 
with less nodes, less powerful hardware, same Cassandar, Java and OS 
version, same config, same schema, less data and same mixed number of 
vnodes.


*Tried*: keep retrying with "nodetool bootstrap resume"
*Result*: this works and unblocked us from adding new nodes to the 
cluster, but this obviously is not how it should be done.



 What do I expect from posting this

I'm suspecting that this is a bug in Cassandra, but lack the evidence to 
support that, and lacks the expertise in debugging Cassandra (or any 
other Java application).
It would be much appreciated if anyone could offer me some help on this, 
or point me to a direction that may lead to the solution.



 Relevant logs

Note: IP address, keyspace and table names are reducted. The IP address 
ending in 111 is the joining node, and the IP address ending in 182 was 
one of the streaming source node.


The logs from the joining node (IP: xxx.xxx.xxx.111):

   DEBUG [Stream-Deserializer-/xxx.xxx.xxx.182:7000-e0e09450]
   2023-09-09 15:59:13,555 StreamDeserializingTask.java:74 - [Stream
   #69de5e80-4f21-11ee-abc5-1de0bb481b0e channel: e0e09450] Received
   Prepare SYNACK ( 440 files}
   INFO  [Stream-Deserializer-/xxx.xxx.xxx.182:7000-e0e09450]
   2023-09-09 15:59:13,556 StreamResultFuture.java:187 - [Stream
   #69de5e80-4f21-11ee-abc5-1de0bb481b0e ID#0] Prepare completed.
   Receiving 440 files(38.941GiB), sending 0 files(0.000KiB)
   DEBUG [Stream-Deserializer-/xxx.xxx.xxx.182:7000-e0e09450]
   2023-09-09 15:59:13,556 StreamCoordinator.java:148 - Connecting next
   session 69de5e80-4f21-11ee-abc5-1de0bb481b0e with /95.217.36.91:7000.
   INFO  [Stream-Deserializer-/xxx.xxx.xxx.182:7000-e0e09450]
   2023-09-09 15:59:13,556 StreamSession.java:368 - [Stream
   #69de5e80-4f21-11ee-abc5-1de0bb481b0e] Starting streaming to
   95.217.36.91:7000
   DEBUG [Stream-Deserializer-/xxx.xxx.xxx.182:7000-e0e09450]
   2023-09-09 15:59:13,556 StreamingMultiplexedChannel.java:167 -