Comment 19 for bug 1721416

Revision history for this message
mkheni (mkheni) wrote :

INFO [Native-Transport-Requests-1] 2017-11-09 15:59:11,914 MigrationManager.java:343 - Create new table: org.apache.cassandra.config.CFMetaData@77ba86ad[cfId=d3ba6ca0-c538-11e7-a44e-879b1e3437da,ksName=ContrailAnalyticsCql,cfName=messagetabletimestamp,flags=[COMPOUND],params=TableParams{comment=, read_repair_chance=0.0, dclocal_read_repair_chance=0.1, bloom_filter_fp_chance=0.01, crc_check_chance=1.0, gc_grace_seconds=0, default_time_to_live=0, memtable_flush_period_in_ms=0, min_index_interval=128, max_index_interval=2048, speculative_retry=99PERCENTILE, caching={'keys' : 'ALL', 'rows_per_partition' : 'NONE'}, compaction=CompactionParams{class=org.apache.cassandra.db.compaction.SizeTieredCompactionStrategy, options={min_threshold=4, max_threshold=32}}, compression=org.apache.cassandra.schema.CompressionParams@cd64306, extensions={}, cdc=false},comparator=comparator(org.apache.cassandra.db.marshal.Int32Type, org.apache.cassandra.db.marshal.UUIDType),partitionColumns=[[] | []],partitionKeyColumns=[key, key2],clusteringColumns=[column1, column2],keyValidator=org.apache.cassandra.db.marshal.CompositeType(org.apache.cassandra.db.marshal.Int32Type,org.apache.cassandra.db.marshal.Int32Type),columnMetadata=[key2, key, column1, column2],droppedColumns={},triggers=[],indexes=[]]

// no logs for ContrailAnalyticsCql keyspace for ~20 seconds

INFO [Native-Transport-Requests-4] 2017-11-09 15:59:33,968 MigrationManager.java:343 - Create new table: org.apache.cassandra.config.CFMetaData@6026e09d[cfId=e0df9900-c538-11e7-a44e-879b1e3437da,ksName=ContrailAnalyticsCql,cfName=messagetabletimestamp,flags=[COMPOUND],params=TableParams{comment=, read_repair_chance=0.0, dclocal_read_repair_chance=0.1, bloom_filter_fp_chance=0.01, crc_check_chance=1.0, gc_grace_seconds=0, default_time_to_live=0, memtable_flush_period_in_ms=0, min_index_interval=128, max_index_interval=2048, speculative_retry=99PERCENTILE, caching={'keys' : 'ALL', 'rows_per_partition' : 'NONE'}, compaction=CompactionParams{class=org.apache.cassandra.db.compaction.SizeTieredCompactionStrategy, options={min_threshold=4, max_threshold=32}}, compression=org.apache.cassandra.schema.CompressionParams@cd64306, extensions={}, cdc=false},comparator=comparator(org.apache.cassandra.db.marshal.Int32Type, org.apache.cassandra.db.marshal.UUIDType),partitionColumns=[[] | []],partitionKeyColumns=[key, key2],clusteringColumns=[column1, column2],keyValidator=org.apache.cassandra.db.marshal.CompositeType(org.apache.cassandra.db.marshal.Int32Type,org.apache.cassandra.db.marshal.Int32Type),columnMetadata=[key2, key, column1, column2],droppedColumns={},triggers=[],indexes=[]]

INFO [MigrationStage:1] 2017-11-09 15:59:36,999 ColumnFamilyStore.java:406 - Initializing ContrailAnalyticsCql.messagetabletimestamp
DEBUG [MigrationStage:1] 2017-11-09 15:59:37,000 Schema.java:425 - Adding org.apache.cassandra.config.CFMetaData@323ed862[cfId=d3ba6ca0-c538-11e7-a44e-879b1e3437da,ksName=ContrailAnalyticsCql,cfName=messagetabletimestamp,flags=[COMPOUND],params=TableParams{comment=, read_repair_chance=0.0, dclocal_read_repair_chance=0.1, bloom_filter_fp_chance=0.01, crc_check_chance=1.0, gc_grace_seconds=0, default_time_to_live=0, memtable_flush_period_in_ms=0, min_index_interval=128, max_index_interval=2048, speculative_retry=99PERCENTILE, caching={'keys' : 'ALL', 'rows_per_partition' : 'NONE'}, compaction=CompactionParams{class=org.apache.cassandra.db.compaction.SizeTieredCompactionStrategy, options={max_threshold=32, min_threshold=4}}, compression=org.apache.cassandra.schema.CompressionParams@cd64306, extensions={}, cdc=false},comparator=comparator(org.apache.cassandra.db.marshal.Int32Type, org.apache.cassandra.db.marshal.UUIDType),partitionColumns=[[] | []],partitionKeyColumns=[key, key2],clusteringColumns=[column1, column2],keyValidator=org.apache.cassandra.db.marshal.CompositeType(org.apache.cassandra.db.marshal.Int32Type,org.apache.cassandra.db.marshal.Int32Type),columnMetadata=[key2, key, column1, column2],droppedColumns={},triggers=[],indexes=[]] to cfIdMap

DEBUG [InternalResponseStage:9] 2017-11-09 15:59:40,601 CFMetaData.java:768 - applying org.apache.cassandra.config.CFMetaData@72a0dd39[cfId=e0df9900-c538-11e7-a44e-879b1e3437da,ksName=ContrailAnalyticsCql,cfName=messagetabletimestamp,flags=[COMPOUND],params=TableParams{comment=, read_repair_chance=0.0, dclocal_read_repair_chance=0.1, bloom_filter_fp_chance=0.01, crc_check_chance=1.0, gc_grace_seconds=0, default_time_to_live=0, memtable_flush_period_in_ms=0, min_index_interval=128, max_index_interval=2048, speculative_retry=99PERCENTILE, caching={'keys' : 'ALL', 'rows_per_partition' : 'NONE'}, compaction=CompactionParams{class=org.apache.cassandra.db.compaction.SizeTieredCompactionStrategy, options={max_threshold=32, min_threshold=4}}, compression=org.apache.cassandra.schema.CompressionParams@cd64306, extensions={}, cdc=false},comparator=comparator(org.apache.cassandra.db.marshal.Int32Type, org.apache.cassandra.db.marshal.UUIDType),partitionColumns=[[] | []],partitionKeyColumns=[key, key2],clusteringColumns=[column1, column2],keyValidator=org.apache.cassandra.db.marshal.CompositeType(org.apache.cassandra.db.marshal.Int32Type,org.apache.cassandra.db.marshal.Int32Type),columnMetadata=[key2, key, column1, column2],droppedColumns={},triggers=[],indexes=[]] to org.apache.cassandra.config.CFMetaData@323ed862[cfId=d3ba6ca0-c538-11e7-a44e-879b1e3437da,ksName=ContrailAnalyticsCql,cfName=messagetabletimestamp,flags=[COMPOUND],params=TableParams{comment=, read_repair_chance=0.0, dclocal_read_repair_chance=0.1, bloom_filter_fp_chance=0.01, crc_check_chance=1.0, gc_grace_seconds=0, default_time_to_live=0, memtable_flush_period_in_ms=0, min_index_interval=128, max_index_interval=2048, speculative_retry=99PERCENTILE, caching={'keys' : 'ALL', 'rows_per_partition' : 'NONE'}, compaction=CompactionParams{class=org.apache.cassandra.db.compaction.SizeTieredCompactionStrategy, options={max_threshold=32, min_threshold=4}}, compression=org.apache.cassandra.schema.CompressionParams@cd64306, extensions={}, cdc=false},comparator=comparator(org.apache.cassandra.db.marshal.Int32Type, org.apache.cassandra.db.marshal.UUIDType),partitionColumns=[[] | []],partitionKeyColumns=[key, key2],clusteringColumns=[column1, column2],keyValidator=org.apache.cassandra.db.marshal.CompositeType(org.apache.cassandra.db.marshal.Int32Type,org.apache.cassandra.db.marshal.Int32Type),columnMetadata=[key2, key, column1, column2],droppedColumns={},triggers=[],indexes=[]]

ERROR [InternalResponseStage:9] 2017-11-09 15:59:40,603 MigrationTask.java:95 - Configuration exception merging remote schema
org.apache.cassandra.exceptions.ConfigurationException: Column family ID mismatch (found e0df9900-c538-11e7-a44e-879b1e3437da; expected d3ba6ca0-c538-11e7-a44e-879b1e3437da)
    at org.apache.cassandra.config.CFMetaData.validateCompatibility(CFMetaData.java:808) ~[apache-cassandra-3.10.jar:3.10]
    at org.apache.cassandra.config.CFMetaData.apply(CFMetaData.java:770) ~[apache-cassandra-3.10.jar:3.10]
    at org.apache.cassandra.config.Schema.updateTable(Schema.java:621) ~[apache-cassandra-3.10.jar:3.10]
    at org.apache.cassandra.schema.SchemaKeyspace.updateKeyspace(SchemaKeyspace.java:1376) ~[apache-cassandra-3.10.jar:3.10]
    at org.apache.cassandra.schema.SchemaKeyspace.mergeSchema(SchemaKeyspace.java:1332) ~[apache-cassandra-3.10.jar:3.10]
    at org.apache.cassandra.schema.SchemaKeyspace.mergeSchemaAndAnnounceVersion(SchemaKeyspace.java:1282) ~[apache-cassandra-3.10.jar:3.10]
    at org.apache.cassandra.service.MigrationTask$1.response(MigrationTask.java:91) ~[apache-cassandra-3.10.jar:3.10]
    at org.apache.cassandra.net.ResponseVerbHandler.doVerb(ResponseVerbHandler.java:53) [apache-cassandra-3.10.jar:3.10]
    at org.apache.cassandra.net.MessageDeliveryTask.run(MessageDeliveryTask.java:66) [apache-cassandra-3.10.jar:3.10]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_121]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_121]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_121]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_121]
    at org.apache.cassandra.concurrent.NamedThreadFactory.lambda$threadLocalDeallocator$0(NamedThreadFactory.java:79) [apache-cassandra-3.10.jar:3.10]
    at java.lang.Thread.run(Thread.java:745) ~[na:1.8.0_121]

The most probable theory so far is -
first an attempt to create table was done at 2017-11-09 15:59:11,914, after that there was no activity related to this and hence driver might have returned an time-out error, Causing collector to issue Create Table again (at 2017-11-09 15:59:33,968) before the first table create could actually be stored in CFIdMap. After that, the table from the first attempt got stored in CFIdMap (at 2017-11-09 15:59:37,000) and when table from second attempt tried to store it (at 2017-11-09 15:59:40,601), we hit the schema-mismatch

Still Need to confirm that the first attempt failed due to request time-out error