You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@cassandra.apache.org by "ZAIDI, ASAD A" <az...@att.com> on 2019/06/12 16:45:25 UTC
RE: postmortem on 2.2.13 scale out difficulties
Adding one node at a time – is that successful?
Check value of streaming_socket_timeout_in_ms parameter in cassandra.yaml and increase if needed.
Have you tried Nodetool bootstrap resume & jvm option i.e. JVM_OPTS="$JVM_OPTS -Dcassandra.consistent.rangemovement=false" ?
From: Carl Mueller [mailto:carl.mueller@smartthings.com.INVALID]
Sent: Wednesday, June 12, 2019 11:35 AM
To: user@cassandra.apache.org
Subject: Re: postmortem on 2.2.13 scale out difficulties
We only were able to scale out four nodes and then failures started occurring, including multiple instances of nodes joining a cluster without streaming.
Sigh.
On Tue, Jun 11, 2019 at 3:11 PM Carl Mueller <ca...@smartthings.com>> wrote:
We had a three-DC (asia-tokyo/europe/us) cassandra 2.2.13 cluster, AWS, IPV6
Needed to scale out the asia datacenter, which was 5 nodes, europe and us were 25 nodes
We were running into bootstrapping issues where the new node failed to bootstrap/stream, it failed with
"java.lang.RuntimeException: A node required to move the data consistently is down"
...even though they were all up based on nodetool status prior to adding the node.
First we increased the phi_convict_threshold to 12, and that did not help.
CASSANDRA-12281 appeared similar to what we had problems with, but I don't think we hit that. Somewhere in there someone wrote
"For us, the workaround is either deleting the data (then bootstrap again), or increasing the ring_delay_ms. And the larger the cluster is, the longer ring_delay_ms is needed. Based on our tests, for a 40 nodes cluster, it requires ring_delay_ms to be >50seconds. For a 70 nodes cluster, >100seconds. Default is 30seconds."
Given the WAN nature or our DCs, we used ring_delay_ms to 100 seconds and it finally worked.
side note:
During the rolling restarts for setting phi_convict_threshold we observed quite a lot of status map variance between nodes (we have a program to poll all of a datacenter or cluster's view of the gossipinfo and statuses. AWS appears to have variance in networking based on the phi_convict_threshold advice, I'm not sure if our difficulties were typical in that regard and/or if our IPV6 and/or globally distributed datacenters were exacerbating factors.
We could not reproduce this in loadtest, although loadtest is only eu and us (but is IPV6)
Re: postmortem on 2.2.13 scale out difficulties
Posted by Carl Mueller <ca...@smartthings.com.INVALID>.
I posted a bug, cassandra-15155 :
https://issues.apache.org/jira/browse/CASSANDRA-15155?jql=project%20%3D%20CASSANDRA
It seems VERY similar to
https://issues.apache.org/jira/browse/CASSANDRA-6648
On Wed, Jun 12, 2019 at 12:14 PM Carl Mueller <ca...@smartthings.com>
wrote:
> And once the cluster token map formation is done, it starts bootstrap and
> we get a ton of these:
>
> WARN [MessagingService-Incoming-/2406:da14:95b:4503:910e:23fd:dafa:9983]
> 2019-06-12 15:22:04,760 IncomingTcpConnection.java:100 -
> UnknownColumnFamilyException reading from socket; closing
> org.apache.cassandra.db.UnknownColumnFamilyException: Couldn't find
> cfId=df425400-c331-11e8-8b96-4b7f4d58af68
>
> And then after LOTS of those
>
> INFO [main] 2019-06-12 15:23:25,515 StorageService.java:1142 - JOINING:
> Starting to bootstrap...
> INFO [main] 2019-06-12 15:23:25,525 StreamResultFuture.java:87 - [Stream
> #05af9ee0-8d26-11e9-85c1-bd5476090c54] Executing streaming plan for
> Bootstrap
> INFO [main] 2019-06-12 15:23:25,526 StorageService.java:1199 - Bootstrap
> completed! for the tokens [-7314981925085449175, ... bunch of tokens...
> 5499447097629838103]
>
>
> On Wed, Jun 12, 2019 at 12:07 PM Carl Mueller <
> carl.mueller@smartthings.com> wrote:
>
>> One node at a time: yes that is what we are doing
>>
>> We have not tried the streaming_socket_timeout_in_ms. It is currently 24
>> hours. (```streaming_socket_timeout_in_ms=86400000```) which would cover
>> the bootstrap timeframe we have seen before (1-2 hours per node)
>>
>> Since it joins with no data, it is serving erroneous data. We may try
>> bootstrap rejoin and the JVM_OPT.... The node appears to think it has
>> bootstrapped even though the gossipinfo shows the new node has a different
>> schema version.
>>
>> We had scaled EU and US from 5 --> 25 without incident (one at a time),
>> and since we increased ring_delay_ms worked haphazardly to get us four
>> joins, and since then failure.
>>
>> The debug log shows:
>>
>> DEBUG [GossipStage:1] 2019-06-12 15:20:08,559 StorageService.java:1998 -
>> New node /2a05:d018:af:1108:86f4:d628:6bca:6983 at token 9200286188287490229
>> DEBUG [GossipStage:1] 2019-06-12 15:20:08,559 StorageService.java:1998 -
>> New node /2a05:d018:af:1108:86f4:d628:6bca:6983 at token 950856676715905899
>> DEBUG [GossipStage:1] 2019-06-12 15:20:08,563 MigrationManager.java:96 -
>> Not pulling schema because versions match or shouldPullSchemaFrom returned
>> false
>> INFO [GossipStage:1] 2019-06-12 15:20:08,563 TokenMetadata.java:464 -
>> Updating topology for /2a05:d018:af:1108:86f4:d628:6bca:6983
>> INFO [GossipStage:1] 2019-06-12 15:20:08,564 TokenMetadata.java:464 -
>> Updating topology for /2a05:d018:af:1108:86f4:d628:6bca:6983
>> DEBUG [GossipStage:1] 2019-06-12 15:20:08,565 MigrationManager.java:96 -
>> Not pulling schema because versions match or shouldPullSchemaFrom returned
>> false
>> INFO [GossipStage:1] 2019-06-12 15:20:08,565 Gossiper.java:1027 - Node
>> /2600:1f18:4b4:5903:64af:955e:b65:8d83 is now part of the cluster
>> DEBUG [GossipStage:1] 2019-06-12 15:20:08,587 StorageService.java:1928 -
>> Node /2600:1f18:4b4:5903:64af:955e:b65:8d83 state NORMAL, token
>> [-1028768087263234868, ...<bunch of tokens>..., 921670352349030554]
>> DEBUG [GossipStage:1] 2019-06-12 15:20:08,588 StorageService.java:1998 -
>> New node /2600:1f18:4b4:5903:64af:955e:b65:8d83 at token
>> -1028768087263234868
>> DEBUG [GossipStage:1] 2019-06-12 15:20:08,588 StorageService.java:1998 -
>> New node /2600:1f18:4b4:5903:64af:955e:b65:8d83 at token
>> -1045740236536355596
>> DEBUG [GossipStage:1] 2019-06-12 15:20:08,589 StorageService.java:1998 -
>> New node /2600:1f18:4b4:5903:64af:955e:b65:8d83 at token
>> -1184422937682103096
>> DEBUG [GossipStage:1] 2019-06-12 15:20:08,589 StorageService.java:1998 -
>> New node /2600:1f18:4b4:5903:64af:955e:b65:8d83 at token
>> -1201924032068728250
>>
>> All the nodes appear to be reporting "Not pulling schema becuase versions
>> match or shouldPullSchmeaFrom returned false. That code
>> (MigrationManager.java) makes reference to a "gossip only" node, did we get
>> stuck in that somehow.
>>
>> On Wed, Jun 12, 2019 at 11:45 AM ZAIDI, ASAD A <az...@att.com> wrote:
>>
>>>
>>>
>>>
>>>
>>> Adding one node at a time – is that successful?
>>>
>>> Check value of streaming_socket_timeout_in_ms parameter in
>>> cassandra.yaml and increase if needed.
>>>
>>> Have you tried Nodetool bootstrap resume & jvm option i.e.
>>> JVM_OPTS="$JVM_OPTS -Dcassandra.consistent.rangemovement=false" ?
>>>
>>>
>>>
>>>
>>>
>>> *From:* Carl Mueller [mailto:carl.mueller@smartthings.com.INVALID]
>>> *Sent:* Wednesday, June 12, 2019 11:35 AM
>>> *To:* user@cassandra.apache.org
>>> *Subject:* Re: postmortem on 2.2.13 scale out difficulties
>>>
>>>
>>>
>>> We only were able to scale out four nodes and then failures started
>>> occurring, including multiple instances of nodes joining a cluster without
>>> streaming.
>>>
>>>
>>>
>>> Sigh.
>>>
>>>
>>>
>>> On Tue, Jun 11, 2019 at 3:11 PM Carl Mueller <
>>> carl.mueller@smartthings.com> wrote:
>>>
>>> We had a three-DC (asia-tokyo/europe/us) cassandra 2.2.13 cluster, AWS,
>>> IPV6
>>>
>>> Needed to scale out the asia datacenter, which was 5 nodes, europe and
>>> us were 25 nodes
>>>
>>> We were running into bootstrapping issues where the new node failed to
>>> bootstrap/stream, it failed with
>>>
>>>
>>>
>>> "java.lang.RuntimeException: A node required to move the data
>>> consistently is down"
>>>
>>>
>>>
>>> ...even though they were all up based on nodetool status prior to adding
>>> the node.
>>>
>>> First we increased the phi_convict_threshold to 12, and that did not
>>> help.
>>>
>>> CASSANDRA-12281 appeared similar to what we had problems with, but I
>>> don't think we hit that. Somewhere in there someone wrote
>>>
>>>
>>>
>>> "For us, the workaround is either deleting the data (then bootstrap
>>> again), or increasing the ring_delay_ms. And the larger the cluster is, the
>>> longer ring_delay_ms is needed. Based on our tests, for a 40 nodes cluster,
>>> it requires ring_delay_ms to be >50seconds. For a 70 nodes cluster,
>>> >100seconds. Default is 30seconds."
>>>
>>> Given the WAN nature or our DCs, we used ring_delay_ms to 100 seconds
>>> and it finally worked.
>>>
>>> side note:
>>>
>>> During the rolling restarts for setting phi_convict_threshold we
>>> observed quite a lot of status map variance between nodes (we have a
>>> program to poll all of a datacenter or cluster's view of the gossipinfo and
>>> statuses. AWS appears to have variance in networking based on the
>>> phi_convict_threshold advice, I'm not sure if our difficulties were typical
>>> in that regard and/or if our IPV6 and/or globally distributed datacenters
>>> were exacerbating factors.
>>>
>>> We could not reproduce this in loadtest, although loadtest is only eu
>>> and us (but is IPV6)
>>>
>>>
Re: postmortem on 2.2.13 scale out difficulties
Posted by Carl Mueller <ca...@smartthings.com.INVALID>.
And once the cluster token map formation is done, it starts bootstrap and
we get a ton of these:
WARN [MessagingService-Incoming-/2406:da14:95b:4503:910e:23fd:dafa:9983]
2019-06-12 15:22:04,760 IncomingTcpConnection.java:100 -
UnknownColumnFamilyException reading from socket; closing
org.apache.cassandra.db.UnknownColumnFamilyException: Couldn't find
cfId=df425400-c331-11e8-8b96-4b7f4d58af68
And then after LOTS of those
INFO [main] 2019-06-12 15:23:25,515 StorageService.java:1142 - JOINING:
Starting to bootstrap...
INFO [main] 2019-06-12 15:23:25,525 StreamResultFuture.java:87 - [Stream
#05af9ee0-8d26-11e9-85c1-bd5476090c54] Executing streaming plan for
Bootstrap
INFO [main] 2019-06-12 15:23:25,526 StorageService.java:1199 - Bootstrap
completed! for the tokens [-7314981925085449175, ... bunch of tokens...
5499447097629838103]
On Wed, Jun 12, 2019 at 12:07 PM Carl Mueller <ca...@smartthings.com>
wrote:
> One node at a time: yes that is what we are doing
>
> We have not tried the streaming_socket_timeout_in_ms. It is currently 24
> hours. (```streaming_socket_timeout_in_ms=86400000```) which would cover
> the bootstrap timeframe we have seen before (1-2 hours per node)
>
> Since it joins with no data, it is serving erroneous data. We may try
> bootstrap rejoin and the JVM_OPT.... The node appears to think it has
> bootstrapped even though the gossipinfo shows the new node has a different
> schema version.
>
> We had scaled EU and US from 5 --> 25 without incident (one at a time),
> and since we increased ring_delay_ms worked haphazardly to get us four
> joins, and since then failure.
>
> The debug log shows:
>
> DEBUG [GossipStage:1] 2019-06-12 15:20:08,559 StorageService.java:1998 -
> New node /2a05:d018:af:1108:86f4:d628:6bca:6983 at token 9200286188287490229
> DEBUG [GossipStage:1] 2019-06-12 15:20:08,559 StorageService.java:1998 -
> New node /2a05:d018:af:1108:86f4:d628:6bca:6983 at token 950856676715905899
> DEBUG [GossipStage:1] 2019-06-12 15:20:08,563 MigrationManager.java:96 -
> Not pulling schema because versions match or shouldPullSchemaFrom returned
> false
> INFO [GossipStage:1] 2019-06-12 15:20:08,563 TokenMetadata.java:464 -
> Updating topology for /2a05:d018:af:1108:86f4:d628:6bca:6983
> INFO [GossipStage:1] 2019-06-12 15:20:08,564 TokenMetadata.java:464 -
> Updating topology for /2a05:d018:af:1108:86f4:d628:6bca:6983
> DEBUG [GossipStage:1] 2019-06-12 15:20:08,565 MigrationManager.java:96 -
> Not pulling schema because versions match or shouldPullSchemaFrom returned
> false
> INFO [GossipStage:1] 2019-06-12 15:20:08,565 Gossiper.java:1027 - Node
> /2600:1f18:4b4:5903:64af:955e:b65:8d83 is now part of the cluster
> DEBUG [GossipStage:1] 2019-06-12 15:20:08,587 StorageService.java:1928 -
> Node /2600:1f18:4b4:5903:64af:955e:b65:8d83 state NORMAL, token
> [-1028768087263234868, ...<bunch of tokens>..., 921670352349030554]
> DEBUG [GossipStage:1] 2019-06-12 15:20:08,588 StorageService.java:1998 -
> New node /2600:1f18:4b4:5903:64af:955e:b65:8d83 at token
> -1028768087263234868
> DEBUG [GossipStage:1] 2019-06-12 15:20:08,588 StorageService.java:1998 -
> New node /2600:1f18:4b4:5903:64af:955e:b65:8d83 at token
> -1045740236536355596
> DEBUG [GossipStage:1] 2019-06-12 15:20:08,589 StorageService.java:1998 -
> New node /2600:1f18:4b4:5903:64af:955e:b65:8d83 at token
> -1184422937682103096
> DEBUG [GossipStage:1] 2019-06-12 15:20:08,589 StorageService.java:1998 -
> New node /2600:1f18:4b4:5903:64af:955e:b65:8d83 at token
> -1201924032068728250
>
> All the nodes appear to be reporting "Not pulling schema becuase versions
> match or shouldPullSchmeaFrom returned false. That code
> (MigrationManager.java) makes reference to a "gossip only" node, did we get
> stuck in that somehow.
>
> On Wed, Jun 12, 2019 at 11:45 AM ZAIDI, ASAD A <az...@att.com> wrote:
>
>>
>>
>>
>>
>> Adding one node at a time – is that successful?
>>
>> Check value of streaming_socket_timeout_in_ms parameter in cassandra.yaml
>> and increase if needed.
>>
>> Have you tried Nodetool bootstrap resume & jvm option i.e.
>> JVM_OPTS="$JVM_OPTS -Dcassandra.consistent.rangemovement=false" ?
>>
>>
>>
>>
>>
>> *From:* Carl Mueller [mailto:carl.mueller@smartthings.com.INVALID]
>> *Sent:* Wednesday, June 12, 2019 11:35 AM
>> *To:* user@cassandra.apache.org
>> *Subject:* Re: postmortem on 2.2.13 scale out difficulties
>>
>>
>>
>> We only were able to scale out four nodes and then failures started
>> occurring, including multiple instances of nodes joining a cluster without
>> streaming.
>>
>>
>>
>> Sigh.
>>
>>
>>
>> On Tue, Jun 11, 2019 at 3:11 PM Carl Mueller <
>> carl.mueller@smartthings.com> wrote:
>>
>> We had a three-DC (asia-tokyo/europe/us) cassandra 2.2.13 cluster, AWS,
>> IPV6
>>
>> Needed to scale out the asia datacenter, which was 5 nodes, europe and us
>> were 25 nodes
>>
>> We were running into bootstrapping issues where the new node failed to
>> bootstrap/stream, it failed with
>>
>>
>>
>> "java.lang.RuntimeException: A node required to move the data
>> consistently is down"
>>
>>
>>
>> ...even though they were all up based on nodetool status prior to adding
>> the node.
>>
>> First we increased the phi_convict_threshold to 12, and that did not
>> help.
>>
>> CASSANDRA-12281 appeared similar to what we had problems with, but I
>> don't think we hit that. Somewhere in there someone wrote
>>
>>
>>
>> "For us, the workaround is either deleting the data (then bootstrap
>> again), or increasing the ring_delay_ms. And the larger the cluster is, the
>> longer ring_delay_ms is needed. Based on our tests, for a 40 nodes cluster,
>> it requires ring_delay_ms to be >50seconds. For a 70 nodes cluster,
>> >100seconds. Default is 30seconds."
>>
>> Given the WAN nature or our DCs, we used ring_delay_ms to 100 seconds and
>> it finally worked.
>>
>> side note:
>>
>> During the rolling restarts for setting phi_convict_threshold we observed
>> quite a lot of status map variance between nodes (we have a program to poll
>> all of a datacenter or cluster's view of the gossipinfo and statuses. AWS
>> appears to have variance in networking based on the phi_convict_threshold
>> advice, I'm not sure if our difficulties were typical in that regard and/or
>> if our IPV6 and/or globally distributed datacenters were exacerbating
>> factors.
>>
>> We could not reproduce this in loadtest, although loadtest is only eu and
>> us (but is IPV6)
>>
>>
Re: postmortem on 2.2.13 scale out difficulties
Posted by Carl Mueller <ca...@smartthings.com.INVALID>.
One node at a time: yes that is what we are doing
We have not tried the streaming_socket_timeout_in_ms. It is currently 24
hours. (```streaming_socket_timeout_in_ms=86400000```) which would cover
the bootstrap timeframe we have seen before (1-2 hours per node)
Since it joins with no data, it is serving erroneous data. We may try
bootstrap rejoin and the JVM_OPT.... The node appears to think it has
bootstrapped even though the gossipinfo shows the new node has a different
schema version.
We had scaled EU and US from 5 --> 25 without incident (one at a time), and
since we increased ring_delay_ms worked haphazardly to get us four joins,
and since then failure.
The debug log shows:
DEBUG [GossipStage:1] 2019-06-12 15:20:08,559 StorageService.java:1998 -
New node /2a05:d018:af:1108:86f4:d628:6bca:6983 at token 9200286188287490229
DEBUG [GossipStage:1] 2019-06-12 15:20:08,559 StorageService.java:1998 -
New node /2a05:d018:af:1108:86f4:d628:6bca:6983 at token 950856676715905899
DEBUG [GossipStage:1] 2019-06-12 15:20:08,563 MigrationManager.java:96 -
Not pulling schema because versions match or shouldPullSchemaFrom returned
false
INFO [GossipStage:1] 2019-06-12 15:20:08,563 TokenMetadata.java:464 -
Updating topology for /2a05:d018:af:1108:86f4:d628:6bca:6983
INFO [GossipStage:1] 2019-06-12 15:20:08,564 TokenMetadata.java:464 -
Updating topology for /2a05:d018:af:1108:86f4:d628:6bca:6983
DEBUG [GossipStage:1] 2019-06-12 15:20:08,565 MigrationManager.java:96 -
Not pulling schema because versions match or shouldPullSchemaFrom returned
false
INFO [GossipStage:1] 2019-06-12 15:20:08,565 Gossiper.java:1027 - Node
/2600:1f18:4b4:5903:64af:955e:b65:8d83 is now part of the cluster
DEBUG [GossipStage:1] 2019-06-12 15:20:08,587 StorageService.java:1928 -
Node /2600:1f18:4b4:5903:64af:955e:b65:8d83 state NORMAL, token
[-1028768087263234868, ...<bunch of tokens>..., 921670352349030554]
DEBUG [GossipStage:1] 2019-06-12 15:20:08,588 StorageService.java:1998 -
New node /2600:1f18:4b4:5903:64af:955e:b65:8d83 at token
-1028768087263234868
DEBUG [GossipStage:1] 2019-06-12 15:20:08,588 StorageService.java:1998 -
New node /2600:1f18:4b4:5903:64af:955e:b65:8d83 at token
-1045740236536355596
DEBUG [GossipStage:1] 2019-06-12 15:20:08,589 StorageService.java:1998 -
New node /2600:1f18:4b4:5903:64af:955e:b65:8d83 at token
-1184422937682103096
DEBUG [GossipStage:1] 2019-06-12 15:20:08,589 StorageService.java:1998 -
New node /2600:1f18:4b4:5903:64af:955e:b65:8d83 at token
-1201924032068728250
All the nodes appear to be reporting "Not pulling schema becuase versions
match or shouldPullSchmeaFrom returned false. That code
(MigrationManager.java) makes reference to a "gossip only" node, did we get
stuck in that somehow.
On Wed, Jun 12, 2019 at 11:45 AM ZAIDI, ASAD A <az...@att.com> wrote:
>
>
>
>
> Adding one node at a time – is that successful?
>
> Check value of streaming_socket_timeout_in_ms parameter in cassandra.yaml
> and increase if needed.
>
> Have you tried Nodetool bootstrap resume & jvm option i.e.
> JVM_OPTS="$JVM_OPTS -Dcassandra.consistent.rangemovement=false" ?
>
>
>
>
>
> *From:* Carl Mueller [mailto:carl.mueller@smartthings.com.INVALID]
> *Sent:* Wednesday, June 12, 2019 11:35 AM
> *To:* user@cassandra.apache.org
> *Subject:* Re: postmortem on 2.2.13 scale out difficulties
>
>
>
> We only were able to scale out four nodes and then failures started
> occurring, including multiple instances of nodes joining a cluster without
> streaming.
>
>
>
> Sigh.
>
>
>
> On Tue, Jun 11, 2019 at 3:11 PM Carl Mueller <ca...@smartthings.com>
> wrote:
>
> We had a three-DC (asia-tokyo/europe/us) cassandra 2.2.13 cluster, AWS,
> IPV6
>
> Needed to scale out the asia datacenter, which was 5 nodes, europe and us
> were 25 nodes
>
> We were running into bootstrapping issues where the new node failed to
> bootstrap/stream, it failed with
>
>
>
> "java.lang.RuntimeException: A node required to move the data consistently
> is down"
>
>
>
> ...even though they were all up based on nodetool status prior to adding
> the node.
>
> First we increased the phi_convict_threshold to 12, and that did not help.
>
> CASSANDRA-12281 appeared similar to what we had problems with, but I don't
> think we hit that. Somewhere in there someone wrote
>
>
>
> "For us, the workaround is either deleting the data (then bootstrap
> again), or increasing the ring_delay_ms. And the larger the cluster is, the
> longer ring_delay_ms is needed. Based on our tests, for a 40 nodes cluster,
> it requires ring_delay_ms to be >50seconds. For a 70 nodes cluster,
> >100seconds. Default is 30seconds."
>
> Given the WAN nature or our DCs, we used ring_delay_ms to 100 seconds and
> it finally worked.
>
> side note:
>
> During the rolling restarts for setting phi_convict_threshold we observed
> quite a lot of status map variance between nodes (we have a program to poll
> all of a datacenter or cluster's view of the gossipinfo and statuses. AWS
> appears to have variance in networking based on the phi_convict_threshold
> advice, I'm not sure if our difficulties were typical in that regard and/or
> if our IPV6 and/or globally distributed datacenters were exacerbating
> factors.
>
> We could not reproduce this in loadtest, although loadtest is only eu and
> us (but is IPV6)
>
>