[
https://issues.apache.org/jira/browse/CASSANDRA-15158?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17191705#comment-17191705
]
Stefan Miklosovic edited comment on CASSANDRA-15158 at 9/7/20, 1:49 PM:
------------------------------------------------------------------------
I am getting this exception on totally clean node, I am bootstrapping a cluster
of 3 nodes:
{code:java}
cassandra_node_1 | INFO [ScheduledTasks:1] 2020-09-07 15:10:13,037
TokenMetadata.java:517 - Updating topology for all endpoints that have changed
cassandra_node_1 | INFO [HANDSHAKE-spark-master-1/172.19.0.5] 2020-09-07
15:10:13,311 OutboundTcpConnection.java:561 - Handshaking version with
spark-master-1/172.19.0.5
cassandra_node_1 | INFO [GossipStage:1] 2020-09-07 15:10:13,870
Gossiper.java:1141 - Node /172.19.0.5 is now part of the cluster
cassandra_node_1 | INFO [GossipStage:1] 2020-09-07 15:10:13,904
TokenMetadata.java:497 - Updating topology for /172.19.0.5
cassandra_node_1 | INFO [GossipStage:1] 2020-09-07 15:10:13,907
TokenMetadata.java:497 - Updating topology for /172.19.0.5
cassandra_node_1 | INFO [GossipStage:1] 2020-09-07 15:10:14,052
Gossiper.java:1103 - InetAddress /172.19.0.5 is now UP
cassandra_node_1 | WARN [MessagingService-Incoming-/172.19.0.5] 2020-09-07
15:10:14,119 IncomingTcpConnection.java:103 - UnknownColumnFamilyException
reading from socket; closing
cassandra_node_1 | org.apache.cassandra.db.UnknownColumnFamilyException:
Couldn't find table for cfId 5bc52802-de25-35ed-aeab-188eecebb090. If a table
was just created, this is likely due to the schema not being fully propagated.
Please wait for schema agreement on table creation.
cassandra_node_1 | at
org.apache.cassandra.config.CFMetaData$Serializer.deserialize(CFMetaData.java:1578)
~[apache-cassandra-3.11.9-SNAPSHOT.jar:3.11.9-SNAPSHOT]
cassandra_node_1 | at
org.apache.cassandra.db.partitions.PartitionUpdate$PartitionUpdateSerializer.deserialize30(PartitionUpdate.java:899)
~[apache-cassandra-3.11.9-SNAPSHOT.jar:3.11.9-SNAPSHOT]
cassandra_node_1 | at
org.apache.cassandra.db.partitions.PartitionUpdate$PartitionUpdateSerializer.deserialize(PartitionUpdate.java:874)
~[apache-cassandra-3.11.9-SNAPSHOT.jar:3.11.9-SNAPSHOT]
cassandra_node_1 | at
org.apache.cassandra.db.Mutation$MutationSerializer.deserialize(Mutation.java:415)
~[apache-cassandra-3.11.9-SNAPSHOT.jar:3.11.9-SNAPSHOT]
cassandra_node_1 | at
org.apache.cassandra.db.Mutation$MutationSerializer.deserialize(Mutation.java:434)
~[apache-cassandra-3.11.9-SNAPSHOT.jar:3.11.9-SNAPSHOT]
cassandra_node_1 | at
org.apache.cassandra.db.Mutation$MutationSerializer.deserialize(Mutation.java:371)
~[apache-cassandra-3.11.9-SNAPSHOT.jar:3.11.9-SNAPSHOT]
cassandra_node_1 | at
org.apache.cassandra.net.MessageIn.read(MessageIn.java:123)
~[apache-cassandra-3.11.9-SNAPSHOT.jar:3.11.9-SNAPSHOT]
cassandra_node_1 | at
org.apache.cassandra.net.IncomingTcpConnection.receiveMessage(IncomingTcpConnection.java:195)
~[apache-cassandra-3.11.9-SNAPSHOT.jar:3.11.9-SNAPSHOT]
cassandra_node_1 | at
org.apache.cassandra.net.IncomingTcpConnection.receiveMessages(IncomingTcpConnection.java:183)
~[apache-cassandra-3.11.9-SNAPSHOT.jar:3.11.9-SNAPSHOT]
{code}
That cfId stands for system_auth/roles. It seems like we are applying changes
before schema agreement has occured so that table is not there yet to apply
mutations against.
This is the log from the second node. The first one booted fine, the second one
throws this, the third one boots fine. It seems like eventually everything is
just fine however that exception is ... concerning.
was (Author: stefan.miklosovic):
I am getting this exception on totally clean node, I am bootstrapping a cluster
of 3 nodes:
{code:java}
cassandra_node_1 | INFO [ScheduledTasks:1] 2020-09-07 15:10:13,037
TokenMetadata.java:517 - Updating topology for all endpoints that have changed
cassandra_node_1 | INFO [HANDSHAKE-spark-master-1/172.19.0.5] 2020-09-07
15:10:13,311 OutboundTcpConnection.java:561 - Handshaking version with
spark-master-1/172.19.0.5
cassandra_node_1 | INFO [GossipStage:1] 2020-09-07 15:10:13,870
Gossiper.java:1141 - Node /172.19.0.5 is now part of the cluster
cassandra_node_1 | INFO [GossipStage:1] 2020-09-07 15:10:13,904
TokenMetadata.java:497 - Updating topology for /172.19.0.5
cassandra_node_1 | INFO [GossipStage:1] 2020-09-07 15:10:13,907
TokenMetadata.java:497 - Updating topology for /172.19.0.5
cassandra_node_1 | INFO [GossipStage:1] 2020-09-07 15:10:14,052
Gossiper.java:1103 - InetAddress /172.19.0.5 is now UP
cassandra_node_1 | WARN [MessagingService-Incoming-/172.19.0.5] 2020-09-07
15:10:14,119 IncomingTcpConnection.java:103 - UnknownColumnFamilyException
reading from socket; closing
cassandra_node_1 | org.apache.cassandra.db.UnknownColumnFamilyException:
Couldn't find table for cfId 5bc52802-de25-35ed-aeab-188eecebb090. If a table
was just created, this is likely due to the schema not being fully propagated.
Please wait for schema agreement on table creation.
cassandra_node_1 | at
org.apache.cassandra.config.CFMetaData$Serializer.deserialize(CFMetaData.java:1578)
~[apache-cassandra-3.11.9-SNAPSHOT.jar:3.11.9-SNAPSHOT]
cassandra_node_1 | at
org.apache.cassandra.db.partitions.PartitionUpdate$PartitionUpdateSerializer.deserialize30(PartitionUpdate.java:899)
~[apache-cassandra-3.11.9-SNAPSHOT.jar:3.11.9-SNAPSHOT]
cassandra_node_1 | at
org.apache.cassandra.db.partitions.PartitionUpdate$PartitionUpdateSerializer.deserialize(PartitionUpdate.java:874)
~[apache-cassandra-3.11.9-SNAPSHOT.jar:3.11.9-SNAPSHOT]
cassandra_node_1 | at
org.apache.cassandra.db.Mutation$MutationSerializer.deserialize(Mutation.java:415)
~[apache-cassandra-3.11.9-SNAPSHOT.jar:3.11.9-SNAPSHOT]
cassandra_node_1 | at
org.apache.cassandra.db.Mutation$MutationSerializer.deserialize(Mutation.java:434)
~[apache-cassandra-3.11.9-SNAPSHOT.jar:3.11.9-SNAPSHOT]
cassandra_node_1 | at
org.apache.cassandra.db.Mutation$MutationSerializer.deserialize(Mutation.java:371)
~[apache-cassandra-3.11.9-SNAPSHOT.jar:3.11.9-SNAPSHOT]
cassandra_node_1 | at
org.apache.cassandra.net.MessageIn.read(MessageIn.java:123)
~[apache-cassandra-3.11.9-SNAPSHOT.jar:3.11.9-SNAPSHOT]
cassandra_node_1 | at
org.apache.cassandra.net.IncomingTcpConnection.receiveMessage(IncomingTcpConnection.java:195)
~[apache-cassandra-3.11.9-SNAPSHOT.jar:3.11.9-SNAPSHOT]
cassandra_node_1 | at
org.apache.cassandra.net.IncomingTcpConnection.receiveMessages(IncomingTcpConnection.java:183)
~[apache-cassandra-3.11.9-SNAPSHOT.jar:3.11.9-SNAPSHOT]
{code}
That cfId stands for system_auth/roles. It seems like we are applying changes
before schema agreement has occured so that table is not there yet to apply
mutations against.
> Wait for schema agreement rather than in flight schema requests when
> bootstrapping
> ----------------------------------------------------------------------------------
>
> Key: CASSANDRA-15158
> URL: https://issues.apache.org/jira/browse/CASSANDRA-15158
> Project: Cassandra
> Issue Type: Bug
> Components: Cluster/Gossip, Cluster/Schema
> Reporter: Vincent White
> Assignee: Blake Eggleston
> Priority: Normal
> Time Spent: 10m
> Remaining Estimate: 0h
>
> Currently when a node is bootstrapping we use a set of latches
> (org.apache.cassandra.service.MigrationTask#inflightTasks) to keep track of
> in-flight schema pull requests, and we don't proceed with
> bootstrapping/stream until all the latches are released (or we timeout
> waiting for each one). One issue with this is that if we have a large schema,
> or the retrieval of the schema from the other nodes was unexpectedly slow
> then we have no explicit check in place to ensure we have actually received a
> schema before we proceed.
> While it's possible to increase "migration_task_wait_in_seconds" to force the
> node to wait on each latche longer, there are cases where this doesn't help
> because the callbacks for the schema pull requests have expired off the
> messaging service's callback map
> (org.apache.cassandra.net.MessagingService#callbacks) after
> request_timeout_in_ms (default 10 seconds) before the other nodes were able
> to respond to the new node.
> This patch checks for schema agreement between the bootstrapping node and the
> rest of the live nodes before proceeding with bootstrapping. It also adds a
> check to prevent the new node from flooding existing nodes with simultaneous
> schema pull requests as can happen in large clusters.
> Removing the latch system should also prevent new nodes in large clusters
> getting stuck for extended amounts of time as they wait
> `migration_task_wait_in_seconds` on each of the latches left orphaned by the
> timed out callbacks.
>
> ||3.11||
> |[PoC|https://github.com/apache/cassandra/compare/cassandra-3.11...vincewhite:check_for_schema]|
> |[dtest|https://github.com/apache/cassandra-dtest/compare/master...vincewhite:wait_for_schema_agreement]|
>
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]